| Bug #31692 | binlog_killed.test crashes sometimes | ||
|---|---|---|---|
| Submitted: | 18 Oct 2007 12:51 | Modified: | 24 Oct 2007 18:43 |
| Reporter: | Ingo Strüwing | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Locking | Severity: | S1 (Critical) |
| Version: | 5.1.23 | OS: | Linux |
| Assigned to: | Ingo Strüwing | CPU Architecture: | Any |
| Tags: | crash | ||
[18 Oct 2007 13:24]
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/35839 ChangeSet@1.2574, 2007-10-18 15:24:30+02:00, istruewing@stella.local +1 -0 Bug#31692 - binlog_killed.test crashes sometimes The server crashed when a thread was killed while locking the general_log table at statement begin. The general_log table is handled like a performance schema table. The state of open tables is saved and cleared so that this table seems to be the only open one. Then this table is opened and locked. After writing, the table is closed and the open table state is restored. Before restoring, however, it is asserted that there is no current table open. After locking the table, mysql_lock_tables() checks if the thread was killed in between. If so, it unlocks the table and returns an error. open_ltable() just returns with the error and leaves closing of the table to close_thread_tables(), which is called at statement end. open_performance_schema_table() did not take this into account. It assumed that a failed open_ltable() would not leave an open table behind. Fixed by closing thread tables after open_ltable() and before restore_backup_open_tables_state() if the thread was killed. No test case. It requires correctly timed parallel execution. Since this bug was detected by the test suite, it seems dispensable to add another test.
[18 Oct 2007 13:38]
Konstantin Osipov
OK to push, it's safe to call close_thread_tables in all cases, so please do so.
[18 Oct 2007 14:14]
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/35844 ChangeSet@1.2576, 2007-10-18 16:14:27+02:00, istruewing@stella.local +1 -0 Bug#31692 - binlog_killed.test crashes sometimes The server crashed when a thread was killed while locking the general_log table at statement begin. The general_log table is handled like a performance schema table. The state of open tables is saved and cleared so that this table seems to be the only open one. Then this table is opened and locked. After writing, the table is closed and the open table state is restored. Before restoring, however, it is asserted that there is no current table open. After locking the table, mysql_lock_tables() checks if the thread was killed in between. If so, it unlocks the table and returns an error. open_ltable() just returns with the error and leaves closing of the table to close_thread_tables(), which is called at statement end. open_performance_schema_table() did not take this into account. It assumed that a failed open_ltable() would not leave an open table behind. Fixed by closing thread tables after open_ltable() and before restore_backup_open_tables_state() if the thread was killed. No test case. It requires correctly timed parallel execution. Since this bug was detected by the test suite, it seems dispensable to add another test.
[19 Oct 2007 10:21]
Ingo Strüwing
Queued to 6.0-engines, 5.2-engines, 5.1-engines.
[22 Oct 2007 17:03]
Bugs System
Pushed into 5.1.23-beta
[24 Oct 2007 18:43]
Paul DuBois
Noted in 5.1.23 changelog.
Description: 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 How to repeat: bk clone bk-internal.mysql.com:/home/bk/mysql-5.1-engines mysql-5.1-bug26379-5 cd mysql-5.1-bug26379-5 BUILD/compile-pentium-debug-max --with-debug=full --prefix="/home2/mydev/install-5.1-bug26379-5" cd mysql-test ./mysql-test-run.pl --mysqld=--binlog-format=statement binlog_innodb binlog_killed Note: This crashes on my machine only every third time. And only in conjunction with binlog_innodb. I could'nt repeat with binlog_killed alone.