| Bug #38798 | Assertion mysql_bin_log.is_open() failed in binlog_trans_log_savepos() | ||
|---|---|---|---|
| Submitted: | 14 Aug 2008 13:36 | Modified: | 15 Sep 2008 17:13 |
| Reporter: | Philip Stoev | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Replication | Severity: | S1 (Critical) |
| Version: | 5.1, 6.0 bzr | OS: | Any |
| Assigned to: | Andrei Elkin | CPU Architecture: | Any |
[14 Aug 2008 14:15]
Philip Stoev
SQL Grammar file for bug 38798
Attachment: bug38798.yy (application/octet-stream, text), 410 bytes.
[14 Aug 2008 14:24]
Philip Stoev
To reproduce this bug, please clone the mysql-test-extra-6.0 tree and execute: $ cd mysql-test-extra-6.0/mysql-test/gentest $ perl runall.pl \ --basedir=/path/to/mysql-5.1 \ --grammar=conf/bug38798.yy \ --threads=1 This will proceed to run a non-concurrent random test from the queries in the grammar file - START TRANSACTION, CREATE ... SELECT and INSERT. The special thing is that the INSERT is ran under BINLOG_FORMAT=ROW whereas the system default is MIXED. Crash will happen after a few dozen queries. Since this test is not concurrent, technically it should not have required the full Random Query Generation framework, however when I tried to execute the queries with the client, no crash was observed. Let me know if I can help with anything else.
[15 Aug 2008 8:57]
Sveta Smirnova
Thank you for the report. Verified as described.
[26 Aug 2008 16:49]
Andrei Elkin
The issue looks to be of a critical character as the problem can be reproduced merely with running 4 queries (to be shown in a test that is coming with the patch).
[26 Aug 2008 17:02]
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/52583 2719 Andrei Elkin 2008-08-26 Bug #38798 Assertion mysql_bin_log.is_open() failed in binlog_trans_log_savepos() The assert is about binlogging must have been activated, but it was not actually according to the reported how-to-repeat instuctions. Analysis revealed that binlog_start_trans_and_stmt() was called without prior testing if binlogging is ON. Fixed with avoing entering binlog_start_trans_and_stmt() if binlog is not activated.
[29 Aug 2008 13:53]
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/52910 2725 Andrei Elkin 2008-08-29 Bug #38798 Assertion mysql_bin_log.is_open() failed in binlog_trans_log_savepos() The assert is about binlogging must have been activated, but it was not actually according to the reported how-to-repeat instuctions. Analysis revealed that binlog_start_trans_and_stmt() was called without prior testing if binlogging is ON. Fixed with avoing entering binlog_start_trans_and_stmt() if binlog is not activated.
[29 Aug 2008 14:02]
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/52911 2725 Andrei Elkin 2008-08-29 Bug #38798 Assertion mysql_bin_log.is_open() failed in binlog_trans_log_savepos() The assert is about binlogging must have been activated, but it was not actually according to the reported how-to-repeat instuctions. Analysis revealed that binlog_start_trans_and_stmt() was called without prior testing if binlogging is ON. Fixed with avoing entering binlog_start_trans_and_stmt() if binlog is not activated.
[29 Aug 2008 14:06]
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/52912 2725 Andrei Elkin 2008-08-29 Bug #38798 Assertion mysql_bin_log.is_open() failed in binlog_trans_log_savepos() The assert is about binlogging must have been activated, but it was not actually according to the reported how-to-repeat instuctions. Analysis revealed that binlog_start_trans_and_stmt() was called without prior testing if binlogging is ON. Fixed with avoing entering binlog_start_trans_and_stmt() if binlog is not activated.
[29 Aug 2008 14:20]
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/52914 2725 Andrei Elkin 2008-08-29 Bug #38798 Assertion mysql_bin_log.is_open() failed in binlog_trans_log_savepos() The assert is about binlogging must have been activated, but it was not actually according to the reported how-to-repeat instuctions. Analysis revealed that binlog_start_trans_and_stmt() was called without prior testing if binlogging is ON. Fixed with avoing entering binlog_start_trans_and_stmt() if binlog is not activated.
[29 Aug 2008 14:31]
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/52915 2725 Andrei Elkin 2008-08-29 Bug #38798 Assertion mysql_bin_log.is_open() failed in binlog_trans_log_savepos() The assert is about binlogging must have been activated, but it was not actually according to the reported how-to-repeat instuctions. Analysis revealed that binlog_start_trans_and_stmt() was called without prior testing if binlogging is ON. Fixed with avoing entering binlog_start_trans_and_stmt() if binlog is not activated.
[29 Aug 2008 14:40]
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/52916 2809 Andrei Elkin 2008-08-29 [merge] Bug #38798 Assertion mysql_bin_log.is_open() failed in binlog_trans_log_savepos() merging with 5.1-bugteam
[29 Aug 2008 15:16]
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/52917 2809 Andrei Elkin 2008-08-29 [merge] Bug #38798 Assertion mysql_bin_log.is_open() failed in binlog_trans_log_savepos() merging with 5.1-bugteam
[29 Aug 2008 15:17]
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/52918 2725 Andrei Elkin 2008-08-29 Bug #38798 Assertion mysql_bin_log.is_open() failed in binlog_trans_log_savepos() The assert is about binlogging must have been activated, but it was not actually according to the reported how-to-repeat instuctions. Analysis revealed that binlog_start_trans_and_stmt() was called without prior testing if binlogging is ON. Fixed with avoing entering binlog_start_trans_and_stmt() if binlog is not activated.
[1 Sep 2008 8:38]
Andrei Elkin
pushed to {5.1,6.0}-bugteam.
[13 Sep 2008 20:53]
Bugs System
Pushed into 6.0.7-alpha (revid:aelkin@mysql.com-20080829142008-m69x26h090nh4ibu) (version source revid:hakan@mysql.com-20080725175322-8wgujj5xuzrjz3ke) (pib:3)
[15 Sep 2008 17:13]
Jon Stephens
Documented in the 5.1.29 and 6.0.7 changelogs as follows:
Server code used in binary logging could in some cases be invoked even
though binary logging was not actually enabled, leading to asserts and
other server errors.
[1 Oct 2008 16:07]
Bugs System
Pushed into 5.1.28 (revid:aelkin@mysql.com-20080829142008-m69x26h090nh4ibu) (version source revid:aelkin@mysql.com-20080829142008-m69x26h090nh4ibu) (pib:4)
[28 Oct 2008 21:03]
Bugs System
Pushed into 5.1.29-ndb-6.2.17 (revid:aelkin@mysql.com-20080829142008-m69x26h090nh4ibu) (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-20080829142008-m69x26h090nh4ibu) (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-20080829142008-m69x26h090nh4ibu) (version source revid:jonas@mysql.com-20081101082305-qx5a1bj0z7i8ueys) (pib:5)
Description: When executing a concurrent workload meant to test replication, the master asserted as follows: #8 0x003df57e in __assert_fail () from /lib/libc.so.6 #9 0x082ff973 in binlog_trans_log_savepos (thd=0x93c0dc0, pos=0xb2b87ea8) at log.cc:1272 #10 0x082ffa13 in THD::binlog_set_stmt_begin (this=0x93c0dc0) at log.cc:3652 #11 0x082ffb19 in THD::binlog_start_trans_and_stmt (this=0x93c0dc0) at log.cc:3623 #12 0x082dc67e in select_create::prepare (this=0x93d1bc8, values=@0x93c21bc, u=0x93c1eb0) at sql_insert.cc:3528 #13 0x082d43b5 in JOIN::prepare (this=0x93d1c60, rref_pointer_array=0x93c2220, tables_init=0x93d19d0, wild_num=1, conds_init=0x0, og_num=0, order_init=0x0, group_init=0x0, having_init=0x0, proc_param_init=0x0, select_lex_arg=0x93c2128, unit_arg=0x93c1eb0) at sql_select.cc:629 #14 0x082d47ae in mysql_select (thd=0x93c0dc0, rref_pointer_array=0x93c2220, tables=0x93d19d0, wild_num=1, fields=@0x93c21bc, conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2416200192, result=0x93d1bc8, unit=0x93c1eb0, select_lex=0x93c2128) at sql_select.cc:2338 #15 0x082d9524 in handle_select (thd=0x93c0dc0, lex=0x93c1e54, result=0x93d1bc8, setup_tables_done_option=0) at sql_select.cc:269 #16 0x08257e5c in mysql_execute_command (thd=0x93c0dc0) at sql_parse.cc:2503 #17 0x0825f95c in mysql_parse (thd=0x93c0dc0, inBuf=0x93d1650 "CREATE TABLE n SELECT * FROM o ; TRUNCATE TABLE n", length=49, found_semicolon=0xb2b8925c) at sql_parse.cc:5650 #18 0x08260533 in dispatch_command (command=COM_QUERY, thd=0x93c0dc0, packet=0x93c55c9 "CREATE TABLE n SELECT * FROM o ; TRUNCATE TABLE n", packet_length=49) at sql_parse.cc:1137 #19 0x08261692 in do_command (thd=0x93c0dc0) at sql_parse.cc:794 #20 0x0824ede6 in handle_one_connection (arg=0x93c0dc0) at sql_connect.cc:1115 #21 0x0057d32f in start_thread () from /lib/libpthread.so.0 #22 0x0049a27e in clone () from /lib/libc.so.6 (gdb) list 1267 DBUG_ASSERT(pos != NULL); 1268 if (thd_get_ha_data(thd, binlog_hton) == NULL) 1269 thd->binlog_setup_trx_data(); 1270 binlog_trx_data *const trx_data= 1271 (binlog_trx_data*) thd_get_ha_data(thd, binlog_hton); 1272 DBUG_ASSERT(mysql_bin_log.is_open()); <<<<<< HERE 1273 *pos= trx_data->position(); 1274 DBUG_PRINT("return", ("*pos: %lu", (ulong) *pos)); 1275 DBUG_VOID_RETURN; 1276 } (gdb) print mysql_bin_log.is_open $6 = {bool (MYSQL_LOG *)} 0x81bb18a <MYSQL_LOG::is_open()> (gdb) print (bool) mysql_bin_log.is_open $7 = false How to repeat: This bug is repeatable, a test case will be uploaded shortly.