MySQL Bugs: #84753: [ERROR] InnoDB: Failed to find tablespace

Bug #84753	[ERROR] InnoDB: Failed to find tablespace \| trx_sys->rseg_array[0] != __null
Submitted:	31 Jan 2017 19:13	Modified:	6 Feb 2017 12:49
Reporter:	Roel Van de Paar	Email Updates:
Status:	Duplicate	Impact on me:	None
Category:	MySQL Server: DML	Severity:	S6 (Debug Builds)
Version:	5.7.16, 5.7.17	OS:	Any
Assigned to:		CPU Architecture:	Any

Description:
2017-01-31T18:49:24.408355Z 0 [ERROR] InnoDB: Failed to find tablespace for table `mysql`.`plugin` in the cache. Attempting to load the tablespace with space id 4
2017-01-31T18:49:24.411788Z 0 [ERROR] InnoDB: Failed to find tablespace for table `mysql`.`gtid_executed` in the cache. Attempting to load the tablespace with space id 20
2017-01-31T18:49:24.420938Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
2017-01-31T18:49:24.420961Z 0 [Note] Skipping generation of SSL certificates as certificate files are present in data directory.
2017-01-31T18:49:24.435274Z 0 [Warning] CA certificate ca.pem is self signed.
2017-01-31T18:49:24.435341Z 0 [Note] Skipping generation of RSA key pair as key files are present in data directory.
2017-01-31T18:49:24.435467Z 0 [Note] Server hostname (bind-address): '*'; port: 19199
2017-01-31T18:49:24.435511Z 0 [Note] IPv6 is available.
2017-01-31T18:49:24.435532Z 0 [Note]   - '::' resolves to '::';
2017-01-31T18:49:24.435588Z 0 [Note] Server socket created on IP: '::'.
2017-01-31T18:49:24.443004Z 0 [ERROR] InnoDB: Failed to find tablespace for table `mysql`.`server_cost` in the cache. Attempting to load the tablespace with space id 21
2017-01-31T18:49:24.443852Z 0 [ERROR] InnoDB: Failed to find tablespace for table `mysql`.`engine_cost` in the cache. Attempting to load the tablespace with space id 22
2017-01-31T18:49:24.446084Z 0 [ERROR] InnoDB: Failed to find tablespace for table `mysql`.`time_zone_leap_second` in the cache. Attempting to load the tablespace with space id 14
2017-01-31T18:49:24.446874Z 0 [ERROR] InnoDB: Failed to find tablespace for table `mysql`.`time_zone_name` in the cache. Attempting to load the tablespace with space id 10
2017-01-31T18:49:24.447662Z 0 [ERROR] InnoDB: Failed to find tablespace for table `mysql`.`time_zone` in the cache. Attempting to load the tablespace with space id 11
2017-01-31T18:49:24.448440Z 0 [ERROR] InnoDB: Failed to find tablespace for table `mysql`.`time_zone_transition_type` in the cache. Attempting to load the tablespace with space id 13
2017-01-31T18:49:24.449227Z 0 [ERROR] InnoDB: Failed to find tablespace for table `mysql`.`time_zone_transition` in the cache. Attempting to load the tablespace with space id 12
2017-01-31T18:49:24.450770Z 0 [ERROR] InnoDB: Failed to find tablespace for table `mysql`.`servers` in the cache. Attempting to load the tablespace with space id 5
2017-01-31T18:49:24.461836Z 0 [Note] Event Scheduler: Loaded 0 events
2017-01-31T18:49:24.462053Z 0 [Note] /sda/MS151116-mysql-5.7.16-linux-x86_64-debug/bin/mysqld: ready for connections.
Version: '5.7.16-debug'  socket: '/sda/MS151116-mysql-5.7.16-linux-x86_64-debug/socket.sock'  port: 19199  MySQL Community Server (GPL)
2017-02-01 05:49:26 0x7f8109123700  InnoDB: Assertion failure in thread 140192179697408 in file trx0trx.cc line 1257
InnoDB: Failing assertion: trx_sys->rseg_array[0] != __null

How to repeat:
# Start mysqld with --no-defaults --innodb-force-recovery=254
DROP DATABASE test;

This is a regression. 5.5.52 does not crash on the same testcase. It does however crash on the following;

# mysqld options required for replay:  --innodb-force-recovery=254
DROP DATABASE test;CREATE DATABASE test;USE test;
set global innodb_trx_rseg_n_slots_debug=1;
CREATE TABLE t1(cdtk DATE,KEY cdtk (cdtk)) ENGINE=InnoDB;
drop tables if exists t1,t2,t3,t4,t5;
ALTER TABLE t1 ADD c2 INT;

With a different crash;

Version: '5.5.52-debug'  socket: '/sda/MS280916-mysql-5.5.52-linux-x86_64-debug/socket.sock'  port: 12949  MySQL Community Server (GPL)
170201  6:02:25  InnoDB: Warning: cannot find a free slot for an undo log. Do you have too
InnoDB: many active transactions running concurrently?
170201  6:02:26  InnoDB: Assertion failure in thread 140429547898624 in file btr0cur.c line 871
InnoDB: Failing assertion: index->id == btr_page_get_index_id(page)

(gdb) bt
#0  0x00007fb84cf25741 in __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
#1  0x00000000007e0548 in my_write_core (sig=6) at /git/mysql-server_dbg/mysys/stacktrace.c:433
#2  0x00000000006a3598 in handle_fatal_signal (sig=6) at /git/mysql-server_dbg/sql/signal_handler.cc:247
#3  <signal handler called>
#4  0x00007fb84b6d71d7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#5  0x00007fb84b6d88c8 in __GI_abort () at abort.c:90
#6  0x00000000008ebcf3 in btr_cur_open_at_index_side_func (from_left=from_left@entry=1, index=index@entry=0x7fb835425d78, latch_mode=latch_mode@entry=1,
    cursor=cursor@entry=0x7fb83551aee8, file=file@entry=0xb0af20 "/git/mysql-server_dbg/storage/innobase/include/btr0pcur.ic", line=line@entry=519, mtr=mtr@entry=0x7fb84d514450)
    at /git/mysql-server_dbg/storage/innobase/btr/btr0cur.c:871
#7  0x000000000088bcd3 in btr_pcur_open_at_index_side (mtr=0x7fb84d514450, do_init=0, pcur=0x7fb83551aee8, latch_mode=1, index=0x7fb835425d78, from_left=1)
    at /git/mysql-server_dbg/storage/innobase/include/btr0pcur.ic:518
#8  row_search_for_mysql (buf=<optimized out>, mode=1, prebuilt=0x7fb83551ae78, match_mode=<optimized out>, direction=<optimized out>)
    at /git/mysql-server_dbg/storage/innobase/row/row0sel.c:3943
#9  0x0000000000850140 in ha_innobase::index_read (this=0x7fb835438010, buf=0x7fb835443010 "\377", key_ptr=0x0, key_len=<optimized out>, find_flag=<optimized out>)
    at /git/mysql-server_dbg/storage/innobase/handler/ha_innodb.cc:5958
#10 0x000000000084d867 in ha_innobase::index_first (this=0x7fb835438010, buf=0x7fb835443010 "\377") at /git/mysql-server_dbg/storage/innobase/handler/ha_innodb.cc:6282
#11 0x000000000085be41 in ha_innobase::rnd_next (this=0x7fb835438010, buf=0x7fb835443010 "\377") at /git/mysql-server_dbg/storage/innobase/handler/ha_innodb.cc:6379
#12 0x000000000077b463 in rr_sequential (info=0x7fb84d514cc0) at /git/mysql-server_dbg/sql/records.cc:461
#13 0x00000000005fb27a in copy_data_between_tables (error_if_not_empty=false, keys_onoff=<optimized out>, deleted=<synthetic pointer>, copied=<synthetic pointer>, order=0x0,
    order_num=0, ignore=<optimized out>, create=..., to=0x7fb83551bc00, from=0x7fb8354a4c00) at /git/mysql-server_dbg/sql/sql_table.cc:7280
#14 mysql_alter_table (thd=thd@entry=0x7fb83ebf9000, new_db=<optimized out>, new_name=0x7fb83541f0c0 "t1", create_info=create_info@entry=0x7fb84d5161a0,
    table_list=table_list@entry=0x7fb83541f0f8, alter_info=alter_info@entry=0x7fb84d516100, order_num=0, order=0x0, ignore=false) at /git/mysql-server_dbg/sql/sql_table.cc:6612
#15 0x00000000007bf3ba in Alter_table_statement::execute (this=<optimized out>, thd=0x7fb83ebf9000) at /git/mysql-server_dbg/sql/sql_alter.cc:106
#16 0x00000000005921f0 in mysql_execute_command (thd=thd@entry=0x7fb83ebf9000) at /git/mysql-server_dbg/sql/sql_parse.cc:4456
#17 0x0000000000593476 in mysql_parse (thd=thd@entry=0x7fb83ebf9000, rawbuf=<optimized out>, length=25, parser_state=parser_state@entry=0x7fb84d517580)
    at /git/mysql-server_dbg/sql/sql_parse.cc:5780
#18 0x0000000000594cc3 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7fb83ebf9000, packet=packet@entry=0x7fb83eb9e001 "ALTER TABLE t1 ADD c2 INT",
    packet_length=packet_length@entry=25) at /git/mysql-server_dbg/sql/sql_parse.cc:1038
#19 0x0000000000596b4c in do_command (thd=0x7fb83ebf9000) at /git/mysql-server_dbg/sql/sql_parse.cc:773
#20 0x000000000063edf8 in do_handle_one_connection (thd_arg=thd_arg@entry=0x7fb83ebf9000) at /git/mysql-server_dbg/sql/sql_connect.cc:862
#21 0x000000000063eeb5 in handle_one_connection (arg=0x7fb83ebf9000) at /git/mysql-server_dbg/sql/sql_connect.cc:781
#22 0x00007fb84cf20dc5 in start_thread (arg=0x7fb84d518700) at pthread_create.c:308
#23 0x00007fb84b79973d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

Stack for the first testcase (5.7.16);

Core was generated by `/sda/MS151116-mysql-5.7.16-linux-x86_64-debug/bin/mysqld --no-defaults --innodb'.
Program terminated with signal 6, Aborted.
#0  0x00007f8108b30741 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  0x00007f8108b30741 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
#1  0x0000000001822fb0 in my_write_core (sig=6) at /git/mysql-server_dbg/mysys/stacktrace.c:247
#2  0x0000000000e7457c in handle_fatal_signal (sig=6) at /git/mysql-server_dbg/sql/signal_handler.cc:220
#3  <signal handler called>
#4  0x00007f8106ec41d7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#5  0x00007f8106ec58c8 in __GI_abort () at abort.c:90
#6  0x0000000001b8980f in ut_dbg_assertion_failed (expr=0x210ff30 "trx_sys->rseg_array[0] != __null", file=0x210f5c0 "/git/mysql-server_dbg/storage/innobase/trx/trx0trx.cc",
    line=1257) at /git/mysql-server_dbg/storage/innobase/ut/ut0dbg.cc:67
#7  0x0000000001b751c0 in trx_assign_rseg_low (max_undo_logs=128, n_tablespaces=0, rseg_type=TRX_RSEG_TYPE_REDO) at /git/mysql-server_dbg/storage/innobase/trx/trx0trx.cc:1257
#8  0x0000000001b759e9 in trx_start_low (trx=0x7f80f8c00cf8, read_write=true) at /git/mysql-server_dbg/storage/innobase/trx/trx0trx.cc:1394
#9  0x0000000001b7985e in trx_start_if_not_started_xa_low (trx=0x7f80f8c00cf8, read_write=true) at /git/mysql-server_dbg/storage/innobase/trx/trx0trx.cc:3037
#10 0x0000000001ab5db5 in row_drop_database_for_mysql (name=0x7f80dfc2e240 "test/", trx=0x7f80f8c00cf8, found=0x7f810911fab8)
    at /git/mysql-server_dbg/storage/innobase/row/row0mysql.cc:5052
#11 0x0000000001965809 in innobase_drop_database (hton=0x7f8100fb74a0, path=0x7f81091200d0 "./test/") at /git/mysql-server_dbg/storage/innobase/handler/ha_innodb.cc:12985
#12 0x0000000000eecbbb in dropdb_handlerton (unused1=0x0, plugin=0x7f810911fbf8, path=0x7f81091200d0) at /git/mysql-server_dbg/sql/handler.cc:994
#13 0x000000000152251b in plugin_foreach_with_mask (thd=0x0, func=0xeecb68 <dropdb_handlerton(THD*, plugin_ref, void*)>, type=1, state_mask=4294967287, arg=0x7f81091200d0)
    at /git/mysql-server_dbg/sql/sql_plugin.cc:2318
#14 0x0000000000eecbf0 in ha_drop_database (path=0x7f81091200d0 "./test/") at /git/mysql-server_dbg/sql/handler.cc:1001
#15 0x00000000014a092e in mysql_rm_db (thd=0x7f80dfc19000, db=..., if_exists=false, silent=false) at /git/mysql-server_dbg/sql/sql_db.cc:888
#16 0x00000000014f4b3e in mysql_execute_command (thd=0x7f80dfc19000, first_level=true) at /git/mysql-server_dbg/sql/sql_parse.cc:3806
#17 0x00000000014f97d5 in mysql_parse (thd=0x7f80dfc19000, parser_state=0x7f8109122560) at /git/mysql-server_dbg/sql/sql_parse.cc:5559
#18 0x00000000014eef69 in dispatch_command (thd=0x7f80dfc19000, com_data=0x7f8109122cb0, command=COM_QUERY) at /git/mysql-server_dbg/sql/sql_parse.cc:1427
#19 0x00000000014ede33 in do_command (thd=0x7f80dfc19000) at /git/mysql-server_dbg/sql/sql_parse.cc:995
#20 0x000000000161d370 in handle_connection (arg=0x7f80e73f97c0) at /git/mysql-server_dbg/sql/conn_handler/connection_handler_per_thread.cc:300
#21 0x000000000184f79c in pfs_spawn_thread (arg=0x7f80ed676020) at /git/mysql-server_dbg/storage/perfschema/pfs.cc:2188
#22 0x00007f8108b2bdc5 in start_thread (arg=0x7f8109123700) at pthread_create.c:308
#23 0x00007f8106f8673d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

Wow. 5.6.34 and 5.6.35 Not affected at all.

Hello Roel,

Thank you for the report.
Observed that 5.7.17 debug build is affected.

Thanks,
Umesh

- I didn't observe any issues with 5.5.54/5.6.35 release/debug build

Duplicate of 

Bug#84485 Drop table crashes if innodb_force_recovery > 4

fixed in 5.7.18.