Please let's request the obvious – the config file, table structure, data dump or at least SHOW INDEX IN.
And the portion of the error log prior to the crash.
Elena Stepanova
added a comment - - edited Please let's request the obvious – the config file, table structure, data dump or at least SHOW INDEX IN .
And the portion of the error log prior to the crash.
# Run with--repeat=N if it doesn't fail right away.
# I also recommend --mysqld=--lock-wait-timeout=3 --mysqld=--innodb-lock-wait-timeout=2,
# as it seems that sometimes it can lock up until the timeout is exceeded.
--source include/have_innodb.inc
CREATEORREPLACETABLE t1 (i INTUNIQUE) ENGINE=InnoDB;
--send
OPTIMIZE TABLE t1;
--connect (con1,localhost,root,,test)
--error ER_DUP_ENTRY
INSERTINTO t1 VALUES (1),(1);
--connection default
--reap
# Cleanup
--disconnect con1
--connection default
DROPTABLE t1;
10.0 78b63425a3f17214b non-debug
#2 <signal handler called>
#3 0x000000000076c626 in field_unpack (to=to@entry=0x7fef60d66710, field=0x7fef60d654b0, rec=0x7fef4b041020 "\375\001", max_length=0, prefix_key=false) at /data/src/10.0/sql/key.cc:359
#4 0x000000000076c77d in key_unpack (to=to@entry=0x7fef60d66710, table=table@entry=0x7fef4b174008, key=key@entry=0x7fef4b1c8670) at /data/src/10.0/sql/key.cc:441
#5 0x00000000006e48d9 in print_keydup_error (table=table@entry=0x7fef4b174008, key=0x7fef4b1c8670, msg=0x7fef5a3aecaa "Duplicate entry '%-.64s' for key '%-.192s'", errflag=errflag@entry=0) at /data/src/10.0/sql/handler.cc:3348
#6 0x00000000006e4a20 in print_keydup_error (table=table@entry=0x7fef4b174008, key=<optimized out>, errflag=errflag@entry=0) at /data/src/10.0/sql/handler.cc:3368
#7 0x00007fef574a081b in commit_try_rebuild (table_name=0x7fef4b02108d "t1", trx=0x7fef4b134c68, old_table=<optimized out>, altered_table=<optimized out>, ctx=<optimized out>, ha_alter_info=<optimized out>) at /data/src/10.0/storage/innobase/handler/handler0alter.cc:5122
#11 0x0000000000621110 in mysql_recreate_table (thd=thd@entry=0x7fef53675008, table_list=table_list@entry=0x7fef4b1c70f0, table_copy=table_copy@entry=false) at /data/src/10.0/sql/sql_table.cc:9714
#12 0x0000000000665415 in admin_recreate_table (thd=thd@entry=0x7fef53675008, table_list=table_list@entry=0x7fef4b1c70f0) at /data/src/10.0/sql/sql_admin.cc:58
#13 0x0000000000666c5e in mysql_admin_table (thd=thd@entry=0x7fef53675008, tables=tables@entry=0x7fef4b1c70f0, check_opt=check_opt@entry=0x7fef53679690, operator_name=operator_name@entry=0xc0ffd1 "optimize", lock_type=lock_type@entry=TL_WRITE, open_for_modify=false, open_for_modify@entry=true, repair_table_use_frm=false, extra_open_options=0, prepare_func=0x0, operator_func=<optimized out>, view_operator_func=0x0) at /data/src/10.0/sql/sql_admin.cc:913
#14 0x0000000000667b84 in Sql_cmd_optimize_table::execute (this=<optimized out>, thd=0x7fef53675008) at /data/src/10.0/sql/sql_admin.cc:1257
#15 0x00000000005a3a87 in mysql_execute_command (thd=0x7fef53675008) at /data/src/10.0/sql/sql_parse.cc:5123
#16 0x00000000005aa0b8 in mysql_parse (thd=0x7fef53675008, rawbuf=<optimized out>, length=17, parser_state=0x7fef60d6a850) at /data/src/10.0/sql/sql_parse.cc:6578
#17 0x00000000005abad9 in dispatch_command (command=<optimized out>, thd=0x7fef53675008, packet=<optimized out>, packet_length=<optimized out>) at /data/src/10.0/sql/sql_parse.cc:1305
#18 0x00000000005ac46f in do_command (thd=<optimized out>) at /data/src/10.0/sql/sql_parse.cc:999
#19 0x000000000065b9e4 in do_handle_one_connection (thd_arg=thd_arg@entry=0x7fef53675008) at /data/src/10.0/sql/sql_connect.cc:1377
#20 0x000000000065ba28 in handle_one_connection (arg=arg@entry=0x7fef53675008) at /data/src/10.0/sql/sql_connect.cc:1292
#21 0x000000000088f6d4 in pfs_spawn_thread (arg=0x7fef5e03f808) at /data/src/10.0/storage/perfschema/pfs.cc:1860
#22 0x00007fef609a8494 in start_thread (arg=0x7fef60d6b700) at pthread_create.c:333
#23 0x00007fef5eaf393f in clone () from /lib/x86_64-linux-gnu/libc.so.6
#7 0x00007f8939ab1ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
#8 0x00007f893236c76a in commit_try_rebuild (ha_alter_info=0x7f893bde2fe0, ctx=0x7f89258fb800, altered_table=0x7f89259a6070, old_table=0x7f892589e470, trx=0x7f8925952278, table_name=0x7f8925861175 "t1") at /data/src/10.0/storage/innobase/handler/handler0alter.cc:5117
#9 0x00007f893236a280 in ha_innodb::commit_inplace_alter_table (this=0x7f892587e088, altered_table=0x7f89259a6070, ha_alter_info=0x7f893bde2fe0, commit=true) at /data/src/10.0/storage/innobase/handler/handler0alter.cc:5817
#10 0x0000000000841067 in handler::ha_commit_inplace_alter_table (this=0x7f892587e088, altered_table=0x7f89259a6070, ha_alter_info=0x7f893bde2fe0, commit=true) at /data/src/10.0/sql/handler.cc:4226
#11 0x00000000006ffa69 in mysql_inplace_alter_table (thd=0x7f892df69070, table_list=0x7f89258fa158, table=0x7f892589e470, altered_table=0x7f89259a6070, ha_alter_info=0x7f893bde2fe0, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7f893bde2a30, alter_ctx=0x7f893bde35c0) at /data/src/10.0/sql/sql_table.cc:7145
#12 0x000000000070406b in mysql_alter_table (thd=0x7f892df69070, new_db=0x0, new_name=0x0, create_info=0x7f893bde4270, table_list=0x7f89258fa158, alter_info=0x7f893bde41e0, order_num=0, order=0x0, ignore=false) at /data/src/10.0/sql/sql_table.cc:8949
#13 0x0000000000706452 in mysql_recreate_table (thd=0x7f892df69070, table_list=0x7f89258fa158, table_copy=false) at /data/src/10.0/sql/sql_table.cc:9714
#14 0x00000000007768d1 in admin_recreate_table (thd=0x7f892df69070, table_list=0x7f89258fa158) at /data/src/10.0/sql/sql_admin.cc:58
Here is another variation, previously filed as MDEV-10706, but finally with a test case. It causes an identical crash on a non-debug build, but a different assertion failure on a debug build. Please make sure that both variations are fixed before closing the bug.
Note: Run with --repeat=N if it doesn't fail right away. Probably lock timeout recommendations from the previous test case also apply here, although I haven't seen this one lock up.
#7 0x00007f04d1458ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
#8 0x00007f04c9f6768b in ha_innodb::inplace_alter_table (this=0x7f04bd845088, altered_table=0x7f04bd5a6070, ha_alter_info=0x7f04d351c260) at /data/src/10.0/storage/innobase/handler/handler0alter.cc:4176
#9 0x0000000000707b7f in handler::ha_inplace_alter_table (this=0x7f04bd845088, altered_table=0x7f04bd5a6070, ha_alter_info=0x7f04d351c260) at /data/src/10.0/sql/handler.h:3580
#10 0x00000000007003b1 in mysql_inplace_alter_table (thd=0x7f04c5b69070, table_list=0x7f04bd4fa160, table=0x7f04bd913c70, altered_table=0x7f04bd5a6070, ha_alter_info=0x7f04d351c260, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7f04d351bcb0, alter_ctx=0x7f04d351c840) at /data/src/10.0/sql/sql_table.cc:7117
#11 0x0000000000704ac7 in mysql_alter_table (thd=0x7f04c5b69070, new_db=0x7f04bd4fa740 "test", new_name=0x0, create_info=0x7f04d351d4e0, table_list=0x7f04bd4fa160, alter_info=0x7f04d351d450, order_num=0, order=0x0, ignore=false) at /data/src/10.0/sql/sql_table.cc:8948
#12 0x000000000076d365 in Sql_cmd_alter_table::execute (this=0x7f04bd4fa748, thd=0x7f04c5b69070) at /data/src/10.0/sql/sql_alter.cc:312
#13 0x000000000065398b in mysql_execute_command (thd=0x7f04c5b69070) at /data/src/10.0/sql/sql_parse.cc:5114
#14 0x0000000000656dc2 in mysql_parse (thd=0x7f04c5b69070, rawbuf=0x7f04bd4fa088 "ALTER TABLE t1 FORCE", length=20, parser_state=0x7f04d351e640) at /data/src/10.0/sql/sql_parse.cc:6569
#15 0x0000000000649901 in dispatch_command (command=COM_QUERY, thd=0x7f04c5b69070, packet=0x7f04cb5ef071 "ALTER TABLE t1 FORCE", packet_length=20) at /data/src/10.0/sql/sql_parse.cc:1296
#16 0x0000000000648c01 in do_command (thd=0x7f04c5b69070) at /data/src/10.0/sql/sql_parse.cc:999
#17 0x0000000000768ab8 in do_handle_one_connection (thd_arg=0x7f04c5b69070) at /data/src/10.0/sql/sql_connect.cc:1377
#18 0x000000000076882a in handle_one_connection (arg=0x7f04c5b69070) at /data/src/10.0/sql/sql_connect.cc:1292
#19 0x0000000000ac9564 in pfs_spawn_thread (arg=0x7f04c5b19670) at /data/src/10.0/storage/perfschema/pfs.cc:1861
#20 0x00007f04d315c494 in start_thread (arg=0x7f04d351f700) at pthread_create.c:333
#21 0x00007f04d151593f in clone () from /lib/x86_64-linux-gnu/libc.so.6
Reproducible on 10.0-10.3, and also on MySQL 5.6.
Not reproducible on 5.5 and on MySQL 5.7, 8.0.3.
Elena Stepanova
added a comment - Here is another variation, previously filed as MDEV-10706 , but finally with a test case. It causes an identical crash on a non-debug build, but a different assertion failure on a debug build. Please make sure that both variations are fixed before closing the bug.
Note: Run with --repeat=N if it doesn't fail right away. Probably lock timeout recommendations from the previous test case also apply here, although I haven't seen this one lock up.
--source include/have_innodb.inc
--connect (con1,localhost,root,,test)
CREATE TABLE t1 (c CHAR DEFAULT '' UNIQUE ) ENGINE=InnoDB;
INSERT INTO t1 () VALUES ();
--connection default
--send
ALTER TABLE t1 FORCE ;
--connection con1
--error ER_NO_SUCH_TABLE
ALTER TABLE non_existing FORCE ;
--error ER_DUP_ENTRY
INSERT INTO t1 () VALUES (),(),(),();
# Cleanup
--disconnect con1
--connection default
--error 0,ER_DUP_ENTRY
--reap
DROP TABLE t1;
10.0 debug d8ccc61f76d56b761
mysqld: /data/src/10.0/storage/innobase/handler/handler0alter.cc:4177: virtual bool ha_innodb::inplace_alter_table(TABLE*, Alter_inplace_info*): Assertion `prebuilt->trx->error_key_num < ha_alter_info->key_count' failed.
171122 15:16:54 [ERROR] mysqld got signal 6 ;
#7 0x00007f04d1458ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
#8 0x00007f04c9f6768b in ha_innodb::inplace_alter_table (this=0x7f04bd845088, altered_table=0x7f04bd5a6070, ha_alter_info=0x7f04d351c260) at /data/src/10.0/storage/innobase/handler/handler0alter.cc:4176
#9 0x0000000000707b7f in handler::ha_inplace_alter_table (this=0x7f04bd845088, altered_table=0x7f04bd5a6070, ha_alter_info=0x7f04d351c260) at /data/src/10.0/sql/handler.h:3580
#10 0x00000000007003b1 in mysql_inplace_alter_table (thd=0x7f04c5b69070, table_list=0x7f04bd4fa160, table=0x7f04bd913c70, altered_table=0x7f04bd5a6070, ha_alter_info=0x7f04d351c260, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7f04d351bcb0, alter_ctx=0x7f04d351c840) at /data/src/10.0/sql/sql_table.cc:7117
#11 0x0000000000704ac7 in mysql_alter_table (thd=0x7f04c5b69070, new_db=0x7f04bd4fa740 "test", new_name=0x0, create_info=0x7f04d351d4e0, table_list=0x7f04bd4fa160, alter_info=0x7f04d351d450, order_num=0, order=0x0, ignore=false) at /data/src/10.0/sql/sql_table.cc:8948
#12 0x000000000076d365 in Sql_cmd_alter_table::execute (this=0x7f04bd4fa748, thd=0x7f04c5b69070) at /data/src/10.0/sql/sql_alter.cc:312
#13 0x000000000065398b in mysql_execute_command (thd=0x7f04c5b69070) at /data/src/10.0/sql/sql_parse.cc:5114
#14 0x0000000000656dc2 in mysql_parse (thd=0x7f04c5b69070, rawbuf=0x7f04bd4fa088 "ALTER TABLE t1 FORCE", length=20, parser_state=0x7f04d351e640) at /data/src/10.0/sql/sql_parse.cc:6569
#15 0x0000000000649901 in dispatch_command (command=COM_QUERY, thd=0x7f04c5b69070, packet=0x7f04cb5ef071 "ALTER TABLE t1 FORCE", packet_length=20) at /data/src/10.0/sql/sql_parse.cc:1296
#16 0x0000000000648c01 in do_command (thd=0x7f04c5b69070) at /data/src/10.0/sql/sql_parse.cc:999
#17 0x0000000000768ab8 in do_handle_one_connection (thd_arg=0x7f04c5b69070) at /data/src/10.0/sql/sql_connect.cc:1377
#18 0x000000000076882a in handle_one_connection (arg=0x7f04c5b69070) at /data/src/10.0/sql/sql_connect.cc:1292
#19 0x0000000000ac9564 in pfs_spawn_thread (arg=0x7f04c5b19670) at /data/src/10.0/storage/perfschema/pfs.cc:1861
#20 0x00007f04d315c494 in start_thread (arg=0x7f04d351f700) at pthread_create.c:333
#21 0x00007f04d151593f in clone () from /lib/x86_64-linux-gnu/libc.so.6
Reproducible on 10.0-10.3, and also on MySQL 5.6.
Not reproducible on 5.5 and on MySQL 5.7, 8.0.3.
CREATETABLE t1 (i INT UNSIGNED NULLUNIQUE) ENGINE=InnoDB;
--connect (con1,localhost,root,,test)
SET DEBUG_SYNC='row_log_table_apply1_before SIGNAL built WAIT_FOR log';
--send
ALTERTABLE t1 FORCE;
--connection default
SET DEBUG_SYNC='now WAIT_FOR built';
--error ER_DUP_ENTRY
INSERTINTO t1 VALUES (0),(0);
SET DEBUG_SYNC='now SIGNAL log';
--connection con1
--error ER_DUP_ENTRY
reap;
--disconnect con1
--connection default
SET DEBUG_SYNC='RESET';
DROPTABLE t1;
It does not crash in MySQL 5.7.9 or MySQL 5.7.20. But the assertion failure is triggered in MySQL 5.6.38, and in MariaDB 10.x (tested the most recent 10.0 and 10.2 today).
I do not see anything obvious in the MySQL 5.7 revision history that could have affected this.
Marko Mäkelä
added a comment - Deterministic test case:
--source include/have_innodb.inc
--source include/have_debug.inc
--source include/have_debug_sync.inc
CREATE TABLE t1 (i INT UNSIGNED NULL UNIQUE ) ENGINE=InnoDB;
--connect (con1,localhost,root,,test)
SET DEBUG_SYNC= 'row_log_table_apply1_before SIGNAL built WAIT_FOR log' ;
--send
ALTER TABLE t1 FORCE ;
--connection default
SET DEBUG_SYNC= 'now WAIT_FOR built' ;
--error ER_DUP_ENTRY
INSERT INTO t1 VALUES (0),(0);
SET DEBUG_SYNC= 'now SIGNAL log' ;
--connection con1
--error ER_DUP_ENTRY
reap;
--disconnect con1
--connection default
SET DEBUG_SYNC= 'RESET' ;
DROP TABLE t1;
It does not crash in MySQL 5.7.9 or MySQL 5.7.20. But the assertion failure is triggered in MySQL 5.6.38, and in MariaDB 10.x (tested the most recent 10.0 and 10.2 today).
I do not see anything obvious in the MySQL 5.7 revision history that could have affected this.
When comparing MySQL 5.7.9 to recent MariaDB, it occured to me that there was a fix in MySQL 5.6.28 and 5.7.10 for a very similar scenario (the difference being that a PRIMARY KEY was specified).
It turns out that this fix was merged incorrectly into MySQL 5.7.10. For some reason, the n_index+ statements were omitted, causing MySQL 5.7.10 to always incorrectly report the first key as the source of duplicates. Because the test case used a PRIMARY KEY, the error would incorrectly be reported to it, instead of the UNIQUE KEY.
It looks like this bug is a regression from the already mentioned upstream fix in MySQL 5.6.28, which was incorrectly merged to 5.7.10.
Marko Mäkelä
added a comment - It looks like this bug is a regression from the already mentioned upstream fix in MySQL 5.6.28, which was incorrectly merged to 5.7.10.
Do you have a test case? Test case from
MDEV-5406is in the test suite and it doesn't crash.