Hi Alfranio,
Great work. I am just requesting a few changes before I give my "OK to
push". Find them below.
Regards,
Luís
STATUS
------
Not Approved.
REQUIRED CHANGES
----------------
RC1. Please, add some documentation to the test cases,
describing what is exactly is being done. It would be nice
to cross-reference the "assertions" in the test case with
the issues you mention in the commit message. Also, in
some cases, would be interesting to print the contents of
the index file after a crash but before the server
restarts (Take the case crash_purge_before_update_index
for instance).
RC2. The test cases are not platform independent. Looking at
result files one can find output resulting from:
cat_file $MYSQLD_DATADIR/master-bin.index;
which in unix like platforms will output:
./master-bin.000XXX
^
|
(Notice the path separator.)
But on windows, it will probably be different. To fix
this, maybe work with "-- replace_regex" (I think it wont
work, but I have not tried), or maybe use "-- perl".
RC3. Please, use source include/start_slave.inc and source
include/stop_slave.inc. Check DETAILS section
for... details! :)
REQUESTS
--------
R1. MYSQL_BIN_LOG::recovery_index_file
This is a request for clarification. Is it really needed to
automatically remove a file if it is considered to be a
corrupt one? Why not move the file aside and rename it with
the suffix '.corrupted' (or something alike)?
SUGGESTIONS
-----------
n/a
DETAILS
-------
There are some questions/suggestions inline. Please, address them.
On Sun, 2009-09-06 at 23:43 +0000, Alfranio Correia wrote:
> #At
> file:///home/acorreia/workspace.sun/repository.mysql/bzrwork/bug-45292/mysql-5.1-bugteam/
> based on revid:joro@stripped
>
> 3102 Alfranio Correia 2009-09-07
> 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.
> 3 - flush the log-bin.index.
>
> Thus a failure while executing step 1 would generate an orphan file.
>
> To fix these issues, we use the index file as a log and introduce a recovery
> procedure as follows:
>
> (purge routine - sql/log.cc - MYSQL_BIN_LOG::purge_logs)
>
> 1 - erase the files.
> 2 - update the log-bin.index.
> 3 - flush the log-bin.index.
>
> (open routine - sql/log.cc - MYSQL_BIN_LOG::open)
>
> 1 - update the log-bin.index if new log-bin entry is not an entry.
> 2 - flush the log-bin.index.
> 3 - open the new log-bin.
>
> (purge routine - sql/log.cc - MYSQL_BIN_LOG::open_index_file)
Is it really "purge" ^ here?
> 1 - open the log-bin.index.
> 2 - for each file in log-bin.index
> 2.1 check if the file exists.
> 2.2 if it does not exist and is not a new log-bin, remove the entry.
> 3 - for a new log-bin:
> 3.1 - if the file is corrupted, remove it.
> 3.2 - otherwise, do nothing.
>
> 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.
Can you please rewrite the commit message in a more clear way? More
specifically, items describing the steps that are being taken (I think
there is the need for definition of new log-bin for instance - check 2.2
above).
> added:
> mysql-test/suite/rpl/r/rpl_index.result
> mysql-test/suite/rpl/t/rpl_index.test
> 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-09-06 23:43:03 +0000
> @@ -1,3 +1,4 @@
> +call mtr.add_suppression('Attempting backtrace');
> flush logs;
> flush logs;
> flush logs;
> @@ -21,7 +22,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 +37,113 @@ 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;
> +flush logs;
> +*** It has master-bin.000001 master-bin.000002 master-bin.000003
> +./master-bin.000001
> +./master-bin.000002
> +./master-bin.000003
> +SET SESSION debug="+d,crash_purge_before_update_index";
> +purge binary logs TO 'master-bin.000003';
> +ERROR HY000: Lost connection to MySQL server during query
> +*** It has master-bin.000003 master-bin.000004
> +./master-bin.000003
> +./master-bin.000004
> +# crash_purge_after_update_index
> +flush logs;
> +*** It has master-bin.000003 master-bin.000004 master-bin.000005
> +./master-bin.000003
> +./master-bin.000004
> +./master-bin.000005
> +SET SESSION debug="+d,crash_purge_after_update_index";
> +purge binary logs TO 'master-bin.000005';
> +ERROR HY000: Lost connection to MySQL server during query
> +*** It has master-bin.000005 master-bin.000006
> +./master-bin.000005
> +./master-bin.000006
> +# crash_create_before_update_index
> +*** It has master-bin.000005 master-bin.000006
> +./master-bin.000005
> +./master-bin.000006
> +SET SESSION debug="+d,crash_create_before_update_index";
> +flush logs;
> +ERROR HY000: Lost connection to MySQL server during query
> +*** It has master-bin.000005 master-bin.000006 master-bin.000007
> +./master-bin.000005
> +./master-bin.000006
> +./master-bin.000007
> +# crash_create_after_update_index
> +*** It has master-bin.000005 master-bin.000006 master-bin.000007
> +./master-bin.000005
> +./master-bin.000006
> +./master-bin.000007
> +SET SESSION debug="+d,crash_create_after_update_index";
> +flush logs;
> +ERROR HY000: Lost connection to MySQL server during query
> +*** It has master-bin.000005 master-bin.000006 master-bin.000007
> +*** master-bin.000008
> +./master-bin.000005
> +./master-bin.000006
> +./master-bin.000007
> +./master-bin.000008
> +# crash_create_after_create_file
> +*** It has master-bin.000005 master-bin.000006 master-bin.000007
> +*** master-bin.000008
> +./master-bin.000005
> +./master-bin.000006
> +./master-bin.000007
> +./master-bin.000008
> +SET SESSION debug="+d,crash_create_after_create_file";
> +flush logs;
> +ERROR HY000: Lost connection to MySQL server during query
> +*** It has master-bin.000005 master-bin.000006 master-bin.000007
> +*** master-bin.000008 master-bin.000009
> +./master-bin.000005
> +./master-bin.000006
> +./master-bin.000007
> +./master-bin.000008
> +./master-bin.000009
> +# crash_updating_index
> +# This shows that the recovery process needs to change the procedure
> +# copy_up_file_and_fill to be completely safe. However, this most likely
> +# requires to change the format of the index file.
> +*** It has master-bin.000005 master-bin.000006 master-bin.000007
> +*** master-bin.000008 master-bin.000009
> +./master-bin.000005
> +./master-bin.000006
> +./master-bin.000007
> +./master-bin.000008
> +./master-bin.000009
> +SET SESSION debug="+d,crash_updating_index";
> +purge binary logs TO 'master-bin.000009';
> +ERROR HY000: Lost connection to MySQL server during query
> +./master-bin.000009
> +./master-bin.000006
> +./master-bin.000007
> +./master-bin.000008
> +./master-bin.000009
> +./master-bin.000010
> +flush logs;
> +purge binary logs TO 'master-bin.000011';
> +Warnings:
> +Warning 1612 Being purged log ./master-bin.000006 was not found
> +Warning 1612 Being purged log ./master-bin.000007 was not found
> +Warning 1612 Being purged log ./master-bin.000008 was not found
> +Warning 1612 Being purged log ./master-bin.000009 was not found
> +./master-bin.000011
> +# crash_reset_before_purge_file
> +./master-bin.000011
> +SET SESSION debug="+d,crash_reset_before_purge_file";
> +RESET MASTER;
> +ERROR HY000: Lost connection to MySQL server during query
> +./master-bin.000011
> +./master-bin.000012
> +# crash_reset_before_purge_index
> +./master-bin.000011
> +./master-bin.000012
> +SET SESSION debug="+d,crash_reset_before_purge_index";
> +RESET MASTER;
> +ERROR HY000: Lost connection to MySQL server during query
> +./master-bin.000001
> 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-09-06 23:43:03 +0000
> @@ -3,6 +3,7 @@
> #
> source include/have_log_bin.inc;
> source include/not_embedded.inc;
> +call mtr.add_suppression('Attempting backtrace');
>
> #
> # testing purge binary logs TO
> @@ -32,6 +33,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 ***
> @@ -66,4 +68,183 @@ rmdir $MYSQLD_DATADIR/master-bin.000001;
> --disable_warnings
> reset master;
> --enable_warnings
> +
> +--echo # crash_purge_before_update_index
> +flush logs;
> +flush logs;
> +--echo *** It has master-bin.000001 master-bin.000002 master-bin.000003
> +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;
> +
> +--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.000003';
> +
> +--enable_reconnect
> +--source include/wait_until_connected_again.inc
> +
> +--echo *** It has master-bin.000003 master-bin.000004
> +--error 1
> +file_exists $MYSQLD_DATADIR/master-bin.000001;
> +--error 1
> +file_exists $MYSQLD_DATADIR/master-bin.000002;
> +file_exists $MYSQLD_DATADIR/master-bin.000003;
> +file_exists $MYSQLD_DATADIR/master-bin.000004;
> +cat_file $MYSQLD_DATADIR/master-bin.index;
> +
> +--echo # crash_purge_after_update_index
> +flush logs;
> +--echo *** It has master-bin.000003 master-bin.000004 master-bin.000005
> +file_exists $MYSQLD_DATADIR/master-bin.000003;
> +file_exists $MYSQLD_DATADIR/master-bin.000004;
> +file_exists $MYSQLD_DATADIR/master-bin.000005;
> +cat_file $MYSQLD_DATADIR/master-bin.index;
> +
> +--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
> +SET SESSION debug="+d,crash_purge_after_update_index";
> +--error 2013
> +purge binary logs TO 'master-bin.000005';
> +
> +--enable_reconnect
> +--source include/wait_until_connected_again.inc
> +
> +--echo *** It has master-bin.000005 master-bin.000006
> +--error 1
> +file_exists $MYSQLD_DATADIR/master-bin.000003;
> +--error 1
> +file_exists $MYSQLD_DATADIR/master-bin.000004;
> +file_exists $MYSQLD_DATADIR/master-bin.000005;
> +file_exists $MYSQLD_DATADIR/master-bin.000006;
> +cat_file $MYSQLD_DATADIR/master-bin.index;
> +
> +--echo # crash_create_before_update_index
> +--echo *** It has master-bin.000005 master-bin.000006
> +file_exists $MYSQLD_DATADIR/master-bin.000005;
> +file_exists $MYSQLD_DATADIR/master-bin.000006;
> +cat_file $MYSQLD_DATADIR/master-bin.index;
> +--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
> +SET SESSION debug="+d,crash_create_before_update_index";
> +--error 2013
> +flush logs;
> +
> +--enable_reconnect
> +--source include/wait_until_connected_again.inc
> +
> +--echo *** It has master-bin.000005 master-bin.000006 master-bin.000007
> +file_exists $MYSQLD_DATADIR/master-bin.000005;
> +file_exists $MYSQLD_DATADIR/master-bin.000006;
> +file_exists $MYSQLD_DATADIR/master-bin.000007;
> +cat_file $MYSQLD_DATADIR/master-bin.index;
> +
> +--echo # crash_create_after_update_index
> +--echo *** It has master-bin.000005 master-bin.000006 master-bin.000007
> +file_exists $MYSQLD_DATADIR/master-bin.000005;
> +file_exists $MYSQLD_DATADIR/master-bin.000006;
> +file_exists $MYSQLD_DATADIR/master-bin.000007;
> +cat_file $MYSQLD_DATADIR/master-bin.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
> +
> +--echo *** It has master-bin.000005 master-bin.000006 master-bin.000007
> +--echo *** master-bin.000008
> +file_exists $MYSQLD_DATADIR/master-bin.000005;
> +file_exists $MYSQLD_DATADIR/master-bin.000006;
> +file_exists $MYSQLD_DATADIR/master-bin.000007;
> +file_exists $MYSQLD_DATADIR/master-bin.000008;
> +cat_file $MYSQLD_DATADIR/master-bin.index;
> +
> +--echo # crash_create_after_create_file
> +--echo *** It has master-bin.000005 master-bin.000006 master-bin.000007
> +--echo *** master-bin.000008
> +file_exists $MYSQLD_DATADIR/master-bin.000005;
> +file_exists $MYSQLD_DATADIR/master-bin.000006;
> +file_exists $MYSQLD_DATADIR/master-bin.000007;
> +file_exists $MYSQLD_DATADIR/master-bin.000008;
> +cat_file $MYSQLD_DATADIR/master-bin.index;
> +
> +--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
> +SET SESSION debug="+d,crash_create_after_create_file";
> +--error 2013
> +flush logs;
> +
> +--enable_reconnect
> +--source include/wait_until_connected_again.inc
> +
> +--echo *** It has master-bin.000005 master-bin.000006 master-bin.000007
> +--echo *** master-bin.000008 master-bin.000009
> +file_exists $MYSQLD_DATADIR/master-bin.000005;
> +file_exists $MYSQLD_DATADIR/master-bin.000006;
> +file_exists $MYSQLD_DATADIR/master-bin.000007;
> +file_exists $MYSQLD_DATADIR/master-bin.000008;
> +file_exists $MYSQLD_DATADIR/master-bin.000009;
> +cat_file $MYSQLD_DATADIR/master-bin.index;
> +
> +--echo # crash_updating_index
> +--echo # This shows that the recovery process needs to change the procedure
> +--echo # copy_up_file_and_fill to be completely safe. However, this most likely
> +--echo # requires to change the format of the index file.
> +--echo *** It has master-bin.000005 master-bin.000006 master-bin.000007
> +--echo *** master-bin.000008 master-bin.000009
> +file_exists $MYSQLD_DATADIR/master-bin.000005;
> +file_exists $MYSQLD_DATADIR/master-bin.000006;
> +file_exists $MYSQLD_DATADIR/master-bin.000007;
> +file_exists $MYSQLD_DATADIR/master-bin.000008;
> +file_exists $MYSQLD_DATADIR/master-bin.000009;
> +cat_file $MYSQLD_DATADIR/master-bin.index;
> +
> +--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
> +SET SESSION debug="+d,crash_updating_index";
> +--error 2013
> +purge binary logs TO 'master-bin.000009';
> +
> +--enable_reconnect
> +--source include/wait_until_connected_again.inc
> +
> +file_exists $MYSQLD_DATADIR/master-bin.000009;
> +file_exists $MYSQLD_DATADIR/master-bin.000010;
> +cat_file $MYSQLD_DATADIR/master-bin.index;
> +flush logs;
> +purge binary logs TO 'master-bin.000011';
> +cat_file $MYSQLD_DATADIR/master-bin.index;
> +
> +--echo # crash_reset_before_purge_file
> +file_exists $MYSQLD_DATADIR/master-bin.000011;
> +cat_file $MYSQLD_DATADIR/master-bin.index;
> +
> +--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
> +SET SESSION debug="+d,crash_reset_before_purge_file";
> +--error 2013
> +RESET MASTER;
> +
> +--enable_reconnect
> +--source include/wait_until_connected_again.inc
> +
> +file_exists $MYSQLD_DATADIR/master-bin.000011;
> +file_exists $MYSQLD_DATADIR/master-bin.000012;
> +cat_file $MYSQLD_DATADIR/master-bin.index;
> +
> +--echo # crash_reset_before_purge_index
> +file_exists $MYSQLD_DATADIR/master-bin.000011;
> +file_exists $MYSQLD_DATADIR/master-bin.000012;
> +cat_file $MYSQLD_DATADIR/master-bin.index;
> +
> +--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
> +SET SESSION debug="+d,crash_reset_before_purge_index";
> +--error 2013
> +RESET MASTER;
> +
> +--enable_reconnect
> +--source include/wait_until_connected_again.inc
> +
> +cat_file $MYSQLD_DATADIR/master-bin.index;
> +
> --echo End of tests
>
> === added file 'mysql-test/suite/rpl/r/rpl_index.result'
> --- a/mysql-test/suite/rpl/r/rpl_index.result 1970-01-01 00:00:00 +0000
> +++ b/mysql-test/suite/rpl/r/rpl_index.result 2009-09-06 23:43:03 +0000
> @@ -0,0 +1,55 @@
> +stop slave;
> +drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9;
> +reset master;
> +reset slave;
> +drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9;
> +start slave;
> +call mtr.add_suppression('Attempting backtrace');
> +STOP SLAVE;
> +CREATE TABLE test (a int);
> +INSERT INTO test VALUES(1);
> +# crash_create_after_update_index
> +*** It has master-bin.000001
> +./master-bin.000001
> +SET SESSION debug="+d,crash_create_after_update_index";
> +flush logs;
> +ERROR HY000: Lost connection to MySQL server during query
> +*** It has master-bin.000001 master-bin.000002
> +./master-bin.000001
> +./master-bin.000002
> +INSERT INTO test VALUES(2);
> +# crash_create_before_update_index
> +*** It has master-bin.000001
> +./master-bin.000001
> +./master-bin.000002
> +SET SESSION debug="+d,crash_create_before_update_index";
> +flush logs;
> +ERROR HY000: Lost connection to MySQL server during query
> +*** It has master-bin.000001 master-bin.000002 master-bin.000003
> +./master-bin.000001
> +./master-bin.000002
> +./master-bin.000003
> +INSERT INTO test VALUES(3);
> +# crash_create_after_create_file
> +*** It has master-bin.000001 master-bin.000002
> +./master-bin.000001
> +./master-bin.000002
> +./master-bin.000003
> +SET SESSION debug="+d,crash_create_after_create_file";
> +flush logs;
> +ERROR HY000: Lost connection to MySQL server during query
> +*** It has master-bin.000001 master-bin.000002 master-bin.000003
> +*** master-bin.000004
> +./master-bin.000001
> +./master-bin.000002
> +./master-bin.000003
> +./master-bin.000004
> +INSERT INTO test VALUES(4);
> +START SLAVE;
> +SELECT * FROM test order by a;
> +a
> +1
> +2
> +3
> +4
> +DROP TABLE test;
>
> === added file 'mysql-test/suite/rpl/t/rpl_index.test'
> --- a/mysql-test/suite/rpl/t/rpl_index.test 1970-01-01 00:00:00 +0000
> +++ b/mysql-test/suite/rpl/t/rpl_index.test 2009-09-06 23:43:03 +0000
> @@ -0,0 +1,94 @@
> +--source include/master-slave.inc
> +--source include/not_embedded.inc
> +
> +call mtr.add_suppression('Attempting backtrace');
> +
> +connection slave;
> +STOP SLAVE;
> +--source include/wait_for_slave_to_stop.inc
Why not just -- source include/stop_slave.inc?
> +connection master;
> +let $MYSQLD_DATADIR= `select @@datadir`;
> +
> +CREATE TABLE test (a int);
> +INSERT INTO test VALUES(1);
> +
> +--echo # crash_create_after_update_index
> +--echo *** It has master-bin.000001
> +file_exists $MYSQLD_DATADIR/master-bin.000001;
> +cat_file $MYSQLD_DATADIR/master-bin.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
> +
> +--echo *** It has master-bin.000001 master-bin.000002
> +file_exists $MYSQLD_DATADIR/master-bin.000001;
> +file_exists $MYSQLD_DATADIR/master-bin.000002;
> +cat_file $MYSQLD_DATADIR/master-bin.index;
> +
> +INSERT INTO test VALUES(2);
> +
> +--echo # crash_create_before_update_index
> +--echo *** It has master-bin.000001
> +file_exists $MYSQLD_DATADIR/master-bin.000001;
> +file_exists $MYSQLD_DATADIR/master-bin.000002;
> +cat_file $MYSQLD_DATADIR/master-bin.index;
> +
> +--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
> +SET SESSION debug="+d,crash_create_before_update_index";
> +--error 2013
> +flush logs;
> +
> +--enable_reconnect
> +--source include/wait_until_connected_again.inc
> +
> +--echo *** It has master-bin.000001 master-bin.000002 master-bin.000003
> +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;
> +
> +INSERT INTO test VALUES(3);
> +
> +--echo # crash_create_after_create_file
> +--echo *** It has master-bin.000001 master-bin.000002
> +file_exists $MYSQLD_DATADIR/master-bin.000001;
> +file_exists $MYSQLD_DATADIR/master-bin.000002;
> +cat_file $MYSQLD_DATADIR/master-bin.index;
> +
> +--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
> +SET SESSION debug="+d,crash_create_after_create_file";
> +--error 2013
> +flush logs;
> +
> +--enable_reconnect
> +--source include/wait_until_connected_again.inc
> +
> +--echo *** It has master-bin.000001 master-bin.000002 master-bin.000003
> +--echo *** master-bin.000004
> +file_exists $MYSQLD_DATADIR/master-bin.000001;
> +file_exists $MYSQLD_DATADIR/master-bin.000002;
> +file_exists $MYSQLD_DATADIR/master-bin.000003;
> +file_exists $MYSQLD_DATADIR/master-bin.000004;
> +cat_file $MYSQLD_DATADIR/master-bin.index;
> +
> +INSERT INTO test VALUES(4);
> +
> +connection slave;
> +START SLAVE;
> +--source include/wait_for_slave_to_start.inc
Why not just -- source include/start_slave.inc?
> +connection master;
> +sync_slave_with_master;
> +
> +connection slave;
> +SELECT * FROM test order by a;
> +
> +connection master;
> +DROP TABLE test;
> +sync_slave_with_master;
>
> === modified file 'sql/log.cc'
> --- a/sql/log.cc 2009-08-28 16:21:54 +0000
> +++ b/sql/log.cc 2009-09-06 23:43:03 +0000
> @@ -62,6 +62,10 @@ static int binlog_commit(handlerton *hto
> static int binlog_rollback(handlerton *hton, THD *thd, bool all);
> static int binlog_prepare(handlerton *hton, THD *thd, bool all);
>
> +#ifdef HAVE_REPLICATION
> +static bool copy_up_file_and_fill(IO_CACHE *index_file, my_off_t offset);
> +#endif
> +
> /**
> Silence all errors and warnings reported when performing a write
> to a log table.
> @@ -2424,7 +2428,6 @@ 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));
> }
>
> /* this is called only once */
> @@ -2468,7 +2471,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));
> @@ -2504,8 +2507,132 @@ bool MYSQL_BIN_LOG::open_index_file(cons
> my_close(index_file_nr,MYF(0));
> return TRUE;
> }
> + return (recovery_index_file(need_mutex));
> +}
> +
> +#ifdef HAVE_REPLICATION
> +
> +/**
> + Keeps the entries in the index file consistent with the files in the directory
> + after a crash. Entries that reference files that were purged are erased.
> + An entry that references a new file is kept regardless the file was created or
> + not. However, we check if it has a correct header and is not corrupted. If so,
> + it is removed.
> +
> + @param need_mudex indicates if it is necessary to aquire a lock.
> +
> + @retval
> + 0 ok
> + @retval
> + 1 error
> + */
> +bool MYSQL_BIN_LOG::recovery_index_file(bool need_mutex)
> +{
> + int error= 0;
> + File file;
> + IO_CACHE cache;
> + const char *errmsg;
> + LOG_INFO log_info;
> + my_off_t offset= 0;
> + bool found= FALSE;
> + char last_log_file_name[FN_REFLEN];
> +
> + DBUG_ENTER("MYSQL_BIN_LOG::recovery_index_file");
> +
> + if ((error= find_log_pos(&log_info, NullS, need_mutex)))
> + DBUG_RETURN (error == LOG_INFO_EOF ? FALSE : TRUE);
> + do
> + {
> + DBUG_PRINT("info", ("Checking file %s", log_info.log_file_name));
> + MY_STAT s;
> + if (!my_stat(log_info.log_file_name, &s, MYF(0)))
> + {
> + if (my_errno == ENOENT)
> + {
> + my_errno= 0;
> + if (!need_mutex)
> + {
> + /*
> + This is to avoid triggering an error in NDB.
> + */
> + ha_binlog_index_purge_file(current_thd, log_info.log_file_name);
> + }
> + sql_print_information("Removing index entry '%s' "
> + "as there is no correspondent binlog file.",
> + log_info.log_file_name);
> + }
> + else
> + {
> + /*
> + Other than ENOENT are fatal
> + */
> + sql_print_information("Failed to check log file '%s'; "
> + "consider examining correspondence "
> + "of your binlog index file "
> + "to the actual binlog files",
> + log_info.log_file_name);
> + error= LOG_INFO_FATAL;
> + goto err;
> + }
> + }
> + else if (!found)
> + {
> + DBUG_PRINT("info", ("The valid entries start at position %lu with file "
> + "%s", log_info.index_file_start_offset,
> + log_info.log_file_name));
> + offset= log_info.index_file_start_offset;
> + found= TRUE;
> + strmake(last_log_file_name, log_info.log_file_name,
> + sizeof(log_info.log_file_name));
> + }
> + else
> + strmake(last_log_file_name, log_info.log_file_name,
> + sizeof(log_info.log_file_name));
> + } while (!find_next_log(&log_info, need_mutex));
> +
> + if (found)
> + {
> + DBUG_PRINT("info", ("There is at least a valid entry. Thus we need to update the
> "
> + "index file."));
> + if (copy_up_file_and_fill(&index_file, offset))
> + goto err;
> +
> + DBUG_PRINT("info", ("Checking if the latest created file %s is not "
> + " corrupted.", last_log_file_name));
> +
> + if ((file= open_binlog(&cache, last_log_file_name, &errmsg)) < 0)
> + {
> + sql_print_error("%s", errmsg);
> + if ((error= my_delete(last_log_file_name, MYF(0))))
> + goto err;
> + }
> + else
> + {
> + end_io_cache(&cache);
> + my_close(file, MYF(MY_WME));
> + }
> + }
> + else
> + {
> + DBUG_PRINT("info", ("There is no valid entry. We just need to truncate the index
> "
> + "file."));
> + if (my_chsize(index_file.file, 0, '\n', MYF(MY_WME)) ||
> + my_sync(index_file.file, MYF(MY_WME)))
> + goto err;
> + reinit_io_cache(&index_file, READ_CACHE, (my_off_t) 0, 0, 1);
> + }
> +
> + DBUG_RETURN(FALSE);
> +
> +err:
> + DBUG_RETURN(TRUE);
> +}
> +#else
> +bool MYSQL_BIN_LOG::recovery_index_file(bool need_mutex __attribute__((unused)))
> +{
> return FALSE;
> }
> +#endif
>
>
> /**
> @@ -2528,13 +2655,61 @@ 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 index_entry[FN_REFLEN];
> +
> DBUG_ENTER("MYSQL_BIN_LOG::open");
> DBUG_PRINT("enter",("log_type: %d",(int) log_type_arg));
>
> - write_error=0;
> + 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(index_entry, new_name))
> + {
> + sql_print_error("MSYQL_BIN_LOG::open failed to copy index entry name.");
> + return(1);
> + }
> + else if (!new_name && generate_new_name(index_entry, log_name))
> + {
> + sql_print_error("MSYQL_BIN_LOG::open failed to get index entry name.");
> + return(1);
> + }
> +
> + DBUG_EXECUTE_IF("crash_create_before_update_index", abort(););
> +
> + MY_STAT s;
> + if (!my_stat(index_entry, &s, MYF(0)))
> + {
> + LOG_INFO log_info;
> + if (my_errno == ENOENT && find_log_pos(&log_info, index_entry,
> need_mutex))
> + {
> + 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*) index_entry,
> + strlen(index_entry)) ||
> + my_b_write(&index_file, (uchar*) "\n", 1) ||
> + flush_io_cache(&index_file) ||
> + my_sync(index_file.file, MYF(MY_WME)))
> + goto err;
> + }
> + else if (my_errno != ENOENT)
> + goto err;
> + }
> +
> + DBUG_EXECUTE_IF("crash_create_after_update_index", abort(););
>
> /* open the main log file */
> if (MYSQL_LOG::open(log_name, log_type_arg, new_name, io_cache_type_arg))
> @@ -2544,11 +2719,10 @@ bool MYSQL_BIN_LOG::open(const char *log
>
> open_count++;
>
> - DBUG_ASSERT(log_type == LOG_BIN);
> + DBUG_EXECUTE_IF("crash_create_after_create_file", abort(););
>
> + DBUG_ASSERT(log_type == LOG_BIN);
> {
> - bool write_file_name_to_index_file=0;
> -
> if (!my_b_filelength(&log_file))
> {
> /*
> @@ -2561,12 +2735,8 @@ bool MYSQL_BIN_LOG::open(const char *log
> BIN_LOG_HEADER_SIZE))
> goto err;
> bytes_written+= BIN_LOG_HEADER_SIZE;
> - 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)
> {
> /*
> @@ -2621,20 +2791,6 @@ bool MYSQL_BIN_LOG::open(const char *log
> if (flush_io_cache(&log_file) ||
> my_sync(log_file.file, MYF(MY_WME)))
> goto err;
> -
> - if (write_file_name_to_index_file)
> - {
> - /*
> - 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) ||
> - my_sync(index_file.file, MYF(MY_WME)))
> - goto err;
> - }
> }
> log_state= LOG_OPENED;
>
> @@ -2708,6 +2864,7 @@ static bool copy_up_file_and_fill(IO_CAC
> (void) my_seek(file, offset-init_offset, MY_SEEK_SET, MYF(0));
> if (my_write(file, io_buf, bytes_read, MYF(MY_WME | MY_NABP)))
> goto err;
> + DBUG_EXECUTE_IF("crash_updating_index", abort(););
> }
> /* The following will either truncate the file or fill the end with \n' */
> if (my_chsize(file, offset - init_offset, '\n', MYF(MY_WME)) ||
> @@ -2905,6 +3062,7 @@ bool MYSQL_BIN_LOG::reset_logs(THD* thd)
> goto err;
> }
>
> + DBUG_EXECUTE_IF("crash_reset_before_purge_file", abort(););
> for (;;)
> {
> if ((error= my_delete_allow_opened(linfo.log_file_name, MYF(0))) != 0)
> @@ -2936,6 +3094,8 @@ bool MYSQL_BIN_LOG::reset_logs(THD* thd)
> break;
> }
>
> + DBUG_EXECUTE_IF("crash_reset_before_purge_index", abort(););
> +
> /* Start logging with a new file */
> close(LOG_CLOSE_INDEX);
> if ((error= my_delete_allow_opened(index_file_name, MYF(0)))) // Reset (open will
> update)
> @@ -2965,8 +3125,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:
> @@ -3068,8 +3228,6 @@ int MYSQL_BIN_LOG::purge_first_log(Relay
> /* Store where we are in the new file for the execution thread */
> flush_relay_log_info(rli);
>
> - DBUG_EXECUTE_IF("crash_before_purge_logs", abort(););
> -
> pthread_mutex_lock(&rli->log_space_lock);
> rli->relay_log.purge_logs(to_purge_if_included, included,
> 0, 0, &rli->log_space_total);
> @@ -3170,91 +3328,15 @@ int MYSQL_BIN_LOG::purge_logs(const char
> }
>
> /*
> - For crash recovery reasons the index needs to be updated before
> - any files are deleted. Move files to be deleted into a temp file
> - to be processed after the index is updated.
> - */
> - if (!my_b_inited(&purge_temp))
> - {
> - if ((error=open_cached_file(&purge_temp, mysql_tmpdir, TEMP_PREFIX,
> - DISK_BUFFER_SIZE, MYF(MY_WME))))
> - {
> - sql_print_error("MYSQL_LOG::purge_logs failed to open purge_temp");
> - goto err;
> - }
> - }
> - else
> - {
> - if ((error=reinit_io_cache(&purge_temp, WRITE_CACHE, 0, 0, 1)))
> - {
> - sql_print_error("MYSQL_LOG::purge_logs failed to reinit purge_temp "
> - "for write");
> - goto err;
> - }
> - }
> -
> - /*
> File name exists in index file; delete until we find this file
> or a file that is used.
> */
> 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)) &&
> - !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)))
> - {
> - sql_print_error("MYSQL_LOG::purge_logs failed to copy %s to purge_temp",
> - log_info.log_file_name);
> - goto err;
> - }
> -
> - if (find_next_log(&log_info, 0) || exit_loop)
> - break;
> - }
> -
> - /* We know how many files to delete. Update index file. */
> - if ((error=update_log_index(&log_info, need_update_threads)))
> + while ((strcmp(to_log,log_info.log_file_name) || (exit_loop= included))
> &&
> + !log_in_use(log_info.log_file_name) &&
> + !is_active(log_info.log_file_name))
> {
> - sql_print_error("MSYQL_LOG::purge_logs failed to update the index file");
> - goto err;
> - }
> -
> - DBUG_EXECUTE_IF("crash_after_update_index", abort(););
> -
> - /* Switch purge_temp for read. */
> - if ((error=reinit_io_cache(&purge_temp, READ_CACHE, 0, 0, 0)))
> - {
> - sql_print_error("MSYQL_LOG::purge_logs failed to reinit purge_temp "
> - "for read");
> - goto err;
> - }
> -
> - /* Read each entry from purge_temp and delete the file. */
> - for (;;)
> - {
> - uint length;
> -
> - if ((length=my_b_gets(&purge_temp, log_info.log_file_name,
> - FN_REFLEN)) <= 1)
> - {
> - if (purge_temp.error)
> - {
> - error= purge_temp.error;
> - sql_print_error("MSYQL_LOG::purge_logs error %d reading from "
> - "purge_temp", error);
> - goto err;
> - }
> -
> - /* Reached EOF */
> - break;
> - }
> -
> - /* Get rid of the trailing '\n' */
> - log_info.log_file_name[length-1]= 0;
> -
> ha_binlog_index_purge_file(current_thd, log_info.log_file_name);
>
> MY_STAT s;
> @@ -3357,10 +3439,22 @@ int MYSQL_BIN_LOG::purge_logs(const char
> }
> }
> }
> + if (find_next_log(&log_info, 0) || exit_loop)
> + break;
> }
>
> + DBUG_EXECUTE_IF("crash_purge_before_update_index", abort(););
> +
> + /* We know how many files to delete. Update index file. */
> + if ((error=update_log_index(&log_info, need_update_threads)))
> + {
> + sql_print_error("MSYQL_LOG::purge_logs failed to update the index file");
> + goto err;
> + }
> +
> + DBUG_EXECUTE_IF("crash_purge_after_update_index", abort(););
> +
> err:
> - close_cached_file(&purge_temp);
> if (need_mutex)
> pthread_mutex_unlock(&LOCK_index);
> DBUG_RETURN(error);
> @@ -3402,25 +3496,13 @@ 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))
> + !log_in_use(log_info.log_file_name) &&
> + !is_active(log_info.log_file_name))
> {
> if (!my_stat(log_info.log_file_name, &stat_area, MYF(0)))
> {
> - if (my_errno == ENOENT)
> - {
> - /*
> - 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);
> + if (my_errno == ENOENT)
> my_errno= 0;
> - }
> else
> {
> /*
> @@ -3613,7 +3695,7 @@ void MYSQL_BIN_LOG::new_file_impl(bool n
> */
>
> open(old_name, log_type, new_name_ptr,
> - io_cache_type, no_auto_events, max_size, 1);
> + io_cache_type, no_auto_events, max_size, 1, FALSE);
> my_free(old_name,MYF(0));
>
> end:
> @@ -5515,7 +5597,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-09-06 23:43:03 +0000
> @@ -233,13 +233,6 @@ class MYSQL_BIN_LOG: public TC_LOG, priv
> pthread_cond_t update_cond;
> ulonglong bytes_written;
> IO_CACHE index_file;
> - /*
> - purge_temp is a temp file used in purge_logs so that the index file
> - can be updated before deleting files from disk, yielding better crash
> - recovery. It is created on demand the first time purge_logs is called
> - and then reused for subsequent calls. It is cleaned up in cleanup().
> - */
> - IO_CACHE purge_temp;
> char index_file_name[FN_REFLEN];
> /*
> The max size before rotation (usable only if log_type == LOG_BIN: binary
> @@ -349,9 +342,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);
> + bool recovery_index_file(bool need_mutex);
> /* Use this to start writing a new log file */
> void new_file();
>
>
> === modified file 'sql/mysqld.cc'
> --- a/sql/mysqld.cc 2009-08-11 14:29:07 +0000
> +++ b/sql/mysqld.cc 2009-09-06 23:43:03 +0000
> @@ -3884,7 +3884,7 @@ server.");
> 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);
> }
> @@ -4048,7 +4048,7 @@ server.");
> }
>
> 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-07-09 07:28:38 +0000
> +++ b/sql/rpl_rli.cc 2009-09-06 23:43:03 +0000
> @@ -158,10 +158,10 @@ int init_relay_log_info(Relay_log_info*
> 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
