Luís Soares wrote:
> Hi Alfranio,
>
> Nice Work. Please find my review comments below.
>
> STATUS
> ------
>
> Not Approved.
>
> REQUIRED CHANGES
> ----------------
>
> RC1. Please revert changes to white spaces that are not
> meaningful, and unnecessary changes. They can cause
> spurious merge problems.
ok.
>
> RC2. Why protect some parts of the code with HAVE_REPLICATION?
> Seems these parts are probably not replication
> specific. Please, double check and if they are not, remove
> the guards. See comments inline.
The code does not compile without the IFs.
>
> RC3. Please, don't duplicate code. Maybe, wrap the duplicate
> code into some private methods. See comments inline.
Ok. Fixed.
>
> RC4. Please, fix the message in some sql_print_warning. See
> comments inline.
Done. Most likely, you meant sql_print_error.
>
> RC5. Should you check that return value of find_log_pos is
> LOG_INFO_EOF ? You can get LOG_INFO_IO which does not
> necessarily mean that no entry was found. See comments
> inline.
>
>
> REQUESTS
> --------
>
> R1. The test case still seems not platform agnostic. Have you
> run it on windows? The paths from the cat_file may cause
> the test to fail. Perhaps to be safe mask/remove
> those (replace_result? replace_regex ?). Maybe something
> like:
>
> -- eval SET @index=LOAD_FILE('$index_file')
> -- replace_regex /\.[\\\/]master/master/
> SELECT @index;
I will check that.
>
> SUGGESTIONS
> -----------
>
> S1. Improve some comments. See inline.
>
> DETAILS
> -------
>
> Please find some comments inline.
>
> On Mon, 2009-11-23 at 03:09 +0000, Alfranio Correia wrote:
>> #At
> file:///home/acorreia/workspace.sun/repository.mysql/bzrwork/bug-45292/mysql-5.1-bugteam/
> based on revid:li-bing.song@stripped
>>
>> 3215 Alfranio Correia 2009-11-23
>> BUG#45292 orphan binary log created when starting server twice
>>
>> This patch fixes three bugs as follows. First, aborting the server while
> purging
>> binary logs might generate orphan files due to how the purge operation was
>> implemented:
>>
>> (purge routine - sql/log.cc - MYSQL_BIN_LOG::purge_logs)
>>
>> 1 - register the files to be removed in a temporary buffer.
>> 2 - update the log-bin.index.
>> 3 - flush the log-bin.index.
>> 4 - erase the files whose names where register in the temporary
> buffer
>> in step 1.
>> Thus a failure while executing step 4 would generate an orphan file.
> Second,
>> a similar issue might happen while creating a new binary as follows:
>>
>> (open routine - sql/log.cc - MYSQL_BIN_LOG::open)
>>
>> 1 - open the new log-bin.
>> 2 - update the log-bin.index.
>>
>> Thus a failure while executing step 1 would generate an orphan file.
>>
>> To fix these issues, we record the files to be purged or created before
> really
>> removing or adding them. So if a failure happens such registers can be used
> to
>> automatically remove dangling files. The new steps might be outlined as
> follows:
>>
>> (purge routine - sql/log.cc - MYSQL_BIN_LOG::purge_logs)
>>
>> 1 - register the files to be removed in the log-bin.log placed in
>> the data directory.
>
> Suggestion: s/register/record?
done.
>
>> 2 - update the log-bin.index.
>> 3 - flush the log-bin.index.
>
> You are closing the "register" at the end of purge_logs, so:
>
> 4. close log-bin.log (and remove it)
>
>
>> (open routine - sql/log.cc - MYSQL_BIN_LOG::open)
>>
>> 1 - register the file to be created in the log-bin.log
>> placed in the data directory.
>> 2 - open the new log-bin.
>> 3 - update the log-bin.index.
>
>
> You are closing the "register" at the end of open, so:
>
> 4. close log-bin.log (and remove it)
>
>
>>
>> (purge routine - sql/log.cc - MYSQL_BIN_LOG::open_index_file)
>>
>> 1 - open the log-bin.index.
>> 2 - open the log-bin.log.
>> 3 - for each file in log-bin.log
>> 3.1 Check if the file is in the log-bin.index and if so ignore it.
>> 3.2 Otherwise, delete it.
>>
>
> You are closing the "register" in the piece of code that adds this
> new logic in open_index_file, so:
>
> 4. close log-bin.log (and remove it)
>
>
>> The third issue can be described as follows. The purge operation was
> allowing
>> to remove a file in use thus leading to the loss of data and possible
>> inconsistencies between the master and slave. Roughly, the routine was
> only
>> taking into account the dump threads and so if a slave was not connect the
>> file might be delete even though it was in use.
>>
>> modified:
>> mysql-test/suite/binlog/r/binlog_index.result
>> mysql-test/suite/binlog/t/binlog_index.test
>> sql/log.cc
>> sql/log.h
>> sql/mysqld.cc
>> sql/rpl_rli.cc
>> === modified file 'mysql-test/suite/binlog/r/binlog_index.result'
>> --- a/mysql-test/suite/binlog/r/binlog_index.result 2009-01-23 12:22:05 +0000
>> +++ b/mysql-test/suite/binlog/r/binlog_index.result 2009-11-23 03:09:52 +0000
>> @@ -1,3 +1,8 @@
>> +call mtr.add_suppression('Attempting backtrace');
>> +call mtr.add_suppression('MSYQL_LOG::purge_logs failed to process registered
> files that would be purged.');
>> +call mtr.add_suppression('MSYQL_BIN_LOG::open failed to sync the index file');
>> +call mtr.add_suppression('Turning logging off for the whole duration of the
> MySQL server process.');
>> +call mtr.add_suppression('MSYQL_BIN_LOG::purge_logs failed to clean registers
> before purging logs.');
>> flush logs;
>> flush logs;
>> flush logs;
>> @@ -21,7 +26,6 @@ flush logs;
>> *** must be a warning master-bin.000001 was not found ***
>> Warnings:
>> Warning 1612 Being purged log master-bin.000001 was not found
>> -Warning 1612 Being purged 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
>> @@ -37,4 +41,79 @@ Level Code Message
>> Error 1377 a problem with deleting master-bin.000001; consider examining
> correspondence of your binlog index file to the actual binlog files
>> Error 1377 Fatal error during log purge
>> reset master;
>> +# crash_purge_before_update_index
>> +flush logs;
>> +SET SESSION debug="+d,crash_purge_before_update_index";
>> +purge binary logs TO 'master-bin.000002';
>> +ERROR HY000: Lost connection to MySQL server during query
>> +./master-bin.000001
>> +./master-bin.000002
>> +./master-bin.000003
>> +# crash_purge_non_critical_after_update_index
>> +flush logs;
>> +SET SESSION debug="+d,crash_purge_non_critical_after_update_index";
>> +purge binary logs TO 'master-bin.000004';
>> +ERROR HY000: Lost connection to MySQL server during query
>> +./master-bin.000004
>> +./master-bin.000005
>> +# crash_purge_critical_after_update_index
>> +flush logs;
>> +SET SESSION debug="+d,crash_purge_critical_after_update_index";
>> +purge binary logs TO 'master-bin.000006';
>> +ERROR HY000: Lost connection to MySQL server during query
>> +./master-bin.000006
>> +./master-bin.000007
>> +# crash_create_non_critical_before_update_index
>> +SET SESSION debug="+d,crash_create_non_critical_before_update_index";
>> +flush logs;
>> +ERROR HY000: Lost connection to MySQL server during query
>> +./master-bin.000006
>> +./master-bin.000007
>> +./master-bin.000008
>> +# crash_create_critical_before_update_index
>> +SET SESSION debug="+d,crash_create_critical_before_update_index";
>> +flush logs;
>> +ERROR HY000: Lost connection to MySQL server during query
>> +./master-bin.000006
>> +./master-bin.000007
>> +./master-bin.000008
>> +./master-bin.000009
>> +# crash_create_after_update_index
>> +SET SESSION debug="+d,crash_create_after_update_index";
>> +flush logs;
>> +ERROR HY000: Lost connection to MySQL server during query
>> +./master-bin.000006
>> +./master-bin.000007
>> +./master-bin.000008
>> +./master-bin.000009
>> +./master-bin.000010
>> +./master-bin.000011
>> +#
>> +# This should put the server in unsafe state and stop
>> +# accepting any command. If we inject a fault at this
>> +# point and continue the execution the server crashes.
>> +# Besides the flush command does not report an error.
>> +#
>> +# fault_injection_registering_index
>> +SET SESSION debug="+d,fault_injection_registering_index";
>> +flush logs;
>> +./master-bin.000006
>> +./master-bin.000007
>> +./master-bin.000008
>> +./master-bin.000009
>> +./master-bin.000010
>> +./master-bin.000011
>> +./master-bin.000012
>> +# fault_injection_updating_index
>> +SET SESSION debug="+d,fault_injection_updating_index";
>> +flush logs;
>> +./master-bin.000006
>> +./master-bin.000007
>> +./master-bin.000008
>> +./master-bin.000009
>> +./master-bin.000010
>> +./master-bin.000011
>> +./master-bin.000012
>> +./master-bin.000013
>> +SET SESSION debug="";
>> End of tests
>>
>> === modified file 'mysql-test/suite/binlog/t/binlog_index.test'
>> --- a/mysql-test/suite/binlog/t/binlog_index.test 2008-04-05 11:09:53 +0000
>> +++ b/mysql-test/suite/binlog/t/binlog_index.test 2009-11-23 03:09:52 +0000
>> @@ -3,6 +3,12 @@
>> #
>> source include/have_log_bin.inc;
>> source include/not_embedded.inc;
>> +call mtr.add_suppression('Attempting backtrace');
>> +call mtr.add_suppression('MSYQL_LOG::purge_logs failed to process registered
> files that would be purged.');
>> +call mtr.add_suppression('MSYQL_BIN_LOG::open failed to sync the index file');
>> +call mtr.add_suppression('Turning logging off for the whole duration of the
> MySQL server process.');
>> +call mtr.add_suppression('MSYQL_BIN_LOG::purge_logs failed to clean registers
> before purging logs.');
>> +let $old=`select @@debug`;
>>
>> #
>> # testing purge binary logs TO
>> @@ -32,6 +38,7 @@ reset master;
>> flush logs;
>> flush logs;
>> flush logs;
>> +
>> remove_file $MYSQLD_DATADIR/master-bin.000001;
>>
>> --echo *** must be a warning master-bin.000001 was not found ***
>> @@ -47,7 +54,7 @@ source include/show_binary_logs.inc;
>> #
>> # testing a fatal error
>> # Turning a binlog file into a directory must be a portable setup
>> -#
>> +#
>>
>> reset master;
>>
>> @@ -66,4 +73,127 @@ rmdir $MYSQLD_DATADIR/master-bin.000001;
>> --disable_warnings
>> reset master;
>> --enable_warnings
>> +
>> +--echo # crash_purge_before_update_index
>> +flush logs;
>> +
>> +--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
>> +SET SESSION debug="+d,crash_purge_before_update_index";
>> +--error 2013
>> +purge binary logs TO 'master-bin.000002';
>> +
>> +--enable_reconnect
>> +--source include/wait_until_connected_again.inc
>> +
>> +file_exists $MYSQLD_DATADIR/master-bin.000001;
>> +file_exists $MYSQLD_DATADIR/master-bin.000002;
>> +file_exists $MYSQLD_DATADIR/master-bin.000003;
>> +cat_file $MYSQLD_DATADIR/master-bin.index;
>> +
>> +--echo # crash_purge_non_critical_after_update_index
>> +flush logs;
>> +
>> +--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
>> +SET SESSION debug="+d,crash_purge_non_critical_after_update_index";
>> +--error 2013
>> +purge binary logs TO 'master-bin.000004';
>> +
>> +--enable_reconnect
>> +--source include/wait_until_connected_again.inc
>> +
>> +--error 1
>> +file_exists $MYSQLD_DATADIR/master-bin.000001;
>> +--error 1
>> +file_exists $MYSQLD_DATADIR/master-bin.000002;
>> +--error 1
>> +file_exists $MYSQLD_DATADIR/master-bin.000003;
>> +cat_file $MYSQLD_DATADIR/master-bin.index;
>> +
>> +--echo # crash_purge_critical_after_update_index
>> +flush logs;
>> +
>> +--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
>> +SET SESSION debug="+d,crash_purge_critical_after_update_index";
>> +--error 2013
>> +purge binary logs TO 'master-bin.000006';
>> +
>> +--enable_reconnect
>> +--source include/wait_until_connected_again.inc
>> +
>> +--error 1
>> +file_exists $MYSQLD_DATADIR/master-bin.000004;
>> +--error 1
>> +file_exists $MYSQLD_DATADIR/master-bin.000005;
>> +file_exists $MYSQLD_DATADIR/master-bin.000006;
>> +file_exists $MYSQLD_DATADIR/master-bin.000007;
>> +--error 1
>> +file_exists $MYSQLD_DATADIR/master-bin.000008;
>> +cat_file $MYSQLD_DATADIR/master-bin.index;
>> +
>> +--echo # crash_create_non_critical_before_update_index
>> +--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
>> +SET SESSION debug="+d,crash_create_non_critical_before_update_index";
>> +--error 2013
>> +flush logs;
>> +
>> +--enable_reconnect
>> +--source include/wait_until_connected_again.inc
>> +
>> +file_exists $MYSQLD_DATADIR/master-bin.000008;
>> +--error 1
>> +file_exists $MYSQLD_DATADIR/master-bin.000009;
>> +cat_file $MYSQLD_DATADIR/master-bin.index;
>> +
>> +--echo # crash_create_critical_before_update_index
>> +--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
>> +SET SESSION debug="+d,crash_create_critical_before_update_index";
>> +--error 2013
>> +flush logs;
>> +
>> +--enable_reconnect
>> +--source include/wait_until_connected_again.inc
>> +
>> +file_exists $MYSQLD_DATADIR/master-bin.000009;
>> +--error 1
>> +file_exists $MYSQLD_DATADIR/master-bin.000010;
>> +--error 1
>> +file_exists $MYSQLD_DATADIR/master-bin.000011;
>> +cat_file $MYSQLD_DATADIR/master-bin.index;
>> +
>> +--echo # crash_create_after_update_index
>> +--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
>> +SET SESSION debug="+d,crash_create_after_update_index";
>> +--error 2013
>> +flush logs;
>> +
>> +--enable_reconnect
>> +--source include/wait_until_connected_again.inc
>> +
>> +file_exists $MYSQLD_DATADIR/master-bin.000010;
>> +file_exists $MYSQLD_DATADIR/master-bin.000011;
>> +cat_file $MYSQLD_DATADIR/master-bin.index;
>> +
>> +--echo #
>> +--echo # This should put the server in unsafe state and stop
>> +--echo # accepting any command. If we inject a fault at this
>> +--echo # point and continue the execution the server crashes.
>> +--echo # Besides the flush command does not report an error.
>> +--echo #
>> +
>> +--echo # fault_injection_registering_index
>> +SET SESSION debug="+d,fault_injection_registering_index";
>> +flush logs;
>> +--source include/restart_mysqld.inc
>> +
>> +cat_file $MYSQLD_DATADIR/master-bin.index;
>> +
>> +--echo # fault_injection_updating_index
>> +SET SESSION debug="+d,fault_injection_updating_index";
>> +flush logs;
>> +--source include/restart_mysqld.inc
>> +
>> +cat_file $MYSQLD_DATADIR/master-bin.index;
>> +
>> +eval SET SESSION debug="$old";
>> +
>> --echo End of tests
>>
>> === modified file 'sql/log.cc'
>> --- a/sql/log.cc 2009-11-20 20:56:43 +0000
>> +++ b/sql/log.cc 2009-11-23 03:09:52 +0000
>> @@ -2429,7 +2429,7 @@ MYSQL_BIN_LOG::MYSQL_BIN_LOG()
>> */
>> index_file_name[0] = 0;
>> bzero((char*) &index_file, sizeof(index_file));
>> - bzero((char*) &purge_temp, sizeof(purge_temp));
>> + bzero((char*) ®ister_file, sizeof(register_file));
>> }
>
> OK
>
>> /* this is called only once */
>> @@ -2473,7 +2473,7 @@ void MYSQL_BIN_LOG::init_pthread_objects
>>
>>
>> bool MYSQL_BIN_LOG::open_index_file(const char *index_file_name_arg,
>> - const char *log_name)
>> + const char *log_name, bool need_mutex)
>> {
>> File index_file_nr= -1;
>> DBUG_ASSERT(!my_b_inited(&index_file));
>
> OK
>
>> @@ -2498,7 +2498,8 @@ bool MYSQL_BIN_LOG::open_index_file(cons
>> init_io_cache(&index_file, index_file_nr,
>> IO_SIZE, WRITE_CACHE,
>> my_seek(index_file_nr,0L,MY_SEEK_END,MYF(0)),
>> - 0, MYF(MY_WME | MY_WAIT_IF_FULL)))
>> + 0, MYF(MY_WME | MY_WAIT_IF_FULL)) ||
>> + DBUG_EVALUATE_IF("fault_injection_openning_index", 1, 0))
>> {
>> /*
>> TODO: all operations creating/deleting the index file or a log, should
>
> OK
>
>> @@ -2509,10 +2510,31 @@ bool MYSQL_BIN_LOG::open_index_file(cons
>> my_close(index_file_nr,MYF(0));
>> return TRUE;
>> }
>> +
>> + #ifdef HAVE_REPLICATION
>> + /*
>> + Sync the index by purging any binary log file that is not registered.
>> + In other words, either purge binary log files that were removed from
>> + the index but not purged from the file system due to a crash or purge
>> + any binary log file that was created but not register in the index
>> + due to a crash.
>> + */
>> +
>> + if (set_register_file_name(index_file_name_arg) ||
>> + open_register(FALSE) ||
>> + purge_index_entry(NULL, NULL, need_mutex) ||
>> + close_register() ||
>> + DBUG_EVALUATE_IF("fault_injection_recovering_index", 1, 0))
>> + {
>> + sql_print_error("MYSQL_BIN_LOG::open_index_file failed to sync the index "
>> + "file.");
>> + return TRUE;
>> + }
>> + #endif
>> +
>> return FALSE;
>> }
>>
>
> RC2: Why protect this with HAVE_REPLICATION? I don't think this is
> replication specific, but rather binary log specific, correct?
See comment above.
>
>> -
>
> RC1: Don't do this ^.
>> /**
>> Open a (new) binlog file.
>>
>> @@ -2533,17 +2555,56 @@ bool MYSQL_BIN_LOG::open(const char *log
>> enum cache_type io_cache_type_arg,
>> bool no_auto_events_arg,
>> ulong max_size_arg,
>> - bool null_created_arg)
>> + bool null_created_arg,
>> + bool need_mutex)
>> {
>> File file= -1;
>> + char new_file_name[FN_REFLEN];
>> +
>> DBUG_ENTER("MYSQL_BIN_LOG::open");
>> DBUG_PRINT("enter",("log_type: %d",(int) log_type_arg));
>>
>> - write_error=0;
>> + /*
>> + This duplicates some of the work done by the MYSQL_LOG constructor but we
>> + need it in here in order to define the name of the file that will be
> created
>> + and register it before the real operation.
>> + */
>> + MYSQL_LOG::init(log_type_arg, io_cache_type_arg);
>> + if (new_name && !strmov(new_file_name, new_name))
>> + {
>> + sql_print_error("MSYQL_BIN_LOG::open failed to allocate memory for "
>> + "file name.");
>> + DBUG_RETURN(1);
>> + }
>> + else if (!new_name && generate_new_name(new_file_name, log_name))
>> + {
>> + sql_print_error("MSYQL_BIN_LOG::open failed to generate new file name.");
>> + DBUG_RETURN(1);
>> + }
>
> RC3: Why not make this part of a private method?
I will follow Jasonh's suggestion.
>
>> + #ifdef HAVE_REPLICATION
>> + if (open_register(TRUE) ||
>> + register_create_index_entry(new_file_name) ||
>> + sync_register() ||
>> + DBUG_EVALUATE_IF("fault_injection_registering_index", 1, 0))
>> + {
>> + sql_print_error("MSYQL_BIN_LOG::open failed to sync the index file.");
>> + DBUG_RETURN(1);
>> + }
>> + DBUG_EXECUTE_IF("crash_create_non_critical_before_update_index", abort(););
>> + #endif
>
> RC2: Again, I don't think this piece of code should be guarded
> with HAVE_REPLICATION.
See comment above.
>
>> + write_error= 0;
>>
>> /* open the main log file */
>> - if (MYSQL_LOG::open(log_name, log_type_arg, new_name, io_cache_type_arg))
>> + if (MYSQL_LOG::open(log_name, log_type_arg, new_file_name,
>> + io_cache_type_arg))
>> + {
>> + #ifdef HAVE_REPLICATION
>> + (void) close_register();
>> + #endif
>
> RC2: Same here.
>
>> DBUG_RETURN(1); /* all warnings issued */
>> + }
>>
>> init(no_auto_events_arg, max_size_arg);
>>
>> @@ -2569,9 +2630,6 @@ bool MYSQL_BIN_LOG::open(const char *log
>> write_file_name_to_index_file= 1;
>> }
>>
>> - DBUG_ASSERT(my_b_inited(&index_file) != 0);
>> - reinit_io_cache(&index_file, WRITE_CACHE,
>> - my_b_filelength(&index_file), 0, 0);
>> if (need_start_event && !no_auto_events)
>> {
>> /*
>
> OK
>
>> @@ -2629,23 +2687,43 @@ bool MYSQL_BIN_LOG::open(const char *log
>>
>> if (write_file_name_to_index_file)
>> {
>> + #ifdef HAVE_REPLICATION
>> + DBUG_EXECUTE_IF("crash_create_critical_before_update_index", abort(););
>> + #endif
>> +
>> + DBUG_ASSERT(my_b_inited(&index_file) != 0);
>> + reinit_io_cache(&index_file, WRITE_CACHE,
>> + my_b_filelength(&index_file), 0, 0);
>> /*
>> As this is a new log file, we write the file name to the index
>> file. As every time we write to the index file, we sync it.
>> */
>> - if (my_b_write(&index_file, (uchar*) log_file_name,
>> - strlen(log_file_name)) ||
>> - my_b_write(&index_file, (uchar*) "\n", 1) ||
>> - flush_io_cache(&index_file) ||
>> + if (DBUG_EVALUATE_IF("fault_injection_updating_index", 1, 0) ||
>> + my_b_write(&index_file, (uchar*) log_file_name,
>> + strlen(log_file_name)) ||
>> + my_b_write(&index_file, (uchar*) "\n", 1) ||
>> + flush_io_cache(&index_file) ||
>> my_sync(index_file.file, MYF(MY_WME)))
>> - goto err;
>> + goto err;
>> +
>> + #ifdef HAVE_REPLICATION
>> + DBUG_EXECUTE_IF("crash_create_after_update_index", abort(););
>> + #endif
>
> RC2: Same here.
>
>> }
>> }
>> log_state= LOG_OPENED;
>>
>> + #ifdef HAVE_REPLICATION
>> + (void) close_register();
>> + #endif
>> +
>
> RC2: Same here.
>
>> DBUG_RETURN(0);
>>
>> err:
>> + #ifdef HAVE_REPLICATION
>> + (void) purge_index_entry(NULL, NULL, need_mutex);
>> + (void) close_register();
>> + #endif
>
> RC2: Same here.
>
>> sql_print_error("Could not use %s for logging (error %d). \
>> Turning logging off for the whole duration of the MySQL server process. \
>> To turn it on again: fix the cause, \
>> @@ -2902,8 +2980,10 @@ bool MYSQL_BIN_LOG::reset_logs(THD* thd)
>> name=0; // Protect against free
>> close(LOG_CLOSE_TO_BE_OPENED);
>>
>> - /* First delete all old log files */
>> -
>> + /*
>> + First delete all old log files.
>> + Note that this routine is not completely safe.
>
> S1: Please add a brief description why this is not safe.
Ok. Done.
>
>> + */
>> if (find_log_pos(&linfo, NullS, 0))
>> {
>> error=1;
>> @@ -2914,7 +2994,7 @@ bool MYSQL_BIN_LOG::reset_logs(THD* thd)
>> {
>> if ((error= my_delete_allow_opened(linfo.log_file_name, MYF(0))) != 0)
>> {
>> - if (my_errno == ENOENT)
>> + if (my_errno == ENOENT)
>
> RC1: Also here.
>
>> {
>> push_warning_printf(current_thd, MYSQL_ERROR::WARN_LEVEL_WARN,
>> ER_LOG_PURGE_NO_FILE, ER(ER_LOG_PURGE_NO_FILE),
>> @@ -2945,7 +3025,7 @@ bool MYSQL_BIN_LOG::reset_logs(THD* thd)
>> close(LOG_CLOSE_INDEX);
>> if ((error= my_delete_allow_opened(index_file_name, MYF(0)))) // Reset (open
> will update)
>> {
>> - if (my_errno == ENOENT)
>> + if (my_errno == ENOENT)
>
> RC1: Also here.
>
>> {
>> push_warning_printf(current_thd, MYSQL_ERROR::WARN_LEVEL_WARN,
>> ER_LOG_PURGE_NO_FILE, ER(ER_LOG_PURGE_NO_FILE),
>> @@ -2970,8 +3050,8 @@ bool MYSQL_BIN_LOG::reset_logs(THD* thd)
>> }
>> if (!thd->slave_thread)
>> need_start_event=1;
>> - if (!open_index_file(index_file_name, 0))
>> - open(save_name, log_type, 0, io_cache_type, no_auto_events, max_size, 0);
>> + if (!open_index_file(index_file_name, 0, FALSE))
>> + open(save_name, log_type, 0, io_cache_type, no_auto_events, max_size, 0,
> FALSE);
>> my_free((uchar*) save_name, MYF(0));
>>
>> err:
>
> OK
>
>> @@ -3038,7 +3118,7 @@ int MYSQL_BIN_LOG::purge_first_log(Relay
>> Read the next log file name from the index file and pass it back to
>> the caller.
>> */
>> - if((error=find_log_pos(&rli->linfo, rli->event_relay_log_name, 0))
> ||
>> + if((error=find_log_pos(&rli->linfo, rli->event_relay_log_name, 0))
> ||
>> (error=find_next_log(&rli->linfo, 0)))
>> {
>> char buff[22];
>
> OK
>
>> @@ -3090,7 +3170,7 @@ int MYSQL_BIN_LOG::purge_first_log(Relay
>> pthread_cond_broadcast(&rli->log_space_cond);
>>
>> /*
>> - * Need to update the log pos because purge logs has been called
>> + * Need to update the log pos because purge logs has been called
>> * after fetching initially the log pos at the begining of the method.
>> */
>> if((error=find_log_pos(&rli->linfo, rli->event_relay_log_name, 0)))
>
> RC1: Same here.
>
>> @@ -3152,13 +3232,13 @@ int MYSQL_BIN_LOG::update_log_index(LOG_
>> my_stat() or my_delete()
>> */
>>
>> -int MYSQL_BIN_LOG::purge_logs(const char *to_log,
>> +int MYSQL_BIN_LOG::purge_logs(const char *to_log,
>> bool included,
>> - bool need_mutex,
>> - bool need_update_threads,
>> + bool need_mutex,
>> + bool need_update_threads,
>
> RC1: Same here.
>
>> ulonglong *decrease_log_space)
>> {
>> - int error;
>> + int error= 0;
>
> Good.
>
>> bool exit_loop= 0;
>> LOG_INFO log_info;
>> THD *thd= current_thd;
>> @@ -3167,35 +3247,17 @@ int MYSQL_BIN_LOG::purge_logs(const char
>>
>> 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*/)))
>> {
>
> RC1: Same here.
>
>> - sql_print_error("MYSQL_LOG::purge_logs was called with file %s not "
>> + sql_print_error("MYSQL_BIN_LOG::purge_logs was called with file %s not "
>> "listed in the index.", to_log);
>
> Good.
>
>> 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_register(TRUE)))
>> {
>> - 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;
>> - }
>> + sql_print_error("MYSQL_BIN_LOG::purge_logs failed to sync the index
> file.");
>> + goto err;
>> }
>>
>> /*
>
> OK
>
>> @@ -3205,20 +3267,27 @@ int MYSQL_BIN_LOG::purge_logs(const char
>> if ((error=find_log_pos(&log_info, NullS, 0 /*no mutex*/)))
>> goto err;
>> while ((strcmp(to_log,log_info.log_file_name) || (exit_loop=included))
> &&
>> + !is_active(log_info.log_file_name) &&
>> !log_in_use(log_info.log_file_name))
>> {
>> - if ((error=my_b_write(&purge_temp, (const
> uchar*)log_info.log_file_name,
>> - strlen(log_info.log_file_name))) ||
>> - (error=my_b_write(&purge_temp, (const uchar*)"\n", 1)))
>> + if ((error= register_purge_index_entry(log_info.log_file_name)))
>> {
>> - sql_print_error("MYSQL_LOG::purge_logs failed to copy %s to purge_temp",
>> + sql_print_error("MYSQL_BIN_LOG::purge_logs failed to copy %s to register
> file.",
>> log_info.log_file_name);
>> goto err;
>> }
>>
>> if (find_next_log(&log_info, 0) || exit_loop)
>> break;
>> - }
>> + }
>> +
>> + DBUG_EXECUTE_IF("crash_purge_before_update_index", abort(););
>> +
>> + if ((error= sync_register()))
>> + {
>> + sql_print_error("MSYQL_LOG::purge_logs failed to flush register file.");
>> + goto err;
>> + }
>
> RC4: Since you have changed the ones before, please fix this
> as well: MYSQL_LOG --> MYSQL_LOG_BIN. Also, fix the ones
> that show up after.
Done.
>
>>
>> /* We know how many files to delete. Update index file. */
>> if ((error=update_log_index(&log_info, need_update_threads)))
>> @@ -3227,29 +3296,141 @@ int MYSQL_BIN_LOG::purge_logs(const char
>> goto err;
>> }
>>
>> - DBUG_EXECUTE_IF("crash_after_update_index", abort(););
>> + DBUG_EXECUTE_IF("crash_purge_critical_after_update_index", abort(););
>> +
>> +err:
>> + /* Read each entry from register_file and delete the file. */
>> + if ((error= purge_index_entry(thd, decrease_log_space, FALSE)))
>> + sql_print_error("MSYQL_LOG::purge_logs failed to process registered files"
>> + " that would be purged.");
>
> RC4: Same here.
>
>> + (void) close_register();
>> +
>> + DBUG_EXECUTE_IF("crash_purge_non_critical_after_update_index", abort(););
>> +
>> + if (need_mutex)
>> + pthread_mutex_unlock(&LOCK_index);
>> + DBUG_RETURN(error);
>> +}
>> +
>> +int MYSQL_BIN_LOG::set_register_file_name(const char *base_file_name)
>> +{
>> + int error= 0;
>> + DBUG_ENTER("MYSQL_BIN_LOG::set_register_file_name");
>> + if (fn_format(register_file_name, base_file_name, mysql_data_home,
>> + ".~rec~", MYF(MY_UNPACK_FILENAME | MY_SAFE_PATH |
>> + MY_REPLACE_EXT)) == NULL)
>> + {
>> + error= 1;
>> + sql_print_error("MYSQL_BIN_LOG::set_register_file_name failed to set "
>> + "file name.");
>> +
>> + }
>> + DBUG_RETURN(error);
>> +}
>> +
>> +int MYSQL_BIN_LOG::open_register(bool destroy)
>> +{
>> + int error= 0;
>> + File file= -1;
>>
>> - /* Switch purge_temp for read. */
>> - if ((error=reinit_io_cache(&purge_temp, READ_CACHE, 0, 0, 0)))
>> + DBUG_ENTER("MYSQL_BIN_LOG::register_file");
>> +
>> + if (destroy)
>> + (void) close_register();
>> +
>> + if (!my_b_inited(®ister_file))
>> {
>> - sql_print_error("MSYQL_LOG::purge_logs failed to reinit purge_temp "
>> + if ((file= my_open(register_file_name, O_RDWR | O_CREAT | O_BINARY,
>> + MYF(MY_WME | ME_WAITTANG))) < 0 ||
>> + init_io_cache(®ister_file, file, IO_SIZE,
>> + (destroy ? WRITE_CACHE : READ_CACHE),
>> + 0, 0, MYF(MY_WME | MY_NABP | MY_WAIT_IF_FULL)))
>> + {
>> + error= 1;
>> + sql_print_error("MYSQL_BIN_LOG::open_register failed to open register "
>> + " file.");
>> + }
>> + }
>> + DBUG_RETURN(error);
>> +}
>> +
>> +int MYSQL_BIN_LOG::close_register(void)
>> +{
>> + int error= 0;
>> +
>> + DBUG_ENTER("MYSQL_BIN_LOG::close_register");
>> +
>> + if (my_b_inited(®ister_file))
>> + {
>> + end_io_cache(®ister_file);
>> + error= my_close(register_file.file, MYF(0));
>> + }
>> + my_delete(register_file_name, MYF(0));
>> + bzero((char*) ®ister_file, sizeof(register_file));
>> +
>> + DBUG_RETURN(error);
>> +}
>> +
>> +int MYSQL_BIN_LOG::sync_register(void)
>> +{
>> + int error= 0;
>> + DBUG_ENTER("MYSQL_BIN_LOG::sync_register");
>> +
>> + if ((error= flush_io_cache(®ister_file)) ||
>> + (error= my_sync(register_file.file, MYF(MY_WME))))
>> + DBUG_RETURN(error);
>> +
>> + DBUG_RETURN(error);
>> +}
>> +
>> +int MYSQL_BIN_LOG::register_purge_index_entry(const char *entry)
>> +{
>> + int error= 0;
>> + DBUG_ENTER("MYSQL_BIN_LOG::register_purge_index_entry");
>> +
>> + if ((error=my_b_write(®ister_file, (const uchar*)entry, strlen(entry)))
> ||
>> + (error=my_b_write(®ister_file, (const uchar*)"\n", 1)))
>> + DBUG_RETURN (error);
>> +
>> + DBUG_RETURN(error);
>> +}
>> +
>> +
>> +int MYSQL_BIN_LOG::register_create_index_entry(const char *entry)
>> +{
>> + DBUG_ENTER("MYSQL_BIN_LOG::register_create_index_entry");
>> + DBUG_RETURN(register_purge_index_entry(entry));
>> +}
>> +
>> +int MYSQL_BIN_LOG::purge_index_entry(THD *thd, ulonglong *decrease_log_space,
>> + bool need_mutex)
>> +{
>> + MY_STAT s;
>> + int error= 0;
>> + LOG_INFO log_info;
>> + LOG_INFO check_log_info;
>> +
>> + DBUG_ENTER("MYSQL_BIN_LOG:_purge_index_entry");
>> +
>> + if ((error=reinit_io_cache(®ister_file, READ_CACHE, 0, 0, 0)))
>> + {
>> + sql_print_error("MSYQL_BIN_LOG::purge_index_entry failed to reinit register
> file "
>> "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,
>> + if ((length=my_b_gets(®ister_file, log_info.log_file_name,
>> FN_REFLEN)) <= 1)
>> {
>> - if (purge_temp.error)
>> + if (register_file.error)
>> {
>> - error= purge_temp.error;
>> - sql_print_error("MSYQL_LOG::purge_logs error %d reading from "
>> - "purge_temp", error);
>> + error= register_file.error;
>> + sql_print_error("MSYQL_BIN_LOG::purge_index_entry error %d reading from
> "
>> + "register file.", error);
>> goto err;
>> }
>
> OK.
>
>> @@ -3260,12 +3441,9 @@ int MYSQL_BIN_LOG::purge_logs(const char
>> /* Get rid of the trailing '\n' */
>> log_info.log_file_name[length-1]= 0;
>>
>> - ha_binlog_index_purge_file(current_thd, log_info.log_file_name);
>> -
>> - MY_STAT s;
>> if (!my_stat(log_info.log_file_name, &s, MYF(0)))
>> {
>> - if (my_errno == ENOENT)
>> + if (my_errno == ENOENT)
>
> RC1: Same here.
>
>> {
>> /*
>> It's not fatal if we can't stat a log file that does not exist;
>> @@ -3310,64 +3488,71 @@ int MYSQL_BIN_LOG::purge_logs(const char
>> }
>> else
>> {
>> - DBUG_PRINT("info",("purging %s",log_info.log_file_name));
>> - if (!my_delete(log_info.log_file_name, MYF(0)))
>> - {
>> - if (decrease_log_space)
>> - *decrease_log_space-= s.st_size;
>> - }
>> - else
>> + if (find_log_pos(&check_log_info, log_info.log_file_name,
> need_mutex))
>> {
>
> RC5: Should you check that return value of find_log_pos is
> LOG_INFO_EOF ?
This cannot happen because you are reading from the temporary file.
So the files were checked before calling the find_log_pos.
>
>> - if (my_errno == ENOENT)
>> + if (!need_mutex)
>> {
>> - 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;
>> + /*
>> + This is to avoid triggering an error in NDB.
>> + */
>> + ha_binlog_index_purge_file(current_thd, log_info.log_file_name);
>> + }
>> +
>> + DBUG_PRINT("info",("purging %s",log_info.log_file_name));
>> + if (!my_delete(log_info.log_file_name, MYF(0)))
>> + {
>> + if (decrease_log_space)
>> + *decrease_log_space-= s.st_size;
>> }
>> else
>> {
>> - if (thd)
>> + if (my_errno == ENOENT)
>> {
>> - 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",
>> + 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
>> {
>> - sql_print_information("Failed to delete file '%s'; "
>> + 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);
>> - }
>> - if (my_errno == EMFILE)
>> - {
>> - DBUG_PRINT("info",
>> - ("my_errno: %d, set ret = LOG_INFO_EMFILE", my_errno));
>> - error= LOG_INFO_EMFILE;
>> + }
>> + else
>> + {
>> + sql_print_information("Failed to delete file '%s'; "
>> + "consider examining correspondence "
>> + "of your binlog index file "
>> + "to the actual binlog files",
>> + log_info.log_file_name);
>> + }
>> + if (my_errno == EMFILE)
>> + {
>> + DBUG_PRINT("info",
>> + ("my_errno: %d, set ret = LOG_INFO_EMFILE",
> my_errno));
>> + error= LOG_INFO_EMFILE;
>> + goto err;
>> + }
>> + error= LOG_INFO_FATAL;
>> goto err;
>> }
>> - error= LOG_INFO_FATAL;
>> - goto err;
>> }
>> }
>> }
>> }
>> -
>> err:
>> - close_cached_file(&purge_temp);
>> - if (need_mutex)
>> - pthread_mutex_unlock(&LOCK_index);
>> DBUG_RETURN(error);
>> }
>
>
> OK.
>
>> @@ -3407,7 +3592,8 @@ int MYSQL_BIN_LOG::purge_logs_before_dat
>> goto err;
>>
>> while (strcmp(log_file_name, log_info.log_file_name) &&
>> - !log_in_use(log_info.log_file_name))
>> + !is_active(log_info.log_file_name) &&
>> + !log_in_use(log_info.log_file_name))
>> {
>> if (!my_stat(log_info.log_file_name, &stat_area, MYF(0)))
>> {
>
> OK
>
>> @@ -3416,14 +3602,6 @@ int MYSQL_BIN_LOG::purge_logs_before_dat
>> /*
>> It's not fatal if we can't stat a log file that does not exist.
>> */
>> - 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 execute my_stat on file '%s'",
>> - log_info.log_file_name);
>> my_errno= 0;
>> }
>> else
>> @@ -3604,6 +3782,7 @@ void MYSQL_BIN_LOG::new_file_impl(bool n
>> name=0; // Don't free name
>> close(LOG_CLOSE_TO_BE_OPENED | LOG_CLOSE_INDEX);
>>
>> +
>
> RC1: Same here.
>
>> /*
>> Note that at this point, log_state != LOG_CLOSED (important for
> is_open()).
>> */
>> @@ -3618,9 +3797,9 @@ void MYSQL_BIN_LOG::new_file_impl(bool n
>> */
>>
>> /* reopen index binlog file, BUG#34582 */
>> - if (!open_index_file(index_file_name, 0))
>> - open(old_name, log_type, new_name_ptr,
>> - io_cache_type, no_auto_events, max_size, 1);
>> + if (!open_index_file(index_file_name, 0, FALSE))
>> + open(old_name, log_type, new_name_ptr,
>> + io_cache_type, no_auto_events, max_size, 1, FALSE);
>> my_free(old_name,MYF(0));
>>
>> end:
>> @@ -5522,7 +5701,7 @@ int TC_LOG_BINLOG::open(const char *opt_
>> if (using_heuristic_recover())
>> {
>> /* generate a new binlog to mask a corrupted one */
>> - open(opt_name, LOG_BIN, 0, WRITE_CACHE, 0, max_binlog_size, 0);
>> + open(opt_name, LOG_BIN, 0, WRITE_CACHE, 0, max_binlog_size, 0, TRUE);
>> cleanup();
>> return 1;
>> }
>
> OK
>
>> === modified file 'sql/log.h'
>> --- a/sql/log.h 2009-06-18 13:52:46 +0000
>> +++ b/sql/log.h 2009-11-23 03:09:52 +0000
>> @@ -233,14 +233,15 @@ class MYSQL_BIN_LOG: public TC_LOG, priv
>> pthread_cond_t update_cond;
>> ulonglong bytes_written;
>> IO_CACHE index_file;
>> + char index_file_name[FN_REFLEN];
>> /*
>> - purge_temp is a temp file used in purge_logs so that the index file
>> + purge_file 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 index_file_name[FN_REFLEN];
>> + IO_CACHE register_file;
>> + char register_file_name[FN_REFLEN];
>> /*
>> The max size before rotation (usable only if log_type == LOG_BIN: binary
>> logs and relay logs).
>
> OK
>
>> @@ -349,9 +350,10 @@ public:
>> const char *new_name,
>> enum cache_type io_cache_type_arg,
>> bool no_auto_events_arg, ulong max_size,
>> - bool null_created);
>> + bool null_created,
>> + bool need_mutex);
>> bool open_index_file(const char *index_file_name_arg,
>> - const char *log_name);
>> + const char *log_name, bool need_mutex);
>> /* Use this to start writing a new log file */
>> void new_file();
>
> OK
>
>> @@ -384,6 +386,15 @@ public:
>> ulonglong *decrease_log_space);
>> int purge_logs_before_date(time_t purge_time);
>> int purge_first_log(Relay_log_info* rli, bool included);
>> + int set_register_file_name(const char *base_file_name);
>> + int open_register(bool destroy);
>> + int close_register(void);
>> + int clean_register(void);
>> + int sync_register(void);
>> + int register_purge_index_entry(const char* entry);
>> + int register_create_index_entry(const char* entry);
>> + int purge_index_entry(THD *thd, ulonglong *decrease_log_space,
>> + bool need_mutex);
>> bool reset_logs(THD* thd);
>> void close(uint exiting);
>>
>
> OK. Perhaps I would name the methods record instead of register.
I've followed Jasonh's suggestion.
>
>> === modified file 'sql/mysqld.cc'
>> --- a/sql/mysqld.cc 2009-11-20 12:09:50 +0000
>> +++ b/sql/mysqld.cc 2009-11-23 03:09:52 +0000
>> @@ -3932,7 +3932,7 @@ a file name for --log-bin-index option",
>> my_free(opt_bin_logname, MYF(MY_ALLOW_ZERO_PTR));
>> opt_bin_logname=my_strdup(buf, MYF(0));
>> }
>> - if (mysql_bin_log.open_index_file(opt_binlog_index_name, ln))
>> + if (mysql_bin_log.open_index_file(opt_binlog_index_name, ln, TRUE))
>> {
>> unireg_abort(1);
>> }
>
> OK
>
>> @@ -4096,7 +4096,7 @@ a file name for --log-bin-index option",
>> }
>>
>> if (opt_bin_log && mysql_bin_log.open(opt_bin_logname, LOG_BIN, 0,
>> - WRITE_CACHE, 0, max_binlog_size, 0))
>> + WRITE_CACHE, 0, max_binlog_size, 0,
> TRUE))
>> unireg_abort(1);
>>
>> #ifdef HAVE_REPLICATION
>
> OK
>
>> === modified file 'sql/rpl_rli.cc'
>> --- a/sql/rpl_rli.cc 2009-11-05 06:07:31 +0000
>> +++ b/sql/rpl_rli.cc 2009-11-23 03:09:52 +0000
>> @@ -181,10 +181,10 @@ a file name for --relay-log-index option
>> note, that if open() fails, we'll still have index file open
>> but a destructor will take care of that
>> */
>> - if (rli->relay_log.open_index_file(opt_relaylog_index_name, ln) ||
>> + if (rli->relay_log.open_index_file(opt_relaylog_index_name, ln, TRUE) ||
>> rli->relay_log.open(ln, LOG_BIN, 0, SEQ_READ_APPEND, 0,
>> (max_relay_log_size ? max_relay_log_size :
>> - max_binlog_size), 1))
>> + max_binlog_size), 1, TRUE))
>> {
>> pthread_mutex_unlock(&rli->data_lock);
>> sql_print_error("Failed in open_log() called from
> init_relay_log_info()");
>>
>
> OK
>
>
