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.
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.
RC3. Please, don't duplicate code. Maybe, wrap the duplicate
code into some private methods. See comments inline.
RC4. Please, fix the message in some sql_print_warning. See
comments inline.
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;
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?
> 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?
> -
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?
> + #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.
> + 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.
> + */
> 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.
>
> /* 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 ?
> - 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.
> === 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
