Bug #40559 assertion failed in check_binlog_magic
Submitted: 6 Nov 2008 17:44 Modified: 30 Mar 2009 16:24
Reporter: Sven Sandberg Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Replication Severity:S1 (Critical)
Version:5.1 OS:Linux
Assigned to: Andrei Elkin CPU Architecture:Any
Tags: assertion, check_binlog_magic

[6 Nov 2008 17:44] Sven Sandberg
Description:
When running tests locally, I stumbled on the following assertion:

binlog.binlog_auto_increment_bug33029 'row' [ fail ]

CURRENT_TEST: binlog.binlog_auto_increment_bug33029
mysqltest: At line 50: query 'DROP PROCEDURE IF EXISTS p2' failed: 2013: Lost connection to MySQL server during query

The result from queries just before the failure was:
< snip >
11
SELECT * FROM t2;
id
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
DROP TABLE IF EXISTS t1, t2;
DROP PROCEDURE IF EXISTS p1;

More results from queries before failure can be found in /home/sven/bzr/b38350-test_cleanup/6.0-rpl/mysql-test/var/2/log/binlog_auto_increment_bug33029.log

 - saving '/home/sven/bzr/b38350-test_cleanup/6.0-rpl/mysql-test/var/2/log/binlog.binlog_auto_increment_bug33029-row/' to '/home/sven/bzr/b38350-test_cleanup/6.0-rpl/mysql-test/var/log/binlog.binlog_auto_increment_bug33029-row/'
 - found 'core.26179' (0/5)

Trying 'gdb' to get a backtrace
Core generated by '/home/sven/bzr/b38350-test_cleanup/6.0-rpl/sql/mysqld'
Output from gdb follows. The first stack trace is from the failing thread.
The following stack traces are from all threads (so the failing one is
duplicated).

warning: Can't read pathname for load map: Input/output error.
Core was generated by `/home/sven/bzr/b38350-test_cleanup/6.0-rpl/sql/mysqld --defaults-group-suffix=.'.
Program terminated with signal 6, Aborted.
[New process 26524]
[New process 26523]
[New process 26376]
[New process 26358]
[New process 26333]
[New process 26331]
[New process 26232]
[New process 26231]
[New process 26230]
[New process 26229]
[New process 26228]
[New process 26221]
[New process 26220]
[New process 26186]
[New process 26185]
[New process 26179]
#0  0xb7f2b410 in __kernel_vsyscall ()
#0  0xb7f2b410 in __kernel_vsyscall ()
#1  0xb7ee4ae7 in pthread_kill () from /lib/tls/i686/cmov/libpthread.so.0
#2  0x08995a91 in my_write_core (sig=6) at stacktrace.c:307
#3  0x083341c4 in handle_segfault (sig=6) at mysqld.cc:2674
#4  <signal handler called>
#5  0xb7f2b410 in __kernel_vsyscall ()
#6  0xb7c49085 in raise () from /lib/tls/i686/cmov/libc.so.6
#7  0xb7c4aa01 in abort () from /lib/tls/i686/cmov/libc.so.6
#8  0xb7c4210e in __assert_fail () from /lib/tls/i686/cmov/libc.so.6
#9  0x0840182f in check_binlog_magic (log=0x9746204, errmsg=0xaf890db4)
    at log.cc:2443
#10 0x084dbb5f in next_event (rli=0x9745a8c) at slave.cc:4076
#11 0x084df589 in exec_relay_log_event (thd=0x97d5988, rli=0x9745a8c)
    at slave.cc:2005
#12 0x084e05ad in handle_slave_sql (arg=0x97447e0) at slave.cc:2708
#13 0xb7edf4fb in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
#14 0xb7cf4e5e in clone () from /lib/tls/i686/cmov/libc.so.6

The full log contains stack traces from all other threads too. It did not fit in the bug report: I will attach it as a file instead.

How to repeat:
?
[6 Nov 2008 17:46] Sven Sandberg
Full error log (including stack traces for all threads)

Attachment: tmp (application/octet-stream, text), 14.24 KiB.

[6 Nov 2008 18:17] Sven Sandberg
I can repeat this every time I run the following:

./mtr binlog_auto_increment_bug33029 binlog_auto_increment_bug33029

Both in 6.0-rpl and 6.0 main.
[6 Nov 2008 18:44] Sven Sandberg
I can reproduce this in 5.1 too.

Built with BUILD/compile-pentium-debug-max
[6 Nov 2008 18:53] Sven Sandberg
In 5.1-rpl and 6.0-rpl, you have to use the --parallel=1 flag to mtr, so that the two test runs get executed in sequence.
[11 Nov 2008 15:03] Susanne Ebrecht
Verified by using actual bzr tree.

./mysql-test-run.pl binlog.binlog_auto_increment_bug33029 binlog_auto_increment_bug33029

binlog.binlog_auto_increment_bug33029 'row' [ pass ]            126
binlog.binlog_auto_increment_bug33029 'row' [ fail ]
[6 Mar 2009 18:19] 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/68537

2836 Andrei Elkin	2009-03-06
      Bug #40559   assertion failed in check_binlog_magic 
      
      The reason of the bug is in that the test makes a trick with relay log files and
      did not reset fully at the end.
      If mtr does not restart the test the new SQL thread tried to work with the old time
      session data.
      
      Fixed with deploying RESET slave at the clean-up.
[18 Mar 2009 13:17] Bugs System
Pushed into 6.0.11-alpha (revid:joro@sun.com-20090318122208-1b5kvg6zeb4hxwp9) (version source revid:joro@sun.com-20090317133112-41qn6aly7arljtlq) (merge vers: 6.0.11-alpha) (pib:6)
[27 Mar 2009 14:56] Bugs System
Pushed into 5.1.34 (revid:joro@sun.com-20090327143448-wuuuycetc562ty6o) (version source revid:leonard@mysql.com-20090316090622-sr8lylqvsl1jrcnv) (merge vers: 5.1.34) (pib:6)
[30 Mar 2009 16:23] Jon Stephens
Failure in test only, no end-user changes to document. Closed without taking further action.
[9 May 2009 16:39] Bugs System
Pushed into 5.1.34-ndb-6.2.18 (revid:jonas@mysql.com-20090508185236-p9b3as7qyauybefl) (version source revid:jonas@mysql.com-20090508185236-p9b3as7qyauybefl) (merge vers: 5.1.34-ndb-6.2.18) (pib:6)
[9 May 2009 17:36] Bugs System
Pushed into 5.1.34-ndb-6.3.25 (revid:jonas@mysql.com-20090509063138-1u3q3v09wnn2txyt) (version source revid:jonas@mysql.com-20090509063138-1u3q3v09wnn2txyt) (merge vers: 5.1.34-ndb-6.3.25) (pib:6)
[9 May 2009 18:34] Bugs System
Pushed into 5.1.34-ndb-7.0.6 (revid:jonas@mysql.com-20090509154927-im9a7g846c6u1hzc) (version source revid:jonas@mysql.com-20090509154927-im9a7g846c6u1hzc) (merge vers: 5.1.34-ndb-7.0.6) (pib:6)