Bug #78701 | InnoDB: Failing assertion: index->table == table & Assertion `0' failed. | ||
---|---|---|---|
Submitted: | 5 Oct 2015 11:46 | Modified: | 23 Nov 2015 9:57 |
Reporter: | Roel Van de Paar | Email Updates: | |
Status: | Closed | Impact on me: | |
Category: | MySQL Server: DML | Severity: | S6 (Debug Builds) |
Version: | 5.7.8 (RC2), 5.7.10 | OS: | Any |
Assigned to: | CPU Architecture: | Any |
[5 Oct 2015 11:46]
Roel Van de Paar
[5 Oct 2015 11:47]
Roel Van de Paar
1444040597_bug_bundle.tar.gz
Attachment: 1444040597_bug_bundle.tar.gz (application/x-gzip, text), 999.11 KiB.
[5 Oct 2015 11:49]
Roel Van de Paar
For some reason, the gdb parse scripts in this particular case do not seem to work. Anyhows, the core is there and can be gdb'ed like this: $ gdb /sda/mysql-5.7.8-rc-linux-x86_64-debug/bin/mysqld /dev/shm/1444040597/data/core{press tab}
[5 Oct 2015 11:50]
Roel Van de Paar
set global innodb_trx_rseg_n_slots_debug=1; Is used in the testcase.
[5 Oct 2015 11:51]
Roel Van de Paar
Full testcase (do not execute in the command line directly, it won't crash, use the procedure above instead), for reference only: DROP DATABASE test;CREATE DATABASE test;USE test; create TABLE t1(a int,b int,key(a),key(b)) partition by hash(a) partitions 4; CREATE TABLE t619(c1 INT); CREATE TABLE t5(c1 YEAR,c2 INT,c3 CHAR); set global innodb_trx_rseg_n_slots_debug=1; CREATE TABLE t11(c1 CHAR); create table `t``1`(a int)engine=InnoDB; CREATE TABLE t12(c1 INT); ALTER TABLE t5 CHANGE c1 c1 DOUBLE(24,0)SIGNED,CHANGE c2 c2 DOUBLE(24,0) UNSIGNED;
[6 Oct 2015 8:52]
Roel Van de Paar
Secondary testcase. Same script/idea - see above for initial instructions, then use the testcase and additional upload below as given. Issue crashes about 2 out of 3 times, and sometimes at a different location. rm -Rf /dev/shm/1444045875 ps -ef | grep mysqld | grep -v grep | grep 1444045875 | awk '{print $2}' | xargs kill -9 ./1444045875_init ./1444045875_start sleep 4 ./1444045875_run_pquery ./1444045875_run ./1444045875_run ./1444045875_run_pquery ./1444045875_run_pquery ./1444045875_run_pquery ./1444045875_run ./1444045875_stop sleep 2 ./1444045875_start sleep 4 ./1444045875_run
[6 Oct 2015 8:53]
Roel Van de Paar
1444045875_bug_bundle.tar.gz
Attachment: 1444045875_bug_bundle.tar.gz (application/x-gzip, text), 999.35 KiB.
[6 Oct 2015 9:02]
Roel Van de Paar
Expected output on run of second testcase: [roel@localhost 496]$ ./1444045875_run Executing testcase ./1444045875.sql against mysqld with socket /dev/shm/1444045875/socket.sock using the mysql CLI client... ERROR 2013 (HY000) at line 2: Lost connection to MySQL server during query ERROR 2006 (HY000) at line 2: MySQL server has gone away Note that the last line of the 1444045875_start can be simplified to: $BIN --no-defaults --basedir=${MYBASE} --datadir=/dev/shm/1444045875/data --tmpdir=/dev/shm/1444045875/tmp --port=35091 --pid-file=/dev/shm/1444045875/pid.pid --core-file --socket=/dev/shm/1444045875/socket.sock --log-output=none --log-error=/dev/shm/1444045875/error.log.out > /dev/shm/1444045875/mysqld.out 2>&1 & Thought the issue seems to become slightly less reproducible then. 2015-10-06T08:49:18.390749Z 12 [ERROR] InnoDB: Flagged corruption of `PRIMARY` in table `test`.`#sql2-7da7-c` in DROP TABLE mysqld: /git/mysql-server_dbg/sql/sql_class.cc:4758: void THD::send_statement_status(): Assertion `0' failed. 08:49:18 UTC - mysqld got signal 6 ; Crashes produced differ.
[6 Oct 2015 9:04]
Roel Van de Paar
+bt #0 0x00007f84feb35771 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61 #1 0x0000000001721318 in my_write_core (sig=6) at /git/mysql-server_dbg/mysys/stacktrace.c:247 #2 0x0000000000dd6008 in handle_fatal_signal (sig=6) at /git/mysql-server_dbg/sql/signal_handler.cc:220 #3 <signal handler called> #4 0x00007f84fd7395d7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56 #5 0x00007f84fd73acc8 in __GI_abort () at abort.c:90 #6 0x00007f84fd732546 in __assert_fail_base (fmt=0x7f84fd882128 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x1e5aef6 "0", file=file@entry=0x1e5b6a8 "/git/mysql-server_dbg/sql/sql_class.cc", line=line@entry=4758, function=function@entry=0x1e5d540 <THD::send_statement_status()::__PRETTY_FUNCTION__> "void THD::send_statement_status()") at assert.c:92 #7 0x00007f84fd7325f2 in __GI___assert_fail (assertion=0x1e5aef6 "0", file=0x1e5b6a8 "/git/mysql-server_dbg/sql/sql_class.cc", line=4758, function=0x1e5d540 <THD::send_statement_status()::__PRETTY_FUNCTION__> "void THD::send_statement_status()") at assert.c:101 #8 0x00000000013c6221 in THD::send_statement_status (this=0x7f84c141a000) at /git/mysql-server_dbg/sql/sql_class.cc:4758 #9 0x000000000141c828 in dispatch_command (thd=0x7f84c141a000, com_data=0x7f84ff12edc0, command=COM_QUERY) at /git/mysql-server_dbg/sql/sql_parse.cc:1686 #10 0x000000000141a10e in do_command (thd=0x7f84c141a000) at /git/mysql-server_dbg/sql/sql_parse.cc:852 #11 0x0000000001541c80 in handle_connection (arg=0x7f84edbff200) at /git/mysql-server_dbg/sql/conn_handler/connection_handler_per_thread.cc:300 #12 0x000000000174e31f in pfs_spawn_thread (arg=0x7f84f4be8d20) at /git/mysql-server_dbg/storage/perfschema/pfs.cc:2178 #13 0x00007f84feb30df5 in start_thread (arg=0x7f84ff12f700) at pthread_create.c:308 #14 0x00007f84fd7fa1ad in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113
[7 Oct 2015 5:45]
MySQL Verification Team
Hello Roel, Thank you for the report. Confirmed that 5.7.8/5.7.10 debug builds are affected. Thanks, Umesh
[7 Oct 2015 5:46]
MySQL Verification Team
// 5.7.8 rm -rf 78701 bin/mysql_install_db --insecure --basedir=/export/umesh/server/binaries/mysql-5.7.8-rc --datadir=/export/umesh/server/binaries/mysql-5.7.8-rc/78701 -v bin/mysqld-debug --no-defaults --basedir=/export/umesh/server/binaries/mysql-5.7.8-rc --datadir=/export/umesh/server/binaries/mysql-5.7.8-rc/78701 --core-file --socket=/tmp/mysql_ushastry.sock --port=15000 --log-error=/export/umesh/server/binaries/mysql-5.7.8-rc/78701/log.err --event-scheduler=ON 2>&1 & Note: Restart server if you are not seeing crash, repeat executing provided test case [umshastr@hod03]/export/umesh/server/binaries/mysql-5.7.8-rc/prn: for i in {1..50}; do ./1444040597_run; done //extract from error log 2015-10-07T05:07:32.978220Z 0 [Note] bin/mysqld-debug: ready for connections. Version: '5.7.8-rc-debug' socket: '/tmp/mysql_ushastry.sock' port: 15000 MySQL Community Server - Debug (GPL) 2015-10-07T05:07:44.454685Z 4 [ERROR] InnoDB: Index `GEN_CLUST_INDEX` of table `test`.`t``1` is corrupted 2015-10-07T05:07:44.454717Z 4 [Note] InnoDB: Load corrupted index `GEN_CLUST_INDEX` of table `test`.`t``1` 2015-10-07T05:07:44.454729Z 4 [ERROR] InnoDB: Trying to load index `GEN_CLUST_INDEX` for table `test`.`t``1`, but the index tree has been freed! 2015-10-07 07:07:44 0x7fc300064700 InnoDB: Assertion failure in thread 140475495761664 in file dict0load.cc line 2561 InnoDB: Failing assertion: index->table == table (gdb) bt #0 0x00007fc32d624771 in pthread_kill () from /lib64/libpthread.so.0 #1 0x000000000178dcb9 in my_write_core (sig=6) at /export/home/pb2/build/sb_0-15961582-1437395640.67/mysql-5.7.8-rc/mysys/stacktrace.c:247 #2 0x0000000000dfe1c8 in handle_fatal_signal (sig=6) at /export/home/pb2/build/sb_0-15961582-1437395640.67/mysql-5.7.8-rc/sql/signal_handler.cc:220 #3 <signal handler called> #4 0x00007fc32c22a5d7 in raise () from /lib64/libc.so.6 #5 0x00007fc32c22bcc8 in abort () from /lib64/libc.so.6 #6 0x0000000001acb353 in ut_dbg_assertion_failed (expr=0x21db275 "index->table == table", file=0x21d9ea8 "/export/home/pb2/build/sb_0-15961582-1437395640.67/mysql-5.7.8-rc/storage/innobase/dict/dict0load.cc", line=2561) at /export/home/pb2/build/sb_0-15961582-1437395640.67/mysql-5.7.8-rc/storage/innobase/ut/ut0dbg.cc:67 #7 0x0000000001b8c286 in dict_load_indexes (table=0x7fc2b80436a0, heap=0x7fc2b803b698, ignore_err=3) at /export/home/pb2/build/sb_0-15961582-1437395640.67/mysql-5.7.8-rc/storage/innobase/dict/dict0load.cc:2561 #8 0x0000000001b8d9fd in dict_load_table_one (name=..., cached=true, ignore_err=3, fk_tables=std::deque with 0 elements) at /export/home/pb2/build/sb_0-15961582-1437395640.67/mysql-5.7.8-rc/storage/innobase/dict/dict0load.cc:3113 #9 0x0000000001b8cd55 in dict_load_table (name=0x7fc30005ee10 "test/t@00601", cached=true, ignore_err=3) at /export/home/pb2/build/sb_0-15961582-1437395640.67/mysql-5.7.8-rc/storage/innobase/dict/dict0load.cc:2848 #10 0x0000000001b70b00 in dict_table_open_on_name (table_name=0x7fc30005ee10 "test/t@00601", dict_locked=1, try_drop=0, ignore_err=3) at /export/home/pb2/build/sb_0-15961582-1437395640.67/mysql-5.7.8-rc/storage/innobase/dict/dict0dict.cc:1215 #11 0x00000000019f6c85 in row_drop_table_for_mysql (name=0x7fc30005ee10 "test/t@00601", trx=0x7fc32321bcf0, drop_db=true, nonatomic=true, handler=0x0) at /export/home/pb2/build/sb_0-15961582-1437395640.67/mysql-5.7.8-rc/storage/innobase/row/row0mysql.cc:4215 #12 0x00000000018b4cf8 in ha_innobase::delete_table (this=0x7fc2b8039420, name=0x7fc3000601f0 "./test/t@00601") at /export/home/pb2/build/sb_0-15961582-1437395640.67/mysql-5.7.8-rc/storage/innobase/handler/ha_innodb.cc:11796 #13 0x0000000000e6b5fc in handler::ha_delete_table (this=0x7fc2b8039420, name=0x7fc3000601f0 "./test/t@00601") at /export/home/pb2/build/sb_0-15961582-1437395640.67/mysql-5.7.8-rc/sql/handler.cc:4637 #14 0x0000000000e65138 in ha_delete_table (thd=0x7fc2b8000c10, table_type=0x33fa5a0, path=0x7fc3000601f0 "./test/t@00601", db=0x7fc2b8019af8 "test", alias=0x7fc2b8019afd "t`1", generate_warning=false) at /export/home/pb2/build/sb_0-15961582-1437395640.67/mysql-5.7.8-rc/sql/handler.cc:2383 #15 0x0000000001500617 in mysql_rm_table_no_locks (thd=0x7fc2b8000c10, tables=0x7fc2b8019570, if_exists=true, drop_temporary=false, drop_view=true, dont_log_query=true) at /export/home/pb2/build/sb_0-15961582-1437395640.67/mysql-5.7.8-rc/sql/sql_table.cc:2539 #16 0x0000000001427576 in mysql_rm_db (thd=0x7fc2b8000c10, db=..., if_exists=false, silent=false) at /export/home/pb2/build/sb_0-15961582-1437395640.67/mysql-5.7.8-rc/sql/sql_db.cc:865 #17 0x000000000147c10b in mysql_execute_command (thd=0x7fc2b8000c10) at /export/home/pb2/build/sb_0-15961582-1437395640.67/mysql-5.7.8-rc/sql/sql_parse.cc:3529 #18 0x00000000014812c1 in mysql_parse (thd=0x7fc2b8000c10, parser_state=0x7fc3000635e0) at /export/home/pb2/build/sb_0-15961582-1437395640.67/mysql-5.7.8-rc/sql/sql_parse.cc:5255 #19 0x000000000147617b in dispatch_command (thd=0x7fc2b8000c10, com_data=0x7fc300063e10, command=COM_QUERY) at /export/home/pb2/build/sb_0-15961582-1437395640.67/mysql-5.7.8-rc/sql/sql_parse.cc:1272 #20 0x0000000001474b8e in do_command (thd=0x7fc2b8000c10) at /export/home/pb2/build/sb_0-15961582-1437395640.67/mysql-5.7.8-rc/sql/sql_parse.cc:852 #21 0x00000000015a2c18 in handle_connection (arg=0x3f1d3a0) at /export/home/pb2/build/sb_0-15961582-1437395640.67/mysql-5.7.8-rc/sql/conn_handler/connection_handler_per_thread.cc:300 #22 0x0000000001819bef in pfs_spawn_thread (arg=0x3f66130) at /export/home/pb2/build/sb_0-15961582-1437395640.67/mysql-5.7.8-rc/storage/perfschema/pfs.cc:2178 #23 0x00007fc32d61fdf5 in start_thread () from /lib64/libpthread.so.0 #24 0x00007fc32c2eb60d in clone () from /lib64/libc.so.6 (gdb)
[7 Oct 2015 5:47]
MySQL Verification Team
// 5.7.10 rm -rf 78701 bin/mysql_install_db --insecure --basedir=/export/umesh/server/binaries/mysql-advanced-5.7.10 --datadir=/export/umesh/server/binaries/mysql-advanced-5.7.10/78701 -v bin/mysqld-debug --no-defaults --basedir=/export/umesh/server/binaries/mysql-advanced-5.7.10 --datadir=/export/umesh/server/binaries/mysql-advanced-5.7.10/78701 --core-file --socket=/tmp/mysql_ushastry.sock --port=15000 --log-error=/export/umesh/server/binaries/mysql-advanced-5.7.10/78701/log.err --event-scheduler=ON 2>&1 & Note: Restart server if you are not seeing crash, repeat executing provided test case [umshastr@hod03]/export/umesh/server/binaries/mysql-advanced-5.7.10/prn: for i in {1..50}; do ./1444040597_run; done // extract from error log 2015-10-07T05:15:50.670082Z 6 [ERROR] InnoDB: The file './test/t1#P#p0.ibd' already exists though the corresponding table did not exist in the InnoDB data dictionary. Have you moved InnoDB .ibd files around without using the SQL commands DISCARD TABLESPACE and IMPORT TABLESPACE, or did mysqld crash in the middle of CREATE TABLE? You can resolve the problem by removing the file './test/t1#P#p0.ibd' under the 'datadir' of MySQL. 2015-10-07T05:15:50.740705Z 6 [Warning] InnoDB: Cannot find a free slot for an undo log. Do you have too many active transactions running concurrently? 2015-10-07T05:15:50.740776Z 6 [ERROR] InnoDB: Unknown error code 47 while dropping table: `test`.`#sql2-26a6-6`. 2015-10-07T05:15:50.740866Z 6 [ERROR] InnoDB: Flagged corruption of `GEN_CLUST_INDEX` in table `test`.`#sql2-26a6-6` in DROP TABLE mysqld-debug: /export/home2/pb2/build/sb_0-16631979-1443716475.4/mysqlcom-pro-5.7.10/sql/sql_class.cc:4750: void THD::send_statement_status(): Assertion `0' failed. 05:15:50 UTC - mysqld got signal 6 ; (gdb) bt #0 0x00007fa919e8b771 in pthread_kill () from /lib64/libpthread.so.0 #1 0x00000000017e4450 in my_write_core (sig=6) at /export/home2/pb2/build/sb_0-16631979-1443716475.4/mysqlcom-pro-5.7.10/mysys/stacktrace.c:247 #2 0x0000000000e507d2 in handle_fatal_signal (sig=6) at /export/home2/pb2/build/sb_0-16631979-1443716475.4/mysqlcom-pro-5.7.10/sql/signal_handler.cc:220 #3 <signal handler called> #4 0x00007fa9188855d7 in raise () from /lib64/libc.so.6 #5 0x00007fa918886cc8 in abort () from /lib64/libc.so.6 #6 0x00007fa91887e546 in __assert_fail_base () from /lib64/libc.so.6 #7 0x00007fa91887e5f2 in __assert_fail () from /lib64/libc.so.6 #8 0x000000000147d88b in THD::send_statement_status (this=0x7fa8a0012330) at /export/home2/pb2/build/sb_0-16631979-1443716475.4/mysqlcom-pro-5.7.10/sql/sql_class.cc:4750 #9 0x00000000014d4e6c in dispatch_command (thd=0x7fa8a0012330, com_data=0x7fa8ec645e00, command=COM_QUERY) at /export/home2/pb2/build/sb_0-16631979-1443716475.4/mysqlcom-pro-5.7.10/sql/sql_parse.cc:1694 #10 0x00000000014d2977 in do_command (thd=0x7fa8a0012330) at /export/home2/pb2/build/sb_0-16631979-1443716475.4/mysqlcom-pro-5.7.10/sql/sql_parse.cc:852 #11 0x00000000015fef49 in handle_connection (arg=0x3bd64e0) at /export/home2/pb2/build/sb_0-16631979-1443716475.4/mysqlcom-pro-5.7.10/sql/conn_handler/connection_handler_per_thread.cc:295 #12 0x0000000001be60c4 in pfs_spawn_thread (arg=0x3c9fee0) at /export/home2/pb2/build/sb_0-16631979-1443716475.4/mysqlcom-pro-5.7.10/storage/perfschema/pfs.cc:2192 #13 0x00007fa919e86df5 in start_thread () from /lib64/libpthread.so.0 #14 0x00007fa91894660d in clone () from /lib64/libc.so.6 (gdb)
[7 Oct 2015 7:01]
Roel Van de Paar
Nice secondary method Umesh. Good stuff.
[23 Nov 2015 9:57]
Erlend Dahl
Fixed in 5.7.10 under the heading of Bug#21575121 ROLLBACK AFTER RECOVERY FAILS ASSERT INDEX->TABLE == TABLE, FTS