List:Commits« Previous MessageNext Message »
From:Alfranio Correia Date:September 6 2009 11:43pm
Subject:bzr commit into mysql-5.1 branch (alfranio.correia:3102) Bug#45292
View as plain text  
#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)
      
            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.

    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
+
+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
+
+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()");


Attachment: [text/bzr-bundle]
Thread
bzr commit into mysql-5.1 branch (alfranio.correia:3102) Bug#45292Alfranio Correia7 Sep
  • Re: bzr commit into mysql-5.1 branch (alfranio.correia:3102) Bug#45292Luís Soares10 Sep
    • Re: bzr commit into mysql-5.1 branch (alfranio.correia:3102) Bug#45292Alfranio Correia11 Sep
    • Re: bzr commit into mysql-5.1 branch (alfranio.correia:3102) Bug#45292Alfranio Correia21 Sep
    • Re: bzr commit into mysql-5.1 branch (alfranio.correia:3102) Bug#45292Alfranio Correia21 Sep