Details
Description
Some tests that call --source include/show_binlog_events.inc will fail if run after a test with binary logging. For example:
./mtr binlog.binlog_empty_xa_prepared --repeat 2
|
binlog.binlog_empty_xa_prepared 'innodb,mix' [ pass ] 1963
|
binlog.binlog_empty_xa_prepared 'innodb,mix' [ 2 fail ]
|
Test ended at 2022-06-28 09:15:03
|
|
|
CURRENT_TEST: binlog.binlog_empty_xa_prepared
|
--- /home/parallels/dev/build-test/build1/mysql-test/suite/binlog/r/binlog_empty_xa_prepared.result 2022-06-13 09:20:12.000000000 +0100
|
+++ /home/parallels/dev/build-test/build1/mysql-test/suite/binlog/r/binlog_empty_xa_prepared.reject 2022-06-28 09:15:03.124868610 +0100
|
@@ -20,6 +20,31 @@
|
include/show_binlog_events.inc
|
Log_name Pos Event_type Server_id End_log_pos Info
|
master-bin.000001 # Gtid # # GTID #-#-#
|
+master-bin.000001 # Query # # use `test`; CREATE TABLE t1 (a INT PRIMARY KEY) ENGINE=InnoDB
|
+master-bin.000001 # Gtid # # BEGIN GTID #-#-#
|
+master-bin.000001 # Annotate_rows # # INSERT INTO t1 VALUES (1)
|
+master-bin.000001 # Table_map # # table_id: # (test.t1)
|
+master-bin.000001 # Write_rows_v1 # # table_id: # flags: STMT_END_F
|
+master-bin.000001 # Xid # # COMMIT /* XID */
|
+master-bin.000001 # Gtid # # GTID #-#-#
|
+master-bin.000001 # Query # # use `test`; CREATE SEQUENCE s ENGINE=InnoDB
|
+master-bin.000001 # Gtid # # BEGIN GTID #-#-#
|
+master-bin.000001 # Annotate_rows # # SELECT NEXT VALUE FOR s
|
+master-bin.000001 # Table_map # # table_id: # (test.s)
|
+master-bin.000001 # Write_rows_v1 # # table_id: # flags: STMT_END_F
|
+master-bin.000001 # Query # # COMMIT
|
+master-bin.000001 # Gtid # # XA START X'32',X'',1 GTID #-#-#
|
+master-bin.000001 # Query # # XA END X'32',X'',1
|
+master-bin.000001 # XA_prepare # # XA PREPARE X'32',X'',1
|
+master-bin.000001 # Gtid # # GTID #-#-#
|
+master-bin.000001 # Query # # XA ROLLBACK X'32',X'',1
|
+master-bin.000001 # Gtid # # GTID #-#-#
|
+master-bin.000001 # Query # # use `test`; DROP SEQUENCE `s` /* generated by server */
|
+master-bin.000001 # Gtid # # GTID #-#-#
|
+master-bin.000001 # Query # # use `test`; DROP TABLE `t1` /* generated by server */
|
+master-bin.000001 # Gtid # # GTID #-#-#
|
+master-bin.000001 # Query # # use `test`; DROP /*!40005 TEMPORARY */ TABLE IF EXISTS `tmp_1`,`seq_1`
|
+master-bin.000001 # Gtid # # GTID #-#-#
|
master-bin.000001 # Query # # use `test`; CREATE TEMPORARY SEQUENCE seq_1
|
master-bin.000001 # Gtid # # BEGIN GTID #-#-#
|
master-bin.000001 # Query # # use `test`; CREATE TEMPORARY TABLE tmp_1(c INT)
|
|
|
mysqltest: Result length mismatch
|
Tests with this problem include:
binlog.binlog_empty_xa_prepared
binlog.binlog_stm_binlog.test
binlog.binlog_stm_datetime_ranges_mdev15289.test
binlog.binlog_stm_do_db.test
binlog.innodb_autoinc_lock_mode_binlog.test
main.mysql_upgrade_view
main.stat_tables_rbr
maria.rollback.test
plugins.test_sql_service.test
Attachments
Issue Links
- relates to
-
MDEV-29866 binlog.binlog_table_map_optional_metadata_binary 'row' fail
-
- Closed
-
Activity
Thanks for the tips, Elena!
It would be very good to do a sweep to fix such tests, because the problem isn't as innocent as a failure on repeat.
I will do this, so for now the Affects and Fix versions are for binlog.binlog_empty_xa_prepared only.
Testing shows a RESET MASTER at the start of the culprit tests solves the issue, as suggested by Elena.
I considered a RESET MASTER at the end of the test (binlog.binlog_table_map_optional_metadata_binary has one), but for binlog.binlog_empty_xa_prepared, a RESET MASTER at the end of the test does not completely eliminate the Result mismatch:
CURRENT_TEST: binlog.binlog_empty_xa_prepared
|
--- /home/parallels/dev/build-25611/build1/mysql-test/suite/binlog/r/binlog_empty_xa_prepared.result 2022-10-27 18:09:18.691777525 +0100
|
+++ /home/parallels/dev/build-25611/build1/mysql-test/suite/binlog/r/binlog_empty_xa_prepared.reject 2022-10-27 18:10:59.924004150 +0100
|
@@ -20,6 +20,8 @@
|
include/show_binlog_events.inc
|
Log_name Pos Event_type Server_id End_log_pos Info
|
master-bin.000001 # Gtid # # GTID #-#-#
|
+master-bin.000001 # Query # # use `test`; DROP /*!40005 TEMPORARY */ TABLE IF EXISTS `tmp_1`,`seq_1`
|
+master-bin.000001 # Gtid # # GTID #-#-#
|
master-bin.000001 # Query # # use `test`; CREATE TEMPORARY SEQUENCE seq_1
|
master-bin.000001 # Gtid # # BEGIN GTID #-#-#
|
master-bin.000001 # Query # # use `test`; CREATE TEMPORARY TABLE tmp_1(c INT)
|
Note that there are likely to be many MTR test cases, specifically among those which enable binary log, which reliably fail upon the 2nd repeat after the first success. It happens because they rely on specific contents of binary logs, but don't ensure that the log is clean at the start of the test; and MTR itself, in turn, doesn't do it in its post-test check.
It would be very good to do a sweep to fix such tests, because the problem isn't as innocent as a failure on repeat. In reality it will happen whenever MTR sorts the test cases in such a way that the guilty test case is run after another one before the server restart. It's pure luck that it isn't happening with this one.
For example, if you do something like
cat << EOF > main/t.test--source include/have_innodb.inc--source include/have_binlog_format_mixed.incCREATE TABLE t (a INT);DROP TABLE t;EOFperl ./mtr main.t binlog.binlog_empty_xa_prepared --noreorderYou will surely get the failure too.
In most cases it can be fixed by just adding RESET MASTER at the beginning of the test.