MySQL Bugs: #28786: binlog_killed.test fails: 'reset master' does not reset binlogging

Bug #28786	binlog_killed.test fails: 'reset master' does not reset binlogging
Submitted:	30 May 2007 19:25	Modified:	10 Oct 2008 12:38
Reporter:	Andrei Elkin	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S1 (Critical)
Version:	5.1.20, 5.0, 4.1,6.0	OS:	Any
Assigned to:	Andrei Elkin	CPU Architecture:	Any

Description:
Failure of execution binlog_killed test was noticed on 
https://intranet.mysql.com/secure/pushbuild/getlog.pl?dir=mysql-5.1-new-rpl&entry=lthalman...

The reason that the test did not pass is the server did not reset binlog
with 'reset master'.

Visual checking binlog at post-execution time showed that instead of purging and restart binlog continued accumulating events.

How to repeat:
This snippet of binlog_killed.test

-- source include/have_innodb.inc
-- source include/have_binlog_format_mixed_or_statement.inc

create table t1 (a int auto_increment, b int, PRIMARY KEY (a)) ENGINE=InnoDB;
create table t2 (a int auto_increment, b int, PRIMARY KEY (a)) ENGINE=MyISAM;
create table t3 (a int auto_increment, b int, PRIMARY KEY (a)) ENGINE=InnoDB;

reset master; # won't purge master-bin.000001

# so that the following query will be appended to master-bin.000001 binlog file
send insert into t2 values (null, null), (null, get_lock("a", 10));

Thank you for the report.

Verified as described using a bit modified test case:

-- source include/have_innodb.inc

create table t1 (a int auto_increment, b int, PRIMARY KEY (a)) ENGINE=InnoDB;
create table t2 (a int auto_increment, b int, PRIMARY KEY (a)) ENGINE=MyISAM;
create table t3 (a int auto_increment, b int, PRIMARY KEY (a)) ENGINE=InnoDB;

reset master; # won't purge master-bin.000001

# so that the following query will be appended to master-bin.000001 binlog file
send insert into t2 values (null, null), (null, get_lock("a", 10));

--exec $MYSQLADMIN -uroot --socket=$MASTER_MYSOCK shutdown

--exec $MYSQL_BINLOG $MYSQLTEST_VARDIR/log/master-bin.000001

Pushed into 5.0.44

Pushed into 5.1.20-beta

No bug fix has been pushed for this bug.

The automatic script was confused by a cset comment refering to this
bug even though the cset was not a fix for this bug.

My observation w.r.t. binlog_killed.test is this:

binlog.binlog_killed           [ fail ]

mysqltest: At line 39: query 'reap' failed with wrong errno 2013: 'Lost connection to MySQL server during query', instead of 0...

The result from queries just before the failure was:
create table t1 (a int auto_increment, b int, PRIMARY KEY (a)) ENGINE=InnoDB;
create table t2 (a int auto_increment, b int, PRIMARY KEY (a)) ENGINE=MyISAM;
create table t3 (a int auto_increment, b int, PRIMARY KEY (a)) ENGINE=InnoDB;
select get_lock("a", 20);
get_lock("a", 20)
1
reset master;
insert into t2 values (null, null), (null, get_lock("a", 10));

The warnings file contains:

master.err: binlog.binlog_killed: Attempting backtrace. You can use the following information to find out
master.err: binlog.binlog_killed: mysqld: sql_class.cc:2551: void THD::restore_backup_open_tables_state(Open_tables_state*): Assertion `open_tables == 0 && temporary_tables == 0 && handler_tables == 0 && derived_tables == 0 && lock == 0 && locked_tables == 0 && prelocked_mode == NON_PRELOCKED' failed.

The stack backtrace is:

#6  0x00002b3ab6c4ec2f in __assert_fail () from /lib/libc.so.6
#7  0x00000000006870b4 in THD::restore_backup_open_tables_state (this=0x1baae08, backup=0x44109cc0) at sql_class.cc:2548
#8  0x00000000007005d0 in open_performance_schema_table (thd=0x1baae08, one_table=0x441099a0, backup=0x44109cc0) at sql_base.cc:7751
#9  0x000000000076b023 in Log_to_csv_event_handler::log_general (this=0x112d030, thd=0x1baae08, event_time=1190987451, user_host=0x4410a230 "root[root] @ localhost []", user_host_len=25, thread_id=4, command_type=0xbcdedf "Query", command_type_len=5, sql_text=0x44109e30 "insert into t2 values (null, null), (null, get_lock(\"a\", 10))", sql_text_len=61, client_cs=0x10e71e0) at log.cc:344
#10 0x0000000000769c5a in LOGGER::general_log_print (this=0x10f81e0, thd=0x1baae08, command=COM_QUERY, format=0xbcdbf7 "%.*b", args=0x4410a4b0) at log.cc:1009
#11 0x0000000000769dbe in general_log_print (thd=0x1baae08, command=COM_QUERY, format=0xbcdbf7 "%.*b") at log.cc:3747
#12 0x00000000006be022 in dispatch_command (command=COM_QUERY, thd=0x1baae08, packet=0x1bad339 "insert into t2 values (null, null), (null, get_lock(\"a\", 10))", packet_length=62) at sql_parse.cc:952

The assert fails because open_tables != 0

This is on Debian GNU/Linux/x86_64. MySQL version 5.1.23.

Raised severity and priority as this is crashing in the test suite.

The crash is a different bug.
Ingo, can you please report that separately?

Merged somewhere into my todo stack.

The crash mentioned by Ingo is reported in BUG#31692, so it is *not*
part of this bug report.

The problem with the embedded server will most likely be fixed in 6.0
instead of 5.1 (target now changed).

Andrei has fixed this test case in the rpl tree (refer to BUG#27571).

Wrong info from Andrei.  It is still open.

Test suite failure.
Disabling the test in 6.0

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/45690

ChangeSet@1.2628, 2008-04-20 01:26:24+04:00, kostja@bodhi.(none) +1 -0
  Disable binlog_killed.test (Bug#28786)

The patch is simply disabling the test case, which fails sporadically.

Pushed into 6.0.6-alpha

A patch is landed on the Bug #15580. It only explains as comments in the test that binlog_killed can not be run on the embedded server.
The real problem of `reset master' will be addressed by bug#15580 fixes.

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/55180

2759 Andrei Elkin	2008-10-03
      Bug #28786 binlog_killed.test fails: 'reset master' does not reset binlogging
      
      The test failed originally -- did not reset binlogging - for the reason

pushed to 5.1-bugteam.

Pushed into 5.1.30  (revid:aelkin@mysql.com-20081003075333-z6jqf5thux0h4ozm) (version source revid:mats@sun.com-20081008113713-2vxny72m5w1tywoi) (pib:4)

Change in test case only - no changes to document for users.

Closed without further action.

Pushed into 6.0.8-alpha  (revid:aelkin@mysql.com-20081003075333-z6jqf5thux0h4ozm) (version source revid:aelkin@mysql.com-20081003125050-hvhhz82gndys1imk) (pib:5)

Pushed into 5.1.29-ndb-6.2.17  (revid:aelkin@mysql.com-20081003075333-z6jqf5thux0h4ozm) (version source revid:tomas.ulin@sun.com-20081028140209-u4emkk1xphi5tkfb) (pib:5)

Pushed into 5.1.29-ndb-6.3.19  (revid:aelkin@mysql.com-20081003075333-z6jqf5thux0h4ozm) (version source revid:tomas.ulin@sun.com-20081028194045-0353yg8cvd2c7dd1) (pib:5)

Pushed into 5.1.29-ndb-6.4.0  (revid:aelkin@mysql.com-20081003075333-z6jqf5thux0h4ozm) (version source revid:jonas@mysql.com-20081101082305-qx5a1bj0z7i8ueys) (pib:5)