Re: bzr commit into mysql-5.1 branch (mats:2658) Bug#32709

[Sven Sandberg]

Hi Mats!

Three comments:

  - Your patch makes the pending rows be moved to the transaction cache, 
which is then thrown away. It would be better if the pending rows were 
just removed and not written to the transaction cache.

  - I think the test case is more complicated than necessary. I suggest 
the following (which is a slightly simplified version of the test you 
provide on the bug page):

   CREATE TABLE t1 (a INT PRIMARY KEY) ENGINE=$type;
   INSERT INTO t1 VALUES (1);
   --error ER_DUP_ENTRY
   INSERT INTO t1 VALUES (1);
   INSERT INTO t1 VALUES (2);
   sync_slave_with_master;

  - You also need to update rpl_row_basic_7ndb.result.

/Sven


Mats Kindahl wrote:
> #At file:///home/bzr/bugs/b32709-5.1-rpl/
> 
>  2658 Mats Kindahl	2008-08-15
>       Bug #32709: Assertion failed: trx_data->empty(), file log.cc
>       
>       The assertion indicates that some data was left in the transaction
>       cache when the server was shut down, which means that a previous
>       statement did not commit or rollback correctly.
>       
>       What happened was that a bug in the rollback of a transactional
>       table caused the transaction cache to be emptied, but not reset.
>       The error can be triggered by having a failing UPDATE or INSERT,
>       on a transactional table, causing an implicit rollback.
>       
>       Fixed by always flushing the pending event to reset the state
>       properly.
> modified:
>   mysql-test/extra/rpl_tests/rpl_row_basic.test
>   mysql-test/suite/rpl/r/rpl_row_basic_2myisam.result
>   mysql-test/suite/rpl/r/rpl_row_basic_3innodb.result
>   mysql-test/suite/rpl/r/rpl_server_id2.result
>   mysql-test/suite/rpl/t/rpl_server_id2.test
>   sql/log.cc
> 
> per-file messages:
>   mysql-test/extra/rpl_tests/rpl_row_basic.test
>     Testing that a failed update (that writes some rows to the
>     transaction cache) does not cause the transaction cache to
>     hold on to the data or forget to reset the transaction cache.
>   mysql-test/suite/rpl/r/rpl_row_basic_2myisam.result
>     Result file change.
>   mysql-test/suite/rpl/r/rpl_row_basic_3innodb.result
>     Result file change.
>   sql/log.cc
>     Moved flush of pending event so that it is always flushed,
>     even if the transaction cache is emptied instead of written
>     to binary log. The flush will reset the state of the trans-
>     action cache correctly, and don't leave it in a state of
>     "empty but not reset".
> === modified file 'mysql-test/extra/rpl_tests/rpl_row_basic.test'
> --- a/mysql-test/extra/rpl_tests/rpl_row_basic.test	2008-07-11 18:51:10 +0000
> +++ b/mysql-test/extra/rpl_tests/rpl_row_basic.test	2008-08-15 08:07:47 +0000
> @@ -435,3 +435,22 @@ connection master;
>  drop table t1, t2, t3, t4, t5, t6, t7;
>  sync_slave_with_master;
>  
> +#
> +# BUG#32709: Assertion failed: trx_data->empty(), file .\log.cc, line 1293
> +#
> +
> +connection master;
> +eval CREATE TABLE t1 ( `pk` int(11) NOT NULL AUTO_INCREMENT, `int_nokey` int(11) NOT
> NULL, `varchar_nokey` varchar(3) NOT NULL, PRIMARY KEY (`pk`) ) ENGINE=$type;
> +
> +INSERT INTO t1 VALUES (1,8,'c'), (2,0,' '), (3,0,' ');
> +--error ER_DUP_ENTRY
> +UPDATE t1 SET pk = 10 WHERE int_nokey = 'z';
> +INSERT INTO t1 ( varchar_nokey ) VALUES ('a' );
> +
> +let $diff_table_1=master:test.t1;
> +let $diff_table_2=slave:test.t1;
> +source include/diff_tables.inc;
> +
> +connection master;
> +drop table t1;
> +sync_slave_with_master;
> 
> === modified file 'mysql-test/suite/rpl/r/rpl_row_basic_2myisam.result'
> --- a/mysql-test/suite/rpl/r/rpl_row_basic_2myisam.result	2008-08-04 05:04:47 +0000
> +++ b/mysql-test/suite/rpl/r/rpl_row_basic_2myisam.result	2008-08-15 08:07:47 +0000
> @@ -514,3 +514,12 @@ INSERT INTO t7 VALUES (1, "", 1);
>  INSERT INTO t7 VALUES (2, repeat(_utf8'a', 255), 2);
>  Comparing tables master:test.t7 and slave:test.t7
>  drop table t1, t2, t3, t4, t5, t6, t7;
> +CREATE TABLE t1 ( `pk` int(11) NOT NULL AUTO_INCREMENT, `int_nokey` int(11) NOT
> NULL, `varchar_nokey` varchar(3) NOT NULL, PRIMARY KEY (`pk`) ) ENGINE='MYISAM' ;
> +INSERT INTO t1 VALUES (1,8,'c'), (2,0,' '), (3,0,' ');
> +UPDATE t1 SET pk = 10 WHERE int_nokey = 'z';
> +ERROR 23000: Duplicate entry '10' for key 'PRIMARY'
> +INSERT INTO t1 ( varchar_nokey ) VALUES ('a' );
> +Warnings:
> +Warning	1364	Field 'int_nokey' doesn't have a default value
> +Comparing tables master:test.t1 and slave:test.t1
> +drop table t1;
> 
> === modified file 'mysql-test/suite/rpl/r/rpl_row_basic_3innodb.result'
> --- a/mysql-test/suite/rpl/r/rpl_row_basic_3innodb.result	2008-08-04 05:04:47 +0000
> +++ b/mysql-test/suite/rpl/r/rpl_row_basic_3innodb.result	2008-08-15 08:07:47 +0000
> @@ -514,3 +514,12 @@ INSERT INTO t7 VALUES (1, "", 1);
>  INSERT INTO t7 VALUES (2, repeat(_utf8'a', 255), 2);
>  Comparing tables master:test.t7 and slave:test.t7
>  drop table t1, t2, t3, t4, t5, t6, t7;
> +CREATE TABLE t1 ( `pk` int(11) NOT NULL AUTO_INCREMENT, `int_nokey` int(11) NOT
> NULL, `varchar_nokey` varchar(3) NOT NULL, PRIMARY KEY (`pk`) ) ENGINE='INNODB' ;
> +INSERT INTO t1 VALUES (1,8,'c'), (2,0,' '), (3,0,' ');
> +UPDATE t1 SET pk = 10 WHERE int_nokey = 'z';
> +ERROR 23000: Duplicate entry '10' for key 'PRIMARY'
> +INSERT INTO t1 ( varchar_nokey ) VALUES ('a' );
> +Warnings:
> +Warning	1364	Field 'int_nokey' doesn't have a default value
> +Comparing tables master:test.t1 and slave:test.t1
> +drop table t1;
> 
> === modified file 'mysql-test/suite/rpl/r/rpl_server_id2.result'
> --- a/mysql-test/suite/rpl/r/rpl_server_id2.result	2007-06-27 12:29:10 +0000
> +++ b/mysql-test/suite/rpl/r/rpl_server_id2.result	2008-08-15 08:07:47 +0000
> @@ -47,7 +47,7 @@ Last_IO_Errno	#
>  Last_IO_Error	#
>  Last_SQL_Errno	0
>  Last_SQL_Error	
> -start slave;
> +include/start_slave.inc
>  insert into t1 values (1);
>  select * from t1;
>  n
> 
> === modified file 'mysql-test/suite/rpl/t/rpl_server_id2.test'
> --- a/mysql-test/suite/rpl/t/rpl_server_id2.test	2007-06-27 12:29:10 +0000
> +++ b/mysql-test/suite/rpl/t/rpl_server_id2.test	2008-08-15 08:07:47 +0000
> @@ -12,7 +12,7 @@ eval change master to master_port=$SLAVE
>  --replace_result $SLAVE_MYPORT SLAVE_PORT
>  --replace_column 18 # 35 # 36 #
>  query_vertical show slave status;
> -start slave;
> +source include/start_slave.inc;
>  insert into t1 values (1);
>  save_master_pos;
>  sync_with_master;
> 
> === modified file 'sql/log.cc'
> --- a/sql/log.cc	2008-07-22 10:41:55 +0000
> +++ b/sql/log.cc	2008-08-15 08:07:47 +0000
> @@ -1377,6 +1377,8 @@ binlog_end_trans(THD *thd, binlog_trx_da
>                        FLAGSTR(thd->options, OPTION_NOT_AUTOCOMMIT),
>                        FLAGSTR(thd->options, OPTION_BEGIN)));
>  
> +  thd->binlog_flush_pending_rows_event(TRUE);
> +
>    /*
>      NULL denotes ROLLBACK with nothing to replicate: i.e., rollback of
>      only transactional tables.  If the transaction contain changes to
> @@ -1395,8 +1397,6 @@ binlog_end_trans(THD *thd, binlog_trx_da
>        were, we would have to ensure that we're not ending a statement
>        inside a stored function.
>       */	
> -    thd->binlog_flush_pending_rows_event(TRUE);
> -
>      error= mysql_bin_log.write(thd, &trx_data->trans_log, end_ev);
>      trx_data->reset();
>  
> 
> 

-- 
Sven Sandberg, Software Engineer
MySQL AB, www.mysql.com