Hi Serg, Just wanted to be sure you saw this. The async binlogging of the checkpoint event after MDEV-532 means a few test cases need to wait for the event to be logged, or they will get races causing failures with result difference in SHOW BINLOG EVENTS or similar. Typically after running FLUSH LOGS. I fixed the ones I found already. But it is possible that a few others will pop up, and it is useful that someone else than me knows how to fix (so I'm picking on you as the reviewer :-). As seen in the patch, it's just a matter of including the file include/wait_for_binlog_checkpoint.inc in the appropriate place. - Kristian. knielsen@knielsen-hq.org writes:

At http://bazaar.launchpad.net/~maria-captains/maria/10.0

------------------------------------------------------------ revno: 3449 revision-id: knielsen@knielsen-hq.org-20121217114911-m3qv20xmk7htleez parent: igor@askmonty.org-20121217004919-xgon81zqncwimr3m committer: knielsen@knielsen-hq.org branch nick: mariadb-10.0-base timestamp: Mon 2012-12-17 12:49:11 +0100 message: MDEV-532: Fix some race conditions in test cases.

With MDEV-532, the binlog_checkpoint event is logged asynchronously from a binlog background thread. This causes some sporadic failures in some test cases whose output depends on order of events in binlog.

Fix using an include file that waits until the binlog checkpoint event has been logged before proceeding with the test case. === modified file 'mysql-test/extra/rpl_tests/rpl_insert_delayed.test' --- a/mysql-test/extra/rpl_tests/rpl_insert_delayed.test 2012-09-22 14:11:40 +0000 +++ b/mysql-test/extra/rpl_tests/rpl_insert_delayed.test 2012-12-17 11:49:11 +0000 @@ -94,8 +94,10 @@ if (`SELECT @@global.binlog_format = 'S #flush the logs before the test connection slave; FLUSH LOGS; + source include/wait_for_binlog_checkpoint.inc; connection master; FLUSH LOGS; + source include/wait_for_binlog_checkpoint.inc; }

CREATE TABLE t1(a int, UNIQUE(a));

=== modified file 'mysql-test/extra/rpl_tests/rpl_log.test' --- a/mysql-test/extra/rpl_tests/rpl_log.test 2011-10-19 19:45:18 +0000 +++ b/mysql-test/extra/rpl_tests/rpl_log.test 2012-12-17 11:49:11 +0000 @@ -43,6 +43,7 @@ let $binlog_limit= 1,4; source include/show_binlog_events.inc; let $binlog_limit=; flush logs; +--source include/wait_for_binlog_checkpoint.inc

# We need an extra update before doing save_master_pos. # Otherwise, an unlikely scenario may occur:

=== modified file 'mysql-test/extra/rpl_tests/rpl_show_relaylog_events.inc' --- a/mysql-test/extra/rpl_tests/rpl_show_relaylog_events.inc 2011-01-13 14:31:37 +0000 +++ b/mysql-test/extra/rpl_tests/rpl_show_relaylog_events.inc 2012-12-17 11:49:11 +0000 @@ -41,8 +41,10 @@ INSERT INTO t1 VALUES (3); #

FLUSH LOGS; +--source include/wait_for_binlog_checkpoint.inc -- connection master FLUSH LOGS; +--source include/wait_for_binlog_checkpoint.inc DROP TABLE t1;

--let $is_relay_log= 0

=== added file 'mysql-test/include/wait_for_binlog_checkpoint.inc' --- a/mysql-test/include/wait_for_binlog_checkpoint.inc 1970-01-01 00:00:00 +0000 +++ b/mysql-test/include/wait_for_binlog_checkpoint.inc 2012-12-17 11:49:11 +0000 @@ -0,0 +1,53 @@ +# include/wait_for_binlog_checkpoint.inc +# +# SUMMARY +# +# Wait until binlog checkpoint has been logged for current binlog file. +# This is useful to avoid races with output difference for binlog +# checkpoints, as these are logged asynchronously from the binlog +# background thread. +# +# USAGE: +# +# --source include/wait_for_binlog_checkpoint.inc + +let $_wait_count= 300; + +let $_found= 0; + +while ($_wait_count) +{ + dec $_wait_count; + let $_cur_binlog= query_get_value(SHOW MASTER STATUS, File, 1); + let $_more= 1; + let $_row= 1; + while ($_more) + { + let $_event= query_get_value(SHOW BINLOG EVENTS IN "$_cur_binlog", Event_type, $_row); + if ($_event == "No such row") + { + let $_more= 0; + } + if ($_event == "Binlog_checkpoint") + { + let $_info= query_get_value(SHOW BINLOG EVENTS IN "$_cur_binlog", Info, $_row); + if (`SELECT INSTR("$_info", "$_cur_binlog") != 0`) + { + let $_more= 0; + let $_wait_count= 0; + let $_found= 1; + } + } + inc $_row; + } + if ($_wait_count) + { + real_sleep 0.1; + } +} + +if (!$_found) +{ + eval SHOW BINLOG EVENTS IN "$_cur_binlog"; + --die ERROR: failed while waiting for binlog checkpoint $_cur_binlog +}

=== modified file 'mysql-test/suite/innodb/t/binlog_consistent.test' --- a/mysql-test/suite/innodb/t/binlog_consistent.test 2012-02-07 15:22:36 +0000 +++ b/mysql-test/suite/innodb/t/binlog_consistent.test 2012-12-17 11:49:11 +0000 @@ -72,6 +72,7 @@ connection con3; --echo # Connection con3 COMMIT; FLUSH LOGS; +--source include/wait_for_binlog_checkpoint.inc

connection default; --echo # Connection default

=== modified file 'mysql-test/suite/multi_source/multisource.test' --- a/mysql-test/suite/multi_source/multisource.test 2012-10-04 20:36:17 +0000 +++ b/mysql-test/suite/multi_source/multisource.test 2012-12-17 11:49:11 +0000 @@ -169,6 +169,7 @@ select * from db2.t1;

--connection master1 flush logs; +--source include/wait_for_binlog_checkpoint.inc --save_master_pos --connection slave --sync_with_master 0, 'master1'

_______________________________________________ commits mailing list commits@mariadb.org https://lists.askmonty.org/cgi-bin/mailman/listinfo/commits