MySQL Bugs: #78496: Too many active concurrent trx+crash on ALTER w/ innodb_trx_rseg_n_slots

Bug #78496	Too many active concurrent trx+crash on ALTER w/ innodb_trx_rseg_n_slots_debug=1
Submitted:	21 Sep 2015 5:49	Modified:	20 Feb 2017 1:17
Reporter:	Roel Van de Paar	Email Updates:
Status:	Verified	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S6 (Debug Builds)
Version:	5.7.8 (RC2), 5.7.10, 5.7.17, 8.0.0, 5.6.28	OS:	Any
Assigned to:		CPU Architecture:	Any
Tags:	debug

Description:
mysql> ALTER TABLE t5 CHANGE c1 c1 DOUBLE(24,0)SIGNED,CHANGE c2 c2 DOUBLE(24,0) UNSIGNED;
ERROR 1025 (HY000): Error on rename of './test/t5' to './test/#sql2-1591-2' (errno: 177 - Too many active concurrent transactions)

AND (on second run of testcase on same mysqld)

mysql> ALTER TABLE t5 CHANGE c1 c1 DOUBLE(24,0)SIGNED,CHANGE c2 c2 DOUBLE(24,0) UNSIGNED;
ERROR 1813 (HY000): Tablespace '`test`.`#sql-1591_2`' exists.

How to repeat:
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;

Also, changing the testcase to:

DROP DATABASE test;CREATE DATABASE test;USE test;
CREATE TABLE t5(c1 YEAR,c2 INT,c3 CHAR);
set global innodb_trx_rseg_n_slots_debug=1;
ALTER TABLE t5 CHANGE c1 c1 DOUBLE(24,0)SIGNED,CHANGE c2 c2 DOUBLE(24,0) UNSIGNED;

Gives different output when executed the second time. I.e. first output is the same as what is shown above, second run of the same testcase gives different output:

mysql> ALTER TABLE t5 CHANGE c1 c1 DOUBLE(24,0)SIGNED,CHANGE c2 c2 DOUBLE(24,0) UNSIGNED;
ERROR 1146 (42S02): Table 'test.t5' doesn't exist

This can also be made to crash.

Hello Roel,

Thank you for the report and test case.
I'm not seeing any crashes with 5.7.10 but only seeing the error messages as reported.

Thanks,
Umesh

// 5.7.10

[umshastr@hod03]/export/umesh/server/binaries/mysql-advanced-5.7.10: bin/mysql -uroot -S /tmp/mysql_ushastry.sock
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 2
Server version: 5.7.10-enterprise-commercial-advanced-debug MySQL Enterprise Server - Advanced Edition Debug (Commercial)

Copyright (c) 2000, 2015, 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;
create TABLE t1(a int,b int,key(a),key(b)) partition by hash(a) partitions 4;
Query OK, 3 rows affected (0.03 sec)

Query OK, 1 row affected (0.00 sec)

Database changed
mysql> create TABLE t1(a int,b int,key(a),key(b)) partition by hash(a) partitions 4;
Query OK, 0 rows affected (0.03 sec)

mysql> CREATE TABLE t619(c1 INT);
CREATE TABLE t5(c1 YEAR,c2 INT,c3 CHAR);
Query OK, 0 rows affected (0.01 sec)

mysql> CREATE TABLE t5(c1 YEAR,c2 INT,c3 CHAR);
set global innodb_trx_rseg_n_slots_debug=1;
Query OK, 0 rows affected (0.00 sec)

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

mysql> CREATE TABLE t11(c1 CHAR);
create table `t``1`(a int)engine=InnoDB;
Query OK, 0 rows affected (0.01 sec)

mysql> create table `t``1`(a int)engine=InnoDB;
CREATE TABLE t12(c1 INT);
Query OK, 0 rows affected (0.01 sec)

mysql> CREATE TABLE t12(c1 INT);
ALTER TABLE t5 CHANGE c1 c1 DOUBLE(24,0)SIGNED,CHANGE c2 c2 DOUBLE(24,0) UNSIGNED;Query OK, 0 rows affected (0.00 sec)

mysql> ALTER TABLE t5 CHANGE c1 c1 DOUBLE(24,0)SIGNED,CHANGE c2 c2 DOUBLE(24,0) UNSIGNED;
ERROR 1025 (HY000): Error on rename of './test/t5' to './test/#sql2-559e-2' (errno: 177 - Too many active concurrent transactions)
mysql>
mysql> ALTER TABLE t5 CHANGE c1 c1 DOUBLE(24,0)SIGNED,CHANGE c2 c2 DOUBLE(24,0) UNSIGNED;
ERROR 1813 (HY000): Tablespace '`test`.`#sql-559e_2`' exists.
mysql>

// 5.8.0 

[umshastr@hod03]/export/umesh/server/binaries/mysql-advanced-5.8.0: bin/mysql -uroot -S /tmp/mysql_ushastry.sock
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 2
Server version: 5.8.0-m17-enterprise-commercial-advanced-debug MySQL Enterprise Server - Advanced Edition Debug (Commercial)

Copyright (c) 2000, 2015, 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;
ERROR 1008 (HY000): Can't drop database 'test'; database doesn't exist
Query OK, 1 row affected (0.00 sec)

Database changed
mysql> create TABLE t1(a int,b int,key(a),key(b)) partition by hash(a) partitions 4;
Query OK, 0 rows affected (0.03 sec)

mysql> CREATE TABLE t619(c1 INT);
Query OK, 0 rows affected (0.00 sec)

mysql> CREATE TABLE t5(c1 YEAR,c2 INT,c3 CHAR);
Query OK, 0 rows affected (0.00 sec)

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

mysql> CREATE TABLE t11(c1 CHAR);
create table `t``1`(a int)engine=InnoDB;
Query OK, 0 rows affected (0.01 sec)

mysql> create table `t``1`(a int)engine=InnoDB;
CREATE TABLE t12(c1 INT);
Query OK, 0 rows affected (0.01 sec)

mysql> CREATE TABLE t12(c1 INT);
ALTER TABLE t5 CHANGE c1 c1 DOUBLE(24,0)SIGNED,CHANGE c2 c2 DOUBLE(24,0) UNSIGNED;
Query OK, 0 rows affected (0.00 sec)

mysql> ALTER TABLE t5 CHANGE c1 c1 DOUBLE(24,0)SIGNED,CHANGE c2 c2 DOUBLE(24,0) UNSIGNED;
ERROR 1025 (HY000): Error on rename of './test/t5' to './test/#sql2-58a9-2' (errno: 177 - Too many active concurrent transactions)
mysql> ALTER TABLE t5 CHANGE c1 c1 DOUBLE(24,0)SIGNED,CHANGE c2 c2 DOUBLE(24,0) UNSIGNED;
ERROR 1813 (HY000): Tablespace '`test`.`#sql-58a9_2`' exists.
mysql>

Yes, crashing it for one reason or another does not seem straightforward.

Posted by developer:
 
Reported version value updated to reflect release name change from 5.8 to 8.0

This testcase;

DROP DATABASE test;CREATE DATABASE test;USE test;
set global innodb_trx_rseg_n_slots_debug=1;
CREATE TABLE t1(a int,b double,primary key(a),index (b)) partition by range (a) partitions 2 (partition x1 values less than (25),partition x2 values less than (100));
ALTER TABLE t1 REBUILD PARTITION ALL;

Crashes;

2017-02-20T00:50:05.958360Z 0 [Note] /sda/MS010217-mysql-5.7.17-linux-x86_64-debug/bin/mysqld: ready for connections.
Version: '5.7.17-debug'  socket: '/sda/MS010217-mysql-5.7.17-linux-x86_64-debug/socket.sock'  port: 18388  MySQL Community Server (GPL)
2017-02-20T00:50:16.500870Z 3 [Warning] InnoDB: Cannot find a free slot for an undo log. Do you have too many active transactions running concurrently?
2017-02-20T00:50:16.500953Z 3 [Warning] InnoDB: Unable to delete statistics for table test.t1#P#x2: Too many concurrent transactions. They can be deleted later using DELETE FROM mysql.innodb_index_stats WHERE database_name = 'test' AND table_name = 't1#P#x2'; DELETE FROM mysql.innodb_table_stats WHERE database_name = 'test' AND table_name = 't1#P#x2';
2017-02-20T00:50:16.501635Z 3 [Warning] InnoDB: Cannot find a free slot for an undo log. Do you have too many active transactions running concurrently?
2017-02-20T00:50:16.501726Z 3 [ERROR] InnoDB: Unknown error code 47 while dropping table: `test`.`t1` /* Partition `x2` */.
2017-02-20T00:50:16.501855Z 3 [ERROR] InnoDB: Flagged corruption of `PRIMARY` in table `test`.`t1` /* Partition `x2` */ in DROP TABLE
2017-02-20T00:50:16.501954Z 3 [ERROR] InnoDB: Flagged corruption of `b` in table `test`.`t1` /* Partition `x2` */ in DROP TABLE
2017-02-20T00:50:16.509553Z 3 [ERROR] Failed to execute action for entry = 6 from ddl log
mysqld: /git/mysql-server_dbg/sql/sql_partition.cc:6863: bool handle_alter_part_end(ALTER_PARTITION_PARAM_TYPE*, bool): Assertion `0' failed.
00:50:16 UTC - mysqld got signal 6 ;
[...]
Query (7f58a142b030): ALTER TABLE t1 REBUILD PARTITION ALL
Connection ID (thread ID): 3

Core was generated by `/sda/MS010217-mysql-5.7.17-linux-x86_64-debug/bin/mysqld --no-defaults --core-f'.
Program terminated with signal 6, Aborted.
#0  0x00007f58deb38741 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
61        val = INTERNAL_SYSCALL (tgkill, err, 3, THREAD_GETMEM (THREAD_SELF, pid),
(gdb) bt
#0  0x00007f58deb38741 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
#1  0x0000000001826d71 in my_write_core (sig=6) at /git/mysql-server_dbg/mysys/stacktrace.c:249
#2  0x0000000000e75574 in handle_fatal_signal (sig=6) at /git/mysql-server_dbg/sql/signal_handler.cc:220
#3  <signal handler called>
#4  0x00007f58dcecc1d7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#5  0x00007f58dcecd8c8 in __GI_abort () at abort.c:90
#6  0x00007f58dcec5146 in __assert_fail_base (fmt=0x7f58dd0163a8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x1f3acae "0",
    file=file@entry=0x1f3ac68 "/git/mysql-server_dbg/sql/sql_partition.cc", line=line@entry=6863,
    function=function@entry=0x1f3d220 <handle_alter_part_end(st_lock_param_type*, bool)::__PRETTY_FUNCTION__> "bool handle_alter_part_end(ALTER_PARTITION_PARAM_TYPE*, bool)")
    at assert.c:92
#7  0x00007f58dcec51f2 in __GI___assert_fail (assertion=0x1f3acae "0", file=0x1f3ac68 "/git/mysql-server_dbg/sql/sql_partition.cc", line=6863,
    function=0x1f3d220 <handle_alter_part_end(st_lock_param_type*, bool)::__PRETTY_FUNCTION__> "bool handle_alter_part_end(ALTER_PARTITION_PARAM_TYPE*, bool)") at assert.c:101
#8  0x000000000150d87a in handle_alter_part_end (lpt=0x7f58df1271e0, error=false) at /git/mysql-server_dbg/sql/sql_partition.cc:6863
#9  0x000000000150e795 in fast_alter_partition_table (thd=0x7f58a1419000, table=0x7f58a145b020, alter_info=0x7f58df128c10, create_info=0x7f58df128cc0, table_list=0x7f58a142b9e0,
    db=0x7f58a142bf68 "test", table_name=0x7f58a142b9a8 "t1", new_part_info=0x7f58a142ca20) at /git/mysql-server_dbg/sql/sql_partition.cc:7208
#10 0x000000000158a7f2 in mysql_alter_table (thd=0x7f58a1419000, new_db=0x7f58a142bf68 "test", new_name=0x0, create_info=0x7f58df128cc0, table_list=0x7f58a142b9e0,
    alter_info=0x7f58df128c10) at /git/mysql-server_dbg/sql/sql_table.cc:9365
#11 0x0000000001702077 in Sql_cmd_alter_table::execute (this=0x7f58a142bf70, thd=0x7f58a1419000) at /git/mysql-server_dbg/sql/sql_alter.cc:316
#12 0x00000000014f97f7 in mysql_execute_command (thd=0x7f58a1419000, first_level=true) at /git/mysql-server_dbg/sql/sql_parse.cc:4893
#13 0x00000000014fb5f5 in mysql_parse (thd=0x7f58a1419000, parser_state=0x7f58df12a550) at /git/mysql-server_dbg/sql/sql_parse.cc:5611
#14 0x00000000014f0c1d in dispatch_command (thd=0x7f58a1419000, com_data=0x7f58df12acb0, command=COM_QUERY) at /git/mysql-server_dbg/sql/sql_parse.cc:1461
#15 0x00000000014efa44 in do_command (thd=0x7f58a1419000) at /git/mysql-server_dbg/sql/sql_parse.cc:999
#16 0x000000000161f9d0 in handle_connection (arg=0x7f58b43ec860) at /git/mysql-server_dbg/sql/conn_handler/connection_handler_per_thread.cc:300
#17 0x00000000018534f9 in pfs_spawn_thread (arg=0x7f58c2a76220) at /git/mysql-server_dbg/storage/perfschema/pfs.cc:2188
#18 0x00007f58deb33dc5 in start_thread (arg=0x7f58df12b700) at pthread_create.c:308
#19 0x00007f58dcf8e73d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

Updated title