Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-18259

ASAN heap-use-after-free or server crash in get_foreign_key_info

    XMLWordPrintable

    Details

      Description

      The test case in the description is highly non-deterministic, run with the high value of --repeat (hundreds).
      Also, when it doesn't crash, it can produce other kinds of failures:

      2019-03-21 22:23:20 20 [ERROR] InnoDB: Failed to load table '`test`.`t3`' which has a foreign key constraint with table '`test`.`t1`'.
      ^ Found warnings in /data/src/10.4-bug/mysql-test/var/log/mysqld.1.err
      

      +#sql2-7566-13d.frm
      +#sql2-7566-13d.ibd
      

      2019-03-21 22:30:32 139973994747648 [ERROR] InnoDB: In ALTER TABLE `test`.`t3` has or is referenced in foreign key constraints which are not compatible with the new table definition.
      

      It contains suppressions for some error codes and messages to be able to reach the ultimate failure (ASAN error or crash), but the errors themselves aren't necessarily expected, and possibly it can hit other ones.

      --source include/have_innodb.inc
       
      call mtr.add_suppression("which has a foreign key constraint with table");
       
      CREATE TABLE tx (x INT, KEY(x)) ENGINE=InnoDB;
      CREATE TABLE t1 (pk INT, a INT, b INT, PRIMARY KEY(pk), FOREIGN KEY (a) REFERENCES tx (x)) ENGINE=InnoDB;
      CREATE TABLE t2 (pk INT, c INT, d INT, KEY(d), PRIMARY KEY(pk), FOREIGN KEY b (c) REFERENCES t2 (d)) ENGINE=InnoDB;
      CREATE TABLE t3 (pk INT, e INT, f INT, KEY(e), PRIMARY KEY(pk), FOREIGN KEY (e) REFERENCES t1 (a)) ENGINE=InnoDB;
       
      --send
        ALTER TABLE t3 ADD FOREIGN KEY (f) REFERENCES t3 (e);
       
      --connect (con1,localhost,root,,test)
      ALTER TABLE t1 FORCE;
      SET SESSION FOREIGN_KEY_CHECKS = OFF;
      --error ER_FK_FAIL_ADD_SYSTEM,ER_FK_NO_INDEX_PARENT
      ALTER TABLE t1 ADD CONSTRAINT b FOREIGN KEY (b) REFERENCES txx (x), ADD FOREIGN KEY fk1 (a) REFERENCES t3 (f);
       
      --error 13
      LOAD DATA INFILE 'non_existing_file' INTO TABLE t1;
      --disconnect con1
       
      --connection default
      --error 0,ER_ERROR_ON_RENAME
      --reap
       
      # Cleanup
      SET FOREIGN_KEY_CHECKS= OFF;
      DROP TABLE IF EXISTS t3, t2, t1, tx;
      

      10.4 de51acd0

      ==13416==ERROR: AddressSanitizer: heap-use-after-free on address 0x618000090918 at pc 0x55bdc069a765 bp 0x7f7080cd81f0 sp 0x7f7080cd81e8
      READ of size 8 at 0x618000090918 thread T28
          #0 0x55bdc069a764 in id_name_t::operator char const*() const /data/src/10.4/storage/innobase/include/dict0mem.h:526
          #1 0x55bdc067fd76 in get_foreign_key_info /data/src/10.4/storage/innobase/handler/ha_innodb.cc:14952
          #2 0x55bdc06807f2 in ha_innobase::get_parent_foreign_key_list(THD*, List<st_foreign_key_info>*) /data/src/10.4/storage/innobase/handler/ha_innodb.cc:15033
          #3 0x55bdbf560cc3 in DML_prelocking_strategy::handle_table(THD*, Query_tables_list*, TABLE_LIST*, bool*) /data/src/10.4/sql/sql_base.cc:4629
          #4 0x55bdbf55c3ef in open_and_process_table /data/src/10.4/sql/sql_base.cc:3810
          #5 0x55bdbf55eca9 in open_tables(THD*, DDL_options_st const&, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*) /data/src/10.4/sql/sql_base.cc:4265
          #6 0x55bdbf5635ed in open_and_lock_tables(THD*, DDL_options_st const&, TABLE_LIST*, bool, unsigned int, Prelocking_strategy*) /data/src/10.4/sql/sql_base.cc:5147
          #7 0x55bdbf4cc53a in open_and_lock_tables(THD*, TABLE_LIST*, bool, unsigned int) /data/src/10.4/sql/sql_base.h:502
          #8 0x55bdbf69f9c8 in mysql_load(THD*, sql_exchange const*, TABLE_LIST*, List<Item>&, List<Item>&, List<Item>&, enum_duplicates, bool, bool) /data/src/10.4/sql/sql_load.cc:388
          #9 0x55bdbf6cf359 in mysql_execute_command(THD*) /data/src/10.4/sql/sql_parse.cc:5233
          #10 0x55bdbf6e2830 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.4/sql/sql_parse.cc:8205
          #11 0x55bdbf6ba73b in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.4/sql/sql_parse.cc:1829
          #12 0x55bdbf6b758c in do_command(THD*) /data/src/10.4/sql/sql_parse.cc:1358
          #13 0x55bdbfa4b433 in do_handle_one_connection(CONNECT*) /data/src/10.4/sql/sql_connect.cc:1399
          #14 0x55bdbfa4ae2c in handle_one_connection /data/src/10.4/sql/sql_connect.cc:1302
          #15 0x55bdc0612efc in pfs_spawn_thread /data/src/10.4/storage/perfschema/pfs.cc:1862
          #16 0x7f709d403493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
          #17 0x7f709b5d193e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe893e)
       
      0x618000090918 is located 152 bytes inside of 792-byte region [0x618000090880,0x618000090b98)
      freed by thread T28 here:
          #0 0x7f709d66d527 in __interceptor_free (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x54527)
          #1 0x55bdc07e4aa1 in mem_heap_block_free(mem_block_info_t*, mem_block_info_t*) /data/src/10.4/storage/innobase/mem/mem0mem.cc:415
          #2 0x55bdc0bf0dbd in mem_heap_free /data/src/10.4/storage/innobase/include/mem0mem.ic:528
          #3 0x55bdc0bf87a3 in dict_mem_index_free(dict_index_t*) /data/src/10.4/storage/innobase/dict/dict0mem.cc:1083
          #4 0x55bdc0bbc128 in dict_index_remove_from_cache_low /data/src/10.4/storage/innobase/dict/dict0dict.cc:2523
          #5 0x55bdc0bbc152 in dict_index_remove_from_cache(dict_table_t*, dict_index_t*) /data/src/10.4/storage/innobase/dict/dict0dict.cc:2534
          #6 0x55bdc08f5d76 in row_merge_drop_indexes(trx_t*, dict_table_t*, unsigned long) /data/src/10.4/storage/innobase/row/row0merge.cc:4013
          #7 0x55bdc06ec610 in innobase_rollback_sec_index /data/src/10.4/storage/innobase/handler/handler0alter.cc:8553
          #8 0x55bdc06f7710 in ha_innobase::commit_inplace_alter_table(TABLE*, Alter_inplace_info*, bool) /data/src/10.4/storage/innobase/handler/handler0alter.cc:11011
          #9 0x55bdbfe7e403 in handler::ha_commit_inplace_alter_table(TABLE*, Alter_inplace_info*, bool) /data/src/10.4/sql/handler.cc:4712
          #10 0x55bdbf8f69e4 in mysql_inplace_alter_table /data/src/10.4/sql/sql_table.cc:7696
          #11 0x55bdbf90493d 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) /data/src/10.4/sql/sql_table.cc:9934
          #12 0x55bdbfa60e00 in Sql_cmd_alter_table::execute(THD*) /data/src/10.4/sql/sql_alter.cc:499
          #13 0x55bdbf6d7e7f in mysql_execute_command(THD*) /data/src/10.4/sql/sql_parse.cc:6394
          #14 0x55bdbf6e2830 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.4/sql/sql_parse.cc:8205
          #15 0x55bdbf6ba73b in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.4/sql/sql_parse.cc:1829
          #16 0x55bdbf6b758c in do_command(THD*) /data/src/10.4/sql/sql_parse.cc:1358
          #17 0x55bdbfa4b433 in do_handle_one_connection(CONNECT*) /data/src/10.4/sql/sql_connect.cc:1399
          #18 0x55bdbfa4ae2c in handle_one_connection /data/src/10.4/sql/sql_connect.cc:1302
          #19 0x55bdc0612efc in pfs_spawn_thread /data/src/10.4/storage/perfschema/pfs.cc:1862
          #20 0x7f709d403493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
       
      previously allocated by thread T28 here:
          #0 0x7f709d66d73f in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x5473f)
          #1 0x55bdc07e4069 in mem_heap_create_block_func(mem_block_info_t*, unsigned long, char const*, unsigned int, unsigned long) /data/src/10.4/storage/innobase/mem/mem0mem.cc:269
          #2 0x55bdc07e47ca in mem_heap_add_block(mem_block_info_t*, unsigned long) /data/src/10.4/storage/innobase/mem/mem0mem.cc:375
          #3 0x55bdc0bf09db in mem_heap_alloc /data/src/10.4/storage/innobase/include/mem0mem.ic:201
          #4 0x55bdc0bf07ad in mem_heap_zalloc /data/src/10.4/storage/innobase/include/mem0mem.ic:170
          #5 0x55bdc0bf694f in dict_mem_index_create(dict_table_t*, char const*, unsigned long, unsigned long) /data/src/10.4/storage/innobase/dict/dict0mem.cc:743
          #6 0x55bdc0bbe6a0 in dict_index_build_internal_non_clust /data/src/10.4/storage/innobase/dict/dict0dict.cc:3020
          #7 0x55bdc0bbaf04 in dict_index_add_to_cache(dict_index_t*, unsigned long, bool, dberr_t*, dict_add_v_col_t const*) /data/src/10.4/storage/innobase/dict/dict0dict.cc:2354
          #8 0x55bdc0b9f3d7 in dict_create_index_step(que_thr_t*) /data/src/10.4/storage/innobase/dict/dict0crea.cc:1346
          #9 0x55bdc086683c in que_thr_step /data/src/10.4/storage/innobase/que/que0que.cc:1052
          #10 0x55bdc0866bdc in que_run_threads_low /data/src/10.4/storage/innobase/que/que0que.cc:1104
          #11 0x55bdc0866f33 in que_run_threads(que_thr_t*) /data/src/10.4/storage/innobase/que/que0que.cc:1144
          #12 0x55bdc06d7302 in create_index_dict /data/src/10.4/storage/innobase/handler/handler0alter.cc:5926
          #13 0x55bdc06dfd7f in prepare_inplace_alter_table_dict /data/src/10.4/storage/innobase/handler/handler0alter.cc:6737
          #14 0x55bdc06e92f5 in ha_innobase::prepare_inplace_alter_table(TABLE*, Alter_inplace_info*) /data/src/10.4/storage/innobase/handler/handler0alter.cc:8127
          #15 0x55bdbfe7e132 in handler::ha_prepare_inplace_alter_table(TABLE*, Alter_inplace_info*) /data/src/10.4/sql/handler.cc:4692
          #16 0x55bdbf8f6258 in mysql_inplace_alter_table /data/src/10.4/sql/sql_table.cc:7611
          #17 0x55bdbf90493d 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) /data/src/10.4/sql/sql_table.cc:9934
          #18 0x55bdbfa60e00 in Sql_cmd_alter_table::execute(THD*) /data/src/10.4/sql/sql_alter.cc:499
          #19 0x55bdbf6d7e7f in mysql_execute_command(THD*) /data/src/10.4/sql/sql_parse.cc:6394
          #20 0x55bdbf6e2830 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.4/sql/sql_parse.cc:8205
          #21 0x55bdbf6ba73b in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.4/sql/sql_parse.cc:1829
          #22 0x55bdbf6b758c in do_command(THD*) /data/src/10.4/sql/sql_parse.cc:1358
          #23 0x55bdbfa4b433 in do_handle_one_connection(CONNECT*) /data/src/10.4/sql/sql_connect.cc:1399
          #24 0x55bdbfa4ae2c in handle_one_connection /data/src/10.4/sql/sql_connect.cc:1302
          #25 0x55bdc0612efc in pfs_spawn_thread /data/src/10.4/storage/perfschema/pfs.cc:1862
          #26 0x7f709d403493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
       
      Thread T28 created by T0 here:
          #0 0x7f709d63cbba in pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x23bba)
          #1 0x55bdc06134c4 in spawn_thread_v1 /data/src/10.4/storage/perfschema/pfs.cc:1912
          #2 0x55bdbf402226 in inline_mysql_thread_create /data/src/10.4/include/mysql/psi/mysql_thread.h:1268
          #3 0x55bdbf417b18 in create_thread_to_handle_connection(CONNECT*) /data/src/10.4/sql/mysqld.cc:6218
          #4 0x55bdbf41821d in create_new_thread(CONNECT*) /data/src/10.4/sql/mysqld.cc:6288
          #5 0x55bdbf4185ad in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /data/src/10.4/sql/mysqld.cc:6386
          #6 0x55bdbf4191f9 in handle_connections_sockets() /data/src/10.4/sql/mysqld.cc:6544
          #7 0x55bdbf417353 in mysqld_main(int, char**) /data/src/10.4/sql/mysqld.cc:5876
          #8 0x55bdbf4000af in main /data/src/10.4/sql/main.cc:25
          #9 0x7f709b5092b0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202b0)
       
      SUMMARY: AddressSanitizer: heap-use-after-free /data/src/10.4/storage/innobase/include/dict0mem.h:526 id_name_t::operator char const*() const
      Shadow bytes around the buggy address:
        0x0c308000a0d0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c308000a0e0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c308000a0f0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c308000a100: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
        0x0c308000a110: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
      =>0x0c308000a120: fd fd fd[fd]fd fd fd fd fd fd fd fd fd fd fd fd
        0x0c308000a130: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
        0x0c308000a140: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
        0x0c308000a150: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
        0x0c308000a160: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
        0x0c308000a170: fd fd fd 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
        Heap right redzone:      fb
        Freed heap region:       fd
        Stack left redzone:      f1
        Stack mid redzone:       f2
        Stack right redzone:     f3
        Stack partial redzone:   f4
        Stack after return:      f5
        Stack use after scope:   f8
        Global redzone:          f9
        Global init order:       f6
        Poisoned by user:        f7
        Contiguous container OOB:fc
        ASan internal:           fe
      ==13416==ABORTING
      

      It seems to be failing somewhat faster on 10.4, less frequently on 10.2/10.3, but I've seen the ASAN failures on all off 10.4 de51acd0, 10.3 117291db, 10.2 a77e2668.
      Also, earlier a similar non-ASAN crash was observed in concurrent tests on 10.2:

      10.2 662217a592

      #3  <signal handler called>
      #4  0x00007f3d82064746 in strlen () from /lib/x86_64-linux-gnu/libc.so.6
      #5  0x000055ddac69933b in get_foreign_key_info (thd=0x7f3d40008c20, foreign=0x7f3d3813dba8) at /home/travis/src/storage/innobase/handler/ha_innodb.cc:15147
      #6  0x000055ddac699698 in ha_innobase::get_parent_foreign_key_list (this=0x7f3d4003d558, thd=0x7f3d40008c20, f_key_list=0x7f3d6a7f49d0) at /home/travis/src/storage/innobase/handler/ha_innodb.cc:15227
      #7  0x000055ddac18ff88 in DML_prelocking_strategy::handle_table (this=0x7f3d6a7f4c60, thd=0x7f3d40008c20, prelocking_ctx=0x7f3d4009d4c0, table_list=0x7f3d400a2a98, need_prelocking=0x7f3d6a7f4ad0) at /home/travis/src/sql/sql_base.cc:4320
      #8  0x000055ddac18e511 in open_and_process_table (thd=0x7f3d40008c20, lex=0x7f3d4009d4b8, tables=0x7f3d400a2a98, counter=0x7f3d6a7f4cb4, flags=512, prelocking_strategy=0x7f3d6a7f4c60, has_prelocking_list=false, ot_ctx=0x7f3d6a7f4be0) at /home/travis/src/sql/sql_base.cc:3566
      #9  0x000055ddac18f4cc in open_tables (thd=0x7f3d40008c20, options=..., start=0x7f3d6a7f4ca0, counter=0x7f3d6a7f4cb4, flags=512, prelocking_strategy=0x7f3d6a7f4c60) at /home/travis/src/sql/sql_base.cc:4011
      #10 0x000055ddac1d68d6 in open_tables (thd=0x7f3d40008c20, tables=0x7f3d6a7f4ca0, counter=0x7f3d6a7f4cb4, flags=512) at /home/travis/src/sql/sql_base.h:475
      #11 0x000055ddac222d46 in select_like_stmt_test_with_open (stmt=0x7f3d4004a4a0, tables=0x7f3d4009ec58, specific_prepare=0x55ddac2239da <mysql_insert_select_prepare_tester(THD*)>, setup_tables_done_option=1073741824) at /home/travis/src/sql/sql_prepare.cc:1807
      #12 0x000055ddac223b08 in mysql_test_insert_select (stmt=0x7f3d4004a4a0, tables=0x7f3d4009ec58) at /home/travis/src/sql/sql_prepare.cc:2236
      #13 0x000055ddac2242ad in check_prepared_statement (stmt=0x7f3d4004a4a0) at /home/travis/src/sql/sql_prepare.cc:2482
      #14 0x000055ddac227c8f in Prepared_statement::prepare (this=0x7f3d4004a4a0, packet=0x7f3d400200b1 "INSERT INTO `view_A` SELECT * FROM `view_A` /* QNO 606 CON_ID 18 */ ", packet_len=68) at /home/travis/src/sql/sql_prepare.cc:4021
      #15 0x000055ddac22466a in mysqld_stmt_prepare (thd=0x7f3d40008c20, packet=0x7f3d400200b1 "INSERT INTO `view_A` SELECT * FROM `view_A` /* QNO 606 CON_ID 18 */ ", packet_length=68) at /home/travis/src/sql/sql_prepare.cc:2646
      #16 0x000055ddac1f96f3 in dispatch_command (command=COM_STMT_PREPARE, thd=0x7f3d40008c20, packet=0x7f3d400200b1 "INSERT INTO `view_A` SELECT * FROM `view_A` /* QNO 606 CON_ID 18 */ ", packet_length=68, is_com_multi=false, is_next_command=false) at /home/travis/src/sql/sql_parse.cc:1783
      #17 0x000055ddac1f8358 in do_command (thd=0x7f3d40008c20) at /home/travis/src/sql/sql_parse.cc:1379
      #18 0x000055ddac34a994 in do_handle_one_connection (connect=0x55ddaf4a40a0) at /home/travis/src/sql/sql_connect.cc:1335
      #19 0x000055ddac34a714 in handle_one_connection (arg=0x55ddaf4a40a0) at /home/travis/src/sql/sql_connect.cc:1241
      #20 0x00007f3d82c4b6ba in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
      #21 0x00007f3d820e041d in clone () from /lib/x86_64-linux-gnu/libc.so.6
      

      elenst-jira-refs f6970b243 Toolbox: c826c29aaa

      perl ./runall-new.pl --basedir=/home/travis/server --vardir=/home/travis/logs/vardir --duration=350 --threads=6 --seed=1547523386 --reporters=Backtrace,ErrorLog,Deadlock --validators=TransformerNoComparator --views --redefine=conf/mariadb/alter_table.yy --redefine=conf/mariadb/sp.yy --redefine=conf/mariadb/bulk_insert.yy --redefine=conf/mariadb/modules/foreign_keys.yy --redefine=conf/mariadb/modules/admin.yy --redefine=conf/mariadb/modules/sql_mode.yy --mysqld=--log_output=FILE --mysqld=--max-statement-time=30 --mysqld=--lock-wait-timeout=10 --mysqld=--loose-innodb-lock-wait-timeout=5 --mysqld=--loose-debug_assert_on_not_freed_memory=0 --grammar=conf/partitioning/partitions.yy --ps-protocol --transformers=ExecuteAsCTE,ExecuteAsExecuteImmediate,ExecuteAsDeleteReturning,ExecuteAsInsertSelect,ExecuteAsUnion,ExecuteAsUpdateDelete,ExecuteAsView
      

      Not reproducible right away.

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              marko Marko Mäkelä
              Reporter:
              elenst Elena Stepanova
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: