Details
-
Bug
-
Status: Closed (View Workflow)
-
Critical
-
Resolution: Fixed
-
10.0.23, 10.1.10, 10.2.0, 10.1.19, 10.3.0
-
10.2.12
Description
During OPTIMIZE TABLE a crash occurred with a backtrace that looks the same as in MDEV-5406.
The fix back then included a comment saying
HACK HACK HACK
|
|
Prepare the list of keys for an error message.
|
It must match what the engine does internally in ::add_index().
|
Here we emulate what innobase_create_key_def() does.
|
Luckily, in 10.0 this will go away.
|
The code indeed seems to have changed in 10.1, so maybe the problem resurfaced this way?
170514 2:50:40 [ERROR] mysqld got signal 11 ;
|
This could be because you hit a bug. It is also possible that this binary
|
or one of the libraries it was linked against is corrupt, improperly built,
|
or misconfigured. This error can also be caused by malfunctioning hardware.
|
|
|
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
|
|
|
We will try our best to scrape up some info that will hopefully help
|
diagnose the problem, but since we have already crashed,
|
something is definitely wrong and this may fail.
|
|
|
Server version: 10.1.19-MariaDB
|
key_buffer_size=16777216
|
read_buffer_size=262144
|
max_used_connections=525
|
max_threads=1002
|
thread_count=246
|
It is possible that mysqld could use up to
|
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 806479 K bytes of memory
|
Hope that's ok; if not, decrease some variables in the equation.
|
|
|
Thread pointer: 0x0x7f7d954eb008
|
Attempting backtrace. You can use the following information to find out
|
where mysqld died. If you see no messages after this, something went
|
terribly wrong...
|
stack_bottom = 0x7eef5265b208 thread_stack 0x48400
|
(my_addr_resolve failure: fork)
|
/apps/mariadb/instances/sysmdbblpfrm/bin/mysqld(my_print_stacktrace+0x2e) [0xc0e2fe]
|
/apps/mariadb/instances/sysmdbblpfrm/bin/mysqld(handle_fatal_signal+0x4ba) [0x76836a]
|
/lib64/libpthread.so.0() [0x3fe2a0f7e0]
|
/apps/mariadb/instances/sysmdbblpfrm/bin/mysqld(key_unpack(String*, TABLE*, st_key*)+0x95) [0x831c35]
|
/apps/mariadb/instances/sysmdbblpfrm/bin/mysqld(print_keydup_error(TABLE*, st_key*, char const*, unsigned long)+0x76) [0x76e136]
|
/apps/mariadb/instances/sysmdbblpfrm/bin/mysqld() [0x91c3e3]
|
/apps/mariadb/instances/sysmdbblpfrm/bin/mysqld() [0x63ce0b]
|
/apps/mariadb/instances/sysmdbblpfrm/bin/mysqld(mysql_alter_table(THD*, char*, char*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool)+0x3c42) [0x644812]
|
/apps/mariadb/instances/sysmdbblpfrm/bin/mysqld(mysql_recreate_table(THD*, TABLE_LIST*, bool)+0x196) [0x644a26]
|
/apps/mariadb/instances/sysmdbblpfrm/bin/mysqld() [0x69ba5e]
|
/apps/mariadb/instances/sysmdbblpfrm/bin/mysqld() [0x69d4da]
|
/apps/mariadb/instances/sysmdbblpfrm/bin/mysqld(Sql_cmd_optimize_table::execute(THD*)+0xe6) [0x69e5d6]
|
/apps/mariadb/instances/sysmdbblpfrm/bin/mysqld(mysql_execute_command(THD*)+0x13db) [0x5b38bb]
|
/apps/mariadb/instances/sysmdbblpfrm/bin/mysqld(mysql_parse(THD*, char*, unsigned int, Parser_state*)+0x354) [0x5bbe54]
|
/apps/mariadb/instances/sysmdbblpfrm/bin/mysqld() [0x5bbee8]
|
/apps/mariadb/instances/sysmdbblpfrm/bin/mysqld(dispatch_command(enum_server_command, THD*, char*, unsigned int)+0x14e5) [0x5bdfc5]
|
/apps/mariadb/instances/sysmdbblpfrm/bin/mysqld(do_command(THD*)+0x2a7) [0x5bf297]
|
/apps/mariadb/instances/sysmdbblpfrm/bin/mysqld(do_handle_one_connection(THD*)+0x183) [0x68e853]
|
/apps/mariadb/instances/sysmdbblpfrm/bin/mysqld(handle_one_connection+0x42) [0x68ea72]
|
/lib64/libpthread.so.0() [0x3fe2a07aa1]
|
/lib64/libc.so.6(clone+0x6d) [0x3fe22e8aad]
|
|
|
Trying to get some variables.
|
Some pointers may be invalid and cause the dump to abort.
|
Query (0x7f7d80b92020): OPTIMIZE TABLE some_db.some_table
|
Connection ID (thread ID): 10354269
|
Status: NOT_KILLED
|
|
|
Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=off
|
Attachments
Issue Links
- blocks
-
MDEV-13900 Testing for MDEV-11369 (instant ADD COLUMN)
-
- Closed
-
- is duplicated by
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
- relates to
-
-
- Closed
-
Activity
No, this was a single incident so far and we only have the error log snippet and backtrace above ...
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.
|
Test case |
# 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
|
|
|
CREATE OR REPLACE TABLE t1 (i INT UNIQUE) ENGINE=InnoDB; |
--send
|
OPTIMIZE TABLE t1; |
|
|
--connect (con1,localhost,root,,test)
|
--error ER_DUP_ENTRY
|
INSERT INTO t1 VALUES (1),(1); |
|
|
--connection default
|
--reap
|
|
|
# Cleanup
|
--disconnect con1
|
--connection default
|
DROP TABLE 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
|
#8 ha_innodb::commit_inplace_alter_table (this=0x7fef4b086020, altered_table=<optimized out>, ha_alter_info=<optimized out>, commit=<optimized out>) at /data/src/10.0/storage/innobase/handler/handler0alter.cc:5817
|
#9 0x000000000062044d in mysql_inplace_alter_table (target_mdl_request=<optimized out>, alter_ctx=<optimized out>, inplace_supported=<optimized out>, ha_alter_info=<optimized out>, altered_table=<optimized out>, table=<optimized out>, table_list=<optimized out>, thd=<optimized out>) at /data/src/10.0/sql/sql_table.cc:7145
|
#10 mysql_alter_table (thd=0x7fef53675008, new_db=0x7fef60d654b0 "\003", new_db@entry=0x0, new_name=0x7fef60d68000 "\200\221\326`\357\177", create_info=0x7fef60d690f0, table_list=0x7fef4b1c70f0, alter_info=0x7fef4b1c70f0, order_num=0, order=0x0, ignore=false) at /data/src/10.0/sql/sql_table.cc:8949
|
#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
|
|
10.0 78b63425a3f17214b debug |
mysqld: /data/src/10.0/storage/innobase/handler/handler0alter.cc:5118: bool commit_try_rebuild(Alter_inplace_info*, ha_innobase_inplace_ctx*, TABLE*, const TABLE*, trx_t*, const char*): Assertion `err_key < ha_alter_info->key_count' failed.
|
170924 16:12:09 [ERROR] mysqld got signal 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
|
#15 0x0000000000779135 in mysql_admin_table(THD *, TABLE_LIST *, HA_CHECK_OPT *, const char *, thr_lock_type, bool, bool, uint, int (*)(THD *, TABLE_LIST *, HA_CHECK_OPT *), struct {...}, int (*)(THD *, TABLE_LIST *, HA_CHECK_OPT *)) (thd=0x7f892df69070, tables=0x7f89258fa158, check_opt=0x7f892df6d830, operator_name=0xec8928 "optimize", lock_type=TL_WRITE, open_for_modify=false, repair_table_use_frm=false, extra_open_options=0, prepare_func=0x0, operator_func=(int (handler::*)(handler * const, THD *, HA_CHECK_OPT *)) 0x840c2e <handler::ha_optimize(THD*, st_ha_check_opt*)>, view_operator_func=0x0) at /data/src/10.0/sql/sql_admin.cc:913
|
#16 0x000000000077a18b in Sql_cmd_optimize_table::execute (this=0x7f89258fa740, thd=0x7f892df69070) at /data/src/10.0/sql/sql_admin.cc:1257
|
#17 0x0000000000652fba in mysql_execute_command (thd=0x7f892df69070) at /data/src/10.0/sql/sql_parse.cc:5123
|
#18 0x00000000006563f0 in mysql_parse (thd=0x7f892df69070, rawbuf=0x7f89258fa088 "OPTIMIZE TABLE t1", length=17, parser_state=0x7f893bde5640) at /data/src/10.0/sql/sql_parse.cc:6578
|
#19 0x0000000000648f1d in dispatch_command (command=COM_QUERY, thd=0x7f892df69070, packet=0x7f89339ef071 "", packet_length=17) at /data/src/10.0/sql/sql_parse.cc:1305
|
#20 0x0000000000648237 in do_command (thd=0x7f892df69070) at /data/src/10.0/sql/sql_parse.cc:999
|
#21 0x0000000000768052 in do_handle_one_connection (thd_arg=0x7f892df69070) at /data/src/10.0/sql/sql_connect.cc:1377
|
#22 0x0000000000767dc4 in handle_one_connection (arg=0x7f892df69070) at /data/src/10.0/sql/sql_connect.cc:1292
|
#23 0x0000000000ac8076 in pfs_spawn_thread (arg=0x7f892df19670) at /data/src/10.0/storage/perfschema/pfs.cc:1860
|
#24 0x00007f893ba23494 in start_thread (arg=0x7f893bde6700) at pthread_create.c:333
|
#25 0x00007f8939b6e93f in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
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.
Another variation that is possibly related to the same problem:
|
10.3 0c6ff122fa080f80c461f77585176c25c284e33d |
mysqld: /home/travis/src/sql/sql_admin.cc:1069: bool mysql_admin_table(THD*, TABLE_LIST*, HA_CHECK_OPT*, const char*, thr_lock_type, bool, bool, uint, int (*)(THD*, TABLE_LIST*, HA_CHECK_OPT*), int (handler::*)(THD*, HA_CHECK_OPT*), int (*)(THD*, TABLE_LIST*, HA_CHECK_OPT*)): Assertion `thd->is_error()' failed.
|
|
|
#5 0x00007f6269267028 in __GI_abort () at abort.c:89
|
#6 0x00007f626925cbf6 in __assert_fail_base (fmt=0x7f62693b1018 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x9e996b6d73 "thd->is_error()", file=file@entry=0x9e996b6780 "/home/travis/src/sql/sql_admin.cc", line=line@entry=1069, function=function@entry=0x9e996b70a0 <mysql_admin_table(THD*, TABLE_LIST*, st_ha_check_opt*, char const*, thr_lock_type, bool, bool, unsigned int, int (*)(THD*, TABLE_LIST*, st_ha_check_opt*), int (handler::*)(THD*, st_ha_check_opt*), int (*)(THD*, TABLE_LIST*, st_ha_check_opt*))::__PRETTY_FUNCTION__> "bool mysql_admin_table(THD*, TABLE_LIST*, HA_CHECK_OPT*, const char*, thr_lock_type, bool, bool, uint, int (*)(THD*, TABLE_LIST*, HA_CHECK_OPT*), int (handler::*)(THD*, HA_CHECK_OPT*), int (*)(THD*, T"...) at assert.c:92
|
#7 0x00007f626925cca2 in __GI___assert_fail (assertion=0x9e996b6d73 "thd->is_error()", file=0x9e996b6780 "/home/travis/src/sql/sql_admin.cc", line=1069, function=0x9e996b70a0 <mysql_admin_table(THD*, TABLE_LIST*, st_ha_check_opt*, char const*, thr_lock_type, bool, bool, unsigned int, int (*)(THD*, TABLE_LIST*, st_ha_check_opt*), int (handler::*)(THD*, st_ha_check_opt*), int (*)(THD*, TABLE_LIST*, st_ha_check_opt*))::__PRETTY_FUNCTION__> "bool mysql_admin_table(THD*, TABLE_LIST*, HA_CHECK_OPT*, const char*, thr_lock_type, bool, bool, uint, int (*)(THD*, TABLE_LIST*, HA_CHECK_OPT*), int (handler::*)(THD*, HA_CHECK_OPT*), int (*)(THD*, T"...) at assert.c:101
|
#8 0x0000009e98c8e571 in mysql_admin_table(THD *, TABLE_LIST *, HA_CHECK_OPT *, const char *, thr_lock_type, bool, bool, uint, int (*)(THD *, TABLE_LIST *, HA_CHECK_OPT *), struct {...}, int (*)(THD *, TABLE_LIST *, HA_CHECK_OPT *)) (thd=0x7f622400b1c0, tables=0x7f622401f720, check_opt=0x7f622400fdf0, operator_name=0x9e996b6ed0 "optimize", lock_type=TL_WRITE, open_for_modify=true, repair_table_use_frm=false, extra_open_options=0, prepare_func=0x0, operator_func=(int (handler::*)(handler * const, THD *, HA_CHECK_OPT *)) 0x9e98dff734 <handler::ha_optimize(THD*, st_ha_check_opt*)>, view_operator_func=0x0) at /home/travis/src/sql/sql_admin.cc:1069
|
#9 0x0000009e98c8f61d in Sql_cmd_optimize_table::execute (this=0x7f622401fd38, thd=0x7f622400b1c0) at /home/travis/src/sql/sql_admin.cc:1366
|
#10 0x0000009e98b31902 in mysql_execute_command (thd=0x7f622400b1c0) at /home/travis/src/sql/sql_parse.cc:6237
|
#11 0x0000009e98b36261 in mysql_parse (thd=0x7f622400b1c0, rawbuf=0x7f622401f608 "OPTIMIZE TABLE `PP_D` /* QNO 1381 CON_ID 18 */", length=46, parser_state=0x7f625017c620, is_com_multi=false, is_next_command=false) at /home/travis/src/sql/sql_parse.cc:7933
|
#12 0x0000009e98b23c78 in dispatch_command (command=COM_QUERY, thd=0x7f622400b1c0, packet=0x7f62240174d1 "", packet_length=47, is_com_multi=false, is_next_command=false) at /home/travis/src/sql/sql_parse.cc:1828
|
#13 0x0000009e98b226a5 in do_command (thd=0x7f622400b1c0) at /home/travis/src/sql/sql_parse.cc:1370
|
#14 0x0000009e98c7afee in do_handle_one_connection (connect=0x9e9c573880) at /home/travis/src/sql/sql_connect.cc:1420
|
#15 0x0000009e98c7ad7b in handle_one_connection (arg=0x9e9c573880) at /home/travis/src/sql/sql_connect.cc:1326
|
#16 0x00007f6269e1e184 in start_thread (arg=0x7f625017d700) at pthread_create.c:312
|
#17 0x00007f626932affd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
|
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.
git diff 449b27fc3205383c62f8c8005b9019be44c8c8b8{~,}| diff -I^@@ -u - <(git diff 449b27fc3205383c62f8c8005b9019be44c8c8b8^2{~,})
|
--- - 2017-12-21 15:44:32.788667258 +0200
|
+++ /dev/fd/63 2017-12-21 15:44:32.779964718 +0200
|
@@ -1,17 +1,16 @@
|
diff --git a/mysql-test/suite/innodb/r/innodb-alter-debug.result b/mysql-test/suite/innodb/r/innodb-alter-debug.result
|
-index 2c9cfe850a9..c6fa1ed0072 100644
|
+index 2c9cfe850a9..229808df1b4 100644
|
--- a/mysql-test/suite/innodb/r/innodb-alter-debug.result
|
+++ b/mysql-test/suite/innodb/r/innodb-alter-debug.result
|
-@@ -24,3 +24,32 @@ t1ć CREATE TABLE `t1ć` (
|
+@@ -24,3 +24,31 @@ t1ć CREATE TABLE `t1ć` (
|
CONSTRAINT `t1c2` FOREIGN KEY (`c2`) REFERENCES `â‘ ` (`c2`)
|
) ENGINE=InnoDB DEFAULT CHARSET=latin1
|
DROP TABLE t1ć, ①;
|
+#
|
-+# Bug #21364096 THE BOGUS DUPLICATE KEY ERROR IN ONLINE DDL
|
-+# WITH INCORRECT KEY NAME
|
-+create table t1 (id int auto_increment primary key,
|
-+a int,
|
-+unique key uk(a))engine=innodb;
|
++# Bug #21364096 THE BOGUS DUPLICATE KEY ERROR IN ONLINE DDL
|
++# WITH INCORRECT KEY NAME
|
++create table t1 (id int auto_increment primary key, a int, unique key uk(a))
|
++engine = innodb;
|
+insert into t1 select 1, 1;
|
+insert into t1 select 2, 2;
|
+SET DEBUG_SYNC = 'row_log_table_apply1_before SIGNAL s1 WAIT_FOR s2';
|
@@ -23,7 +22,7 @@
|
+SET DEBUG_SYNC = 'now SIGNAL s2';
|
+/* connection default */
|
+/* reap */ alter table t1 add b int, ALGORITHM=inplace;
|
-+ERROR 23000: Duplicate entry '3' for key 'PRIMARY'
|
++ERROR 23000: Duplicate entry '1' for key 'uk'
|
+SET DEBUG_SYNC = 'row_log_table_apply1_before SIGNAL s1 WAIT_FOR s2';
|
+alter table t1 add b int, ALGORITHM=inplace;;
|
+/* connection con1 */
|
@@ -33,10 +32,10 @@
|
+SET DEBUG_SYNC = 'now SIGNAL s2';
|
+/* connection default */
|
+/* reap */ alter table t1 add b int, ALGORITHM=inplace;
|
-+ERROR 23000: Duplicate entry '2' for key 'PRIMARY'
|
++ERROR 23000: Duplicate entry '1' for key 'uk'
|
+drop table t1;
|
diff --git a/mysql-test/suite/innodb/t/innodb-alter-debug.test b/mysql-test/suite/innodb/t/innodb-alter-debug.test
|
-index 48cef81df7e..59cc1307c84 100644
|
+index 48cef81df7e..5ab32ed14da 100644
|
--- a/mysql-test/suite/innodb/t/innodb-alter-debug.test
|
+++ b/mysql-test/suite/innodb/t/innodb-alter-debug.test
|
@@ -1,5 +1,8 @@
|
@@ -48,18 +47,17 @@
|
|
SET NAMES utf8;
|
|
-@@ -26,3 +29,50 @@ SET DEBUG = '-d,ib_rename_column_error';
|
+@@ -26,3 +29,49 @@ SET DEBUG = '-d,ib_rename_column_error';
|
SHOW CREATE TABLE t1ć;
|
|
DROP TABLE t1ć, ①;
|
+
|
+--echo #
|
-+--echo # Bug #21364096 THE BOGUS DUPLICATE KEY ERROR IN ONLINE DDL
|
-+--echo # WITH INCORRECT KEY NAME
|
++--echo # Bug #21364096 THE BOGUS DUPLICATE KEY ERROR IN ONLINE DDL
|
++--echo # WITH INCORRECT KEY NAME
|
+
|
-+create table t1 (id int auto_increment primary key,
|
-+ a int,
|
-+ unique key uk(a))engine=innodb;
|
++create table t1 (id int auto_increment primary key, a int, unique key uk(a))
|
++engine = innodb;
|
+insert into t1 select 1, 1;
|
+insert into t1 select 2, 2;
|
+SET DEBUG_SYNC = 'row_log_table_apply1_before SIGNAL s1 WAIT_FOR s2';
|
@@ -100,10 +98,10 @@
|
+# Wait till all disconnects are completed
|
+--source include/wait_until_count_sessions.inc
|
diff --git a/storage/innobase/row/row0log.cc b/storage/innobase/row/row0log.cc
|
-index b43207ac8fa..d6e2a139b75 100644
|
+index f88baa42d58..3989b669c28 100644
|
--- a/storage/innobase/row/row0log.cc
|
+++ b/storage/innobase/row/row0log.cc
|
-@@ -1613,6 +1613,7 @@ row_log_table_apply_insert_low(
|
+@@ -1454,6 +1454,7 @@ row_log_table_apply_insert_low(
|
dtuple_t* entry;
|
const row_log_t*log = dup->index->online_log;
|
dict_index_t* index = dict_table_get_first_index(log->table);
|
@@ -111,10 +109,19 @@
|
|
ut_ad(dtuple_validate(row));
|
ut_ad(trx_id);
|
-@@ -1658,6 +1659,12 @@ row_log_table_apply_insert_low(
|
+@@ -1489,6 +1490,8 @@ row_log_table_apply_insert_low(
|
+ }
|
+
|
+ do {
|
++ n_index++;
|
++
|
+ if (!(index = dict_table_get_next_index(index))) {
|
+ break;
|
+ }
|
+@@ -1501,6 +1504,12 @@ row_log_table_apply_insert_low(
|
+ error = row_ins_sec_index_entry_low(
|
flags, BTR_MODIFY_TREE,
|
- index, offsets_heap, heap, entry, trx_id, thr,
|
- false);
|
+ index, offsets_heap, heap, entry, trx_id, thr);
|
+
|
+ /* Report correct index name for duplicate key error. */
|
+ if (error == DB_DUPLICATE_KEY) {
|
@@ -132,9 +139,18 @@
|
|
ut_ad(dtuple_get_n_fields_cmp(old_pk)
|
== dict_index_get_n_unique(index));
|
-@@ -2308,6 +2316,11 @@ func_exit_committed:
|
+@@ -2083,6 +2093,8 @@ func_exit_committed:
|
+ break;
|
+ }
|
+
|
++ n_index++;
|
++
|
+ if (index->type & DICT_FTS) {
|
+ continue;
|
+ }
|
+@@ -2126,6 +2138,11 @@ func_exit_committed:
|
BTR_MODIFY_TREE, index, offsets_heap, heap,
|
- entry, trx_id, thr, false);
|
+ entry, trx_id, thr);
|
|
+ /* Report correct index name for duplicate key error. */
|
+ if (error == DB_DUPLICATE_KEY) {
|
@@ -142,5 +158,5 @@
|
+ }
|
+
|
mtr_start(&mtr);
|
- mtr.set_named_space(index->space);
|
}
|
+ |
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.