Bug #88325 | InnoDB: Assertion failure: log0ddl.cc:1424:error == DB_SUCCESS | ||
---|---|---|---|
Submitted: | 2 Nov 2017 6:47 | Modified: | 22 Dec 2017 8:01 |
Reporter: | Roel Van de Paar | Email Updates: | |
Status: | Not a Bug | Impact on me: | |
Category: | MySQL Server: DML | Severity: | S6 (Debug Builds) |
Version: | 8.0.3 RC | OS: | Any |
Assigned to: | CPU Architecture: | Any |
[2 Nov 2017 6:47]
Roel Van de Paar
[2 Nov 2017 7:07]
MySQL Verification Team
Hello Roel , Thank you for the report and test case. Observed that 8.0.3(8.0.4) debug build is affected. Thanks, Umesh
[2 Nov 2017 7:09]
MySQL Verification Team
-- 8.0.4 rm -rf 88325 bin/mysqld-debug --initialize-insecure --basedir=$PWD --datadir=$PWD/88325 bin/mysqld-debug --no-defaults --basedir=$PWD --datadir=$PWD/88325 --core-file --socket=/tmp/mysql_ushastry.sock --port=3306 --log-error=$PWD/88325/log.err 2>&1 & (gdb) bt #0 0x00007f4b6c63f771 in pthread_kill () from /lib64/libpthread.so.0 #1 0x0000000003632c99 in my_write_core (sig=6) at /export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/mysys/stacktrace.cc:291 #2 0x00000000028fa2d9 in handle_fatal_signal (sig=6) at /export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/sql/signal_handler.cc:234 #3 <signal handler called> #4 0x00007f4b6b0395d7 in raise () from /lib64/libc.so.6 #5 0x00007f4b6b03acc8 in abort () from /lib64/libc.so.6 #6 0x00000000038cee21 in ut_dbg_assertion_failed (expr=0x481cd9f "error == DB_SUCCESS", file=0x481cb60 "/export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/storage/innobase/log/log0ddl.cc", line=1434) at /export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/storage/innobase/ut/ut0dbg.cc:71 #7 0x000000000376cad9 in Log_DDL::delete_by_id (this=0x7f4b58bc1128, trx=0x7f4b5e8428d0, id=6) at /export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/storage/innobase/log/log0ddl.cc:1434 #8 0x000000000376b437 in Log_DDL::write_delete_space_log (this=0x7f4b58bc1128, trx=0x7f4b5e8428d0, table=0x7f4ad81344d8, space_id=3, file_path=0x7f4ad8036ef8 "./test/#sql-ib1055-2732793693.ibd", is_drop=false, dict_locked=true) at /export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/storage/innobase/log/log0ddl.cc:1065 #9 0x000000000398b21f in dict_build_tablespace_for_table (table=0x7f4ad81344d8, trx=0x7f4b5e8428d0) at /export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/storage/innobase/dict/dict0crea.cc:236 #10 0x000000000398ab5a in dict_build_table_def (table=0x7f4ad81344d8, trx=0x7f4b5e8428d0) at /export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/storage/innobase/dict/dict0crea.cc:86 #11 0x00000000038087fb in row_create_table_for_mysql (table=0x7f4ad81344d8, compression=0x0, trx=0x7f4b5e8428d0) at /export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/storage/innobase/row/row0mysql.cc:3019 #12 0x00000000036e0a03 in prepare_inplace_alter_table_dict<dd::Table> (ha_alter_info=0x7f4b5c4964b0, altered_table=0x7f4ad8037c80, old_table=0x7f4ad80ee550, old_dd_tab=0x7f4ad8100430, new_dd_tab=0x7f4ad80337a0, table_name=0x7f4ad80efb6d "t1", flags=33, flags2=16, fts_doc_id_col=18446744073709551615, add_fts_doc_id=false, add_fts_doc_id_idx=false) at /export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/storage/innobase/handler/handler0alter.cc:4669 #13 0x00000000036ed5b3 in ha_innobase::prepare_inplace_alter_table_impl<dd::Table> (this=0x7f4ad8115ee0, altered_table=0x7f4ad8037c80, ha_alter_info=0x7f4b5c4964b0, old_dd_tab=0x7f4ad8100430, new_dd_tab=0x7f4ad80337a0) at /export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/storage/innobase/handler/handler0alter.cc:6027 #14 0x00000000036d0d93 in ha_innobase::prepare_inplace_alter_table (this=0x7f4ad8115ee0, altered_table=0x7f4ad8037c80, ha_alter_info=0x7f4b5c4964b0, old_dd_tab=0x7f4ad8100430, new_dd_tab=0x7f4ad80337a0) at /export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/storage/innobase/handler/handler0alter.cc:1058 #15 0x0000000002a438e0 in handler::ha_prepare_inplace_alter_table (this=0x7f4ad8115ee0, altered_table=0x7f4ad8037c80, ha_alter_info=0x7f4b5c4964b0, old_table_def=0x7f4ad8100430, new_table_def=0x7f4ad80337a0) at /export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/sql/handler.cc:5065 #16 0x0000000002645290 in mysql_inplace_alter_table (thd=0x7f4ad8000be0, new_schema=..., table_def=0x7f4ad8100430, altered_table_def=0x7f4ad80337a0, table_list=0x7f4ad8009f38, table=0x7f4ad80ee550, altered_table=0x7f4ad8037c80, ha_alter_info=0x7f4b5c4964b0, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, Python Exception <type 'exceptions.IndexError'> list index out of range: target_mdl_request=0x7f4b5c497b60, alter_ctx=0x7f4b5c498c70, columns=std::set with 1 elements, fk_invalidator=0x7f4b5c497b30) at /export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/sql/sql_table.cc:10229 #17 0x000000000264e27a in mysql_alter_table (thd=0x7f4ad8000be0, new_db=0x7f4ad800a4b8 "test", new_name=0x0, create_info=0x7f4b5c49a1f0, table_list=0x7f4ad8009f38, alter_info=0x7f4b5c49a0e0) at /export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/sql/sql_table.cc:13543 #18 0x0000000002c49c9d in Sql_cmd_alter_table::execute (this=0x7f4ad800a560, thd=0x7f4ad8000be0) at /export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/sql/sql_alter.cc:324 #19 0x00000000025b0427 in mysql_execute_command (thd=0x7f4ad8000be0, first_level=true) at /export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/sql/sql_parse.cc:4614 #20 0x00000000025b2837 in mysql_parse (thd=0x7f4ad8000be0, parser_state=0x7f4b5c49b420) at /export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/sql/sql_parse.cc:5407 #21 0x00000000025a8c20 in dispatch_command (thd=0x7f4ad8000be0, com_data=0x7f4b5c49bd10, command=COM_QUERY) at /export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/sql/sql_parse.cc:1706 ---Type <return> to continue, or q <return> to quit--- #22 0x00000000025a7761 in do_command (thd=0x7f4ad8000be0) at /export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/sql/sql_parse.cc:1292 #23 0x00000000028eadeb in handle_connection (arg=0x86aa250) at /export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/sql/conn_handler/connection_handler_per_thread.cc:328 #24 0x0000000003b21b5e in pfs_spawn_thread (arg=0x871fae0) at /export/umesh/server/binaries/Trunk/bug/mysql-8.0-export-12033604/storage/perfschema/pfs.cc:2987 #25 0x00007f4b6c63adf5 in start_thread () from /lib64/libpthread.so.0 #26 0x00007f4b6b0fa60d in clone () from /lib64/libc.so.6 (gdb)
[2 Nov 2017 7:10]
MySQL Verification Team
--8.0.3 rm -rf 88325 bin/mysqld-debug --initialize-insecure --basedir=$PWD --datadir=$PWD/88325 bin/mysqld-debug --no-defaults --basedir=$PWD --datadir=$PWD/88325 --core-file --socket=/tmp/mysql_ushastry.sock --port=3306 --log-error=$PWD/88325/log.err 2>&1 & #0 0x00007fbe8777d771 in pthread_kill () from /lib64/libpthread.so.0 #1 0x00000000034fb0bb in my_write_core (sig=6) at ../../mysqlcom-pro-8.0.3-rc/mysys/stacktrace.cc:291 #2 0x00000000026d704a in handle_fatal_signal (sig=6) at ../../mysqlcom-pro-8.0.3-rc/sql/signal_handler.cc:234 #3 <signal handler called> #4 0x00007fbe861775d7 in raise () from /lib64/libc.so.6 #5 0x00007fbe86178cc8 in abort () from /lib64/libc.so.6 #6 0x00000000038e97f3 in ut_dbg_assertion_failed (expr=0x490f07f "error == DB_SUCCESS", file=0x490ee68 "../../../mysqlcom-pro-8.0.3-rc/storage/innobase/log/log0ddl.cc", line=1424) at ../../../mysqlcom-pro-8.0.3-rc/storage/innobase/ut/ut0dbg.cc:60 #7 0x000000000377344f in Log_DDL::delete_by_id (this=0x7fbe74d46108, trx=0x7fbe7999a8d0, id=6) at ../../../mysqlcom-pro-8.0.3-rc/storage/innobase/log/log0ddl.cc:1424 #8 0x0000000003771dad in Log_DDL::write_delete_space_log (this=0x7fbe74d46108, trx=0x7fbe7999a8d0, table=0x7fbdf4a5b4f8, space_id=3, file_path=0x7fbdf4136aa8 "./test/#sql-ib68-1196940008.ibd", is_drop=false, dict_locked=true) at ../../../mysqlcom-pro-8.0.3-rc/storage/innobase/log/log0ddl.cc:1055 #9 0x00000000039aa330 in dict_build_tablespace_for_table (table=0x7fbdf4a5b4f8, trx=0x7fbe7999a8d0) at ../../../mysqlcom-pro-8.0.3-rc/storage/innobase/dict/dict0crea.cc:227 #10 0x00000000039a9ca2 in dict_build_table_def (table=0x7fbdf4a5b4f8, trx=0x7fbe7999a8d0) at ../../../mysqlcom-pro-8.0.3-rc/storage/innobase/dict/dict0crea.cc:77 #11 0x000000000381433d in row_create_table_for_mysql (table=0x7fbdf4a5b4f8, compression=0x0, trx=0x7fbe7999a8d0) at ../../../mysqlcom-pro-8.0.3-rc/storage/innobase/row/row0mysql.cc:3019 #12 0x00000000036dea2c in prepare_inplace_alter_table_dict<dd::Table> (ha_alter_info=0x7fbe795ef4a0, altered_table=0x7fbdf4a4c8d0, old_table=0x7fbdf4027ea0, old_dd_tab=0x7fbdf4111b20, new_dd_tab=0x7fbdf4a4b5a0, table_name=0x7fbdf412ff0d "t1", flags=33, flags2=16, fts_doc_id_col=18446744073709551615, add_fts_doc_id=false, add_fts_doc_id_idx=false) at ../../../mysqlcom-pro-8.0.3-rc/storage/innobase/handler/handler0alter.cc:4669 #13 0x00000000036eb751 in ha_innobase::prepare_inplace_alter_table_impl<dd::Table> (this=0x7fbdf41326b0, altered_table=0x7fbdf4a4c8d0, ha_alter_info=0x7fbe795ef4a0, old_dd_tab=0x7fbdf4111b20, new_dd_tab=0x7fbdf4a4b5a0) at ../../../mysqlcom-pro-8.0.3-rc/storage/innobase/handler/handler0alter.cc:6027 #14 0x00000000036ced8d in ha_innobase::prepare_inplace_alter_table (this=0x7fbdf41326b0, altered_table=0x7fbdf4a4c8d0, ha_alter_info=0x7fbe795ef4a0, old_dd_tab=0x7fbdf4111b20, new_dd_tab=0x7fbdf4a4b5a0) at ../../../mysqlcom-pro-8.0.3-rc/storage/innobase/handler/handler0alter.cc:1058 #15 0x000000000283a228 in handler::ha_prepare_inplace_alter_table (this=0x7fbdf41326b0, altered_table=0x7fbdf4a4c8d0, ha_alter_info=0x7fbe795ef4a0, old_table_def=0x7fbdf4111b20, new_table_def=0x7fbdf4a4b5a0) at ../../mysqlcom-pro-8.0.3-rc/sql/handler.cc:5063 #16 0x00000000023be715 in mysql_inplace_alter_table (thd=0x7fbdf4000be0, new_schema=..., table_def=0x7fbdf4111b20, altered_table_def=0x7fbdf4a4b5a0, table_list=0x7fbdf4009f80, table=0x7fbdf4027ea0, altered_table=0x7fbdf4a4c8d0, ha_alter_info=0x7fbe795ef4a0, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, Python Exception <type 'exceptions.IndexError'> list index out of range: target_mdl_request=0x7fbe795f0b40, alter_ctx=0x7fbe795f1c50, columns=std::set with 1 elements, fk_invalidator=0x7fbe795f0b10) at ../../mysqlcom-pro-8.0.3-rc/sql/sql_table.cc:10121 #17 0x00000000023c7599 in mysql_alter_table (thd=0x7fbdf4000be0, new_db=0x7fbdf400a4f8 "test", new_name=0x0, create_info=0x7fbe795f31d0, table_list=0x7fbdf4009f80, alter_info=0x7fbe795f30c0) at ../../mysqlcom-pro-8.0.3-rc/sql/sql_table.cc:13381 #18 0x0000000002a6b547 in Sql_cmd_alter_table::execute (this=0x7fbdf400a5a0, thd=0x7fbdf4000be0) at ../../mysqlcom-pro-8.0.3-rc/sql/sql_alter.cc:324 #19 0x0000000002325839 in mysql_execute_command (thd=0x7fbdf4000be0, first_level=true) at ../../mysqlcom-pro-8.0.3-rc/sql/sql_parse.cc:4628 #20 0x0000000002327c0e in mysql_parse (thd=0x7fbdf4000be0, parser_state=0x7fbe795f4420) at ../../mysqlcom-pro-8.0.3-rc/sql/sql_parse.cc:5414 #21 0x000000000231dead in dispatch_command (thd=0x7fbdf4000be0, com_data=0x7fbe795f4d10, command=COM_QUERY) at ../../mysqlcom-pro-8.0.3-rc/sql/sql_parse.cc:1708 #22 0x000000000231c9ac in do_command (thd=0x7fbdf4000be0) at ../../mysqlcom-pro-8.0.3-rc/sql/sql_parse.cc:1291 #23 0x00000000026c69c3 in handle_connection (arg=0x8d01430) at ../../mysqlcom-pro-8.0.3-rc/sql/conn_handler/connection_handler_per_thread.cc:328 #24 0x000000000352d230 in pfs_spawn_thread (arg=0x8d2e3b0) at ../../../mysqlcom-pro-8.0.3-rc/storage/perfschema/pfs.cc:2985 #25 0x00007fbe87778df5 in start_thread () from /lib64/libpthread.so.0 #26 0x00007fbe8623860d in clone () from /lib64/libc.so.6
[3 Nov 2017 23:31]
Roel Van de Paar
Also see bug 88356
[9 Nov 2017 13:10]
Erlend Dahl
Posted by developer: [2 Nov 2017 3:34] Bin X Su The test case is using some variable only defined in debug build. So IMHO, this is not a severe loss of service. We define this innodb_trx_rseg_n_slots_debug for debug purpose only, and it's true that it can be set to 1, which is not a proper value. If we only allow one rollback segment, then no background thread can run, which will result in all kinds of crashes easily. So this bug itself is somehow bogus, but maybe we can document this innodb_trx_rseg_n_slots_debug to say a proper value should be bigger or equal to 2.
[16 Nov 2017 9:42]
Erlend Dahl
Bug#88324 handle_fatal_signal (sig=11) in ha_innobase::update_thd was marked as a duplicate.
[16 Nov 2017 9:48]
Roel Van de Paar
5.7.19 does not produce the same assertion; 5.7.19>ALTER TABLE t1 DROP COLUMN c1; ERROR 1637 (HY000): Too many active concurrent transactions Was it verified why 8.0.3 differs and asserts whereas 5.7.19 can handle the situation? As I said in bug 88355 before, I see a set of issues in 8.0.3 with testcases using low innodb_trx_rseg_n_slots_debug
[16 Nov 2017 9:49]
Roel Van de Paar
.
[22 Dec 2017 8:01]
Erlend Dahl
Comment from the InnoDB dev team: [2 Nov 2017 3:34] Bin X Su We define this innodb_trx_rseg_n_slots_debug for debug purpose only, and it's true that it can be set to 1, which is not a proper value. If we only allow one rollback segment, then no background thread can run, which will result in all kinds of crashes easily.