[MDEV-25360] Server crash, ASAN errors or assertion failure in dict_col_t::name upon DROP COLUMN after ER_FK_FAIL_ADD_SYSTEM Created: 2021-04-07  Updated: 2021-04-28  Resolved: 2021-04-28

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.4, 10.5, 10.6
Fix Version/s: 10.4.19, 10.5.10

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Thirunarayanan Balathandayuthapani
Resolution: Fixed Votes: 0
Labels: None


 Description    

--source include/have_innodb.inc
 
 
 
CREATE TABLE t1 (
 
  pk int,
 
  a int,
 
  primary key (pk),
 
  FOREIGN KEY fk (a) REFERENCES t1 (pk)
 
) ENGINE=InnoDB;
 
 
 
CREATE TABLE t2 (
 
 pk int,
 
 b int,
 
 c int,
 
 d int,
 
 key (b),
 
 primary key (pk,d)
 
) ENGINE=InnoDB;
 
 
 
ALTER TABLE t2 ADD e INT;
 
 
 
SET FOREIGN_KEY_CHECKS= 0;
 
--error ER_FK_FAIL_ADD_SYSTEM
 
ALTER TABLE t2 DROP COLUMN c, ADD FOREIGN KEY fk (pk) REFERENCES x (x);
 
ALTER TABLE t2 DROP e;
 
 
 
# Cleanup
 
DROP TABLE t2, t1;

10.5 81258f14 non-debug ASAN

 
=================================================================
 
==754926==ERROR: AddressSanitizer: use-after-poison on address 0x61b0000558f9 at pc 0x7f43f0fafa6d bp 0x7f43e1890ca0 sp 0x7f43e1890448
 
READ of size 18 at 0x61b0000558f9 thread T13
 
    #0 0x7f43f0fafa6c  (/lib/x86_64-linux-gnu/libasan.so.5+0x67a6c)
 
    #1 0x5598a666bbdb in dict_col_t::name(dict_table_t const&) const /data/src/10.5/storage/innobase/dict/dict0dict.cc:458
 
    #2 0x5598a618414f in dict_table_t::instant_column(dict_table_t const&, unsigned long const*) /data/src/10.5/storage/innobase/handler/handler0alter.cc:681
 
    #3 0x5598a6185769 in ha_innobase_inplace_ctx::instant_column() /data/src/10.5/storage/innobase/handler/handler0alter.cc:1054
 
    #4 0x5598a6185769 in innobase_instant_try /data/src/10.5/storage/innobase/handler/handler0alter.cc:5637
 
    #5 0x5598a618d24b in commit_try_norebuild(Alter_inplace_info*, ha_innobase_inplace_ctx*, TABLE*, TABLE const*, trx_t*, char const*) /data/src/10.5/storage/innobase/handler/handler0alter.cc:10316
 
    #6 0x5598a6161c9c in ha_innobase::commit_inplace_alter_table(TABLE*, Alter_inplace_info*, bool) /data/src/10.5/storage/innobase/handler/handler0alter.cc:11079
 
    #7 0x5598a51b9992 in mysql_inplace_alter_table /data/src/10.5/sql/sql_table.cc:8139
 
    #8 0x5598a51b9992 in mysql_alter_table(THD*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool, bool) /data/src/10.5/sql/sql_table.cc:10677
 
    #9 0x5598a52fe9ed in Sql_cmd_alter_table::execute(THD*) /data/src/10.5/sql/sql_alter.cc:539
 
    #10 0x5598a4f51692 in mysql_execute_command(THD*) /data/src/10.5/sql/sql_parse.cc:6049
 
    #11 0x5598a4f1781c in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.5/sql/sql_parse.cc:8093
 
    #12 0x5598a4f46158 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.5/sql/sql_parse.cc:1889
 
    #13 0x5598a4f4c001 in do_command(THD*) /data/src/10.5/sql/sql_parse.cc:1370
 
    #14 0x5598a52ed0bc in do_handle_one_connection(CONNECT*, bool) /data/src/10.5/sql/sql_connect.cc:1410
 
    #15 0x5598a52edc54 in handle_one_connection /data/src/10.5/sql/sql_connect.cc:1312
 
    #16 0x5598a5ee7078 in pfs_spawn_thread /data/src/10.5/storage/perfschema/pfs.cc:2201
 
    #17 0x7f43f0b05608 in start_thread /build/glibc-eX1tMB/glibc-2.31/nptl/pthread_create.c:477
 
    #18 0x7f43f06d9292 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x122292)
 
 
 
0x61b0000558f9 is located 889 bytes inside of 1616-byte region [0x61b000055580,0x61b000055bd0)
 
allocated by thread T13 here:
 
    #0 0x7f43f1055bc8 in malloc (/lib/x86_64-linux-gnu/libasan.so.5+0x10dbc8)
 
    #1 0x5598a627ffef in ut_allocator<unsigned char, true>::allocate(unsigned long, unsigned char const*, unsigned int, bool, bool) /data/src/10.5/storage/innobase/include/ut0new.h:377
 
    #2 0x5598a627ffef in mem_heap_create_block_func(mem_block_info_t*, unsigned long, unsigned long) /data/src/10.5/storage/innobase/mem/mem0mem.cc:277
 
    #3 0x5598a628055c in mem_heap_add_block(mem_block_info_t*, unsigned long) /data/src/10.5/storage/innobase/mem/mem0mem.cc:378
 
    #4 0x5598a66cee44 in mem_heap_alloc /data/src/10.5/storage/innobase/include/mem0mem.ic:191
 
    #5 0x5598a66cee44 in dict_mem_table_create(char const*, fil_space_t*, unsigned long, unsigned long, unsigned long, unsigned long) /data/src/10.5/storage/innobase/dict/dict0mem.cc:183
 
    #6 0x5598a611ecf6 in create_table_info_t::create_table_def() /data/src/10.5/storage/innobase/handler/ha_innodb.cc:10430
 
    #7 0x5598a6118d17 in create_table_info_t::create_table(bool) /data/src/10.5/storage/innobase/handler/ha_innodb.cc:12480
 
    #8 0x5598a6135b0b in ha_innobase::create(char const*, TABLE*, HA_CREATE_INFO*, bool, trx_t*) /data/src/10.5/storage/innobase/handler/ha_innodb.cc:13028
 
    #9 0x5598a5668285 in handler::ha_create(char const*, TABLE*, HA_CREATE_INFO*) /data/src/10.5/sql/handler.cc:5091
 
    #10 0x5598a5669e7b in ha_create_table(THD*, char const*, char const*, char const*, HA_CREATE_INFO*, st_mysql_const_unsigned_lex_string*) /data/src/10.5/sql/handler.cc:5556
 
    #11 0x5598a5196cba in create_table_impl /data/src/10.5/sql/sql_table.cc:5376
 
    #12 0x5598a5197565 in mysql_create_table_no_lock(THD*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, Table_specification_st*, Alter_info*, bool*, int, TABLE_LIST*) /data/src/10.5/sql/sql_table.cc:5460
 
    #13 0x5598a5197e3b in mysql_create_table(THD*, TABLE_LIST*, Table_specification_st*, Alter_info*) /data/src/10.5/sql/sql_table.cc:5564
 
    #14 0x5598a51a8d93 in Sql_cmd_create_table_like::execute(THD*) /data/src/10.5/sql/sql_table.cc:12141
 
    #15 0x5598a4f51692 in mysql_execute_command(THD*) /data/src/10.5/sql/sql_parse.cc:6049
 
    #16 0x5598a4f1781c in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.5/sql/sql_parse.cc:8093
 
    #17 0x5598a4f46158 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.5/sql/sql_parse.cc:1889
 
    #18 0x5598a4f4c001 in do_command(THD*) /data/src/10.5/sql/sql_parse.cc:1370
 
    #19 0x5598a52ed0bc in do_handle_one_connection(CONNECT*, bool) /data/src/10.5/sql/sql_connect.cc:1410
 
    #20 0x5598a52edc54 in handle_one_connection /data/src/10.5/sql/sql_connect.cc:1312
 
    #21 0x5598a5ee7078 in pfs_spawn_thread /data/src/10.5/storage/perfschema/pfs.cc:2201
 
    #22 0x7f43f0b05608 in start_thread /build/glibc-eX1tMB/glibc-2.31/nptl/pthread_create.c:477
 
 
 
Thread T13 created by T0 here:
 
    #0 0x7f43f0f82805 in pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x3a805)
 
    #1 0x5598a5ee7316 in my_thread_create /data/src/10.5/storage/perfschema/my_thread.h:38
 
    #2 0x5598a5ee7316 in pfs_spawn_thread_v1 /data/src/10.5/storage/perfschema/pfs.cc:2252
 
    #3 0x5598a4ca09ee in inline_mysql_thread_create /data/src/10.5/include/mysql/psi/mysql_thread.h:1323
 
    #4 0x5598a4ca09ee in create_thread_to_handle_connection(CONNECT*) /data/src/10.5/sql/mysqld.cc:6012
 
    #5 0x5598a4cac544 in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /data/src/10.5/sql/mysqld.cc:6136
 
    #6 0x5598a4cacf62 in handle_connections_sockets() /data/src/10.5/sql/mysqld.cc:6263
 
    #7 0x5598a4caebc3 in mysqld_main(int, char**) /data/src/10.5/sql/mysqld.cc:5658
 
    #8 0x7f43f05de0b2 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x270b2)
 
 
 
SUMMARY: AddressSanitizer: use-after-poison (/lib/x86_64-linux-gnu/libasan.so.5+0x67a6c) 
Shadow bytes around the buggy address:
 
  0x0c3680002ac0: f7 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0c3680002ad0: 00 00 00 00 00 00 00 00 00 00 00 00 00 f7 f7 00
 
  0x0c3680002ae0: 00 00 00 00 00 00 00 00 00 00 f7 00 00 00 00 00
 
  0x0c3680002af0: 01 f7 00 00 00 00 00 03 f7 00 00 00 00 00 00 00
 
  0x0c3680002b00: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
=>0x0c3680002b10: 00 00 00 00 00 00 00 00 00 f7 00 00 00 00 00[01]
 
  0x0c3680002b20: f7 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0c3680002b30: 00 00 00 00 00 00 00 00 00 00 00 00 00 f7 00 00
 
  0x0c3680002b40: 00 f7 00 00 00 00 f7 06 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c3680002b50: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c3680002b60: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
Shadow byte legend (one shadow byte represents 8 application bytes):
 
  Addressable:           00
 
  Partially addressable: 01 02 03 04 05 06 07 
  Heap left redzone:       fa
 
  Freed heap region:       fd
 
  Stack left redzone:      f1
 
  Stack mid redzone:       f2
 
  Stack right redzone:     f3
 
  Stack after return:      f5
 
  Stack use after scope:   f8
 
  Global redzone:          f9
 
  Global init order:       f6
 
  Poisoned by user:        f7
 
  Container overflow:      fc
 
  Array cookie:            ac
 
  Intra object redzone:    bb
 
  ASan internal:           fe
 
  Left alloca redzone:     ca
 
  Right alloca redzone:    cb
 
  Shadow gap:              cc
 
==754926==ABORTING
 
210407 16:46:10 [ERROR] mysqld got signal 6 ;
 
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.5.10-MariaDB-log
 
key_buffer_size=1048576
 
read_buffer_size=131072
 
max_used_connections=1
 
max_threads=153
 
thread_count=1
 
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63646 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x62b00009a218
 
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 = 0x7f43e189a800 thread_stack 0x5fc00
 
??:0(__interceptor_tcgetattr)[0x7f43f0fb4d30]
 
/mnt-hd8t/bld/10.5-rel-asan-nightly/bin/mariadbd(my_print_stacktrace+0xf6)[0x5598a69ec186]
 
/mnt-hd8t/bld/10.5-rel-asan-nightly/bin/mariadbd(handle_fatal_signal+0xb44)[0x5598a5647b64]
 
sigaction.c:0(__restore_rt)[0x7f43f0b113c0]
 
??:0(gsignal)[0x7f43f05fd18b]
 
??:0(abort)[0x7f43f05dc859]
 
??:0(__sanitizer_set_report_fd)[0x7f43f10736a2]
 
??:0(__sanitizer_get_module_and_offset_for_pc)[0x7f43f107e24c]
 
??:0(__sanitizer_ptr_cmp)[0x7f43f105f8ec]
 
??:0(__asan_on_error)[0x7f43f105f363]
 
??:0(__interceptor_xdr_longlong_t)[0x7f43f0fafa8c]
 
dict/dict0dict.cc:458(dict_col_t::name(dict_table_t const&) const)[0x5598a666bbdc]
 
include/dict0mem.h:509(id_name_t::operator=(char const*))[0x5598a6184150]
 
handler/handler0alter.cc:1054(ha_innobase_inplace_ctx::instant_column())[0x5598a618576a]
 
handler/handler0alter.cc:10316(commit_try_norebuild(Alter_inplace_info*, ha_innobase_inplace_ctx*, TABLE*, TABLE const*, trx_t*, char const*))[0x5598a618d24c]
 
handler/handler0alter.cc:11054(ha_innobase::commit_inplace_alter_table(TABLE*, Alter_inplace_info*, bool))[0x5598a6161c9d]
 
sql/sql_table.cc:8139(mysql_alter_table(THD*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool, bool))[0x5598a51b9993]
 
sql/sql_alter.cc:539(Sql_cmd_alter_table::execute(THD*))[0x5598a52fe9ee]
 
sql/sql_parse.cc:6049(mysql_execute_command(THD*))[0x5598a4f51693]
 
sql/sql_parse.cc:8110(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x5598a4f1781d]
 
sql/sql_parse.cc:1892(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x5598a4f46159]
 
sql/sql_parse.cc:1370(do_command(THD*))[0x5598a4f4c002]
 
sql/sql_connect.cc:1410(do_handle_one_connection(CONNECT*, bool))[0x5598a52ed0bd]
 
sql/sql_connect.cc:1312(handle_one_connection)[0x5598a52edc55]
 
perfschema/pfs.cc:2204(pfs_spawn_thread)[0x5598a5ee7079]
 
nptl/pthread_create.c:478(start_thread)[0x7f43f0b05609]
 
??:0(clone)[0x7f43f06d9293]
 
 
 
Trying to get some variables.
 
Some pointers may be invalid and cause the dump to abort.
 
Query (0x62b0000a1238): ALTER TABLE t2 DROP e
 
 
 
Connection ID (thread ID): 4
 
Status: NOT_KILLED

10.5 81258f14 debug

 
mariadbd: /data/src/10.5/storage/innobase/dict/dict0dict.cc:452: const char* dict_col_t::name(const dict_table_t&) const: Assertion `col_nr < table.n_def' failed.
 
210407 16:47:11 [ERROR] mysqld got signal 6 ;
 
 
 
#7  0x00007f609675ef36 in __GI___assert_fail (assertion=0x557e23d03c07 "col_nr < table.n_def", file=0x557e23d038f0 "/data/src/10.5/storage/innobase/dict/dict0dict.cc", line=452, function=0x557e23d03bb8 "const char* dict_col_t::name(const dict_table_t&) const") at assert.c:101
 
#8  0x0000557e2365e4f9 in dict_col_t::name (this=0x7f6060224550, table=...) at /data/src/10.5/storage/innobase/dict/dict0dict.cc:452
 
#9  0x0000557e2336c9ce in dict_table_t::instant_column (this=0x7f6060223f58, table=..., col_map=0x7f606013f998) at /data/src/10.5/storage/innobase/handler/handler0alter.cc:681
 
#10 0x0000557e2336e5c3 in ha_innobase_inplace_ctx::instant_column (this=0x7f6060017078) at /data/src/10.5/storage/innobase/handler/handler0alter.cc:1054
 
#11 0x0000557e2334bfec in innobase_instant_try (ha_alter_info=0x7f60903048e0, ctx=0x7f6060017078, altered_table=0x7f6090304980, table=0x7f6060216618, trx=0x7f6090db3360) at /data/src/10.5/storage/innobase/handler/handler0alter.cc:5637
 
#12 0x0000557e2337202e in commit_try_norebuild (ha_alter_info=0x7f60903048e0, ctx=0x7f6060017078, altered_table=0x7f6090304980, old_table=0x7f6060216618, trx=0x7f6090db3360, table_name=0x7f6060043d15 "t2") at /data/src/10.5/storage/innobase/handler/handler0alter.cc:10316
 
#13 0x0000557e2335fb9d in ha_innobase::commit_inplace_alter_table (this=0x7f6060041ec0, altered_table=0x7f6090304980, ha_alter_info=0x7f60903048e0, commit=true) at /data/src/10.5/storage/innobase/handler/handler0alter.cc:11079
 
#14 0x0000557e22e8f14c in handler::ha_commit_inplace_alter_table (this=0x7f6060041ec0, altered_table=0x7f6090304980, ha_alter_info=0x7f60903048e0, commit=true) at /data/src/10.5/sql/handler.cc:4855
 
#15 0x0000557e22c1816e in mysql_inplace_alter_table (thd=0x7f6060000db8, table_list=0x7f60600153c0, table=0x7f6060216618, altered_table=0x7f6090304980, ha_alter_info=0x7f60903048e0, target_mdl_request=0x7f6090304d50, alter_ctx=0x7f60903058a0) at /data/src/10.5/sql/sql_table.cc:8139
 
#16 0x0000557e22c1fc24 in mysql_alter_table (thd=0x7f6060000db8, new_db=0x7f6060005810, new_name=0x7f6060005c30, create_info=0x7f60903064b0, table_list=0x7f60600153c0, alter_info=0x7f60903063e0, order_num=0, order=0x0, ignore=false, if_exists=false) at /data/src/10.5/sql/sql_table.cc:10677
 
#17 0x0000557e22cc8020 in Sql_cmd_alter_table::execute (this=0x7f6060015ac0, thd=0x7f6060000db8) at /data/src/10.5/sql/sql_alter.cc:539
 
#18 0x0000557e22b1e270 in mysql_execute_command (thd=0x7f6060000db8) at /data/src/10.5/sql/sql_parse.cc:6049
 
#19 0x0000557e22b24494 in mysql_parse (thd=0x7f6060000db8, rawbuf=0x7f60600152f0 "ALTER TABLE t2 DROP e", length=21, parser_state=0x7f6090307510, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:8093
 
#20 0x0000557e22b1035f in dispatch_command (command=COM_QUERY, thd=0x7f6060000db8, packet=0x7f606000b5a9 "ALTER TABLE t2 DROP e", packet_length=21, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:1889
 
#21 0x0000557e22b0eb53 in do_command (thd=0x7f6060000db8) at /data/src/10.5/sql/sql_parse.cc:1370
 
#22 0x0000557e22cbd3e3 in do_handle_one_connection (connect=0x557e25737f88, put_in_cache=true) at /data/src/10.5/sql/sql_connect.cc:1410
 
#23 0x0000557e22cbd146 in handle_one_connection (arg=0x557e256fb308) at /data/src/10.5/sql/sql_connect.cc:1312
 
#24 0x0000557e23221077 in pfs_spawn_thread (arg=0x557e25737bb8) at /data/src/10.5/storage/perfschema/pfs.cc:2201
 
#25 0x00007f6096c76609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#26 0x00007f609684a293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Reproducible on 10.4-10.6, at least as far back as 10.4.6 (I didn't check further).
Not reproducible on 10.3.

 Comments   
Comment by Thirunarayanan Balathandayuthapani [ 2021-04-26 ]

Patch is in bb-10.4-thiru

Comment by Marko Mäkelä [ 2021-04-27 ]

Thank you, the fix looks correct to me.

Comment by Thirunarayanan Balathandayuthapani [ 2021-04-28 ]

Pushed the patch with wrong MDEV# In commit message. Sorry for that.

commit 4cd92143eae9b397589e5b449d1a85c43b3e4f6b (HEAD -> 10.4, origin/bb-10.4-MDEV-25630, origin/HEAD, origin/10.4, 10.4-test)
 
Author: Thirunarayanan Balathandayuthapani <thiru@mariadb.com>
 
Date:   Wed Apr 28 03:56:24 2021 +0530
 
 
 
    MDEV-25630 Rollback of instant operation adds wrong column to secondary index

Generated at Thu Feb 08 09:37:06 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.