Bug #74663 DROP TABLE corrupts table | inode fsp0fsp.cc line 1887 fseg_inode_get
Submitted: 3 Nov 2014 6:31 Modified: 2 Mar 2018 4:19
Reporter: Ramesh Sivaraman Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S3 (Non-critical)
Version:5.6.20-debug, 5.6.22 OS:Linux (CentOS 7)
Assigned to: CPU Architecture:Any

[3 Nov 2014 6:31] Ramesh Sivaraman
Description:
2014-11-03 05:55:19 7fd392356700  InnoDB: Assertion failure in thread 140546667800320 in file fsp0fsp.cc line 1887
InnoDB: Failing assertion: inode

*** GDB info

#0  0x00007fd391d5d771 in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000000a9035e in my_write_core (sig=6) at /ssd/ramesh/mysql-server/mysql-5.6/mysys/stacktrace.c:422
#2  0x0000000000723688 in handle_fatal_signal (sig=6) at /ssd/ramesh/mysql-server/mysql-5.6/sql/signal_handler.cc:230
#3  <signal handler called>
#4  0x00007fd390b695c9 in raise () from /lib64/libc.so.6
#5  0x00007fd390b6acd8 in abort () from /lib64/libc.so.6
#6  0x0000000000d91704 in fseg_inode_get (header=0x7fd31180c04a "", space=6, zip_size=0, mtr=0x7fd392351410) at /ssd/ramesh/mysql-server/mysql-5.6/storage/innobase/fsp/fsp0fsp.cc:1887
#7  0x0000000000d94690 in fseg_page_is_free (seg_header=0x7fd31180c04a "", space=6, page=3) at /ssd/ramesh/mysql-server/mysql-5.6/storage/innobase/fsp/fsp0fsp.cc:3225
#8  0x0000000000ced60a in btr_validate_level (index=0x7fd2f546cff8, trx=0x7fd2f54c7478, level=0) at /ssd/ramesh/mysql-server/mysql-5.6/storage/innobase/btr/btr0btr.cc:4532
#9  0x0000000000cee6e2 in btr_validate_index (index=0x7fd2f546cff8, trx=0x7fd2f54c7478) at /ssd/ramesh/mysql-server/mysql-5.6/storage/innobase/btr/btr0btr.cc:4865
#10 0x0000000000b57c33 in ha_innobase::check (this=0x7fd2f547d010, thd=0x7fd2feb24000, check_opt=0x7fd2feb26f28) at /ssd/ramesh/mysql-server/mysql-5.6/storage/innobase/handler/ha_innodb.cc:11309
#11 0x000000000063b7df in handler::ha_check (this=0x7fd2f547d010, thd=0x7fd2feb24000, check_opt=0x7fd2feb26f28) at /ssd/ramesh/mysql-server/mysql-5.6/sql/handler.cc:4091
#12 0x000000000097e965 in mysql_admin_table(THD *, TABLE_LIST *, HA_CHECK_OPT *, const char *, thr_lock_type, bool, bool, uint, int (*)(THD *, TABLE_LIST *, HA_CHECK_OPT *), struct {...}, int (*)(THD *, TABLE_LIST *)) (thd=0x7fd2feb24000, tables=0x7fd2f541f0f0, check_opt=0x7fd2feb26f28, operator_name=0xf9024c "check", lock_type=TL_READ_NO_INSERT, open_for_modify=false, repair_table_use_frm=false, extra_open_options=32, prepare_func=0x0, operator_func=(int (handler::*)(handler * const, THD *, HA_CHECK_OPT *)) 0x63b6ba <handler::ha_check(THD*, st_ha_check_opt*)>, view_operator_func=0x86936f <view_checksum(THD*, TABLE_LIST*)>) at /ssd/ramesh/mysql-server/mysql-5.6/sql/sql_admin.cc:654
#13 0x0000000000980286 in Sql_cmd_check_table::execute (this=0x7fd2f541f658, thd=0x7fd2feb24000) at /ssd/ramesh/mysql-server/mysql-5.6/sql/sql_admin.cc:1107
#14 0x00000000007d5ea3 in mysql_execute_command (thd=0x7fd2feb24000) at /ssd/ramesh/mysql-server/mysql-5.6/sql/sql_parse.cc:4945
#15 0x00000000007d8fa4 in mysql_parse (thd=0x7fd2feb24000, rawbuf=0x7fd2f541f010 "CHECK TABLE t1 EXTENDED", length=23, parser_state=0x7fd392354e70) at /ssd/ramesh/mysql-server/mysql-5.6/sql/sql_parse.cc:6245
#16 0x00000000007cc557 in dispatch_command (command=COM_QUERY, thd=0x7fd2feb24000, packet=0x7fd2feb62001 "", packet_length=23) at /ssd/ramesh/mysql-server/mysql-5.6/sql/sql_parse.cc:1332
#17 0x00000000007cb646 in do_command (thd=0x7fd2feb24000) at /ssd/ramesh/mysql-server/mysql-5.6/sql/sql_parse.cc:1034
#18 0x0000000000793a61 in do_handle_one_connection (thd_arg=0x7fd2feb24000) at /ssd/ramesh/mysql-server/mysql-5.6/sql/sql_connect.cc:982
#19 0x000000000079354a in handle_one_connection (arg=0x7fd2feb24000) at /ssd/ramesh/mysql-server/mysql-5.6/sql/sql_connect.cc:898
#20 0x0000000000ad4b5c in pfs_spawn_thread (arg=0x7fd38e3feb00) at /ssd/ramesh/mysql-server/mysql-5.6/storage/perfschema/pfs.cc:1860
#21 0x00007fd391d58df3 in start_thread () from /lib64/libpthread.so.0
#22 0x00007fd390c2a01d in clone () from /lib64/libc.so.6

How to repeat:
DROP DATABASE test;CREATE DATABASE test;USE test;
SET global innodb_rollback_segments=-7;
set global innodb_trx_rseg_n_slots_debug=1;
create TABLE t1(f1 date);
DROP TABLE t1;
CHECK TABLE t1 EXTENDED;
[3 Nov 2014 9:03] MySQL Verification Team
Hello Ramesh Sivaraman,

Thank you for the report.
I'm not seeing any assertion in latest 5.6/5.7 builds.
Any specific setting to trigger this? 

// 5.6.21/5.6.22 debug/optimized builds

mysql>
mysql> DROP DATABASE test;CREATE DATABASE test;USE test;
Query OK, 0 rows affected (0.00 sec)

Query OK, 1 row affected (0.00 sec)

Database changed
mysql> SET global innodb_rollback_segments=-7;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql> set global innodb_trx_rseg_n_slots_debug=1;
Query OK, 0 rows affected (0.00 sec)

mysql> create TABLE t1(f1 date);
Query OK, 0 rows affected (0.07 sec)

mysql> DROP TABLE t1;
Query OK, 0 rows affected (0.01 sec)

mysql> CHECK TABLE t1 EXTENDED;
+---------+-------+----------+-------------------------------+
| Table   | Op    | Msg_type | Msg_text                      |
+---------+-------+----------+-------------------------------+
| test.t1 | check | Error    | Table 'test.t1' doesn't exist |
| test.t1 | check | status   | Operation failed              |
+---------+-------+----------+-------------------------------+
2 rows in set (0.00 sec)

// 5.7.6 debug build

mysql> show variables like '%version%';
+-------------------------+---------------------------------------------------------------+
| Variable_name           | Value                                                         |
+-------------------------+---------------------------------------------------------------+
| innodb_version          | 5.7.6                                                         |
| protocol_version        | 10                                                            |
| slave_type_conversions  |                                                               |
| version                 | 5.7.6-m16-enterprise-commercial-advanced-debug                |
| version_comment         | MySQL Enterprise Server - Advanced Edition Debug (Commercial) |
| version_compile_machine | x86_64                                                        |
| version_compile_os      | Linux                                                         |
+-------------------------+---------------------------------------------------------------+
7 rows in set (0.00 sec)

mysql> DROP DATABASE test;CREATE DATABASE test;USE test;
Query OK, 0 rows affected (0.00 sec)

Query OK, 1 row affected (0.00 sec)

Database changed
mysql> SET global innodb_rollback_segments=-7;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql> set global innodb_trx_rseg_n_slots_debug=1;
Query OK, 0 rows affected (0.00 sec)

mysql> create TABLE t1(f1 date);
Query OK, 0 rows affected (0.04 sec)

mysql> DROP TABLE t1;
Query OK, 0 rows affected (0.02 sec)

mysql> CHECK TABLE t1 EXTENDED;
+---------+-------+----------+-------------------------------+
| Table   | Op    | Msg_type | Msg_text                      |
+---------+-------+----------+-------------------------------+
| test.t1 | check | Error    | Table 'test.t1' doesn't exist |
| test.t1 | check | status   | Operation failed              |
+---------+-------+----------+-------------------------------+
2 rows in set (0.00 sec)

Thanks,
Umesh
[4 Nov 2014 2:01] Ramesh Sivaraman
Hi Umesh,

Please find the server start-up command.

/ssd/ramesh/mysql-server/mysql-5.6.20-linux-x86_64-debug/bin/mysqld --innodb_buffer_pool_size=2147483648 --basedir=/ssd/ramesh/mysql-server/mysql-5.6.20-linux-x86_64-debug --tmpdir=/ssd/ramesh/mysql-server/mysql-5.6.20-linux-x86_64-debug/data --datadir=/ssd/ramesh/mysql-server/mysql-5.6.20-linux-x86_64-debug/data --core --socket=/ssd/ramesh/mysql-server/mysql-5.6.20-linux-x86_64-debug/socket.sock --port=19815 --log-error=/ssd/ramesh/mysql-server/mysql-5.6.20-linux-x86_64-debug/log/master.err  --maximum-bulk_insert_buffer_size=1M --maximum-join_buffer_size=1M --maximum-max_heap_table_size=1M --maximum-max_join_size=1M --maximum-myisam_max_sort_file_size=1M --maximum-myisam_mmap_size=1M --maximum-myisam_sort_buffer_size=1M --maximum-optimizer_trace_max_mem_size=1M --maximum-preload_buffer_size=1M --maximum-query_alloc_block_size=1M --maximum-query_prealloc_size=1M --maximum-range_alloc_block_size=1M --maximum-read_buffer_size=1M --maximum-read_rnd_buffer_size=1M --maximum-sort_buffer_size=1M --maximum-tmp_table_size=1M --maximum-transaction_alloc_block_size=1M --maximum-transaction_prealloc_size=1M --log-output=none --sql_mode=ONLY_FULL_GROUP_BY 

Able to reproduce with debug build.

mysql> DROP DATABASE test;CREATE DATABASE test;USE test;
Query OK, 0 rows affected (0.00 sec)

Query OK, 1 row affected (0.00 sec)

Database changed
mysql> SET global innodb_rollback_segments=-7;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql> set global innodb_trx_rseg_n_slots_debug=1;
Query OK, 0 rows affected (0.00 sec)

mysql> create TABLE t1(f1 date);
Query OK, 0 rows affected (0.07 sec)

mysql> DROP TABLE t1;
ERROR 177 (HY000): Too many active concurrent transactions
mysql> CHECK TABLE t1 EXTENDED;
ERROR 2013 (HY000): Lost connection to MySQL server during query
mysql>
[4 Nov 2014 8:48] MySQL Verification Team
Thank you for the feedback.
Confirmed that 5.6.22 debug build asserts.

// 5.6.22 debug build

/data/ushastry/server/mysql-advanced-5.6.22/scripts/mysql_install_db --basedir=/data/ushastry/server/mysql-advanced-5.6.22 --datadir=/tmp/bug --user=root
/data/ushastry/server/mysql-advanced-5.6.22/bin/mysqld-debug --basedir=/data/ushastry/server/mysql-advanced-5.6.22 --tmpdir=/tmp/bug --datadir=/tmp/bug --core --socket=/tmp/mysql.sock  --port=3306 --log-error=/tmp/bug/log.err --maximum-bulk_insert_buffer_size=1M --maximum-join_buffer_size=1M --maximum-max_heap_table_size=1M --maximum-max_join_size=1M --maximum-myisam_max_sort_file_size=1M --maximum-myisam_mmap_size=1M --maximum-myisam_sort_buffer_size=1M --maximum-optimizer_trace_max_mem_size=1M --maximum-preload_buffer_size=1M --maximum-query_alloc_block_size=1M --maximum-query_prealloc_size=1M --maximum-range_alloc_block_size=1M --maximum-read_buffer_size=1M --maximum-read_rnd_buffer_size=1M --maximum-sort_buffer_size=1M --maximum-tmp_table_size=1M --maximum-transaction_alloc_block_size=1M --maximum-transaction_prealloc_size=1M --log-output=none --sql_mode=ONLY_FULL_GROUP_BY --user=root 2>&1 &

[root@cluster-repo mysql-advanced-5.6.22]# bin/mysql -u root -p
Enter password:
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 5.6.22-enterprise-commercial-advanced-debug MySQL Enterprise Server - Advanced Edition Debug (Commercial)

Copyright (c) 2000, 2014, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> DROP DATABASE test;CREATE DATABASE test;USE test;
Query OK, 0 rows affected (0.00 sec)

Query OK, 1 row affected (0.01 sec)

Database changed
mysql> SET global innodb_rollback_segments=-7;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql> set global innodb_trx_rseg_n_slots_debug=1;
Query OK, 0 rows affected (0.00 sec)

mysql> create TABLE t1(f1 date);
Query OK, 0 rows affected (0.05 sec)

mysql> DROP TABLE t1;
ERROR 177 (HY000): Too many active concurrent transactions
mysql> CHECK TABLE t1 EXTENDED;
ERROR 2013 (HY000): Lost connection to MySQL server during query

(gdb) bt
#0  0x0000003deb00c8ac in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000000b0011b in my_write_core (sig=6) at /pb2/build/sb_0-13562263-1414689457.82/mysqlcom-pro-5.6.22/mysys/stacktrace.c:422
#2  0x000000000077ecb8 in handle_fatal_signal (sig=6) at /pb2/build/sb_0-13562263-1414689457.82/mysqlcom-pro-5.6.22/sql/signal_handler.cc:230
#3  <signal handler called>
#4  0x0000003deac32625 in raise () from /lib64/libc.so.6
#5  0x0000003deac33e05 in abort () from /lib64/libc.so.6
#6  0x0000000000ddf185 in fseg_inode_get (header=0x7fb68f6e004a "", space=6, zip_size=0, mtr=0x7fb6893f21a0)
    at /pb2/build/sb_0-13562263-1414689457.82/mysqlcom-pro-5.6.22/storage/innobase/fsp/fsp0fsp.cc:1887
#7  0x0000000000de240a in fseg_page_is_free (seg_header=0x7fb68f6e004a "", space=6, page=3) at /pb2/build/sb_0-13562263-1414689457.82/mysqlcom-pro-5.6.22/storage/innobase/fsp/fsp0fsp.cc:3225
#8  0x0000000000d39833 in btr_validate_level (index=0x7fb66001bff8, trx=0x7fb660030f58, level=0)
    at /pb2/build/sb_0-13562263-1414689457.82/mysqlcom-pro-5.6.22/storage/innobase/btr/btr0btr.cc:4668
#9  0x0000000000d3a9d8 in btr_validate_index (index=0x7fb66001bff8, trx=0x7fb660030f58) at /pb2/build/sb_0-13562263-1414689457.82/mysqlcom-pro-5.6.22/storage/innobase/btr/btr0btr.cc:5001
#10 0x0000000000ba1d25 in ha_innobase::check (this=0x7fb660023720, thd=0x2354bf0, check_opt=0x2357b18)
    at /pb2/build/sb_0-13562263-1414689457.82/mysqlcom-pro-5.6.22/storage/innobase/handler/ha_innodb.cc:11338
#11 0x00000000006930ff in handler::ha_check (this=0x7fb660023720, thd=0x2354bf0, check_opt=0x2357b18) at /pb2/build/sb_0-13562263-1414689457.82/mysqlcom-pro-5.6.22/sql/handler.cc:4091
#12 0x00000000009e7682 in mysql_admin_table (thd=0x2354bf0, tables=0x7fb6600050b0, check_opt=0x2357b18, operator_name=0x10bebf4 "check", lock_type=TL_READ_NO_INSERT, open_for_modify=false,
    repair_table_use_frm=false, extra_open_options=32, prepare_func=0, operator_func=(int (handler::*)(handler *, THD *, HA_CHECK_OPT *)) 0x692fd6 <handler::ha_check(THD*, HA_CHECK_OPT*)>,
    view_operator_func=0x8cb214 <view_checksum(THD*, TABLE_LIST*)>) at /pb2/build/sb_0-13562263-1414689457.82/mysqlcom-pro-5.6.22/sql/sql_admin.cc:654
#13 0x00000000009e919d in Sql_cmd_check_table::execute (this=0x7fb660005618, thd=0x2354bf0) at /pb2/build/sb_0-13562263-1414689457.82/mysqlcom-pro-5.6.22/sql/sql_admin.cc:1108
#14 0x0000000000834a46 in mysql_execute_command (thd=0x2354bf0) at /pb2/build/sb_0-13562263-1414689457.82/mysqlcom-pro-5.6.22/sql/sql_parse.cc:4945
#15 0x00000000008380e1 in mysql_parse (thd=0x2354bf0, rawbuf=0x7fb660004fd0 "CHECK TABLE t1 EXTENDED", length=23, parser_state=0x7fb6893f5680)
    at /pb2/build/sb_0-13562263-1414689457.82/mysqlcom-pro-5.6.22/sql/sql_parse.cc:6357
#16 0x000000000082aa63 in dispatch_command (command=COM_QUERY, thd=0x2354bf0, packet=0x2484541 "", packet_length=23)
    at /pb2/build/sb_0-13562263-1414689457.82/mysqlcom-pro-5.6.22/sql/sql_parse.cc:1332
#17 0x0000000000829ac8 in do_command (thd=0x2354bf0) at /pb2/build/sb_0-13562263-1414689457.82/mysqlcom-pro-5.6.22/sql/sql_parse.cc:1034
#18 0x00000000007f0f17 in do_handle_one_connection (thd_arg=0x2354bf0) at /pb2/build/sb_0-13562263-1414689457.82/mysqlcom-pro-5.6.22/sql/sql_connect.cc:982
#19 0x00000000007f09e8 in handle_one_connection (arg=0x2354bf0) at /pb2/build/sb_0-13562263-1414689457.82/mysqlcom-pro-5.6.22/sql/sql_connect.cc:898
#20 0x0000000000e64c25 in pfs_spawn_thread (arg=0x2447c70) at /pb2/build/sb_0-13562263-1414689457.82/mysqlcom-pro-5.6.22/storage/perfschema/pfs.cc:1860
#21 0x0000003deb0079d1 in start_thread () from /lib64/libpthread.so.0
#22 0x0000003deace89dd in clone () from /lib64/libc.so.6
[4 Nov 2014 8:52] MySQL Verification Team
// 5.7.6 debug build

(gdb) bt
#0  0x0000003deb00c8ac in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000000f990a1 in my_write_core (sig=6) at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/mysys/stacktrace.c:247
#2  0x000000000092d7cc in handle_fatal_signal (sig=6) at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/sql/signal_handler.cc:219
#3  <signal handler called>
#4  0x0000003deac32625 in raise () from /lib64/libc.so.6
#5  0x0000003deac33e05 in abort () from /lib64/libc.so.6
#6  0x000000000121b81b in ut_dbg_assertion_failed (expr=0x17843f6 "inode", file=0x17838c0 "/pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/fsp/fsp0fsp.cc",
    line=2034) at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/ut/ut0dbg.cc:67
#7  0x000000000130378c in fseg_inode_get (header=0x7f026c33804a "", space=20, page_size=..., mtr=0x7f0279a899a0)
    at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/fsp/fsp0fsp.cc:2034
#8  0x0000000001306f35 in fseg_page_is_free (seg_header=0x7f026c33804a "", space_id=20, page=3)
    at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/fsp/fsp0fsp.cc:3310
#9  0x000000000123ae36 in btr_validate_level (index=0x7f023c024648, trx=0x7f027a6738f8, level=0, lockout=false)
    at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/btr/btr0btr.cc:4586
#10 0x000000000123c7a0 in btr_validate_index (index=0x7f023c024648, trx=0x7f027a6738f8, lockout=false)
    at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/btr/btr0btr.cc:5067
#11 0x0000000001047d8c in ha_innobase::check (this=0x7f023c01f730, thd=0x7f023c000d30, check_opt=0x7f023c003528)
    at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/handler/ha_innodb.cc:12048
#12 0x00000000009980f7 in handler::ha_check (this=0x7f023c01f730, thd=0x7f023c000d30, check_opt=0x7f023c003528)
    at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/sql/handler.cc:4190
#13 0x0000000000e7a4b1 in mysql_admin_table (thd=0x7f023c000d30, tables=0x7f023c005db8, check_opt=0x7f023c003528, operator_name=0x168737c "check", lock_type=TL_READ_NO_INSERT,
    open_for_modify=false, repair_table_use_frm=false, extra_open_options=32, prepare_func=0, operator_func=
    (int (handler::*)(handler *, THD *, HA_CHECK_OPT *)) 0x997fce <handler::ha_check(THD*, HA_CHECK_OPT*)>, view_operator_func=0xd5ec7f <view_checksum(THD*, TABLE_LIST*)>)
    at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/sql/sql_admin.cc:663
#14 0x0000000000e7c0b3 in Sql_cmd_check_table::execute (this=0x7f023c006338, thd=0x7f023c000d30) at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/sql/sql_admin.cc:1132
#15 0x0000000000cbb4f7 in mysql_execute_command (thd=0x7f023c000d30) at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/sql/sql_parse.cc:4785
#16 0x0000000000cbce6a in mysql_parse (thd=0x7f023c000d30, parser_state=0x7f0279a8d660) at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/sql/sql_parse.cc:5397
#17 0x0000000000cb0f2c in dispatch_command (command=COM_QUERY, thd=0x7f023c000d30, packet=0x7f023c009a61 "", packet_length=23)
    at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/sql/sql_parse.cc:1249
#18 0x0000000000cafbd4 in do_command (thd=0x7f023c000d30) at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/sql/sql_parse.cc:833
#19 0x0000000000dbe89c in handle_connection (arg=0x4d444e0) at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/sql/conn_handler/connection_handler_per_thread.cc:298
#20 0x000000000138347f in pfs_spawn_thread (arg=0x4dc6c30) at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/perfschema/pfs.cc:2137
#21 0x0000003deb0079d1 in start_thread () from /lib64/libpthread.so.0
#22 0x0000003deace89dd in clone () from /lib64/libc.so.6
[4 Nov 2014 14:23] Marko Mäkelä
Bug#74682 (crash in ALTER TABLE after failed DROP TABLE) was marked as a duplicate of this bug.

The root cause looks like the following:

mysql> DROP TABLE t1;
ERROR 177 (HY000): Too many active concurrent transactions

Apparently, InnoDB will somehow corrupt the table in this case, and any subsequent operation on the table may fail.
[6 Nov 2014 8:14] Marko Mäkelä
Posted by developer:
 
This seems to be a design problem in all InnoDB versions (starting with MySQL 3.23).

Currently, InnoDB DROP TABLE is not fully crash-safe.
The freeing of an index tree is implemented as a trigger on the InnoDB-internal SYS_INDEXES table. When a record in the clustered index of SYS_INDEXES is delete-marked, the corresponding index tree will be dropped. This is bad design, because the freeing cannot be rolled back.

The crash recovery of DROP TABLE is based on a roll-forward. If the undo log record is marked as a table operation, InnoDB crash recovery will attempt to drop the table based on trx->table_id.

This problem occurs when we run out of undo log space, apparently before we get a chance to mark the transaction as a table operation. In that case, I would guess that we will roll back the changes to the SYS_INDEXES records (undeleting the rows), without even attempting to un-free the index tree.

I guess that we start the dropping of the indexes from the clustered index, which is where all the data is stored. It might be safer to drop the secondary indexes first. A safer option would be to mark the table as corrupted, and then carry on with the deletion. That ought to be crash-safe, in the sense that in the event of a server kill, the table would either exist, be properly marked as corrupted, or be dropped. Currently, we have a corrupted table that is not marked as such.

A proper fix of this will be provided by the transactional DDL_LOG table in WL#7016, which is part of the Global Data Dictionary. When committing the DROP TABLE operation, we would write a log entry for dropping the index trees or the tablespace. Only after committing, we would actually free the data. In this way, the operation could be rolled back without problems, in case we run out of undo log space.
[6 Nov 2014 8:22] Marko Mäkelä
Posted by developer:
 
In the posted stack trace, CHECK TABLE is complaining that an index page is marked as free. This check was added in MySQL 5.6, as part of transportable tablespaces (WL#5522). My initial implementation of IMPORT traversed all index trees using the CHECK TABLE code, and I wanted to have this consistency check there. Later, the IMPORT was rewritten to process the pages sequentially, instead of following the index tree order.
[14 Nov 2014 10:24] Marko Mäkelä
Posted by developer:
 
Also ALTER TABLE can corrupt a table when it is unable to write undo logs.
See Bug#19830715 ASSERTION FAILED IN COMMIT_TRY_NOREBUILD (SIG 6 IN HANDLER0ALTER.CC:5036)
which I marked as a duplicate of this bug.
[15 Nov 2014 5:04] Roel Van de Paar
See bug #74876
[15 Nov 2014 5:08] Ramesh Sivaraman
Added "| inode fsp0fsp.cc line 1887 fseg_inode_get" in title
[20 Jan 2016 14:46] Naga Satyanarayana Bodapati
Posted by developer:
 
This bug can be closed as it mostly theoritical bug.

See my post to BUG#22570845

Posted by developer:
 
This bug is mostly theoretical bug because of the debug variable  innodb_trx_rseg_n_slots_debug.

Was able to reproduce the problem in 5.6 as well.

It is duplicate of BUG#19947739 ( although the failing assertions are different).

The underlying cause is same. "DDLs are known to corrupt SYS_TABLES when they cannot get undo slot. This can happen only when there are 128k concurrent transactions". So I suggest to close all bugs related to "set global innodb_trx_rseg_n_slots_debug=1;" and DDLs

We will see innodb throw warnings like this when it reaches the max concurrent transaction limit.

 InnoDB: Warning: cannot find a free slot for an undo log. Do you have too
InnoDB: many active transactions running concurrently?

At this stage, ALTERs will not succeed and may corrupt the database. But this will be seen only when you reach the max concurrent tranasactions limit (128K?)

====

s/ALTERs/DDLs
[21 Jan 2016 6:14] Laurynas Biveinis
IMHO this is still a bug - of low triage - even if for it occur one needs to run out of undo space (128K parallel transactions), and even if fixing it currently is not very feasible. A comment above suggests that WL#7016 will fix this properly, perhaps it can be closed then?
[13 Aug 2017 23:15] Roel Van de Paar
Also see bug 74363
[2 Mar 2018 4:19] Ramesh Sivaraman
Found similar assertion. Not sure whether it is same or not.

testcase
........

CREATE DATABASE test;
USE test;
SET SESSION expand_fast_index_creation=ON;#NOERROR
set global innodb_trx_rseg_n_slots_debug=1;#NOERROR
CREATE TABLE ti (a MEDIUMINT, b MEDIUMINT NOT NULL, c CHAR(88) NOT NULL, d VARCHAR(100) NOT NULL, e VARBINARY(87), f VARBINARY(59) NOT NULL, g MEDIUMBLOB NOT NULL, h LONGBLOB, id BIGINT NOT NULL, KEY(b), KEY(e), PRIMARY KEY(id)) ENGINE=RocksDB;#ERROR: 1050 - Table 'ti' already exists
ALTER TABLE ti CHANGE COLUMN c c BINARY(3); ;

gdb info
.......
#0  0x00007f52093809b1 in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000001872701 in my_write_core (sig=6) at /sda/qa/ps_57_new_dbg/mysys/stacktrace.c:249
#2  0x0000000000e9086f in handle_fatal_signal (sig=6) at /sda/qa/ps_57_new_dbg/sql/signal_handler.cc:223
#3  <signal handler called>
#4  0x00007f520748c1f7 in raise () from /lib64/libc.so.6
#5  0x00007f520748d8e8 in abort () from /lib64/libc.so.6
#6  0x00007f5207485266 in __assert_fail_base () from /lib64/libc.so.6
#7  0x00007f5207485312 in __assert_fail () from /lib64/libc.so.6
#8  0x000000000191aa60 in commit_try_norebuild (ha_alter_info=0x7f520996eef0, ctx=0x7f51b20fc6f0, altered_table=0x7f51b2113e20, old_table=0x7f51b2113e20, trx=0x7f51f4401070, table_name=0x7f51b2114b80 "#sql-35f1_2") at /sda/qa/ps_57_new_dbg/storage/innobase/handler/handler0alter.cc:7869
#9  0x0000000001915b34 in ha_innobase::commit_inplace_alter_table (this=0x7f51b20c7630, altered_table=0x7f51b2113e20, ha_alter_info=0x7f520996eef0, commit=true) at /sda/qa/ps_57_new_dbg/storage/innobase/handler/handler0alter.cc:8412
#10 0x0000000000f27ede in handler::ha_commit_inplace_alter_table (this=0x7f51b20c7630, altered_table=0x7f51b2113e20, ha_alter_info=0x7f520996eef0, commit=true) at /sda/qa/ps_57_new_dbg/sql/handler.cc:5123
#11 0x00000000015d0b3b in remove_secondary_keys (thd=0x7f51b2019000, create_info=0x7f5209970ae0, table=0x7f51b2113e20, alter_info=0x7f5209970a10) at /sda/qa/ps_57_new_dbg/sql/sql_table.cc:9282
#12 0x00000000015d344b in mysql_alter_table (thd=0x7f51b2019000, new_db=0x7f51b202cf78 "test", new_name=0x0, create_info=0x7f5209970ae0, table_list=0x7f51b202c9f0, alter_info=0x7f5209970a10) at /sda/qa/ps_57_new_dbg/sql/sql_table.cc:10347
#13 0x0000000001742a88 in Sql_cmd_alter_table::execute (this=0x7f51b202d080, thd=0x7f51b2019000) at /sda/qa/ps_57_new_dbg/sql/sql_alter.cc:338
#14 0x0000000001539fab in mysql_execute_command (thd=0x7f51b2019000, first_level=true) at /sda/qa/ps_57_new_dbg/sql/sql_parse.cc:5117
#15 0x000000000153c047 in mysql_parse (thd=0x7f51b2019000, parser_state=0x7f5209972470) at /sda/qa/ps_57_new_dbg/sql/sql_parse.cc:5901
#16 0x0000000001530b97 in dispatch_command (thd=0x7f51b2019000, com_data=0x7f5209972c50, command=COM_QUERY) at /sda/qa/ps_57_new_dbg/sql/sql_parse.cc:1490
#17 0x000000000152fa1f in do_command (thd=0x7f51b2019000) at /sda/qa/ps_57_new_dbg/sql/sql_parse.cc:1021
#18 0x0000000001670184 in handle_connection (arg=0x7f51e8fbd850) at /sda/qa/ps_57_new_dbg/sql/conn_handler/connection_handler_per_thread.cc:312
#19 0x0000000001d091f3 in pfs_spawn_thread (arg=0x7f520541a020) at /sda/qa/ps_57_new_dbg/storage/perfschema/pfs.cc:2190
#20 0x00007f520937be25 in start_thread () from /lib64/libpthread.so.0
#21 0x00007f520754f34d in clone () from /lib64/libc.so.6