Hi Alfranio,
Nice Work. We're almost there.
STATUS
------
Not approved.
REQUIRED CHANGES
----------------
RC1. I am still missing your OK regarding the test running on
windows how it is today (using the cat_file on index
files). Please make sure that it does not fail there
because of filesystem paths not being masked out.
RC2. Mind the spurious new lines ;) .
RC3. I still think that we should check the return value of
find_log_pos in MYSQL_BIN_LOG::purge_index_entry .
REQUESTS
--------
R1. Why not call the new function "define_new_file":
"MYSQL_LOG::init_and_set_log_file_name" instead?
Given that it merges the two procedures...
R2. About the guards HAVE_REPLICATION, I see that Zhenxing has
already mentioned that these are being misused in some other
places in the code. So I am ok with filing a new bug to
address this.
SUGGESTIONS
-----------
n/a
DETAILS
-------
n/a
On Mon, 2009-11-30 at 17:58 +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-30
> 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:
>
> (create 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 records 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.~rec~ placed in
> the data directory.
> 2 - update the log-bin.index.
> 3 - flush the log-bin.index.
> 4 - delete the log-bin.~rec~.
>
> (create routine - sql/log.cc - MYSQL_BIN_LOG::open)
>
> 1 - register the file to be created in the log-bin.~rec~
> placed in the data directory.
> 2 - open the new log-bin.
> 3 - update the log-bin.index.
> 4 - delete the log-bin.~rec~.
>
> (recovery routine - sql/log.cc - MYSQL_BIN_LOG::open_index_file)
>
> 1 - open the log-bin.index.
> 2 - open the log-bin.~rec~.
> 3 - for each file in log-bin.~rec~.
> 3.1 Check if the file is in the log-bin.index and if so ignore it.
> 3.2 Otherwise, delete 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-30 17:58:07 +0000
> @@ -1,3 +1,8 @@
> +call mtr.add_suppression('Attempting backtrace');
> +call mtr.add_suppression('MSYQL_BIN_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-30 17:58:07 +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_BIN_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
> @@ -66,4 +72,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-30 17:58:07 +0000
> @@ -1897,6 +1897,22 @@ void MYSQL_LOG::init(enum_log_type log_t
> }
>
>
> +bool MYSQL_LOG::define_new_file(const char *log_name,
> + const char *new_name,
> + enum_log_type log_type_arg,
> + enum cache_type io_cache_type_arg)
> +{
> + init(log_type_arg, io_cache_type_arg);
> +
> + if (new_name && !strmov(log_file_name, new_name))
> + return TRUE;
> + else if (!new_name && generate_new_name(log_file_name, log_name))
> + return TRUE;
> +
> + return FALSE;
> +}
> +
> +
> /*
> Open a (new) log file.
>
> @@ -1929,17 +1945,14 @@ bool MYSQL_LOG::open(const char *log_nam
>
> write_error= 0;
>
> - init(log_type_arg, io_cache_type_arg);
> -
> if (!(name= my_strdup(log_name, MYF(MY_WME))))
> {
> name= (char *)log_name; // for the error message
> goto err;
> }
>
> - if (new_name)
> - strmov(log_file_name, new_name);
> - else if (generate_new_name(log_file_name, name))
> + if (define_new_file(name, new_name,
> + log_type_arg, io_cache_type_arg))
> goto err;
>
> if (io_cache_type == SEQ_READ_APPEND)
> @@ -2429,7 +2442,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*) &purge_index_file, sizeof(purge_index_file));
> }
>
> /* this is called only once */
> @@ -2473,7 +2486,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));
> @@ -2498,7 +2511,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
> @@ -2509,6 +2523,28 @@ 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_purge_index_file_name(index_file_name_arg) ||
> + open_purge_index_file(FALSE) ||
> + purge_index_entry(NULL, NULL, need_mutex) ||
> + close_purge_index_file() ||
> + 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;
> }
>
> @@ -2533,17 +2569,44 @@ 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;
> +
> DBUG_ENTER("MYSQL_BIN_LOG::open");
> DBUG_PRINT("enter",("log_type: %d",(int) log_type_arg));
>
> - write_error=0;
> + if (MYSQL_LOG::define_new_file(log_name, new_name, log_type_arg,
> + io_cache_type_arg))
> + {
> + sql_print_error("MSYQL_BIN_LOG::open failed to generate new file name.");
> + DBUG_RETURN(1);
> + }
> +
> + #ifdef HAVE_REPLICATION
> + if (open_purge_index_file(TRUE) ||
> + register_create_index_entry(log_file_name) ||
> + sync_purge_index_file() ||
> + 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
> +
> + 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_name,
> + io_cache_type_arg))
> + {
> + #ifdef HAVE_REPLICATION
> + close_purge_index_file();
> + #endif
> DBUG_RETURN(1); /* all warnings issued */
> + }
>
> init(no_auto_events_arg, max_size_arg);
>
> @@ -2569,9 +2632,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)
> {
> /*
> @@ -2629,23 +2689,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
> }
> }
> log_state= LOG_OPENED;
>
> + #ifdef HAVE_REPLICATION
> + close_purge_index_file();
> + #endif
> +
> DBUG_RETURN(0);
>
> err:
> + #ifdef HAVE_REPLICATION
> + purge_index_entry(NULL, NULL, need_mutex);
> + close_purge_index_file();
> + #endif
> 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 +2982,15 @@ 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 and then update the index file.
> + As we first delete the log files and do not use sort of logging,
> + a crash may lead to an inconsistent state where the index has
> + references to non-existent files.
>
> + We need to invert the steps and use the purge_index_file methods
> + in order to make the operation safe.
> + */
> if (find_log_pos(&linfo, NullS, 0))
> {
> error=1;
> @@ -2970,8 +3057,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:
> @@ -3158,7 +3245,7 @@ int MYSQL_BIN_LOG::purge_logs(const char
> bool need_update_threads,
> ulonglong *decrease_log_space)
> {
> - int error;
> + int error= 0;
> bool exit_loop= 0;
> LOG_INFO log_info;
> THD *thd= current_thd;
> @@ -3169,33 +3256,15 @@ int MYSQL_BIN_LOG::purge_logs(const char
> pthread_mutex_lock(&LOCK_index);
> 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 "
> + sql_print_error("MYSQL_BIN_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_purge_index_file(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;
> }
>
> /*
> @@ -3205,51 +3274,170 @@ 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_purge_index_file()))
> + {
> + sql_print_error("MSYQL_BIN_LOG::purge_logs failed to flush register file.");
> + goto err;
> + }
>
> /* 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");
> + sql_print_error("MSYQL_BIN_LOG::purge_logs failed to update the index file");
> 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 purge_index_file and delete the file. */
> + if ((error= purge_index_entry(thd, decrease_log_space, FALSE)))
> + sql_print_error("MSYQL_BIN_LOG::purge_logs failed to process registered files"
> + " that would be purged.");
> + close_purge_index_file();
> +
> + DBUG_EXECUTE_IF("crash_purge_non_critical_after_update_index", abort(););
>
> - /* Switch purge_temp for read. */
> - if ((error=reinit_io_cache(&purge_temp, READ_CACHE, 0, 0, 0)))
> + if (need_mutex)
> + pthread_mutex_unlock(&LOCK_index);
> + DBUG_RETURN(error);
> +}
> +
> +int MYSQL_BIN_LOG::set_purge_index_file_name(const char *base_file_name)
> +{
> + int error= 0;
> + DBUG_ENTER("MYSQL_BIN_LOG::set_purge_index_file_name");
> + if (fn_format(purge_index_file_name, base_file_name, mysql_data_home,
> + ".~rec~", MYF(MY_UNPACK_FILENAME | MY_SAFE_PATH |
> + MY_REPLACE_EXT)) == NULL)
> {
> - sql_print_error("MSYQL_LOG::purge_logs failed to reinit purge_temp "
> + error= 1;
> + sql_print_error("MYSQL_BIN_LOG::set_purge_index_file_name failed to set "
> + "file name.");
> +
> + }
> + DBUG_RETURN(error);
> +}
> +
> +int MYSQL_BIN_LOG::open_purge_index_file(bool destroy)
> +{
> + int error= 0;
> + File file= -1;
> +
> + DBUG_ENTER("MYSQL_BIN_LOG::purge_index_file");
> +
> + if (destroy)
> + close_purge_index_file();
> +
> + if (!my_b_inited(&purge_index_file))
> + {
> + if ((file= my_open(purge_index_file_name, O_RDWR | O_CREAT | O_BINARY,
> + MYF(MY_WME | ME_WAITTANG))) < 0 ||
> + init_io_cache(&purge_index_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_purge_index_file failed to open register
> "
> + " file.");
> + }
> + }
> + DBUG_RETURN(error);
> +}
> +
> +int MYSQL_BIN_LOG::close_purge_index_file()
> +{
> + int error= 0;
> +
> + DBUG_ENTER("MYSQL_BIN_LOG::close_purge_index_file");
> +
> + if (my_b_inited(&purge_index_file))
> + {
> + end_io_cache(&purge_index_file);
> + error= my_close(purge_index_file.file, MYF(0));
> + }
> + my_delete(purge_index_file_name, MYF(0));
> + bzero((char*) &purge_index_file, sizeof(purge_index_file));
> +
> + DBUG_RETURN(error);
> +}
> +
> +int MYSQL_BIN_LOG::sync_purge_index_file()
> +{
> + int error= 0;
> + DBUG_ENTER("MYSQL_BIN_LOG::sync_purge_index_file");
> +
> + if ((error= flush_io_cache(&purge_index_file)) ||
> + (error= my_sync(purge_index_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(&purge_index_file, (const uchar*)entry, strlen(entry)))
> ||
> + (error=my_b_write(&purge_index_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(&purge_index_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(&purge_index_file, log_info.log_file_name,
> FN_REFLEN)) <= 1)
> {
> - if (purge_temp.error)
> + if (purge_index_file.error)
> {
> - error= purge_temp.error;
> - sql_print_error("MSYQL_LOG::purge_logs error %d reading from "
> - "purge_temp", error);
> + error= purge_index_file.error;
> + sql_print_error("MSYQL_BIN_LOG::purge_index_entry error %d reading from "
> + "register file.", error);
> goto err;
> }
>
> @@ -3260,9 +3448,6 @@ 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)
> @@ -3310,64 +3495,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 (find_log_pos(&check_log_info, log_info.log_file_name, need_mutex))
> {
> - if (decrease_log_space)
> - *decrease_log_space-= s.st_size;
> - }
> - else
> - {
> - 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);
> }
>
> @@ -3407,7 +3599,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)))
> {
> @@ -3416,14 +3609,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 +3789,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);
>
> +
> /*
> Note that at this point, log_state != LOG_CLOSED (important for is_open()).
> */
> @@ -3618,9 +3804,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 +5708,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;
> }
>
> === modified file 'sql/log.h'
> --- a/sql/log.h 2009-06-18 13:52:46 +0000
> +++ b/sql/log.h 2009-11-30 17:58:07 +0000
> @@ -172,6 +172,10 @@ public:
> enum_log_type log_type,
> const char *new_name,
> enum cache_type io_cache_type_arg);
> + bool define_new_file(const char *log_name,
> + const char *new_name,
> + enum_log_type log_type_arg,
> + enum cache_type io_cache_type_arg);
> void init(enum_log_type log_type_arg,
> enum cache_type io_cache_type_arg);
> void close(uint exiting);
> @@ -233,14 +237,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 purge_index_file;
> + char purge_index_file_name[FN_REFLEN];
> /*
> The max size before rotation (usable only if log_type == LOG_BIN: binary
> logs and relay logs).
> @@ -349,9 +354,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();
>
> @@ -384,6 +390,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_purge_index_file_name(const char *base_file_name);
> + int open_purge_index_file(bool destroy);
> + int close_purge_index_file();
> + int clean_purge_index_file();
> + int sync_purge_index_file();
> + 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);
>
>
> === modified file 'sql/mysqld.cc'
> --- a/sql/mysqld.cc 2009-11-20 12:09:50 +0000
> +++ b/sql/mysqld.cc 2009-11-30 17:58:07 +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);
> }
> @@ -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
>
> === 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-30 17:58:07 +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()");
>
--
Luís
