Bug #76912 | Assertion `m_status == DA_ERROR' failed. | ||
---|---|---|---|
Submitted: | 2 May 2015 5:43 | Modified: | 10 May 2017 7:11 |
Reporter: | Roel Van de Paar | Email Updates: | |
Status: | Closed | Impact on me: | |
Category: | MySQL Server: Information schema | Severity: | S6 (Debug Builds) |
Version: | 5.7.6-m16, 5.7.8, 8.0.0 | OS: | Any |
Assigned to: | CPU Architecture: | Any |
[2 May 2015 5:43]
Roel Van de Paar
[2 May 2015 5:44]
Roel Van de Paar
Likely present in 5.6 also, ref https://bugs.launchpad.net/percona-server/+bug/1384632
[2 May 2015 6:11]
MySQL Verification Team
Hello Roel, Thank you for the bug report and test case. Observed that 5.7.8/5.8.0 debug builds are affected. Thanks, Umesh
[2 May 2015 6:12]
MySQL Verification Team
// 5.7.8 - only debug builds affected bin/mysql_install_db --insecure --basedir=/export/umesh/server/binaries/mysql-5.7.8 --datadir=/export/umesh/server/binaries/mysql-5.7.8/76912 -v bin/mysqld-debug --basedir=/export/umesh/server/binaries/mysql-5.7.8 --datadir=/export/umesh/server/binaries/mysql-5.7.8/76912 --sql_mode=ONLY_FULL_GROUP_BY --core-file --socket=/tmp/mysql_ushastry.sock --port=15000 --log-error=/export/umesh/server/binaries/mysql-5.7.8/76912/log.err 2>&1 & - build commit: 16c9f19989b93346cf1868250a00760b9ebd19e1 date: 2015-05-01 07:16:38 +0530 build-date: 2015-05-01 04:12:15 +0200 short: 16c9f19 branch: mysql-5.7 MySQL source 5.7.8 (gdb) bt #0 0x00007f2437f26771 in pthread_kill () from /lib64/libpthread.so.0 #1 0x00000000019323a5 in my_write_core (sig=6) at /export/home/pb2/build/sb_0-15183682-1430447752.71/mysqlcom-pro-5.7.8-rc/mysys/stacktrace.c:247 #2 0x0000000000f7d7b0 in handle_fatal_signal (sig=6) at /export/home/pb2/build/sb_0-15183682-1430447752.71/mysqlcom-pro-5.7.8-rc/sql/signal_handler.cc:220 #3 <signal handler called> #4 0x00007f2436b2c5c9 in raise () from /lib64/libc.so.6 #5 0x00007f2436b2dcd8 in abort () from /lib64/libc.so.6 #6 0x00007f2436b25536 in __assert_fail_base () from /lib64/libc.so.6 #7 0x00007f2436b255e2 in __assert_fail () from /lib64/libc.so.6 #8 0x000000000157238f in Diagnostics_area::mysql_errno (this=0x7f239c003588) at /export/home/pb2/build/sb_0-15183682-1430447752.71/mysqlcom-pro-5.7.8-rc/sql/sql_error.h:385 #9 0x000000000172942e in XID_STATE::set_error (this=0x7f239c004160, thd=0x7f239c000bb0) at /export/home/pb2/build/sb_0-15183682-1430447752.71/mysqlcom-pro-5.7.8-rc/sql/xa.cc:821 #10 0x0000000000fe38c2 in ha_rollback_low (thd=0x7f239c000bb0, all=true) at /export/home/pb2/build/sb_0-15183682-1430447752.71/mysqlcom-pro-5.7.8-rc/sql/handler.cc:1802 #11 0x000000000152d095 in TC_LOG_DUMMY::rollback (this=0x2e5d3a8 <tc_log_dummy>, thd=0x7f239c000bb0, all=true) at /export/home/pb2/build/sb_0-15183682-1430447752.71/mysqlcom-pro-5.7.8-rc/sql/log.h:107 #12 0x0000000000fe3a34 in ha_rollback_trans (thd=0x7f239c000bb0, all=true) at /export/home/pb2/build/sb_0-15183682-1430447752.71/mysqlcom-pro-5.7.8-rc/sql/handler.cc:1855 #13 0x00000000017162b7 in trans_rollback_implicit (thd=0x7f239c000bb0) at /export/home/pb2/build/sb_0-15183682-1430447752.71/mysqlcom-pro-5.7.8-rc/sql/transaction.cc:350 #14 0x00000000016216e3 in mysql_execute_command (thd=0x7f239c000bb0) at /export/home/pb2/build/sb_0-15183682-1430447752.71/mysqlcom-pro-5.7.8-rc/sql/sql_parse.cc:4651 #15 0x0000000001622ac8 in mysql_parse (thd=0x7f239c000bb0, parser_state=0x7f240a9b65e0) at /export/home/pb2/build/sb_0-15183682-1430447752.71/mysqlcom-pro-5.7.8-rc/sql/sql_parse.cc:5186 #16 0x0000000001617af8 in dispatch_command (thd=0x7f239c000bb0, com_data=0x7f240a9b6e10, command=COM_QUERY) at /export/home/pb2/build/sb_0-15183682-1430447752.71/mysqlcom-pro-5.7.8-rc/sql/sql_parse.cc:1278 #17 0x00000000016164db in do_command (thd=0x7f239c000bb0) at /export/home/pb2/build/sb_0-15183682-1430447752.71/mysqlcom-pro-5.7.8-rc/sql/sql_parse.cc:851 #18 0x0000000001740b1c in handle_connection (arg=0x53ecb70) at /export/home/pb2/build/sb_0-15183682-1430447752.71/mysqlcom-pro-5.7.8-rc/sql/conn_handler/connection_handler_per_thread.cc:299 #19 0x00000000019bd4b1 in pfs_spawn_thread (arg=0x53c6600) at /export/home/pb2/build/sb_0-15183682-1430447752.71/mysqlcom-pro-5.7.8-rc/storage/perfschema/pfs.cc:2147 #20 0x00007f2437f21df3 in start_thread () from /lib64/libpthread.so.0 #21 0x00007f2436bed47d in clone () from /lib64/libc.so.6 (gdb)
[2 May 2015 6:12]
MySQL Verification Team
// 5.8.0 - debug build affected bin/mysql_install_db --insecure --basedir=/export/umesh/server/binaries/mysql-5.8.0 --datadir=/export/umesh/server/binaries/mysql-5.8.0/76912 -v bin/mysqld-debug --basedir=/export/umesh/server/binaries/mysql-5.8.0 --datadir=/export/umesh/server/binaries/mysql-5.8.0/76912 --core-file --socket=/tmp/mysql_ushastry.sock --port=15000 --log-error=/export/umesh/server/binaries/mysql-5.8.0/76912/log.err 2>&1 & // build commit: 9102310a2863f9014c1b58669c8418aa18268ac2 date: 2015-04-30 19:11:30 +0530 build-date: 2015-04-30 17:07:18 +0200 short: 9102310a branch: mysql-trunk MySQL source 5.8.0 (gdb) bt #0 0x00007f9a4618f771 in pthread_kill () from /lib64/libpthread.so.0 #1 0x00000000018b9d8c in my_write_core (sig=6) at /export/home3/pb2/build/sb_0-15177417-1430408158.32/mysqlcom-pro-5.8.0-m17/mysys/stacktrace.c:247 #2 0x0000000000f476db in handle_fatal_signal (sig=6) at /export/home3/pb2/build/sb_0-15177417-1430408158.32/mysqlcom-pro-5.8.0-m17/sql/signal_handler.cc:221 #3 <signal handler called> #4 0x00007f9a44d955c9 in raise () from /lib64/libc.so.6 #5 0x00007f9a44d96cd8 in abort () from /lib64/libc.so.6 #6 0x00007f9a44d8e536 in __assert_fail_base () from /lib64/libc.so.6 #7 0x00007f9a44d8e5e2 in __assert_fail () from /lib64/libc.so.6 #8 0x0000000001515309 in Diagnostics_area::mysql_errno (this=0x7f99ac003588) at /export/home3/pb2/build/sb_0-15177417-1430408158.32/mysqlcom-pro-5.8.0-m17/sql/sql_error.h:387 #9 0x00000000016bcd1c in XID_STATE::set_error (this=0x7f99ac004160, thd=0x7f99ac000bb0) at /export/home3/pb2/build/sb_0-15177417-1430408158.32/mysqlcom-pro-5.8.0-m17/sql/xa.cc:859 #10 0x0000000000fae72d in ha_rollback_low (thd=0x7f99ac000bb0, all=true) at /export/home3/pb2/build/sb_0-15177417-1430408158.32/mysqlcom-pro-5.8.0-m17/sql/handler.cc:1741 #11 0x00000000014cfac5 in TC_LOG_DUMMY::rollback (this=0x2daa348 <tc_log_dummy>, thd=0x7f99ac000bb0, all=true) at /export/home3/pb2/build/sb_0-15177417-1430408158.32/mysqlcom-pro-5.8.0-m17/sql/log.cc:2067 #12 0x0000000000fae896 in ha_rollback_trans (thd=0x7f99ac000bb0, all=true) at /export/home3/pb2/build/sb_0-15177417-1430408158.32/mysqlcom-pro-5.8.0-m17/sql/handler.cc:1794 #13 0x00000000016aa270 in trans_rollback_implicit (thd=0x7f99ac000bb0) at /export/home3/pb2/build/sb_0-15177417-1430408158.32/mysqlcom-pro-5.8.0-m17/sql/transaction.cc:352 #14 0x00000000015b7cba in mysql_execute_command (thd=0x7f99ac000bb0) at /export/home3/pb2/build/sb_0-15177417-1430408158.32/mysqlcom-pro-5.8.0-m17/sql/sql_parse.cc:4607 #15 0x00000000015b92df in mysql_parse (thd=0x7f99ac000bb0, parser_state=0x7f9a18c0de50) at /export/home3/pb2/build/sb_0-15177417-1430408158.32/mysqlcom-pro-5.8.0-m17/sql/sql_parse.cc:5145 #16 0x00000000015af11e in dispatch_command (thd=0x7f99ac000bb0, com_data=0x7f9a18c0ee00, command=COM_QUERY) at /export/home3/pb2/build/sb_0-15177417-1430408158.32/mysqlcom-pro-5.8.0-m17/sql/sql_parse.cc:1245 #17 0x00000000015addb7 in do_command (thd=0x7f99ac000bb0) at /export/home3/pb2/build/sb_0-15177417-1430408158.32/mysqlcom-pro-5.8.0-m17/sql/sql_parse.cc:816 #18 0x00000000016d3846 in handle_connection (arg=0x407fcb0) at /export/home3/pb2/build/sb_0-15177417-1430408158.32/mysqlcom-pro-5.8.0-m17/sql/conn_handler/connection_handler_per_thread.cc:300 #19 0x0000000001c83559 in pfs_spawn_thread (arg=0x41513c0) at /export/home3/pb2/build/sb_0-15177417-1430408158.32/mysqlcom-pro-5.8.0-m17/storage/perfschema/pfs.cc:2147 #20 0x00007f9a4618adf3 in start_thread () from /lib64/libpthread.so.0 #21 0x00007f9a44e5647d in clone () from /lib64/libc.so.6 (gdb)
[2 May 2015 6:12]
MySQL Verification Team
I'm not seeing any issues with latest 5.6.25 builds.
[4 May 2015 5:03]
Roel Van de Paar
Yeah the 5.6 bit is interesting...
[6 May 2015 13:28]
Erlend Dahl
Posted by developer: MTR test case: CREATE TABLE t1(c1 INT NOT NULL) ENGINE = csv; LOCK TABLES t1 WRITE; INSERT INTO t1 VALUES(0); SELECT GET_LOCK('TEST3',0); CHECK TABLE t1 EXTENDED; --error 1142 LOCK TABLES performance_schema.table_io_waits_summary_by_table WRITE; XA START 'test2'; SELECT COUNT(*)FROM information_schema.key_column_usage; DROP TABLE t1;
[11 May 2015 3:47]
Erlend Dahl
Posted by developer: Bisecting with the simplified testcase CREATE TABLE t1(c1 INT NOT NULL) ENGINE = csv; LOCK TABLES t1 WRITE; INSERT INTO t1 VALUES(0); SELECT GET_LOCK('TEST3',0); CHECK TABLE t1; UNLOCK TABLES; XA START 'test2'; SELECT COUNT(*)FROM information_schema.key_column_usage; gives this as the regression source: WL#1159 "Allow multiple locks in GET_LOCK()". pushed on July 2, 2014.
[15 May 2015 8:12]
Dyre Tjeldvoll
Posted by developer: Root cause seem to be in the function fill_schema_table_by_open() which first sets thd->transaction_rollback_request at #0 THD::mark_transaction_to_rollback (this=0x7fff881eb820, all=true) at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/sql/sql_class.cc:2846 #1 0x00000000012b854b in MDL_deadlock_discovery_repair_handler::handle_condition (this=0x7fffddfa9040, thd=0x7fff881eb820, sql_errno=1213, sqlstate=0x1d49e8b "40001", level=0x7fffddfa8750, msg=0x7fffddfa8820 "Deadlock found when trying to get lock; try restarting transaction") at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/sql/sql_base.cc:4305 #2 0x00000000012c7e42 in THD::handle_condition (this=0x7fff881eb820, sql_errno=1213, sqlstate=0x1d49e8b "40001", level=0x7fffddfa8750, msg=0x7fffddfa8820 "Deadlock found when trying to get lock; try restarting transaction") at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/sql/sql_class.cc:678 #3 0x00000000012c85dd in THD::raise_condition (this=0x7fff881eb820, sql_errno=1213, sqlstate=0x1d49e8b "40001", level=Sql_condition::SL_ERROR, msg=0x7fffddfa8820 "Deadlock found when trying to get lock; try restarting transaction") at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/sql/sql_class.cc:817 #4 0x0000000000d3a751 in my_message_sql (error=1213, ---Type <return> to continue, or q <return> to quit--- str=0x7fffddfa8820 "Deadlock found when trying to get lock; try restarting transaction", MyFlags=0) at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/sql/mysqld.cc:2362 #5 0x0000000001618f3e in my_error (nr=1213, MyFlags=0) at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/mysys/my_error.c:212 #6 0x0000000001246bca in MDL_context::acquire_lock (this=0x7fff881eb8b8, mdl_request=0x7fff88f45050, lock_wait_timeout=31536000) at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/sql/mdl.cc:3593 #7 0x0000000001246e6f in MDL_context::acquire_locks (this=0x7fff881eb8b8, mdl_requests=0x7fffddfa8fd0, lock_wait_timeout=31536000) at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/sql/mdl.cc:3710 #8 0x00000000012ac42a in lock_table_names (thd=0x7fff881eb820, tables_start=0x7fff88f44cb0, tables_end=0x0, lock_wait_timeout=31536000, flags=0) at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/sql/sql_base.cc:5096 #9 0x00000000012ab0ba in Open_table_context::recover_from_failed_open ( this=0x7fffddfa90d0) at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/sql/sql_---Type <return> to continue, or q <return> to quit--- base.cc:4367 #10 0x00000000012acc53 in open_tables (thd=0x7fff881eb820, start=0x7fffddfa9190, counter=0x7fffddfa9340, flags=1282, prelocking_strategy=0x7fffddfa91d0) at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/sql/sql_base.cc:5433 #11 0x00000000012addff in open_tables_for_query (thd=0x7fff881eb820, tables=0x7fff88f44728, flags=1282) at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/sql/sql_base.cc:6130 #12 0x000000000138857c in fill_schema_table_by_open (thd=0x7fff881eb820, is_show_fields_or_keys=false, table=0x7fff88dd3950, schema_table=0x2853240 <schema_tables+640>, orig_db_name=0x7fff882eb7a0, orig_table_name=0x7fff88e4ad18, open_tables_state_backup=0x7fffddfa9de0, can_deadlock=true) at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/sql/sql_show.cc:3869 and then later resets the diagnostics area, but not the transaction_rollback_request flag: Old value = Diagnostics_area::DA_ERROR New value = Diagnostics_area::DA_EMPTY Diagnostics_area::reset_diagnostics_area (this=0x7fffddfa9f80) at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/sql/sql_error.cc:374 374 DBUG_VOID_RETURN; (gdb) where #0 Diagnostics_area::reset_diagnostics_area (this=0x7fffddfa9f80) at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/sql/sql_error.cc:374 #1 0x000000000127f25d in THD::clear_error (this=0x7fff881eb820) at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/sql/sql_class.h:2450 #2 0x00000000013922a0 in get_schema_key_column_usage_record ( thd=0x7fff881eb820, tables=0x7fff88f44728, table=0x7fff88dd3950, res=true, db_name=0x7fff882eb7a0, table_name=0x7fff88e4ad18) at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/sql/sql_show.cc:6351 #3 0x00000000013886cc in fill_schema_table_by_open (thd=0x7fff881eb820, is_show_fields_or_keys=false, table=0x7fff88dd3950, schema_table=0x2853240 <schema_tables+640>, orig_db_name=0x7fff882eb7a0, orig_table_name=0x7fff88e4ad18, open_tables_state_backup=0x7fffddfa9de0, can_deadlock=true) at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/sql/sql_show.cc:3911
[15 May 2015 8:28]
Dyre Tjeldvoll
Posted by developer: A general observation here is that it appears potentially dangerous to call THD::clear_error() without also checking the value of transaction_rollback_request. As a test I tried adding DBUG_ASSERT(!transaction_rollback_request) inside THD::clear_error() and run the test suite to see what would happen. Got one crash: Thread 1 (Thread 0x7fdaf5891700 (LWP 1630)): #0 0x00007fdb0f64b68c in pthread_kill () from /lib64/libpthread.so.0 #1 0x00000000016213f4 in my_write_core (sig=6) at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/mysys/stacktrace.c:247 #2 0x0000000000d4e993 in handle_fatal_signal (sig=6) at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/sql/signal_handler.cc:221 #3 <signal handler called> #4 0x00007fdb0e2438d7 in raise () from /lib64/libc.so.6 #5 0x00007fdb0e24553a in abort () from /lib64/libc.so.6 #6 0x00007fdb0e23c47d in __assert_fail_base () from /lib64/libc.so.6 #7 0x00007fdb0e23c532 in __assert_fail () from /lib64/libc.so.6 #8 0x000000000127f277 in THD::clear_error (this=0x7fda800009a0) at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/sql/sql_class.h:2451 #9 0x00000000015c9df9 in handle_slave_worker (arg=0x7fda900ce350) at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/sql/rpl_slave.cc:5846 #10 0x0000000001a4999a in pfs_spawn_thread (arg=0x7fda90158e90) at /export/home/tmp/clones/bug21021848_assertion_m_status==da_error/storage/perfschema/pfs.cc:2147 #11 0x00007fdb0f64552a in start_thread () from /lib64/libpthread.so.0 #12 0x00007fdb0e30f22d in clone () from /lib64/libc.so.6 Not sure if the XA-abort case could ever occur here...
[19 Jul 2015 21:25]
Paul DuBois
Noted in 5.6.27, 5.7.9, 5.8.0 changelogs. If an INFORMATION_SCHEMA query that performed a table-open operation encountered a corrupt table and attempted to repair it, a deadlock could occur, resulting in an aborted transaction without an appropriate error being reported. Such queries now do not attempt table repair.
[18 Jun 2016 21:26]
Omer Barnir
Posted by developer: Reported version value updated to reflect release name change from 5.8 to 8.0
[10 May 2017 7:11]
Roel Van de Paar
Also see bug 86260