MySQL Bugs: #30367: Tests using "mysqlbinlog" do not show an expected "ROLLBACK/*!*/;"

Bug #30367	Tests using "mysqlbinlog" do not show an expected "ROLLBACK/!/;"
Submitted:	10 Aug 2007 20:04	Modified:	22 Aug 2007 17:26
Reporter:	Joerg Bruehe	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Logging	Severity:	S3 (Non-critical)
Version:	5.1.21	OS:	Any (all)
Assigned to:	Andrei Elkin	CPU Architecture:	Any

Description:
This seems to be a regression, new in 5.1.21-beta,
no such effect has been noticed in 5.1.20-beta builds.

This occurs on all platforms, in all test runs.
Affected tests:
main.mysqlbinlog
main.mysqlbinlog2
main.user_var-binlog

This is the shortest symptom:

main.user_var-binlog           [ fail ]

Errors are (from /PATH/mysqltest-time) :
mysqltest: Result length mismatch
(the last lines may be the most important ones)
Below are the diffs between actual and expected results:
-------------------------------------------------------
*** /PATH/mysql-test/r/user_var-binlog.result
--- /PATH/mysql-test/r/user_var-binlog.reject
***************
*** 17,23
  /*!40019 SET @@session.max_insert_delayed_threads=0*/;
  /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
  DELIMITER /*!*/;
- ROLLBACK/*!*/;
  SET @`a b`:=_latin1 0x68656C6C6F COLLATE `latin1_swedish_ci`/*!*/;
  use test/*!*/;
  SET TIMESTAMP=10000/*!*/;
--- 17,22
-------------------------------------------------------

Somewhat longer:

main.mysqlbinlog               [ fail ]

Errors are (from /PATH/mysqltest-time) :
mysqltest: Result length mismatch
(the last lines may be the most important ones)
Below are the diffs between actual and expected results:
-------------------------------------------------------
*** /PATH/mysql-test/r/mysqlbinlog.result
--- /PATH/mysql-test/r/mysqlbinlog.reject
***************
*** 16,22
  /*!40019 SET @@session.max_insert_delayed_threads=0*/;
  /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
  DELIMITER /*!*/;
- ROLLBACK/*!*/;
  use test/*!*/;
  SET TIMESTAMP=1000000000/*!*/;
  SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=1, @@session.unique_checks=1/*!*/;
--- 16,21
***************
*** 66,72
  /*!40019 SET @@session.max_insert_delayed_threads=0*/;
  /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
  DELIMITER /*!*/;
- ROLLBACK/*!*/;
  SET INSERT_ID=1/*!*/;
  DELIMITER ;
  # End of log file
--- 65,70
***************
*** 93,99
  /*!40019 SET @@session.max_insert_delayed_threads=0*/;
  /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
  DELIMITER /*!*/;
- ROLLBACK/*!*/;
  use test/*!*/;
  SET TIMESTAMP=1000000000/*!*/;
  SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=1, @@session.unique_checks=1/*!*/;
--- 91,96
***************
*** 143,149
  /*!40019 SET @@session.max_insert_delayed_threads=0*/;
  /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
  DELIMITER /*!*/;
- ROLLBACK/*!*/;
  SET INSERT_ID=1/*!*/;
  DELIMITER ;
  # End of log file
--- 140,145
-------------------------------------------------------

This is much longer, here is just the start:

main.mysqlbinlog2              [ fail ]

Errors are (from /PATH/mysqltest-time) :
mysqltest: Result length mismatch
(the last lines may be the most important ones)
Below are the diffs between actual and expected results:
-------------------------------------------------------
*** /PATH/mysql-test/r/mysqlbinlog2.result
--- /PATH/mysql-test/r/mysqlbinlog2.reject
***************
*** 18,24
  /*!40019 SET @@session.max_insert_delayed_threads=0*/;
  /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
  DELIMITER /*!*/;
- ROLLBACK/*!*/;
  use test/*!*/;
  SET TIMESTAMP=1579609942/*!*/;
  SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=1, @@session.unique_checks=1/*!*/;
--- 18,23
***************
.....

How to repeat:
Run the test suite on any platform.

Similar problem in other tests:

binlog.binlog_row_ctype_ucs
binlog.binlog_stm_ctype_ucs
rpl.rpl_row_mysqlbinlog

And the last one:

rpl.rpl_stm_charset

The latest pb does not show the failures on trees that are close in sync with the main 5.1. The same failures were in some other trees and ceased (e.g on Aug 3rd for mysql-5.1-rpl).
Despite the failures are repeatable on mysql-5.1-build,
me and Rafal are suggesting to merge mysql-5.1-build - seems to be the only problematic tree - with mysql-5.1 first and watch what will happen.

This is a bit complicated and not according to assumed procedures:

The bug was introduced by a fix that came into the code for 5.1.21 quite late, and so it was detected only during the first builds of 5.1.21.
When discussing and analyzing it, Monty discovered that a fix he had already done would also correct this bug.
So this fix was pulled into the code for building 5.1.21, builds were restarted, and the bug did not occur again.

In effect, no version released by MySQL did contain the bug (it was in some intermediate states only), and no changeset lists the bug number (fixed by routine work, not specifically).

Therefore, I set it to "closed".