List:Commits« Previous MessageNext Message »
From:Dao-Gang.Qu Date:October 15 2010 5:30am
Subject:bzr commit into mysql-next-mr-bugfixing branch (Dao-Gang.Qu:3324) Bug#56913
View as plain text  
#At file:///home/daogangqu/mysql/bzrwork1/pushwl5404/mysql-next-mr-bugfixing/ based on revid:dao-gang.qu@stripped

 3324 Dao-Gang.Qu@stripped	2010-10-15
      Bug #56913    rpl_row_ignorable_event fails sporadically on next-mr-bugfixing codebase
      
      In RBR, The rows are inserted to a queue by the thread executing
      the 'INSERT DELAYED' statement, and are taken out from the queue
      by the handler thread to do the real insertion. Because these two
      threads are running in parallel, there is a possibility that they
      are run in an interleaved manner, and result in different number
      of table_map and rows events.
      
      Added a debug option for the test to make the binlog of multi
      'INSERT DELAYED ...' stmt stable by forcing every value is
      executed into one execution series, and then each value will
      be binlogged into a separate rows event with its table map
      event. And the original SQL statement will be displayed just
      for the first separate rows event because the query is NULL
      in other separate rows. 
     @ mysql-test/suite/rpl/r/rpl_row_ignorable_event.result
        Updated for the patch of Bug#56913.
     @ mysql-test/suite/rpl/t/rpl_row_ignorable_event.test
        Updated to test single 'INSERT DELAYED ...' stmt as the binlog
        of multi 'INSERT DELAYED ...' stmt is unstable.
     @ sql/log_event.cc
        Added code to clear query in case the randomizing pointer
        to the query will be used to binlog Rows_query_log_event
        for the second and following separate rows events for
        multi 'INSERT DELAYED ...' stmt
     @ sql/sql_insert.cc
        Set DBUG point to make every value is executed in one separate
        execution series for multi 'INSERT DELAYED ...' stmt.

    modified:
      mysql-test/suite/rpl/r/rpl_row_ignorable_event.result
      mysql-test/suite/rpl/t/rpl_row_ignorable_event.test
      sql/log_event.cc
      sql/sql_insert.cc
=== modified file 'mysql-test/suite/rpl/r/rpl_row_ignorable_event.result'
--- a/mysql-test/suite/rpl/r/rpl_row_ignorable_event.result	2010-09-01 02:51:08 +0000
+++ b/mysql-test/suite/rpl/r/rpl_row_ignorable_event.result	2010-10-15 05:30:43 +0000
@@ -4,6 +4,8 @@ reset master;
 reset slave;
 drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9;
 start slave;
+SET @old_debug= @@global.debug;
+SET GLOBAL debug="+d,waiting_for_delayed_insert_queue_is_empty";
 # Test non-transaction
 create table t1(a int, b int) engine= myisam;
 insert into t1(a,b) values(1,1),(2,1);
@@ -42,6 +44,7 @@ insert into t5(a, b) values(3,1);
 update t4,t5 set t4.a=4, t5.a=5 where t4.b=t5.b;
 # Test insert delayed ...
 insert delayed into t3(a,b) values(1,5),(1,6),(1,7);
+SET @@global.debug= @old_debug;
 # Test load data infile
 create table t6(a VARCHAR(60)) engine= myisam;
 load data infile '../../std_data/words.dat' into table t6;
@@ -132,6 +135,10 @@ master-bin.000001	#	Query	#	#	BEGIN
 master-bin.000001	#	Rows_query	#	#	# insert delayed into t3(a,b) values(1,5),(1,6),(1,7)
 master-bin.000001	#	Table_map	#	#	table_id: # (test.t3)
 master-bin.000001	#	Write_rows	#	#	table_id: # flags: STMT_END_F
+master-bin.000001	#	Table_map	#	#	table_id: # (test.t3)
+master-bin.000001	#	Write_rows	#	#	table_id: # flags: STMT_END_F
+master-bin.000001	#	Table_map	#	#	table_id: # (test.t3)
+master-bin.000001	#	Write_rows	#	#	table_id: # flags: STMT_END_F
 master-bin.000001	#	Query	#	#	COMMIT
 master-bin.000001	#	Query	#	#	use `test`; create table t6(a VARCHAR(60)) engine= myisam
 master-bin.000001	#	Query	#	#	BEGIN
@@ -526,10 +533,18 @@ BEGIN
 ### SET
 ###   @1=1 /* INT meta=0 nullable=1 is_null=0 */
 ###   @2=5 /* INT meta=0 nullable=1 is_null=0 */
+# at #
+# at #
+#server id #  end_log_pos # 	Table_map: `test`.`t3` mapped to number #
+#server id #  end_log_pos # 	Write_rows: table id # flags: STMT_END_F
 ### INSERT INTO test.t3
 ### SET
 ###   @1=1 /* INT meta=0 nullable=1 is_null=0 */
 ###   @2=6 /* INT meta=0 nullable=1 is_null=0 */
+# at #
+# at #
+#server id #  end_log_pos # 	Table_map: `test`.`t3` mapped to number #
+#server id #  end_log_pos # 	Write_rows: table id # flags: STMT_END_F
 ### INSERT INTO test.t3
 ### SET
 ###   @1=1 /* INT meta=0 nullable=1 is_null=0 */
@@ -935,6 +950,14 @@ slave-bin.000001	#	Rows_query	#	#	# inse
 slave-bin.000001	#	Table_map	#	#	table_id: # (test.t3)
 slave-bin.000001	#	Write_rows	#	#	table_id: # flags: STMT_END_F
 slave-bin.000001	#	Query	#	#	COMMIT
+slave-bin.000001	#	Query	#	#	BEGIN
+slave-bin.000001	#	Table_map	#	#	table_id: # (test.t3)
+slave-bin.000001	#	Write_rows	#	#	table_id: # flags: STMT_END_F
+slave-bin.000001	#	Query	#	#	COMMIT
+slave-bin.000001	#	Query	#	#	BEGIN
+slave-bin.000001	#	Table_map	#	#	table_id: # (test.t3)
+slave-bin.000001	#	Write_rows	#	#	table_id: # flags: STMT_END_F
+slave-bin.000001	#	Query	#	#	COMMIT
 slave-bin.000001	#	Query	#	#	use `test`; create table t6(a VARCHAR(60)) engine= myisam
 slave-bin.000001	#	Query	#	#	BEGIN
 slave-bin.000001	#	Rows_query	#	#	# load data infile '../../std_data/words.dat' into table t6

=== modified file 'mysql-test/suite/rpl/t/rpl_row_ignorable_event.test'
--- a/mysql-test/suite/rpl/t/rpl_row_ignorable_event.test	2010-08-06 02:20:44 +0000
+++ b/mysql-test/suite/rpl/t/rpl_row_ignorable_event.test	2010-10-15 05:30:43 +0000
@@ -12,6 +12,8 @@ source include/master-slave.inc;
 source include/have_binlog_rows_query.inc;
 source include/have_innodb.inc;
 
+SET @old_debug= @@global.debug;
+SET GLOBAL debug="+d,waiting_for_delayed_insert_queue_is_empty";
 --echo # Test non-transaction
 let $binlog_start= query_get_value("SHOW MASTER STATUS", Position, 1);
 let $master_binlog= query_get_value(SHOW MASTER STATUS, File, 1);
@@ -58,7 +60,11 @@ insert into t5(a, b) values(3,1);
 update t4,t5 set t4.a=4, t5.a=5 where t4.b=t5.b;
 
 --echo # Test insert delayed ...
+let $table=t3;
 insert delayed into t3(a,b) values(1,5),(1,6),(1,7);
+let $count=4;
+--source include/wait_until_rows_count.inc
+SET @@global.debug= @old_debug;
 
 --echo # Test load data infile
 create table t6(a VARCHAR(60)) engine= myisam;

=== modified file 'sql/log_event.cc'
--- a/sql/log_event.cc	2010-09-24 15:24:54 +0000
+++ b/sql/log_event.cc	2010-10-15 05:30:43 +0000
@@ -143,6 +143,7 @@ void handle_rows_query_log_event(Log_eve
   {
     delete rli->rows_query_ev;
     rli->rows_query_ev= NULL;
+    rli->sql_thd->set_query(NULL, 0);
   }
 
   /* Record the Rows_query log event until all its rows event are applied */

=== modified file 'sql/sql_insert.cc'
--- a/sql/sql_insert.cc	2010-10-04 11:51:33 +0000
+++ b/sql/sql_insert.cc	2010-10-15 05:30:43 +0000
@@ -2353,6 +2353,8 @@ int write_delayed(THD *thd, TABLE *table
                        (ulong) query.length));
 
   thd_proc_info(thd, "waiting for handler insert");
+  DBUG_EXECUTE_IF("waiting_for_delayed_insert_queue_is_empty",
+                  while(di->stacked_inserts) sleep(1););
   mysql_mutex_lock(&di->mutex);
   while (di->stacked_inserts >= delayed_queue_size && !thd->killed)
     mysql_cond_wait(&di->cond_client, &di->mutex);


Attachment: [text/bzr-bundle] bzr/dao-gang.qu@sun.com-20101015053043-qz73pr4x6tfrpras.bundle
Thread
bzr commit into mysql-next-mr-bugfixing branch (Dao-Gang.Qu:3324) Bug#56913Dao-Gang.Qu15 Oct