List:Commits« Previous MessageNext Message »
From:Luis Soares Date:April 26 2010 10:27am
Subject:bzr commit into mysql-5.1-bugteam branch (luis.soares:3356) Bug#46166
View as plain text  
#At file:///home/lsoares/Workspace/bzr/work/bugfixing/46166/mysql-5.1-bugteam/ based on revid:kristofer.pettersson@stripped

 3356 Luis Soares	2010-04-26
      BUG#46166: MYSQL_BIN_LOG::new_file_impl is not propagating error 
                 when generating new name.
            
      If find_uniq_filename returns an error, then this error is not
      being propagated upwards, and execution does not report error 
      to the user (although a entry in the error log is generated).
      
      Additionally, some more errors were ignored in new_file_impl:
        - when writing the rotate event
        - when reopening the index and binary log file
      
      This patch addresses this by propagating the error up in the
      execution stack. Furthermore, when rotation of the binary log
      fails, an incident event is written, because there may be a
      chance that some changes for a given statement, were not properly
      logged. For example, in SBR, LOAD DATA INFILE statement requires
      more than one event to be logged, should rotation fail while
      logging part of the LOAD DATA events, then the logged data would
      become inconsistent with the data in the storage engine.
     @ mysql-test/suite/binlog/t/binlog_index.test
        The error on open of index and binary log on new_file_impl is now
        caught. Thence the user will get an error message. We need to
        accomodate this change in the test case for the failing FLUSH LOGS.
     @ mysql-test/suite/rpl/t/rpl_binlog_errors-master.opt
        Sets max_binlog_size to 4096.
     @ mysql-test/suite/rpl/t/rpl_binlog_errors.test
        Added a test case for asserting that the error is found and 
        reported.
     @ sql/handler.cc
        Catching error now returned by unlog (in ha_commit_trans) and 
        returning it.
     @ sql/log.cc
        Propagating errors from new_file_impl upwards. The errors that
        new_file_impl catches now are:
          - error on generate_new_name
          - error on writing the rotate event
          - error when opening the index or the binary log file.
     @ sql/log.h
        Changing declaration of:
        - rotate_and_purge
        - new_file
        - new_file_without_locking
        - new_file_impl
        - unlog
        
        They now return int instead of void.
     @ sql/rpl_injector.cc
        Changes to catch the return from rotate_and_purge.
     @ sql/slave.cc
        Changes to catch the return values for new_file and rotate_relay_log.
     @ sql/slave.h
        Changes to rotate_relay_log declaration (now returns int 
        instead of void).
     @ sql/sql_load.cc
        In SBR, some logging of LOAD DATA events goes through 
        IO_CACHE_CALLBACK invocation at mf_iocache.c:_my_b_get. The 
        IO_CACHE implementation is ignoring the return value for from 
        these callbacks (pre_read and post_read), so we need to find 
        out at the end of the execution if the error is set or not 
        in THD.
     @ sql/sql_parse.cc
        Catching the rotate_relay_log and rotate_and_purge return values.

    added:
      mysql-test/suite/rpl/r/rpl_binlog_errors.result
      mysql-test/suite/rpl/t/rpl_binlog_errors-master.opt
      mysql-test/suite/rpl/t/rpl_binlog_errors.test
    modified:
      mysql-test/suite/binlog/r/binlog_index.result
      mysql-test/suite/binlog/t/binlog_index.test
      sql/handler.cc
      sql/log.cc
      sql/log.h
      sql/rpl_injector.cc
      sql/slave.cc
      sql/slave.h
      sql/sql_load.cc
      sql/sql_parse.cc
=== modified file 'mysql-test/suite/binlog/r/binlog_index.result'
--- a/mysql-test/suite/binlog/r/binlog_index.result	2009-12-16 19:52:56 +0000
+++ b/mysql-test/suite/binlog/r/binlog_index.result	2010-04-26 10:27:35 +0000
@@ -116,11 +116,11 @@ 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;
+ERROR HY000: Can't open file: './master-bin.000012' (errno: 1)
 SET @index=LOAD_FILE('MYSQLTEST_VARDIR/mysqld.1/data//master-bin.index');
 SELECT @index;
 @index
@@ -135,6 +135,7 @@ master-bin.000012
 # fault_injection_updating_index
 SET SESSION debug="+d,fault_injection_updating_index";
 flush logs;
+ERROR HY000: Can't open file: './master-bin.000013' (errno: 1)
 SET @index=LOAD_FILE('MYSQLTEST_VARDIR/mysqld.1/data//master-bin.index');
 SELECT @index;
 @index

=== modified file 'mysql-test/suite/binlog/t/binlog_index.test'
--- a/mysql-test/suite/binlog/t/binlog_index.test	2009-12-08 16:03:19 +0000
+++ b/mysql-test/suite/binlog/t/binlog_index.test	2010-04-26 10:27:35 +0000
@@ -205,11 +205,11 @@ SELECT @index;
 --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";
+-- error ER_CANT_OPEN_FILE
 flush logs;
 --source include/restart_mysqld.inc
 
@@ -221,6 +221,7 @@ SELECT @index;
 
 --echo # fault_injection_updating_index
 SET SESSION debug="+d,fault_injection_updating_index";
+-- error ER_CANT_OPEN_FILE
 flush logs;
 --source include/restart_mysqld.inc
 

=== added file 'mysql-test/suite/rpl/r/rpl_binlog_errors.result'
--- a/mysql-test/suite/rpl/r/rpl_binlog_errors.result	1970-01-01 00:00:00 +0000
+++ b/mysql-test/suite/rpl/r/rpl_binlog_errors.result	2010-04-26 10:27:35 +0000
@@ -0,0 +1,164 @@
+call mtr.add_suppression("Can't generate a unique log-filename");
+call mtr.add_suppression("Writing one row to the row-based binary log failed.*");
+call mtr.add_suppression("Error writing file .*");
+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;
+include/stop_slave.inc
+SET @old_debug= @@global.debug;
+SELECT repeat('x',8192) INTO OUTFILE 'MYSQLTEST_VARDIR/tmp/bug_46166.data';
+RESET MASTER;
+######################################################################
+### assertion: no problem flushing logs (should show two binlogs)
+FLUSH LOGS;
+show binary logs;
+Log_name	File_size
+master-bin.000001	#
+master-bin.000002	#
+######################################################################
+### assertion: check that FLUSH LOGS actually fails and reports failure
+### back to the user if find_uniq_filename fails (should show
+### just one binlog)
+RESET MASTER;
+SET GLOBAL debug="+d,error_unique_log_filename";
+FLUSH LOGS;
+ERROR HY000: Can't generate a unique log-filename master-bin.(1-999)
+
+show binary logs;
+Log_name	File_size
+master-bin.000001	#
+SET GLOBAL debug="";
+RESET MASTER;
+CREATE TABLE t1 (a int);
+INSERT INTO t1 VALUES (1);
+CREATE TABLE t2 (a TEXT) Engine=InnoDB;
+CREATE TABLE t4 (a TEXT);
+######################################################################
+### assertion: check that even if one is using a transactional table
+### if rotation fails we get the error but, transaction is not rolled 
+### back, ie, rotation happens only after the commit is done and the 
+### event was already written to the binlog 
+###    (check handler.cc:ha_commit_trans()).
+SET GLOBAL debug="+d,error_unique_log_filename";
+SELECT count(*) FROM t2;
+count(*)
+0
+SET AUTOCOMMIT=0;
+INSERT INTO t2 VALUES ('muse');
+LOAD DATA INFILE 'MYSQLTEST_VARDIR/tmp/bug_46166.data' INTO TABLE t2;
+INSERT INTO t2 VALUES ('muse');
+COMMIT;
+ERROR HY000: Can't generate a unique log-filename master-bin.(1-999)
+
+SET AUTOCOMMIT= 1;
+SELECT count(*) FROM t2;
+count(*)
+3
+### clean up and move to the next test 
+SET GLOBAL debug="";
+FLUSH LOGS;
+RESET MASTER;
+######################################################################
+### assertion: check that on a non-transactional table, if rotation
+### fails then an error is reported and an incident event is written
+### to the current binary log.
+SET GLOBAL debug="+d,error_unique_log_filename";
+SELECT count(*) FROM t4;
+count(*)
+0
+LOAD DATA INFILE 'MYSQLTEST_VARDIR/tmp/bug_46166.data' INTO TABLE t4;
+ERROR HY000: Can't generate a unique log-filename master-bin.(1-999)
+
+SELECT count(*) FROM t4;
+count(*)
+1
+### check that the incident event is written to the current log
+SET GLOBAL debug="";
+FLUSH LOGS;
+SHOW BINLOG EVENTS IN 'BINLOG_FILE' FROM <binlog_start> LIMIT 1;
+Log_name	Pos	Event_type	Server_id	End_log_pos	Info
+BINLOG_FILE	#	Incident	#	#	#1 (LOST_EVENTS): 
+RESET MASTER;
+######################################################################
+### assertion: we force binlog to rotate because it exceeds the 
+### max_binlog_size option (should show two binary logs) 
+LOAD DATA INFILE 'MYSQLTEST_VARDIR/tmp/bug_46166.data' INTO TABLE t2;
+show binary logs;
+Log_name	File_size
+master-bin.000001	#
+master-bin.000002	#
+######################################################################
+### assertion: assert that mysql reports error when implicit rotation,
+### due to max_binlog_size, happens
+SELECT count(*) FROM t4;
+count(*)
+1
+INSERT INTO t2 VALUES ('aaa'), ('bbb'), ('ccc'), ('ddd');
+SET GLOBAL debug="+d,error_unique_log_filename";
+LOAD DATA INFILE 'MYSQLTEST_VARDIR/tmp/bug_46166.data' INTO TABLE t4;
+ERROR HY000: Can't generate a unique log-filename master-bin.(1-999)
+
+######################################################################
+### assertion: check that statements end up in error
+DELETE FROM t4;
+ERROR HY000: Can't generate a unique log-filename master-bin.(1-999)
+
+DELETE FROM t2;
+ERROR HY000: Can't generate a unique log-filename master-bin.(1-999)
+
+######################################################################
+### assertion: show that despite the fact that events could not be 
+### logged, the DELETEs have succeeded
+SELECT count(*) FROM t4;
+count(*)
+0
+SELECT count(*) FROM t2;
+count(*)
+0
+######################################################################
+### assertion: check that if we disable binlogging, then statements
+### succeed.
+SET SQL_LOG_BIN=0;
+INSERT INTO t2 VALUES ('aaa'), ('bbb'), ('ccc'), ('ddd');
+INSERT INTO t4 VALUES ('eee'), ('fff'), ('ggg'), ('hhh');
+SELECT count(*) FROM t2;
+count(*)
+4
+SELECT count(*) FROM t4;
+count(*)
+4
+DELETE FROM t2;
+DELETE FROM t4;
+SELECT count(*) FROM t2;
+count(*)
+0
+SELECT count(*) FROM t4;
+count(*)
+0
+SET SQL_LOG_BIN=1;
+SET GLOBAL debug= @old_debug;
+DROP TABLE t1, t2, t4;
+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;
+include/stop_slave.inc
+call mtr.add_suppression("Can't generate a unique log-filename.*");
+call mtr.add_suppression("Slave I/O: Relay log write failure: could not queue event from master.*");
+SET @old_debug=@@global.debug;
+SET GLOBAL debug="+d,error_unique_log_filename";
+START SLAVE;
+Relay log write failure: could not queue event from master
+FLUSH LOGS;
+ERROR HY000: Can't generate a unique log-filename slave-bin.(1-999)
+
+include/stop_slave.inc
+SET GLOBAL debug=@old_debug;
+RESET SLAVE;
+RESET MASTER;
+include/start_slave.inc

=== added file 'mysql-test/suite/rpl/t/rpl_binlog_errors-master.opt'
--- a/mysql-test/suite/rpl/t/rpl_binlog_errors-master.opt	1970-01-01 00:00:00 +0000
+++ b/mysql-test/suite/rpl/t/rpl_binlog_errors-master.opt	2010-04-26 10:27:35 +0000
@@ -0,0 +1 @@
+--max_binlog_size=4096

=== added file 'mysql-test/suite/rpl/t/rpl_binlog_errors.test'
--- a/mysql-test/suite/rpl/t/rpl_binlog_errors.test	1970-01-01 00:00:00 +0000
+++ b/mysql-test/suite/rpl/t/rpl_binlog_errors.test	2010-04-26 10:27:35 +0000
@@ -0,0 +1,192 @@
+# BUG#46166: MYSQL_BIN_LOG::new_file_impl is not propagating error
+#            when generating new name.
+#  
+# WHY
+# ===
+#
+# We want to check whether error is reported or not when
+# new_file_impl fails (this may happen when rotation is not
+# possible because there is some problem finding an 
+# unique filename).
+#
+# HOW
+# ===
+# 
+# Test cases are documented inline.
+
+call mtr.add_suppression("Can't generate a unique log-filename");
+call mtr.add_suppression("Writing one row to the row-based binary log failed.*");
+call mtr.add_suppression("Error writing file .*");
+
+-- source include/master-slave.inc
+-- source include/have_innodb.inc
+-- source include/have_debug.inc
+
+# stopping slave as it is not needed for the first part of the test
+-- connection slave
+-- source include/stop_slave.inc
+-- connection master
+
+SET @old_debug= @@global.debug;
+
+-- let $load_file= $MYSQLTEST_VARDIR/tmp/bug_46166.data
+-- let $MYSQLD_DATADIR= `select @@datadir`
+-- replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
+-- eval SELECT repeat('x',8192) INTO OUTFILE '$load_file'
+
+RESET MASTER;
+
+-- echo ######################################################################
+-- echo ### assertion: no problem flushing logs (should show two binlogs)
+FLUSH LOGS;
+-- source include/show_binary_logs.inc
+
+-- echo ######################################################################
+-- echo ### assertion: check that FLUSH LOGS actually fails and reports failure
+-- echo ### back to the user if find_uniq_filename fails (should show
+-- echo ### just one binlog)
+RESET MASTER;
+SET GLOBAL debug="+d,error_unique_log_filename";
+-- error ER_NO_UNIQUE_LOGFILE
+FLUSH LOGS;
+-- source include/show_binary_logs.inc
+
+## clean up and move to next test
+SET GLOBAL debug="";
+RESET MASTER;
+
+# issue some statements
+CREATE TABLE t1 (a int);
+INSERT INTO t1 VALUES (1);
+CREATE TABLE t2 (a TEXT) Engine=InnoDB;
+CREATE TABLE t4 (a TEXT);
+
+-- echo ######################################################################
+-- echo ### assertion: check that even if one is using a transactional table
+-- echo ### if rotation fails we get the error but, transaction is not rolled 
+-- echo ### back, ie, rotation happens only after the commit is done and the 
+-- echo ### event was already written to the binlog 
+-- echo ###    (check handler.cc:ha_commit_trans()).
+SET GLOBAL debug="+d,error_unique_log_filename";
+SELECT count(*) FROM t2;
+SET AUTOCOMMIT=0;
+INSERT INTO t2 VALUES ('muse');
+-- replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
+-- eval LOAD DATA INFILE '$load_file' INTO TABLE t2
+INSERT INTO t2 VALUES ('muse');
+-- error ER_NO_UNIQUE_LOGFILE
+COMMIT;
+SET AUTOCOMMIT= 1;
+SELECT count(*) FROM t2;
+
+-- echo ### clean up and move to the next test 
+SET GLOBAL debug="";
+FLUSH LOGS;
+RESET MASTER;
+
+-- echo ######################################################################
+-- echo ### assertion: check that on a non-transactional table, if rotation
+-- echo ### fails then an error is reported and an incident event is written
+-- echo ### to the current binary log.
+SET GLOBAL debug="+d,error_unique_log_filename";
+SELECT count(*) FROM t4;
+-- replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
+-- error ER_NO_UNIQUE_LOGFILE
+-- eval LOAD DATA INFILE '$load_file' INTO TABLE t4
+SELECT count(*) FROM t4;
+
+-- echo ### check that the incident event is written to the current log
+SET GLOBAL debug="";
+-- let $binlog_start= query_get_value(SHOW MASTER STATUS, Position, 1)
+-- let $binlog_file= query_get_value(SHOW MASTER STATUS, File, 1)
+
+# 22 is the size of the incident event, so we start from 22 bytes before the
+# current position
+-- let $binlog_start = `SELECT $binlog_start - 22`
+FLUSH LOGS;
+-- replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR $binlog_start <binlog_start> $binlog_file BINLOG_FILE
+-- replace_column 2 # 4 # 5 #
+-- eval SHOW BINLOG EVENTS IN '$binlog_file' FROM $binlog_start LIMIT 1
+RESET MASTER;
+
+-- echo ######################################################################
+-- echo ### assertion: we force binlog to rotate because it exceeds the 
+-- echo ### max_binlog_size option (should show two binary logs) 
+-- replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
+-- eval LOAD DATA INFILE '$load_file' INTO TABLE t2
+-- source include/show_binary_logs.inc
+
+-- echo ######################################################################
+-- echo ### assertion: assert that mysql reports error when implicit rotation,
+-- echo ### due to max_binlog_size, happens
+SELECT count(*) FROM t4;
+INSERT INTO t2 VALUES ('aaa'), ('bbb'), ('ccc'), ('ddd');
+SET GLOBAL debug="+d,error_unique_log_filename";
+-- replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
+-- error ER_NO_UNIQUE_LOGFILE
+-- eval LOAD DATA INFILE '$load_file' INTO TABLE t4
+
+-- echo ######################################################################
+-- echo ### assertion: check that statements end up in error
+-- error ER_NO_UNIQUE_LOGFILE
+DELETE FROM t4;
+-- error ER_NO_UNIQUE_LOGFILE
+DELETE FROM t2;
+
+-- echo ######################################################################
+-- echo ### assertion: show that despite the fact that events could not be 
+-- echo ### logged, the DELETEs have succeeded
+SELECT count(*) FROM t4;
+SELECT count(*) FROM t2;
+
+-- echo ######################################################################
+-- echo ### assertion: check that if we disable binlogging, then statements
+-- echo ### succeed.
+SET SQL_LOG_BIN=0;
+INSERT INTO t2 VALUES ('aaa'), ('bbb'), ('ccc'), ('ddd');
+INSERT INTO t4 VALUES ('eee'), ('fff'), ('ggg'), ('hhh');
+SELECT count(*) FROM t2;
+SELECT count(*) FROM t4;
+DELETE FROM t2;
+DELETE FROM t4;
+SELECT count(*) FROM t2;
+SELECT count(*) FROM t4;
+SET SQL_LOG_BIN=1;
+
+SET GLOBAL debug= @old_debug;
+DROP TABLE t1, t2, t4;
+
+
+##### check that slave IO thread shuts down gracefully
+
+### setup
+-- connection master
+-- source include/master-slave-reset.inc
+-- connection slave
+# need to stop because master-slave-reset starts the slave automatically
+-- source include/stop_slave.inc 
+call mtr.add_suppression("Can't generate a unique log-filename.*");
+call mtr.add_suppression("Slave I/O: Relay log write failure: could not queue event from master.*");
+SET @old_debug=@@global.debug;
+SET GLOBAL debug="+d,error_unique_log_filename";
+
+# start the slave and wait for IO thread to stop because it cant rotate
+START SLAVE;
+-- source include/wait_for_slave_sql_to_start.inc
+-- source include/wait_for_slave_io_to_stop.inc
+
+-- let $error= query_get_value(SHOW SLAVE STATUS, Last_IO_Error, 1)
+-- echo $error
+
+# check that FLUSH LOGS will also report error on the slave (not that needed)
+-- error ER_NO_UNIQUE_LOGFILE
+FLUSH LOGS;
+
+### clean up
+-- source include/stop_slave.inc
+SET GLOBAL debug=@old_debug;
+RESET SLAVE;
+RESET MASTER;
+-- source include/start_slave.inc
+-- connection master
+-- source include/master-slave-end.inc

=== modified file 'sql/handler.cc'
--- a/sql/handler.cc	2010-04-14 09:53:59 +0000
+++ b/sql/handler.cc	2010-04-26 10:27:35 +0000
@@ -1065,6 +1065,8 @@ ha_check_and_coalesce_trx_read_only(THD 
     1   transaction was rolled back
   @retval
     2   error during commit, data may be inconsistent
+  @retval
+    3   error during unlog
 
   @todo
     Since we don't support nested statement transactions in 5.0,
@@ -1192,7 +1194,8 @@ int ha_commit_trans(THD *thd, bool all)
     error=ha_commit_one_phase(thd, all) ? (cookie ? 2 : 1) : 0;
     DBUG_EXECUTE_IF("crash_commit_before_unlog", abort(););
     if (cookie)
-      tc_log->unlog(cookie, xid);
+      if(tc_log->unlog(cookie, xid))
+        error= 3;
     DBUG_EXECUTE_IF("crash_commit_after", abort(););
 end:
     if (rw_trans)

=== modified file 'sql/log.cc'
--- a/sql/log.cc	2010-03-28 11:57:33 +0000
+++ b/sql/log.cc	2010-04-26 10:27:35 +0000
@@ -1864,6 +1864,8 @@ static int find_uniq_filename(char *name
   char			*start, *end;
   DBUG_ENTER("find_uniq_filename");
 
+  DBUG_EXECUTE_IF("error_unique_log_filename", DBUG_RETURN(1););
+
   length= dirname_part(buff, name, &buf_length);
   start=  name + length;
   end=    strend(start);
@@ -2101,6 +2103,8 @@ int MYSQL_LOG::generate_new_name(char *n
     {
       if (find_uniq_filename(new_name))
       {
+        my_printf_error(ER_NO_UNIQUE_LOGFILE, ER(ER_NO_UNIQUE_LOGFILE),
+                        MYF(0), log_name);
 	sql_print_error(ER(ER_NO_UNIQUE_LOGFILE), log_name);
 	return 1;
       }
@@ -3730,15 +3734,15 @@ bool MYSQL_BIN_LOG::is_active(const char
   method).
 */
 
-void MYSQL_BIN_LOG::new_file()
+int MYSQL_BIN_LOG::new_file()
 {
-  new_file_impl(1);
+  return new_file_impl(1);
 }
 
 
-void MYSQL_BIN_LOG::new_file_without_locking()
+int MYSQL_BIN_LOG::new_file_without_locking()
 {
-  new_file_impl(0);
+  return new_file_impl(0);
 }
 
 
@@ -3751,15 +3755,16 @@ void MYSQL_BIN_LOG::new_file_without_loc
     The new file name is stored last in the index file
 */
 
-void MYSQL_BIN_LOG::new_file_impl(bool need_lock)
+int MYSQL_BIN_LOG::new_file_impl(bool need_lock)
 {
-  char new_name[FN_REFLEN], *new_name_ptr, *old_name;
+  int error= 0;
+  char new_name[FN_REFLEN], *new_name_ptr, *old_name, *file_to_open;
 
   DBUG_ENTER("MYSQL_BIN_LOG::new_file_impl");
   if (!is_open())
   {
     DBUG_PRINT("info",("log is closed"));
-    DBUG_VOID_RETURN;
+    DBUG_RETURN(error);
   }
 
   if (need_lock)
@@ -3797,7 +3802,7 @@ void MYSQL_BIN_LOG::new_file_impl(bool n
     We have to do this here and not in open as we want to store the
     new file name in the current binary log file.
   */
-  if (generate_new_name(new_name, name))
+  if ((error= generate_new_name(new_name, name)))
     goto end;
   new_name_ptr=new_name;
 
@@ -3811,7 +3816,8 @@ void MYSQL_BIN_LOG::new_file_impl(bool n
       */
       Rotate_log_event r(new_name+dirname_length(new_name),
                          0, LOG_EVENT_OFFSET, is_relay_log ? Rotate_log_event::RELAY_LOG : 0);
-      r.write(&log_file);
+      if((error= r.write(&log_file)))
+        goto end;
       bytes_written += r.data_written;
     }
     /*
@@ -3839,9 +3845,15 @@ void MYSQL_BIN_LOG::new_file_impl(bool n
   */
 
   /* reopen index binlog file, BUG#34582 */
-  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);
+  if ((error= ((file_to_open= index_file_name) && 
+               (error= open_index_file(index_file_name, 0, FALSE))) ||
+              ((file_to_open= new_name_ptr) &&
+               (error= open(old_name, log_type, new_name_ptr,
+                            io_cache_type, no_auto_events, 
+                            max_size, 1, FALSE)))))
+      my_printf_error(ER_CANT_OPEN_FILE, ER(ER_CANT_OPEN_FILE), 
+                      MYF(0), file_to_open, error);
+
   my_free(old_name,MYF(0));
 
 end:
@@ -3849,7 +3861,7 @@ end:
     pthread_mutex_unlock(&LOCK_log);
   pthread_mutex_unlock(&LOCK_index);
 
-  DBUG_VOID_RETURN;
+  DBUG_RETURN(error);
 }
 
 
@@ -3872,8 +3884,7 @@ bool MYSQL_BIN_LOG::append(Log_event* ev
   bytes_written+= ev->data_written;
   DBUG_PRINT("info",("max_size: %lu",max_size));
   if ((uint) my_b_append_tell(&log_file) > max_size)
-    new_file_without_locking();
-
+    error= new_file_without_locking();
 err:
   pthread_mutex_unlock(&LOCK_log);
   signal_update();				// Safe as we don't call close
@@ -3902,8 +3913,7 @@ bool MYSQL_BIN_LOG::appendv(const char* 
   } while ((buf=va_arg(args,const char*)) && (len=va_arg(args,uint)));
   DBUG_PRINT("info",("max_size: %lu",max_size));
   if ((uint) my_b_append_tell(&log_file) > max_size)
-    new_file_without_locking();
-
+    error= new_file_without_locking();
 err:
   if (!error)
     signal_update();
@@ -4212,7 +4222,7 @@ MYSQL_BIN_LOG::flush_and_set_pending_row
       if (!error)
       {
         signal_update();
-        rotate_and_purge(RP_LOCK_LOG_IS_ALREADY_LOCKED);
+        error= rotate_and_purge(RP_LOCK_LOG_IS_ALREADY_LOCKED);
       }
     }
 
@@ -4408,7 +4418,9 @@ bool MYSQL_BIN_LOG::write(Log_event *eve
       if (flush_and_sync())
 	goto err;
       signal_update();
-      rotate_and_purge(RP_LOCK_LOG_IS_ALREADY_LOCKED);
+      if ((error= rotate_and_purge(RP_LOCK_LOG_IS_ALREADY_LOCKED)))
+        goto err;
+      
     }
     error=0;
 
@@ -4494,8 +4506,10 @@ bool general_log_write(THD *thd, enum en
   return FALSE;
 }
 
-void MYSQL_BIN_LOG::rotate_and_purge(uint flags)
+int MYSQL_BIN_LOG::rotate_and_purge(uint flags)
 {
+  int error= 0;
+  DBUG_ENTER("MYSQL_BIN_LOG::rotate_and_purge");
 #ifdef HAVE_REPLICATION
   bool check_purge= false;
 #endif
@@ -4504,7 +4518,7 @@ void MYSQL_BIN_LOG::rotate_and_purge(uin
   if ((flags & RP_FORCE_ROTATE) ||
       (my_b_tell(&log_file) >= (my_off_t) max_size))
   {
-    new_file_without_locking();
+    error= new_file_without_locking();
 #ifdef HAVE_REPLICATION
     check_purge= true;
 #endif
@@ -4512,6 +4526,26 @@ void MYSQL_BIN_LOG::rotate_and_purge(uin
   if (!(flags & RP_LOCK_LOG_IS_ALREADY_LOCKED))
     pthread_mutex_unlock(&LOCK_log);
 
+  if (error)
+  {
+    /** 
+       Be conservative... There are possible lost events (eg, 
+       failing to log the Execute_load_query_log_event
+       on a LOAD DATA while using a non-transactional
+       table)!
+    */
+    Incident incident= INCIDENT_LOST_EVENTS;
+    Incident_log_event ev(current_thd, incident);
+    /** 
+       We give it a shot and try to write an incident event anyway
+       to the current log. 
+    */
+    (void) ev.write(&log_file);
+
+    goto end;
+  }
+
+
 #ifdef HAVE_REPLICATION
   /*
     NOTE: Run purge_logs wo/ holding LOCK_log
@@ -4524,6 +4558,9 @@ void MYSQL_BIN_LOG::rotate_and_purge(uin
       purge_logs_before_date(purge_time);
   }
 #endif
+
+end:
+  DBUG_RETURN(error);
 }
 
 uint MYSQL_BIN_LOG::next_file_id()
@@ -4722,7 +4759,7 @@ bool MYSQL_BIN_LOG::write_incident(THD *
     if (!error && !(error= flush_and_sync()))
     {
       signal_update();
-      rotate_and_purge(RP_LOCK_LOG_IS_ALREADY_LOCKED);
+      error= rotate_and_purge(RP_LOCK_LOG_IS_ALREADY_LOCKED);
     }
     pthread_mutex_unlock(&LOCK_log);
   }
@@ -4834,7 +4871,8 @@ bool MYSQL_BIN_LOG::write(THD *thd, IO_C
       pthread_mutex_unlock(&LOCK_prep_xids);
     }
     else
-      rotate_and_purge(RP_LOCK_LOG_IS_ALREADY_LOCKED);
+      if (rotate_and_purge(RP_LOCK_LOG_IS_ALREADY_LOCKED))
+        goto err;
   }
   VOID(pthread_mutex_unlock(&LOCK_log));
 
@@ -5597,7 +5635,7 @@ int TC_LOG_MMAP::sync()
   cookie points directly to the memory where xid was logged.
 */
 
-void TC_LOG_MMAP::unlog(ulong cookie, my_xid xid)
+int TC_LOG_MMAP::unlog(ulong cookie, my_xid xid)
 {
   PAGE *p=pages+(cookie/tc_log_page_size);
   my_xid *x=(my_xid *)(data+cookie);
@@ -5615,6 +5653,7 @@ void TC_LOG_MMAP::unlog(ulong cookie, my
   if (p->waiters == 0)                 // the page is in pool and ready to rock
     pthread_cond_signal(&COND_pool);   // ping ... for overflow()
   pthread_mutex_unlock(&p->lock);
+  return 0;
 }
 
 void TC_LOG_MMAP::close()
@@ -5856,8 +5895,9 @@ int TC_LOG_BINLOG::log_xid(THD *thd, my_
   DBUG_RETURN(!binlog_end_trans(thd, trx_data, &xle, TRUE));
 }
 
-void TC_LOG_BINLOG::unlog(ulong cookie, my_xid xid)
+int TC_LOG_BINLOG::unlog(ulong cookie, my_xid xid)
 {
+  DBUG_ENTER("TC_LOG_BINLOG::unlog");
   pthread_mutex_lock(&LOCK_prep_xids);
   DBUG_ASSERT(prepared_xids > 0);
   if (--prepared_xids == 0) {
@@ -5865,7 +5905,7 @@ void TC_LOG_BINLOG::unlog(ulong cookie, 
     pthread_cond_signal(&COND_prep_xids);
   }
   pthread_mutex_unlock(&LOCK_prep_xids);
-  rotate_and_purge(0);     // as ::write() did not rotate
+  DBUG_RETURN(rotate_and_purge(0));     // as ::write() did not rotate
 }
 
 int TC_LOG_BINLOG::recover(IO_CACHE *log, Format_description_log_event *fdle)

=== modified file 'sql/log.h'
--- a/sql/log.h	2009-12-04 14:40:42 +0000
+++ b/sql/log.h	2010-04-26 10:27:35 +0000
@@ -34,7 +34,7 @@ class TC_LOG
   virtual int open(const char *opt_name)=0;
   virtual void close()=0;
   virtual int log_xid(THD *thd, my_xid xid)=0;
-  virtual void unlog(ulong cookie, my_xid xid)=0;
+  virtual int unlog(ulong cookie, my_xid xid)=0;
 };
 
 class TC_LOG_DUMMY: public TC_LOG // use it to disable the logging
@@ -44,7 +44,7 @@ public:
   int open(const char *opt_name)        { return 0; }
   void close()                          { }
   int log_xid(THD *thd, my_xid xid)         { return 1; }
-  void unlog(ulong cookie, my_xid xid)  { }
+  int unlog(ulong cookie, my_xid xid)  { return 0; }
 };
 
 #ifdef HAVE_MMAP
@@ -89,7 +89,7 @@ class TC_LOG_MMAP: public TC_LOG
   int open(const char *opt_name);
   void close();
   int log_xid(THD *thd, my_xid xid);
-  void unlog(ulong cookie, my_xid xid);
+  int unlog(ulong cookie, my_xid xid);
   int recover();
 
   private:
@@ -280,8 +280,8 @@ class MYSQL_BIN_LOG: public TC_LOG, priv
     new_file() is locking. new_file_without_locking() does not acquire
     LOCK_log.
   */
-  void new_file_without_locking();
-  void new_file_impl(bool need_lock);
+  int new_file_without_locking();
+  int new_file_impl(bool need_lock);
 
 public:
   MYSQL_LOG::generate_name;
@@ -311,7 +311,7 @@ public:
   int open(const char *opt_name);
   void close();
   int log_xid(THD *thd, my_xid xid);
-  void unlog(ulong cookie, my_xid xid);
+  int unlog(ulong cookie, my_xid xid);
   int recover(IO_CACHE *log, Format_description_log_event *fdle);
 #if !defined(MYSQL_CLIENT)
   bool is_table_mapped(TABLE *table) const
@@ -359,7 +359,7 @@ public:
   bool open_index_file(const char *index_file_name_arg,
                        const char *log_name, bool need_mutex);
   /* Use this to start writing a new log file */
-  void new_file();
+  int new_file();
 
   bool write(Log_event* event_info); // binary log write
   bool write(THD *thd, IO_CACHE *cache, Log_event *commit_event, bool incident);
@@ -383,7 +383,7 @@ public:
   void make_log_name(char* buf, const char* log_ident);
   bool is_active(const char* log_file_name);
   int update_log_index(LOG_INFO* linfo, bool need_update_threads);
-  void rotate_and_purge(uint flags);
+  int rotate_and_purge(uint flags);
   bool flush_and_sync();
   int purge_logs(const char *to_log, bool included,
                  bool need_mutex, bool need_update_threads,

=== modified file 'sql/rpl_injector.cc'
--- a/sql/rpl_injector.cc	2010-01-28 21:51:40 +0000
+++ b/sql/rpl_injector.cc	2010-04-26 10:27:35 +0000
@@ -229,8 +229,7 @@ int injector::record_incident(THD *thd, 
   Incident_log_event ev(thd, incident);
   if (int error= mysql_bin_log.write(&ev))
     return error;
-  mysql_bin_log.rotate_and_purge(RP_FORCE_ROTATE);
-  return 0;
+  return mysql_bin_log.rotate_and_purge(RP_FORCE_ROTATE);
 }
 
 int injector::record_incident(THD *thd, Incident incident, LEX_STRING const message)
@@ -238,6 +237,5 @@ int injector::record_incident(THD *thd, 
   Incident_log_event ev(thd, incident, message);
   if (int error= mysql_bin_log.write(&ev))
     return error;
-  mysql_bin_log.rotate_and_purge(RP_FORCE_ROTATE);
-  return 0;
+  return mysql_bin_log.rotate_and_purge(RP_FORCE_ROTATE);
 }

=== modified file 'sql/slave.cc'
--- a/sql/slave.cc	2010-03-19 09:06:40 +0000
+++ b/sql/slave.cc	2010-04-26 10:27:35 +0000
@@ -3360,8 +3360,7 @@ static int process_io_rotate(Master_info
     Rotate the relay log makes binlog format detection easier (at next slave
     start or mysqlbinlog)
   */
-  rotate_relay_log(mi); /* will take the right mutexes */
-  DBUG_RETURN(0);
+  DBUG_RETURN(rotate_relay_log(mi) /* will take the right mutexes */);
 }
 
 /*
@@ -4390,10 +4389,11 @@ err:
   is void).
 */
 
-void rotate_relay_log(Master_info* mi)
+int rotate_relay_log(Master_info* mi)
 {
   DBUG_ENTER("rotate_relay_log");
   Relay_log_info* rli= &mi->rli;
+  int error= 0;
 
   /* We don't lock rli->run_lock. This would lead to deadlocks. */
   pthread_mutex_lock(&mi->run_lock);
@@ -4409,7 +4409,8 @@ void rotate_relay_log(Master_info* mi)
   }
 
   /* If the relay log is closed, new_file() will do nothing. */
-  rli->relay_log.new_file();
+  if ((error= rli->relay_log.new_file()))
+    goto end;
 
   /*
     We harvest now, because otherwise BIN_LOG_HEADER_SIZE will not immediately
@@ -4427,7 +4428,7 @@ void rotate_relay_log(Master_info* mi)
   rli->relay_log.harvest_bytes_written(&rli->log_space_total);
 end:
   pthread_mutex_unlock(&mi->run_lock);
-  DBUG_VOID_RETURN;
+  DBUG_RETURN(error);
 }
 
 

=== modified file 'sql/slave.h'
--- a/sql/slave.h	2009-12-14 16:32:22 +0000
+++ b/sql/slave.h	2010-04-26 10:27:35 +0000
@@ -189,7 +189,7 @@ int purge_relay_logs(Relay_log_info* rli
 		     const char** errmsg);
 void set_slave_thread_options(THD* thd);
 void set_slave_thread_default_charset(THD *thd, Relay_log_info const *rli);
-void rotate_relay_log(Master_info* mi);
+int rotate_relay_log(Master_info* mi);
 int apply_event_and_update_pos(Log_event* ev, THD* thd, Relay_log_info* rli);
 
 pthread_handler_t handle_slave_io(void *arg);

=== modified file 'sql/sql_load.cc'
--- a/sql/sql_load.cc	2010-04-16 14:56:16 +0000
+++ b/sql/sql_load.cc	2010-04-26 10:27:35 +0000
@@ -559,6 +559,8 @@ int mysql_load(THD *thd,sql_exchange *ex
                                                   transactional_table,
                                                   errcode);
       }
+
+      error= error || thd->is_error();
     }
     if (error)
       goto err;

=== modified file 'sql/sql_parse.cc'
--- a/sql/sql_parse.cc	2010-04-12 10:12:20 +0000
+++ b/sql/sql_parse.cc	2010-04-26 10:27:35 +0000
@@ -3160,7 +3160,11 @@ end_with_restore_list:
       {
         Incident_log_event ev(thd, incident);
         (void) mysql_bin_log.write(&ev);        /* error is ignored */
-        mysql_bin_log.rotate_and_purge(RP_FORCE_ROTATE);
+        if (mysql_bin_log.rotate_and_purge(RP_FORCE_ROTATE))
+        {
+          res= 1;
+          break;
+        }
       }
       DBUG_PRINT("debug", ("Just after generate_incident()"));
     }
@@ -6843,12 +6847,16 @@ bool reload_acl_and_cache(THD *thd, ulon
     tmp_write_to_binlog= 0;
     if( mysql_bin_log.is_open() )
     {
-      mysql_bin_log.rotate_and_purge(RP_FORCE_ROTATE);
+      if (mysql_bin_log.rotate_and_purge(RP_FORCE_ROTATE))
+        return 1;
     }
 #ifdef HAVE_REPLICATION
+    int rotate_error= 0;
     pthread_mutex_lock(&LOCK_active_mi);
-    rotate_relay_log(active_mi);
+    rotate_error= rotate_relay_log(active_mi);
     pthread_mutex_unlock(&LOCK_active_mi);
+    if (rotate_error)
+      return 1;
 #endif
 
     /* flush slow and general logs */


Attachment: [text/bzr-bundle] bzr/luis.soares@sun.com-20100426102735-eh19yj17jgr5n936.bundle
Thread
bzr commit into mysql-5.1-bugteam branch (luis.soares:3356) Bug#46166Luis Soares26 Apr
  • Re: bzr commit into mysql-5.1-bugteam branch (luis.soares:3356)Bug#46166Alfranio Correia29 Apr
    • Re: bzr commit into mysql-5.1-bugteam branch (luis.soares:3356)Bug#46166Luís Soares29 Apr
  • Re: bzr commit into mysql-5.1-bugteam branch (luis.soares:3356)Bug#46166He Zhenxing1 May