[MDEV-23686] ASAN heap-use-after-free or server crash in id_name_t::operator / get_foreign_key_info / ha_innobase::get_parent_foreign_key_list Created: 2020-09-07  Updated: 2023-04-27

Status: Confirmed
Project: MariaDB Server
Component/s: Locking
Affects Version/s: 10.1, 10.2, 10.3, 10.4
Fix Version/s: 10.4

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Sergei Golubchik
Resolution: Unresolved Votes: 0
Labels: rr-profile-analyzed

Issue Links:
Relates
relates to MDEV-18259 ASAN heap-use-after-free or server cr... Closed
relates to MDEV-19194 Server crash or ASAN use-after-poison... Confirmed

 Description   

The provided test case only fails for me on 10.1-10.2, but a similar failure has been observed on 10.3-10.4 versions, see comments. I have no records so far of it happening on 10.5.

Run with --repeat=N. The failure is well reproducible for me on current 10.2 with ASAN builds, usually on the first attempt and always within 5-10 runs, but it can vary on different machines and builds.

--source include/have_innodb.inc
 
 
 
CREATE TABLE t1 (
 
  pk INT,
 
  a INT NOT NULL,
 
  PRIMARY KEY (pk),
 
  FOREIGN KEY fk1 (a) REFERENCES t1 (pk)
 
) ENGINE=InnoDB;
 
 
 
CREATE TABLE t2 (
 
  pk INT PRIMARY KEY,
 
  FOREIGN KEY fk2 (pk) REFERENCES t1 (a)
 
) ENGINE=InnoDB;
 
 
 
CREATE TABLE t3 (pk INT PRIMARY KEY) ENGINE=InnoDB;
 
 
 
--connect (con1,localhost,root,,test)
 
--send
 
  ALTER TABLE t2 ADD b INT;
 
 
 
--connection default
 
SET FOREIGN_KEY_CHECKS= OFF;
 
--error ER_FK_INCORRECT_OPTION
 
ALTER TABLE t1 ADD FOREIGN KEY fk3 (a) REFERENCES t3 (pk) ON DELETE SET NULL;
 
LOCK TABLE t1 WRITE;
 
 
 
# Cleanup
 
--disconnect con1
 
UNLOCK TABLES;
 
DROP TABLE t1, t2, t3;

10.2 9dedba16

 
==1627217==ERROR: AddressSanitizer: heap-use-after-free on address 0x617000039298 at pc 0x556e295adae9 bp 0x7f508c580a20 sp 0x7f508c580a10
 
READ of size 8 at 0x617000039298 thread T27
 
    #0 0x556e295adae8 in id_name_t::operator char const*() const /data/src/10.2/storage/innobase/include/dict0mem.h:541
 
    #1 0x556e2958ce2d in get_foreign_key_info /data/src/10.2/storage/innobase/handler/ha_innodb.cc:15358
 
    #2 0x556e2958d9fc in ha_innobase::get_parent_foreign_key_list(THD*, List<st_foreign_key_info>*) /data/src/10.2/storage/innobase/handler/ha_innodb.cc:15439
 
    #3 0x556e288e7601 in DML_prelocking_strategy::handle_table(THD*, Query_tables_list*, TABLE_LIST*, bool*) /data/src/10.2/sql/sql_base.cc:4389
 
    #4 0x556e288e7e69 in Lock_tables_prelocking_strategy::handle_table(THD*, Query_tables_list*, TABLE_LIST*, bool*) /data/src/10.2/sql/sql_base.cc:4493
 
    #5 0x556e288e1fe4 in extend_table_list(THD*, TABLE_LIST*, Prelocking_strategy*, bool) /data/src/10.2/sql/sql_base.cc:3350
 
    #6 0x556e288e3772 in open_and_process_table /data/src/10.2/sql/sql_base.cc:3663
 
    #7 0x556e288e57cd in open_tables(THD*, DDL_options_st const&, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*) /data/src/10.2/sql/sql_base.cc:4076
 
    #8 0x556e289ef06b in open_tables /data/src/10.2/sql/sql_base.h:248
 
    #9 0x556e289fdde3 in lock_tables_open_and_lock_tables /data/src/10.2/sql/sql_parse.cc:2816
 
    #10 0x556e28a09cb4 in mysql_execute_command(THD*) /data/src/10.2/sql/sql_parse.cc:4649
 
    #11 0x556e28a1ef47 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.2/sql/sql_parse.cc:7733
 
    #12 0x556e289f8242 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.2/sql/sql_parse.cc:1823
 
    #13 0x556e289f501e in do_command(THD*) /data/src/10.2/sql/sql_parse.cc:1377
 
    #14 0x556e28d78735 in do_handle_one_connection(CONNECT*) /data/src/10.2/sql/sql_connect.cc:1336
 
    #15 0x556e28d77ff8 in handle_one_connection /data/src/10.2/sql/sql_connect.cc:1241
 
    #16 0x556e2a0fe0f5 in pfs_spawn_thread /data/src/10.2/storage/perfschema/pfs.cc:1869
 
    #17 0x7f50a3128608 in start_thread /build/glibc-YYA7BZ/glibc-2.31/nptl/pthread_create.c:477
 
    #18 0x7f50a2d02102 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x122102)
 
 
 
0x617000039298 is located 152 bytes inside of 680-byte region [0x617000039200,0x6170000394a8)
 
freed by thread T27 here:
 
    #0 0x7f50a32957cf in __interceptor_free (/lib/x86_64-linux-gnu/libasan.so.5+0x10d7cf)
 
    #1 0x556e296f8e72 in mem_heap_block_free(mem_block_info_t*, mem_block_info_t*) /data/src/10.2/storage/innobase/mem/mem0mem.cc:428
 
    #2 0x556e29b7f233 in mem_heap_free /data/src/10.2/storage/innobase/include/mem0mem.ic:416
 
    #3 0x556e29b86219 in dict_mem_index_free(dict_index_t*) /data/src/10.2/storage/innobase/dict/dict0mem.cc:1081
 
    #4 0x556e29b3d9a4 in dict_index_remove_from_cache_low /data/src/10.2/storage/innobase/dict/dict0dict.cc:2420
 
    #5 0x556e29b3d9d2 in dict_index_remove_from_cache(dict_table_t*, dict_index_t*) /data/src/10.2/storage/innobase/dict/dict0dict.cc:2431
 
    #6 0x556e29811664 in row_merge_drop_indexes(trx_t*, dict_table_t*, unsigned long) /data/src/10.2/storage/innobase/row/row0merge.cc:3870
 
    #7 0x556e295fe875 in innobase_rollback_sec_index /data/src/10.2/storage/innobase/handler/handler0alter.cc:6471
 
    #8 0x556e29608077 in ha_innobase::commit_inplace_alter_table(TABLE*, Alter_inplace_info*, bool) /data/src/10.2/storage/innobase/handler/handler0alter.cc:8577
 
    #9 0x556e29052282 in handler::ha_commit_inplace_alter_table(TABLE*, Alter_inplace_info*, bool) /data/src/10.2/sql/handler.cc:4378
 
    #10 0x556e28c3377a in mysql_inplace_alter_table /data/src/10.2/sql/sql_table.cc:7480
 
    #11 0x556e28c42cbe in mysql_alter_table(THD*, char*, char*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool) /data/src/10.2/sql/sql_table.cc:9622
 
    #12 0x556e28d8817d in Sql_cmd_alter_table::execute(THD*) /data/src/10.2/sql/sql_alter.cc:333
 
    #13 0x556e28a1353b in mysql_execute_command(THD*) /data/src/10.2/sql/sql_parse.cc:5964
 
    #14 0x556e28a1ef47 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.2/sql/sql_parse.cc:7733
 
    #15 0x556e289f8242 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.2/sql/sql_parse.cc:1823
 
    #16 0x556e289f501e in do_command(THD*) /data/src/10.2/sql/sql_parse.cc:1377
 
    #17 0x556e28d78735 in do_handle_one_connection(CONNECT*) /data/src/10.2/sql/sql_connect.cc:1336
 
    #18 0x556e28d77ff8 in handle_one_connection /data/src/10.2/sql/sql_connect.cc:1241
 
    #19 0x556e2a0fe0f5 in pfs_spawn_thread /data/src/10.2/storage/perfschema/pfs.cc:1869
 
    #20 0x7f50a3128608 in start_thread /build/glibc-YYA7BZ/glibc-2.31/nptl/pthread_create.c:477
 
 
 
previously allocated by thread T27 here:
 
    #0 0x7f50a3295bc8 in malloc (/lib/x86_64-linux-gnu/libasan.so.5+0x10dbc8)
 
    #1 0x556e296f83c3 in mem_heap_create_block_func(mem_block_info_t*, unsigned long, char const*, unsigned int, unsigned long) /data/src/10.2/storage/innobase/mem/mem0mem.cc:289
 
    #2 0x556e296f8c46 in mem_heap_add_block(mem_block_info_t*, unsigned long) /data/src/10.2/storage/innobase/mem/mem0mem.cc:390
 
    #3 0x556e29b7ef2f in mem_heap_alloc /data/src/10.2/storage/innobase/include/mem0mem.ic:191
 
    #4 0x556e29b7edf6 in mem_heap_zalloc /data/src/10.2/storage/innobase/include/mem0mem.ic:160
 
    #5 0x556e29b83e3c in dict_mem_index_create(char const*, char const*, unsigned long, unsigned long, unsigned long) /data/src/10.2/storage/innobase/dict/dict0mem.cc:743
 
    #6 0x556e29b408a6 in dict_index_build_internal_non_clust /data/src/10.2/storage/innobase/dict/dict0dict.cc:2902
 
    #7 0x556e29b3c79e in dict_index_add_to_cache(dict_table_t*, dict_index_t*&, unsigned long, dict_add_v_col_t const*) /data/src/10.2/storage/innobase/dict/dict0dict.cc:2270
 
    #8 0x556e29b22266 in dict_create_index_step(que_thr_t*) /data/src/10.2/storage/innobase/dict/dict0crea.cc:1485
 
    #9 0x556e29784043 in que_thr_step /data/src/10.2/storage/innobase/que/que0que.cc:1052
 
    #10 0x556e2978436e in que_run_threads_low /data/src/10.2/storage/innobase/que/que0que.cc:1104
 
    #11 0x556e29784734 in que_run_threads(que_thr_t*) /data/src/10.2/storage/innobase/que/que0que.cc:1144
 
    #12 0x556e2981393e in row_merge_create_index_graph /data/src/10.2/storage/innobase/row/row0merge.cc:4335
 
    #13 0x556e2981433c in row_merge_create_index(trx_t*, dict_table_t*, index_def_t const*, dict_add_v_col_t const*) /data/src/10.2/storage/innobase/row/row0merge.cc:4406
 
    #14 0x556e295f1bf3 in prepare_inplace_alter_table_dict /data/src/10.2/storage/innobase/handler/handler0alter.cc:4841
 
    #15 0x556e295fb61b in ha_innobase::prepare_inplace_alter_table(TABLE*, Alter_inplace_info*) /data/src/10.2/storage/innobase/handler/handler0alter.cc:6048
 
    #16 0x556e290520cd in handler::ha_prepare_inplace_alter_table(TABLE*, Alter_inplace_info*) /data/src/10.2/sql/handler.cc:4358
 
    #17 0x556e28c3322d in mysql_inplace_alter_table /data/src/10.2/sql/sql_table.cc:7420
 
    #18 0x556e28c42cbe in mysql_alter_table(THD*, char*, char*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool) /data/src/10.2/sql/sql_table.cc:9622
 
    #19 0x556e28d8817d in Sql_cmd_alter_table::execute(THD*) /data/src/10.2/sql/sql_alter.cc:333
 
    #20 0x556e28a1353b in mysql_execute_command(THD*) /data/src/10.2/sql/sql_parse.cc:5964
 
    #21 0x556e28a1ef47 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.2/sql/sql_parse.cc:7733
 
    #22 0x556e289f8242 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.2/sql/sql_parse.cc:1823
 
    #23 0x556e289f501e in do_command(THD*) /data/src/10.2/sql/sql_parse.cc:1377
 
    #24 0x556e28d78735 in do_handle_one_connection(CONNECT*) /data/src/10.2/sql/sql_connect.cc:1336
 
    #25 0x556e28d77ff8 in handle_one_connection /data/src/10.2/sql/sql_connect.cc:1241
 
    #26 0x556e2a0fe0f5 in pfs_spawn_thread /data/src/10.2/storage/perfschema/pfs.cc:1869
 
    #27 0x7f50a3128608 in start_thread /build/glibc-YYA7BZ/glibc-2.31/nptl/pthread_create.c:477
 
 
 
Thread T27 created by T0 here:
 
    #0 0x7f50a31c2805 in pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x3a805)
 
    #1 0x556e2a0fe4e6 in spawn_thread_v1 /data/src/10.2/storage/perfschema/pfs.cc:1919
 
    #2 0x556e2879cf67 in inline_mysql_thread_create /data/src/10.2/include/mysql/psi/mysql_thread.h:1246
 
    #3 0x556e287b48f7 in create_thread_to_handle_connection(CONNECT*) /data/src/10.2/sql/mysqld.cc:6518
 
    #4 0x556e287b5088 in create_new_thread /data/src/10.2/sql/mysqld.cc:6588
 
    #5 0x556e287b6213 in handle_connections_sockets() /data/src/10.2/sql/mysqld.cc:6846
 
    #6 0x556e287b3c69 in mysqld_main(int, char**) /data/src/10.2/sql/mysqld.cc:6137
 
    #7 0x556e2879b84c in main /data/src/10.2/sql/main.cc:25
 
    #8 0x7f50a2c070b2 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x270b2)
 
 
 
SUMMARY: AddressSanitizer: heap-use-after-free /data/src/10.2/storage/innobase/include/dict0mem.h:541 in id_name_t::operator char const*() const
 
Shadow bytes around the buggy address:
 
  0x0c2e7ffff200: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c2e7ffff210: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c2e7ffff220: fd fd fd fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c2e7ffff230: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c2e7ffff240: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
=>0x0c2e7ffff250: fd fd fd[fd]fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c2e7ffff260: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c2e7ffff270: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c2e7ffff280: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c2e7ffff290: fd fd fd fd fd fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c2e7ffff2a0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
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
 
==1627217==ABORTING

Reproducible on 10.1, 10.2.
Couldn't reproduce on 10.3-10.5.
Non-ASAN builds have been seen crashing a similar way with non-simplified versions of the test case.
rr profile is available.

 Comments   
Comment by Elena Stepanova [ 2020-09-07 ]

Here is a stack trace of a similar crash in concurrent tests on 10.4, even though the test case in the description doesn't fail on 10.4:

10.4 571764c0

 
#3  <signal handler called>
 
#4  0x00007f6ea699c901 in __strlen_sse2_pminub () from /lib64/libc.so.6
 
#5  0x000055cd9cfe6365 in get_foreign_key_info (thd=0x7f6e28000af0, foreign=0x7f6e0c02c280) at /home/elenst/src/10.4/storage/innobase/handler/ha_innodb.cc:15083
 
#6  0x000055cd9cfe6659 in ha_innobase::get_parent_foreign_key_list (this=0x7f6e141991c8, thd=0x7f6e28000af0, f_key_list=0x7f6e90dc6810) at /home/elenst/src/10.4/storage/innobase/handler/ha_innodb.cc:15158
 
#7  0x000055cd9c9426d9 in DML_prelocking_strategy::handle_table (this=0x7f6e90dc6b70, thd=0x7f6e28000af0, prelocking_ctx=0x7f6e28004960, table_list=0x7f6e28011ef8, need_prelocking=0x7f6e90dc68dd) at /home/elenst/src/10.4/sql/sql_base.cc:4738
 
#8  0x000055cd9c93fc0c in extend_table_list (thd=0x7f6e28000af0, tables=0x7f6e28011ef8, prelocking_strategy=0x7f6e90dc6b70, has_prelocking_list=false) at /home/elenst/src/10.4/sql/sql_base.cc:3633
 
#9  0x000055cd9c940762 in open_and_process_table (thd=0x7f6e28000af0, tables=0x7f6e28011ef8, counter=0x7f6e90dc6af4, flags=0, prelocking_strategy=0x7f6e90dc6b70, has_prelocking_list=false, ot_ctx=0x7f6e90dc6a60) at /home/elenst/src/10.4/sql/sql_base.cc:3947
 
#10 0x000055cd9c941806 in open_tables (thd=0x7f6e28000af0, options=..., start=0x7f6e90dc6ad8, counter=0x7f6e90dc6af4, flags=0, prelocking_strategy=0x7f6e90dc6b70) at /home/elenst/src/10.4/sql/sql_base.cc:4367
 
#11 0x000055cd9c94398e in open_and_lock_tables (thd=0x7f6e28000af0, options=..., tables=0x7f6e28011ef8, derived=true, flags=0, prelocking_strategy=0x7f6e90dc6b70) at /home/elenst/src/10.4/sql/sql_base.cc:5269
 
#12 0x000055cd9c8fd1a9 in open_and_lock_tables (thd=0x7f6e28000af0, tables=0x7f6e28011ef8, derived=true, flags=0) at /home/elenst/src/10.4/sql/sql_base.h:505
 
#13 0x000055cd9c9e4c1a in mysql_execute_command (thd=0x7f6e28000af0) at /home/elenst/src/10.4/sql/sql_parse.cc:4598
 
#14 0x000055cd9c9efc7b in mysql_parse (thd=0x7f6e28000af0, rawbuf=0x7f6e28011d58 "INSERT /* QNO 3667 CON_ID 17 */ INTO `table_merge_child` SELECT * FROM `alt_t4`", length=79, parser_state=0x7f6e90dc75c0, is_com_multi=false, is_next_command=false) at /home/elenst/src/10.4/sql/sql_parse.cc:7896
 
#15 0x000055cd9c9dc32e in dispatch_command (command=COM_QUERY, thd=0x7f6e28000af0, packet=0x7f6e28008291 "INSERT /* QNO 3667 CON_ID 17 */ INTO `table_merge_child` SELECT * FROM `alt_t4`", packet_length=79, is_com_multi=false, is_next_command=false) at /home/elenst/src/10.4/sql/sql_parse.cc:1835
 
#16 0x000055cd9c9daa14 in do_command (thd=0x7f6e28000af0) at /home/elenst/src/10.4/sql/sql_parse.cc:1353
 
#17 0x000055cd9cb66a16 in do_handle_one_connection (connect=0x55cda0c8f5f0) at /home/elenst/src/10.4/sql/sql_connect.cc:1412
 
#18 0x000055cd9cb66745 in handle_one_connection (arg=0x55cda0c8f5f0) at /home/elenst/src/10.4/sql/sql_connect.cc:1316
 
#19 0x00007f6ea7e9add5 in start_thread () from /lib64/libpthread.so.0
 
#20 0x00007f6ea692bead in clone () from /lib64/libc.so.6

Also happened on 10.3.

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

thiru, I think that you may have fixed something similar recently, or at least should have ideas how to fix this. Here is some analysis of the trace:

10.2

 
Thread 29 hit Breakpoint 4, 0x000055591ea3d062 in id_name_t::operator char const* (this=0x617000048e98)
 
    at /home/mariadb/MDEV-23686/10.2/storage/innobase/include/dict0mem.h:541
 
541			return(m_name);
 
(rr) disassemble
 
Dump of assembler code for function id_name_t::operator char const*() const:
 
   0x000055591ea3d03a <+0>:	push   %rbp
 
   0x000055591ea3d03b <+1>:	mov    %rsp,%rbp
 
   0x000055591ea3d03e <+4>:	sub    $0x10,%rsp
 
   0x000055591ea3d042 <+8>:	mov    %rdi,-0x8(%rbp)
 
   0x000055591ea3d046 <+12>:	mov    -0x8(%rbp),%rax
 
   0x000055591ea3d04a <+16>:	mov    %rax,%rdx
 
   0x000055591ea3d04d <+19>:	shr    $0x3,%rdx
 
   0x000055591ea3d051 <+23>:	add    $0x7fff8000,%rdx
 
   0x000055591ea3d058 <+30>:	movzbl (%rdx),%edx
 
   0x000055591ea3d05b <+33>:	test   %dl,%dl
 
   0x000055591ea3d05d <+35>:	je     0x55591ea3d067 <id_name_t::operator char const*() const+45>
 
   0x000055591ea3d05f <+37>:	mov    %rax,%rdi
 
=> 0x000055591ea3d062 <+40>:	callq  0x55591dbbbfe0 <__asan_report_load8@plt>
 
   0x000055591ea3d067 <+45>:	mov    -0x8(%rbp),%rax
 
   0x000055591ea3d06b <+49>:	mov    (%rax),%rax
 
   0x000055591ea3d06e <+52>:	leaveq 
   0x000055591ea3d06f <+53>:	retq   
End of assembler dump.
 
(rr) rsi
 
0x000055591ea3d05f	541			return(m_name);
 
(rr) display/i $pc
 
…
 
(rr) rsi
 
…
 
(rr) rsi
 
0x000055591ea3d058	541			return(m_name);
 
1: x/i $pc
 
=> 0x55591ea3d058 <id_name_t::operator char const*() const+30>:	
    movzbl (%rdx),%edx
 
(rr) p/x *(char*)$rdx
 
$3 = 0xfd
 
(rr) watch -l *(char*)$rdx
 
Hardware watchpoint 5: -location *(char*)$rdx
 
(rr) rc
 
(rr) rc
 
Continuing.
 
 
 
Thread 29 hit Hardware watchpoint 5: -location *(char*)$rdx
 
 
 
Old value = -3 '\375'
 
New value = 0 '\000'
 
__memset_sse2_unaligned_erms () at ../sysdeps/x86_64/multiarch/memset-vec-unaligned-erms.S:189
 
189	../sysdeps/x86_64/multiarch/memset-vec-unaligned-erms.S: No such file or directory.
 
1: x/i $pc
 
=> 0x7f9b69f969a6 <__memset_sse2_unaligned_erms+102>:	movdqu %xmm0,0x10(%rdi)
 
(rr) bt
 
…
 
#5  0x000055591f0b32c7 in dict_mem_index_free (index=0x617000048e88) at /home/mariadb/MDEV-23686/10.2/storage/innobase/dict/dict0mem.cc:1081
 
#6  0x000055591f065165 in dict_index_remove_from_cache_low (table=0x618000042d08, index=0x617000048e88, lru_evict=0) at /home/mariadb/MDEV-23686/10.2/storage/innobase/dict/dict0dict.cc:2420
 
#7  0x000055591f06518f in dict_index_remove_from_cache (table=0x618000042d08, index=0x617000048e88) at /home/mariadb/MDEV-23686/10.2/storage/innobase/dict/dict0dict.cc:2431
 
#8  0x000055591ecd6136 in row_merge_drop_indexes (trx=0x7f9b62129a58, table=0x618000042d08, locked=1) at /home/mariadb/MDEV-23686/10.2/storage/innobase/row/row0merge.cc:3870
 
#9  0x000055591ea8efae in innobase_rollback_sec_index (user_table=0x618000042d08, table=0x61f00004faf0, locked=1, trx=0x7f9b62129a58)
 
    at /home/mariadb/MDEV-23686/10.2/storage/innobase/handler/handler0alter.cc:6471
 
#10 0x000055591ea98c4d in ha_innobase::commit_inplace_alter_table (this=0x61d0001e5110, altered_table=0x61f0000508f0, ha_alter_info=0x7f9b4f504690, commit=true)
 
    at /home/mariadb/MDEV-23686/10.2/storage/innobase/handler/handler0alter.cc:8577

Note: the index was freed earlier in the same thread. So, maybe in innobase_rollback_sec_index() or row_merge_drop_indexes() we should adjust the cached foreign key constraints?

Note: I did not check why those rollback functions are being called despite commit=true.

Comment by Thirunarayanan Balathandayuthapani [ 2021-04-14 ]

Test case to repeat the issue in 10.2:

--source include/have_innodb.inc
 
set foreign_key_checks=0;
 
CREATE TABLE t1 (pk INT,a INT NOT NULL,PRIMARY KEY (pk),FOREIGN KEY fk1 (a) REFERENCES t1 (pk)) ENGINE=InnoDB;
 
CREATE TABLE t2 (pk INT PRIMARY KEY,FOREIGN KEY fk2 (pk) REFERENCES t1 (a))engine=innodb;
 
CREATE TABLE t3 (pk INT PRIMARY KEY) ENGINE=InnoDB;
 
SET DEBUG_SYNC="inplace_after_index_build SIGNAL con1_signal WAIT_FOR default_signal";
 
send ALTER TABLE t1 ADD FOREIGN KEY fk3 (a) REFERENCES t3 (pk) ON DELETE SET NULL;
 
connect(con1,localhost,root,,,);
 
SET DEBUG_SYNC="now WAIT_FOR con1_signal";
 
SET FOREIGN_KEY_CHECKS=0;
 
ALTER TABLE t2 ADD b INT;
 
set DEBUG_SYNC="now SIGNAL default_signal";
 
connection default;
 
--error 1825
 
reap;
 
LOCK TABLE t1 WRITE;
 
UNLOCK TABLES;
 
disconnect con1;
 
DROP TABLE t3, t2, t1;
 
SET DEBUG_SYNC="RESET";

Comment by Thirunarayanan Balathandayuthapani [ 2021-04-14 ]

In above test case, ALTER TABLE t1 ADD FOREIGN KEY fk3 (a) REFERENCES t3 (pk) ON DELETE SET NULL fails during commit
phase of alter table due to foreign key constraint trying to set NULL for non-null column. But in the meantime, the child table
goes through table rebuild and chooses the newly added index fk3 as referenced index. During rollback of add foreign key fk3,
InnoDB drops the newly added index fk3 and it is not removed from the foreign set of table t1.

When the parent table undergoes DDL, MDL should be taken on the child table to avoid the DDL on the child table.
But the server fails to do it in this case.

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