Bug #88263 fil0fil.cc:8619:recv_recovery_is_on() || Log_DDL::is_in_recovery() assert
Submitted: 28 Oct 2017 0:27 Modified: 20 Nov 2017 13:48
Reporter: Roel Van de Paar (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: DML Severity:S6 (Debug Builds)
Version:8.0.3 RC OS:Any
Assigned to: CPU Architecture:Any
Tags: debug

[28 Oct 2017 0:27] Roel Van de Paar
Description:
rc-debug-log'  socket: '/sda/MS201017-mysql-8.0.3-rc-linux-x86_64-debug/socket.sock'  port: 16654  MySQL Community Server (GPL)
2017-10-27T23:56:58.347854Z 7 [ERROR] InnoDB: In ALTER TABLE `test`.`t1` has or is referenced in foreign key constraints which are not compatible with the new table definition.
2017-10-27T23:56:58.451351Z 7 [ERROR] InnoDB: Assertion failure: fil0fil.cc:8619:recv_recovery_is_on() || Log_DDL::is_in_recovery()
InnoDB: thread 139691481159424
InnoDB: We intentionally generate a memory trap.

Core was generated by `/sda/MS201017-mysql-8.0.3-rc-linux-x86_64-debug/bin/mysqld --no-defaults --thre'.
Program terminated with signal 6, Aborted.
#0  0x00007f0c74bda9b1 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  0x00007f0c74bda9b1 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
#1  0x000000000369e428 in my_write_core (sig=6) at /git/mysql-server_dbg/mysys/stacktrace.cc:291
#2  0x000000000286b8f6 in handle_fatal_signal (sig=6) at /git/mysql-server_dbg/sql/signal_handler.cc:234
#3  <signal handler called>
#4  0x00007f0c72ef21f7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#5  0x00007f0c72ef38e8 in __GI_abort () at abort.c:90
#6  0x0000000003a8b8f9 in ut_dbg_assertion_failed (expr=0x4925ca8 "recv_recovery_is_on() || Log_DDL::is_in_recovery()", 
    file=0x49225e0 "/git/mysql-server_dbg/storage/innobase/fil/fil0fil.cc", line=8619)
    at /git/mysql-server_dbg/storage/innobase/ut/ut0dbg.cc:60
#7  0x0000000003bcafab in fil_tablespace_open_for_recovery (space_id=2, path="./test/#sql-6b6_7.ibd", lsn=13898341)
    at /git/mysql-server_dbg/storage/innobase/fil/fil0fil.cc:8619
#8  0x0000000003bcca26 in Fil_Open::open_for_recovery (this=0x7f0c5f4138f0, space_id=2)
    at /git/mysql-server_dbg/storage/innobase/fil/fil0fil.cc:9156
#9  0x0000000003bbbd85 in fil_op_replay_rename_for_ddl (page_id=..., name=0x7f0c2c87cfb8 "./test/#sql-6b6_7.ibd", 
    new_name=0x7f0c2c87cff0 "./test/t1.ibd") at /git/mysql-server_dbg/storage/innobase/fil/fil0fil.cc:3111
#10 0x0000000003917a65 in Log_DDL::replay_rename_space_log (this=0x7f0c3bcc6918, space_id=2, 
    old_file_path=0x7f0c2c87cfb8 "./test/#sql-6b6_7.ibd", new_file_path=0x7f0c2c87cff0 "./test/t1.ibd")
    at /git/mysql-server_dbg/storage/innobase/log/log0ddl.cc:1654
#11 0x00000000039174f5 in Log_DDL::replay (this=0x7f0c3bcc6918, record=...)
    at /git/mysql-server_dbg/storage/innobase/log/log0ddl.cc:1538
#12 0x0000000003917134 in Log_DDL::replay_by_thread_id (this=0x7f0c3bcc6918, thread_id=7)
    at /git/mysql-server_dbg/storage/innobase/log/log0ddl.cc:1471
#13 0x000000000391827f in Log_DDL::post_ddl (this=0x7f0c3bcc6918, thd=0x7f0c2c819000)
    at /git/mysql-server_dbg/storage/innobase/log/log0ddl.cc:1792
#14 0x0000000003820c9a in innobase_post_ddl (thd=0x7f0c2c819000) at /git/mysql-server_dbg/storage/innobase/handler/ha_innodb.cc:4435
#15 0x0000000002560a72 in mysql_alter_table (thd=0x7f0c2c819000, new_db=0x7f0c2c830288 "test", new_name=0x0, 
    create_info=0x7f0c751ca980, table_list=0x7f0c2c82fd10, alter_info=0x7f0c751caa70) at /git/mysql-server_dbg/sql/sql_table.cc:14107
#16 0x0000000002c00ec1 in Sql_cmd_alter_table::execute (this=0x7f0c2c830290, thd=0x7f0c2c819000)
    at /git/mysql-server_dbg/sql/sql_alter.cc:324
#17 0x00000000024be1ff in mysql_execute_command (thd=0x7f0c2c819000, first_level=true) at /git/mysql-server_dbg/sql/sql_parse.cc:4628
#18 0x00000000024c042b in mysql_parse (thd=0x7f0c2c819000, parser_state=0x7f0c751cc2f0) at /git/mysql-server_dbg/sql/sql_parse.cc:5414
#19 0x00000000024b68e7 in dispatch_command (thd=0x7f0c2c819000, com_data=0x7f0c751ccb80, command=COM_QUERY)
    at /git/mysql-server_dbg/sql/sql_parse.cc:1708
#20 0x00000000024b53f5 in do_command (thd=0x7f0c2c819000) at /git/mysql-server_dbg/sql/sql_parse.cc:1291
#21 0x000000000285b2d6 in handle_connection (arg=0x7f0c612eb3c0)
    at /git/mysql-server_dbg/sql/conn_handler/connection_handler_per_thread.cc:328
#22 0x00000000036ec54d in pfs_spawn_thread (arg=0x7f0c61394620) at /git/mysql-server_dbg/storage/perfschema/pfs.cc:2985
#23 0x00007f0c74bd5e25 in start_thread (arg=0x7f0c751cd700) at pthread_create.c:308
#24 0x00007f0c72fb534d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

How to repeat:
# mysqld options required for replay:  --thread-stack=0
CREATE DATABASE test;
USE test;
create table t1(f1 int key)engine=MEMORY;
ALTER TABLE t1 ENGINE=InnoDB;
[28 Oct 2017 0:27] Roel Van de Paar
Besides the crash, "In ALTER TABLE `test`.`t1` has or is referenced in foreign key constraints" seems to contain a grammatical error. ("has been" ?)
[28 Oct 2017 19:36] Miguel Solorzano
Thank you for the bug report. Verified as described.
[20 Nov 2017 13:48] Daniel Price
Posted by developer:
 
Fixed as of the upcoming 8.0.4  release, and here's the changelog entry:

 A call to a recovery-related function during the post-DDL phase of a DDL
operation raised an assertion.