MySQL Bugs: #74676: Got error -1 from storage engine on truncate table statement

Bug #74676	Got error -1 from storage engine on truncate table statement
Submitted:	4 Nov 2014 4:27	Modified:	12 Nov 2014 18:11
Reporter:	Ramesh Sivaraman	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: DDL	Severity:	S3 (Non-critical)
Version:	5.6.20-debug, 5.6.21	OS:	Linux (CentOS 7)
Assigned to:		CPU Architecture:	Any

Description:
*** Error info

2014-11-04 04:25:47 14554 [Note] /ssd/ramesh/mysql-server/mysql-5.6.21-linux-x86_64-debug/bin/mysqld: ready for connections.
Version: '5.6.21-debug'  socket: '/ssd/ramesh/mysql-server/mysql-5.6.21-linux-x86_64-debug/socket.sock'  port: 13489  MySQL Community Server (GPL)
2014-11-04 04:25:56 7fe035e15700  InnoDB: Warning: cannot find a free slot for an undo log. Do you have too
InnoDB: many active transactions running concurrently?
2014-11-04 04:25:56 7fe035e15700  InnoDB: Unable to assign a new identifier to table `test`.`t1`
InnoDB: after truncating it.  Background processes may corrupt the table!
2014-11-04 04:25:56 7fe035e15700  InnoDB: table "test"."t1"is corrupted. Please drop the table and recreate
2014-11-04 04:25:56 14554 [Warning] InnoDB: Cannot open table test/t1 from the internal data dictionary of InnoDB though the .frm file for the table exists. See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting.html for how you can resolve the problem.
2014-11-04 04:26:04 7fe035e15700  InnoDB: table "test"."t1"is corrupted. Please drop the table and recreate
2014-11-04 04:26:04 14554 [Warning] InnoDB: Cannot open table test/t1 from the internal data dictionary of InnoDB though the .frm file for the table exists. See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting.html for how you can resolve the problem.

*** SQL log

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> CREATE TABLE t1(c1 INT);
Query OK, 0 rows affected (0.05 sec)

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

mysql> insert INTO t1 values(1),(1),(1),(1);
Query OK, 4 rows affected (0.01 sec)
Records: 4  Duplicates: 0  Warnings: 0

mysql> truncate TABLE t1;
ERROR 1030 (HY000): Got error -1 from storage engine
mysql> create TABLE t1(a CHAR (1)charset utf8 collate utf8_bin,b int,primary key (a)) select a,1 as c FROM t1;
ERROR 1146 (42S02): Table 'test.t1' doesn't exist
mysql>

How to repeat:
DROP DATABASE test;CREATE DATABASE test;USE test;
CREATE TABLE t1(c1 INT);
set global innodb_trx_rseg_n_slots_debug=1;
insert INTO t1 values(1),(1),(1),(1);
truncate TABLE t1;
create TABLE t1(a CHAR (1)charset utf8 collate utf8_bin,b int,primary key (a)) select a,1 as c FROM t1;

Hello Ramesh Sivaraman,

Thank you for the bug report and test case.
Confirmed the issue with debug build of 5.6.21.

Thanks,
Umes

// 5.6.21 debug build only

mysql> show variables like '%version%';
+-------------------------+--------------------------------------+
| Variable_name           | Value                                |
+-------------------------+--------------------------------------+
| innodb_version          | 5.6.21                               |
| protocol_version        | 10                                   |
| slave_type_conversions  |                                      |
| version                 | 5.6.21-debug                         |
| version_comment         | MySQL Community Server - Debug (GPL) |
| version_compile_machine | x86_64                               |
| version_compile_os      | linux-glibc2.5                       |
+-------------------------+--------------------------------------+
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> CREATE TABLE t1(c1 INT);
Query OK, 0 rows affected (0.03 sec)

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

mysql> insert INTO t1 values(1),(1),(1),(1);
Query OK, 4 rows affected (0.01 sec)
Records: 4  Duplicates: 0  Warnings: 0

mysql> truncate TABLE t1;
ERROR 1030 (HY000): Got error -1 from storage engine

// 

2014-11-06 13:09:56 7f40edc93700  InnoDB: Warning: cannot find a free slot for an undo log. Do you have too
InnoDB: many active transactions running concurrently?
2014-11-06 13:09:56 7f40edc93700  InnoDB: Unable to assign a new identifier to table `test`.`t1`
InnoDB: after truncating it.  Background processes may corrupt the table!
2014-11-06 13:10:28 7f40edc93700  InnoDB: table "test"."t1"is corrupted. Please drop the table and recreate
2014-11-06 13:10:28 323 [Warning] InnoDB: Cannot open table test/t1 from the internal data dictionary of InnoDB though the .frm file for the table exists. See http://dev.mysql.com/doc/refman/5.6
/en/innodb-troubleshooting.html for how you can resolve the problem.
2014-11-06 13:10:29 7f40edc93700  InnoDB: table "test"."t1"is corrupted. Please drop the table and recreate
2014-11-06 13:10:29 323 [Warning] InnoDB: Cannot open table test/t1 from the internal data dictionary of InnoDB though the .frm file for the table exists. See http://dev.mysql.com/doc/refman/5.6
/en/innodb-troubleshooting.html for how you can resolve the problem.

// with 5.7.6 debug build

mysql> create database if not exists test;
Query OK, 1 row affected (0.00 sec)

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

Query OK, 1 row affected (0.00 sec)

Database changed
mysql> CREATE TABLE t1(c1 INT);
set global innodb_trx_rseg_n_slots_debug=1;
Query OK, 0 rows affected (0.04 sec)

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

mysql> insert INTO t1 values(1),(1),(1),(1);
truncate TABLE t1;
Query OK, 4 rows affected (0.00 sec)
Records: 4  Duplicates: 0  Warnings: 0

mysql> truncate TABLE t1;
create TABLE t1(a CHAR (1)charset utf8 collate utf8_bin,b int,primary key (a)) select a,1 as c FROM t1;ERROR 1637 (HY000): Too many active concurrent transactions
mysql> create TABLE t1(a CHAR (1)charset utf8 collate utf8_bin,b int,primary key (a)) select a,1 as c FROM t1;
ERROR 1050 (42S01): Table 't1' already exists
mysql> truncate TABLE t1;
ERROR 1637 (HY000): Too many active concurrent transactions
mysql> truncate TABLE t1;
ERROR 1637 (HY000): Too many active concurrent transactions
mysql> truncate TABLE t1;
ERROR 1637 (HY000): Too many active concurrent transactions
mysql> truncate TABLE t1;
ERROR 1637 (HY000): Too many active concurrent transactions
mysql> DROP DATABASE test;CREATE DATABASE test;USE test;
ERROR 177 (HY000): Too many active concurrent transactions
ERROR 1007 (HY000): Can't create database 'test'; database exists
Database changed
mysql> CREATE TABLE t1(c1 INT);
ERROR 1050 (42S01): Table 't1' already exists
mysql> set global innodb_trx_rseg_n_slots_debug=1;
Query OK, 0 rows affected (0.00 sec)

mysql> insert INTO t1 values(1),(1),(1),(1);
truncate TABLE t1;
create TABLE t1(a CHAR (1)charset utf8 collate utf8_bin,b int,primary key (a)) select a,1 as c FROM t1;
ERROR 2013 (HY000): Lost connection to MySQL server during query

(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=0x175ace8 "index->id == btr_page_get_index_id(page)",
    file=0x175a248 "/pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/btr/btr0cur.cc", line=1238)
    at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/ut/ut0dbg.cc:67
#7  0x0000000001247ebf in btr_cur_search_to_nth_level (index=0x7f1e30027898, level=0, tuple=0x7f1e30039028, mode=PAGE_CUR_LE, latch_mode=2, cursor=0x7f1e7003c880, has_search_latch=0,
    file=0x171a330 "/pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/row/row0ins.cc", line=2351, mtr=0x7f1e7003c050)
    at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/btr/btr0cur.cc:1238
#8  0x0000000001136bc6 in btr_pcur_open_low (index=0x7f1e30027898, level=0, tuple=0x7f1e30039028, mode=PAGE_CUR_LE, latch_mode=2, cursor=0x7f1e7003c880,
    file=0x171a330 "/pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/row/row0ins.cc", line=2351, mtr=0x7f1e7003c050)
    at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/include/btr0pcur.ic:455
#9  0x000000000113bd9b in row_ins_clust_index_entry_low (flags=0, mode=2, index=0x7f1e30027898, n_uniq=0, entry=0x7f1e30039028, n_ext=0, thr=0x7f1e3003a470, dup_chk_only=false)
    at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/row/row0ins.cc:2351
#10 0x000000000113e18a in row_ins_clust_index_entry (index=0x7f1e30027898, entry=0x7f1e30039028, thr=0x7f1e3003a470, n_ext=0, dup_chk_only=false)
    at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/row/row0ins.cc:3158
#11 0x000000000113e626 in row_ins_index_entry (index=0x7f1e30027898, entry=0x7f1e30039028, thr=0x7f1e3003a470)
    at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/row/row0ins.cc:3281
#12 0x000000000113eab2 in row_ins_index_entry_step (node=0x7f1e3003a228, thr=0x7f1e3003a470)
    at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/row/row0ins.cc:3422
#13 0x000000000113ee40 in row_ins (node=0x7f1e3003a228, thr=0x7f1e3003a470) at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/row/row0ins.cc:3564
#14 0x000000000113f3b3 in row_ins_step (thr=0x7f1e3003a470) at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/row/row0ins.cc:3735
#15 0x000000000115b0fa in row_insert_for_mysql_using_ins_graph (mysql_rec=0x7f1e30033ef0 "\375\001", prebuilt=0x7f1e30039d38)
    at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/row/row0mysql.cc:1570
#16 0x000000000115b5cd in row_insert_for_mysql (mysql_rec=0x7f1e30033ef0 "\375\001", prebuilt=0x7f1e30039d38)
    at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/row/row0mysql.cc:1681
#17 0x000000000103d3e1 in ha_innobase::write_row (this=0x7f1e30033c20, record=0x7f1e30033ef0 "\375\001")
    at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/innobase/handler/ha_innodb.cc:6697
#18 0x000000000099f23c in handler::ha_write_row (this=0x7f1e30033c20, buf=0x7f1e30033ef0 "\375\001") at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/sql/handler.cc:7443
#19 0x0000000000e92911 in write_record (thd=0x7f1e30000cf0, table=0x7f1e30038610, info=0x7f1e7003dca0, update=0x7f1e7003dc20)
    at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/sql/sql_insert.cc:1680
#20 0x0000000000e901a1 in mysql_insert (thd=0x7f1e30000cf0, table_list=0x7f1e30005d98, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR)
    at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/sql/sql_insert.cc:708
#21 0x0000000000cb6855 in mysql_execute_command (thd=0x7f1e30000cf0) at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/sql/sql_parse.cc:3338
#22 0x0000000000cbce6a in mysql_parse (thd=0x7f1e30000cf0, parser_state=0x7f1e7003f660) at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/sql/sql_parse.cc:5397
#23 0x0000000000cb0f2c in dispatch_command (command=COM_QUERY, thd=0x7f1e30000cf0, packet=0x7f1e30009a21 "insert INTO t1 values(1),(1),(1),(1)", packet_length=36)
    at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/sql/sql_parse.cc:1249
#24 0x0000000000cafbd4 in do_command (thd=0x7f1e30000cf0) at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/sql/sql_parse.cc:833
#25 0x0000000000dbe89c in handle_connection (arg=0x436ba00) at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/sql/conn_handler/connection_handler_per_thread.cc:298
#26 0x000000000138347f in pfs_spawn_thread (arg=0x41c1e60) at /pb2/build/sb_0-13559856-1414670154.69/mysqlcom-pro-5.7.6-m16/storage/perfschema/pfs.cc:2137
#27 0x0000003deb0079d1 in start_thread () from /lib64/libpthread.so.0
#28 0x0000003deace89dd in clone () from /lib64/libc.so.6

Fixed as of the upcoming 5.7.6 release, and here's the changelog entry:

A failed "DROP TABLE" operation could leave a table in an inconsistent
state without marking the table as corrupted.

Great. Can it also be back ported to 5.6?