List:Commits« Previous MessageNext Message »
From:Daogang Qu Date:October 12 2010 1:31am
Subject:Re: bzr commit into mysql-next-mr-bugfixing branch (Dao-Gang.Qu:3321)
Bug#56913
View as plain text  
2010-10-11 18:05, He Zhenxing wrote:
> Hi Daogang,
>
> The patch looks fine, but I think the commit message need some
> improvements.
>    
Thanks for the your comments.  Please review the updated patch:
http://lists.mysql.com/commits/120538

Best Regards,

Daogang
> Please look below for the details.
>
> Dao-Gang.Qu@stripped wrote:
>    
>> #At file:///home/daogangqu/mysql/bzrwork1/pushwl5404/mysql-next-mr-bugfixing/
> based on revid:luis.soares@stripped
>>
>>   3321 Dao-Gang.Qu@stripped	2010-10-09
>>        Bug #56913    rpl_row_ignorable_event fails sporadically on
> next-mr-bugfixing codebase
>>
>>        In RBR, every value is inserted into a queue for multi 'INSERT DELAYED
> ...'
>>        stmt by one thread. Then these values will be taken out and inserted
>>        into table in one execution series or in separate execution series by
>>        another thread parallelly. Values in one execution series will be
>>        binlogged into one rows event with its table map event, values in
>>        separate execution series will be binlogged into separate rows event
>>        with its table map event. So the binlog of multi 'INSERT DELAYED ...'
>>        stmt is unstable.
>>
>>      
> I'd suggest something like this:
>
> The rows are inserted to a queue by the thread that 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 a
> interweaved manner, and result in different number of table_map and rows
> events.
>
>    
>>        To make the binlog of multi 'INSERT DELAYED ...' stmt stable to force
>>        every value is executed in one separate execution series, and then it
>>        will be binlogged into 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.
>>      
> Added a debug option for the test to make the binlog of .....
>
>    
>>       @ 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
>>          Update 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/log_event.h
>>        sql/rpl_slave.cc
>>        sql/sql_binlog.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-09 07:04:50
> +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-09 07:04:50
> +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,12 @@ 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;
>> +let $count=1;
>>   insert delayed into t3(a,b) values(1,5),(1,6),(1,7);
>> +inc $count; inc $count; inc $count;
>> +--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-09 07:04:50 +0000
>> @@ -128,10 +128,11 @@ static const char *HA_ERR(int i)
>>   /**
>>     Delay to delete the Rows_query log event until all its rows event are
> applied
>>
>> +  @param thd   pointer to the thread for executing the log event
>>     @param ev    log event should be deleted
>>     @param rli   Relay_log_info structure for the slave IO thread.
>>   */
>> -void handle_rows_query_log_event(Log_event *ev, Relay_log_info *rli)
>> +void handle_rows_query_log_event(THD* thd, Log_event *ev, Relay_log_info *rli)
>>   {
>>     DBUG_ENTER("handle_rows_query_log_event");
>>     Log_event_type ev_type= ev->get_type_code();
>> @@ -143,6 +144,7 @@ void handle_rows_query_log_event(Log_eve
>>     {
>>       delete rli->rows_query_ev;
>>       rli->rows_query_ev= NULL;
>> +    thd->set_query(NULL, 0);
>>     }
>>
>>     /* Record the Rows_query log event until all its rows event are applied */
>>
>> === modified file 'sql/log_event.h'
>> --- a/sql/log_event.h	2010-09-01 02:51:08 +0000
>> +++ b/sql/log_event.h	2010-10-09 07:04:50 +0000
>> @@ -4196,7 +4196,7 @@ private:
>>   int append_query_string(CHARSET_INFO *csinfo,
>>                           String const *from, String *to);
>>   bool sqlcom_can_generate_row_events(const THD *thd);
>> -void handle_rows_query_log_event(Log_event *ev, Relay_log_info *rli);
>> +void handle_rows_query_log_event(THD* thd, Log_event *ev, Relay_log_info *rli);
>>
>>   /**
>>     @} (end of group Replication)
>>
>> === modified file 'sql/rpl_slave.cc'
>> --- a/sql/rpl_slave.cc	2010-09-26 23:56:20 +0000
>> +++ b/sql/rpl_slave.cc	2010-10-09 07:04:50 +0000
>> @@ -2811,7 +2811,7 @@ static int exec_relay_log_event(THD* thd
>>       if (ev->get_type_code() != FORMAT_DESCRIPTION_EVENT)
>>       {
>>         if (thd->variables.binlog_rows_query_log_events)
>> -        handle_rows_query_log_event(ev, rli);
>> +        handle_rows_query_log_event(thd, ev, rli);
>>
>>         DBUG_PRINT("info", ("Deleting the event after it has been executed"));
>>         if (ev->get_type_code() != ROWS_QUERY_LOG_EVENT)
>>
>> === modified file 'sql/sql_binlog.cc'
>> --- a/sql/sql_binlog.cc	2010-09-21 11:32:50 +0000
>> +++ b/sql/sql_binlog.cc	2010-10-09 07:04:50 +0000
>> @@ -274,7 +274,7 @@ void mysql_client_binlog_statement(THD*
>>         if (ev->get_type_code() != FORMAT_DESCRIPTION_EVENT)
>>         {
>>           if (thd->variables.binlog_rows_query_log_events)
>> -          handle_rows_query_log_event(ev, rli);
>> +          handle_rows_query_log_event(thd, ev, rli);
>>           if (ev->get_type_code() != ROWS_QUERY_LOG_EVENT)
>>           {
>>             delete ev;
>>
>> === 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-09 07:04:50 +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););
>>      
> I'd suggest name the debug option as:
>    delayed_insert_one_row_each_time
>    
> but no strong opinion, choose as you like.
>    
Thanks!
>    
>>     mysql_mutex_lock(&di->mutex);
>>     while (di->stacked_inserts>= delayed_queue_size&& 
> !thd->killed)
>>       mysql_cond_wait(&di->cond_client,&di->mutex);
>>      
>
>    

Thread
bzr commit into mysql-next-mr-bugfixing branch (Dao-Gang.Qu:3321) Bug#56913Dao-Gang.Qu9 Oct
  • Re: bzr commit into mysql-next-mr-bugfixing branch (Dao-Gang.Qu:3321)Bug#56913He Zhenxing11 Oct
    • Re: bzr commit into mysql-next-mr-bugfixing branch (Dao-Gang.Qu:3321)Bug#56913Daogang Qu12 Oct