#At file:///home/acorreia/workspace.sun/playground.mysql/bug-38826-mysql-5.0/
2704 Alfranio Correia 2008-11-02
Fixed race condition while purging logs. Now, we update the index file first and then remove the files.
BUG#38826.
modified:
mysql-test/r/binlog_index.result
sql/log.cc
sql/sql_class.h
per-file messages:
mysql-test/r/binlog_index.result
Fixed result. When logs are purged by date, there may be two warnings if a bin log cannot be my_stat. The first in MYSQL_LOG::purge_logs_before_date and the second in MYSQL_LOG::purge_logs.
sql/log.cc
Fixed race condition while purging logs. We use a temporary buffer to store the name of the files, update the index and right after we start removing the files.
The method MYSQL_LOG::purge_logs_before_date was refactored and now only figures out which is the last file that needs to be purged and calls the method MYSQL_LOG::purge_logs.
sql/sql_class.h
Introduced a buffer/temp file to be used while purging logs so that the index file can be updated before deleting files from disk.
=== modified file 'mysql-test/r/binlog_index.result'
--- a/mysql-test/r/binlog_index.result 2008-04-01 10:29:53 +0000
+++ b/mysql-test/r/binlog_index.result 2008-11-02 20:16:55 +0000
@@ -21,6 +21,7 @@ flush logs;
*** must be a warning master-bin.000001 was not found ***
Warnings:
Warning 1477 Being purged log MYSQLTEST_VARDIR/log/master-bin.000001 was not found
+Warning 1477 Being purged log MYSQLTEST_VARDIR/log/master-bin.000001 was not found
*** must show one record, of the active binlog, left in the index file after PURGE ***
show binary logs;
Log_name File_size
=== modified file 'sql/log.cc'
--- a/sql/log.cc 2008-07-24 12:28:21 +0000
+++ b/sql/log.cc 2008-11-02 20:16:55 +0000
@@ -417,6 +417,7 @@ MYSQL_LOG::MYSQL_LOG()
index_file_name[0] = 0;
bzero((char*) &log_file,sizeof(log_file));
bzero((char*) &index_file, sizeof(index_file));
+ bzero((char*) &purge_temp, sizeof(purge_temp));
}
/* this is called only once */
@@ -1199,8 +1200,37 @@ int MYSQL_LOG::purge_logs(const char *to
if (need_mutex)
pthread_mutex_lock(&LOCK_index);
- if ((error=find_log_pos(&log_info, to_log, 0 /*no mutex*/)))
+
+ if ((error=find_log_pos(&log_info, to_log, 0 /*no mutex*/)))
+ {
+ sql_print_error("MYSQL_LOG::purge_logs was called with file %s not "
+ "listed in the index.", to_log);
goto err;
+ }
+
+ /*
+ For crash recovery reasons the index needs to be updated before
+ any files are deleted. Move files to be deleted into a temp file
+ to be processed after the index is updated.
+ */
+ if (!my_b_inited(&purge_temp))
+ {
+ if (error=open_cached_file(&purge_temp, mysql_tmpdir, TEMP_PREFIX,
+ DISK_BUFFER_SIZE, MYF(MY_WME)))
+ {
+ sql_print_error("MYSQL_LOG::purge_logs failed to open purge_temp");
+ goto err;
+ }
+ }
+ else
+ {
+ if (error=reinit_io_cache(&purge_temp, WRITE_CACHE, 0, 0, 1))
+ {
+ sql_print_error("MYSQL_LOG::purge_logs failed to reinit purge_temp "
+ "for write");
+ goto err;
+ }
+ }
/*
File name exists in index file; delete until we find this file
@@ -1211,6 +1241,59 @@ int MYSQL_LOG::purge_logs(const char *to
while ((strcmp(to_log,log_info.log_file_name) || (exit_loop=included)) &&
!log_in_use(log_info.log_file_name))
{
+ if ((error=my_b_write(&purge_temp, (byte*)log_info.log_file_name,
+ strlen(log_info.log_file_name))) ||
+ (error=my_b_write(&purge_temp, (byte*)"\n", 1)))
+ {
+ sql_print_error("MYSQL_LOG::purge_logs failed to copy %s to purge_temp",
+ log_info.log_file_name);
+ goto err;
+ }
+
+ if (find_next_log(&log_info, 0) || exit_loop)
+ break;
+ }
+
+ /* We know how many files to delete. Update index file. */
+ if (error=update_log_index(&log_info, need_update_threads))
+ {
+ sql_print_error("MSYQL_LOG::purge_logs failed to update the index file");
+ goto err;
+ }
+
+ DBUG_EXECUTE_IF("crash_after_update_index", abort(););
+
+ /* Switch purge_temp for read. */
+ if (error=reinit_io_cache(&purge_temp, READ_CACHE, 0, 0, 0))
+ {
+ sql_print_error("MSYQL_LOG::purge_logs failed to reinit purge_temp "
+ "for read");
+ goto err;
+ }
+
+ /* Read each entry from purge_temp and delete the file. */
+ for (;;)
+ {
+ uint length;
+
+ if ((length=my_b_gets(&purge_temp, log_info.log_file_name,
+ FN_REFLEN)) <= 1)
+ {
+ if (purge_temp.error)
+ {
+ error= purge_temp.error;
+ sql_print_error("MSYQL_LOG::purge_logs error %d reading from "
+ "purge_temp", error);
+ goto err;
+ }
+
+ /* Reached EOF */
+ break;
+ }
+
+ /* Get rid of the trailing '\n' */
+ log_info.log_file_name[length-1]= 0;
+
MY_STAT s;
if (!my_stat(log_info.log_file_name, &s, MYF(0)))
{
@@ -1304,15 +1387,7 @@ int MYSQL_LOG::purge_logs(const char *to
}
}
}
- if (find_next_log(&log_info, 0) || exit_loop)
- break;
}
-
- /*
- If we get killed -9 here, the sysadmin would have to edit
- the log index file after restart - otherwise, this should be safe
- */
- error= update_log_index(&log_info, need_update_threads);
err:
if (need_mutex)
@@ -1326,7 +1401,6 @@ err:
SYNOPSIS
purge_logs_before_date()
- thd Thread pointer
before_date Delete all log files before given date.
NOTES
@@ -1343,6 +1417,7 @@ err:
int MYSQL_LOG::purge_logs_before_date(time_t purge_time)
{
int error;
+ char to_log[FN_REFLEN];
LOG_INFO log_info;
MY_STAT stat_area;
THD *thd= current_thd;
@@ -1351,11 +1426,8 @@ int MYSQL_LOG::purge_logs_before_date(ti
pthread_mutex_lock(&LOCK_index);
- /*
- Delete until we find curren file
- or a file that is used or a file
- that is older than purge_time.
- */
+ to_log[0] = 0;
+
if ((error=find_log_pos(&log_info, NullS, 0 /*no mutex*/)))
goto err;
@@ -1405,54 +1477,18 @@ int MYSQL_LOG::purge_logs_before_date(ti
}
else
{
- if (stat_area.st_mtime >= purge_time)
+ if (stat_area.st_mtime < purge_time)
+ strmake(to_log,
+ log_info.log_file_name,
+ sizeof(log_info.log_file_name));
+ else
break;
- if (my_delete(log_info.log_file_name, MYF(0)))
- {
- if (my_errno == ENOENT)
- {
- /* It's not fatal even if we can't delete a log file */
- if (thd)
- {
- push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
- ER_LOG_PURGE_NO_FILE, ER(ER_LOG_PURGE_NO_FILE),
- log_info.log_file_name);
- }
- sql_print_information("Failed to delete file '%s'",
- log_info.log_file_name);
- my_errno= 0;
- }
- else
- {
- if (thd)
- {
- push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_ERROR,
- ER_BINLOG_PURGE_FATAL_ERR,
- "a problem with deleting %s; "
- "consider examining correspondence "
- "of your binlog index file "
- "to the actual binlog files",
- log_info.log_file_name);
- }
- else
- {
- sql_print_information("Failed to delete log file '%s'",
- log_info.log_file_name);
- }
- error= LOG_INFO_FATAL;
- goto err;
- }
- }
}
if (find_next_log(&log_info, 0))
break;
}
- /*
- If we get killed -9 here, the sysadmin would have to edit
- the log index file after restart - otherwise, this should be safe
- */
- error= update_log_index(&log_info, 1);
+ error = (to_log[0] ? purge_logs(to_log, 1, 0, 1, (ulonglong *) 0) : 0);
err:
pthread_mutex_unlock(&LOCK_index);
=== modified file 'sql/sql_class.h'
--- a/sql/sql_class.h 2008-09-17 06:34:00 +0000
+++ b/sql/sql_class.h 2008-11-02 20:16:55 +0000
@@ -205,6 +205,13 @@ class MYSQL_LOG: public TC_LOG
time_t last_time,query_start;
IO_CACHE log_file;
IO_CACHE index_file;
+ /*
+ purge_temp is a temp file used in purge_logs so that the index file
+ can be updated before deleting files from disk, yielding better crash
+ recovery. It is created on demand the first time purge_logs is called
+ and then reused for subsequent calls. It is cleaned up in cleanup().
+ */
+ IO_CACHE purge_temp;
char *name;
char time_buff[20],db[NAME_LEN+1];
char log_file_name[FN_REFLEN],index_file_name[FN_REFLEN];
| Thread |
|---|
| • bzr commit into mysql-5.0-bugteam branch (alfranio.correia:2704) Bug#38826 | Alfranio Correia | 2 Nov |
