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

[30 May 2007 19:25] Andrei Elkin
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));
[30 May 2007 21:20] Sveta Smirnova
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
[1 Jun 2007 19:20] Bugs System
Pushed into 5.0.44
[1 Jun 2007 19:22] Bugs System
Pushed into 5.1.20-beta
[5 Jun 2007 0:02] Lars Thalmann
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.
[28 Sep 2007 15:45] Ingo Strüwing
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.
[28 Sep 2007 15:47] Ingo Strüwing
Raised severity and priority as this is crashing in the test suite.
[17 Oct 2007 12:18] Lars Thalmann
The crash is a different bug.
Ingo, can you please report that separately?
[17 Oct 2007 13:04] Ingo Strüwing
Merged somewhere into my todo stack.
[19 Oct 2007 12:34] Lars Thalmann
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).
[8 Nov 2007 13:30] Lars Thalmann
Andrei has fixed this test case in the rpl tree (refer to BUG#27571).
[8 Nov 2007 13:33] Lars Thalmann
Wrong info from Andrei.  It is still open.
[19 Apr 2008 21:23] Konstantin Osipov
Test suite failure.
Disabling the test in 6.0
[19 Apr 2008 21:26] Bugs System
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)
[19 Apr 2008 21:43] Konstantin Osipov
The patch is simply disabling the test case, which fails sporadically.
[20 Apr 2008 13:01] Bugs System
Pushed into 6.0.6-alpha
[19 Sep 2008 15:41] Andrei Elkin
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.
[3 Oct 2008 7:54] Bugs System
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
[3 Oct 2008 14:51] Andrei Elkin
pushed to 5.1-bugteam.
[9 Oct 2008 17:41] Bugs System
Pushed into 5.1.30  (revid:aelkin@mysql.com-20081003075333-z6jqf5thux0h4ozm) (version source revid:mats@sun.com-20081008113713-2vxny72m5w1tywoi) (pib:4)
[10 Oct 2008 12:38] Jon Stephens
Change in test case only - no changes to document for users.

Closed without further action.
[17 Oct 2008 16:42] Bugs System
Pushed into 6.0.8-alpha  (revid:aelkin@mysql.com-20081003075333-z6jqf5thux0h4ozm) (version source revid:aelkin@mysql.com-20081003125050-hvhhz82gndys1imk) (pib:5)
[28 Oct 2008 21:02] Bugs System
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)
[28 Oct 2008 22:21] Bugs System
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)
[1 Nov 2008 9:46] Bugs System
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)