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

Assertion `index->id == btr_page_get_index_id(page)' failed in btr_cur_search_to_nth_level

Details

    Description

      Note: The test is exactly the same as in MDEV-13205, but the assertion failure is different on 10.2, so I'm filing it separately just in case.

      Run the test with repeat=N. So far repeat=5 has always been enough for me.

      --source include/have_innodb.inc
       
      CREATE TABLE t1 (c VARCHAR(64)) ENGINE=InnoDB;
      INSERT INTO t1 VALUES  ('foo'),('bar');
       
      CREATE TABLE t2 ENGINE = InnoDB AS SELECT * FROM t1;
      CREATE TABLE t3 ENGINE = InnoDB AS SELECT * FROM t1;
       
      --send
      ALTER TABLE t2 ADD UNIQUE (c);
      --connect (con2,127.0.0.1,root,,test)
      --error 0,ER_DUP_ENTRY
      INSERT INTO t2 SELECT * FROM t1;
      ALTER TABLE t3 ADD FOREIGN KEY (c) REFERENCES t2 (c);
       
      # Cleanup
      --disconnect con2
      --connection default
      --error 0,ER_DUP_ENTRY
      --reap
      DROP TABLE t3, t2, t1;
      

      10.2 23edc7c88f29d7bee01f39f1a58f4ada05f724c3

      mysqld: /data/src/10.2/storage/innobase/btr/btr0cur.cc:1309: dberr_t btr_cur_search_to_nth_level(dict_index_t*, ulint, const dtuple_t*, page_cur_mode_t, ulint, btr_cur_t*, ulint, const char*, unsigned int, mtr_t*, ib_uint64_t): Assertion `index->id == btr_page_get_index_id(page)' failed.
      170629  3:44:34 [ERROR] mysqld got signal 6 ;
      

      #7  0x00007fadb57afee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
      #8  0x0000559d383932ea in btr_cur_search_to_nth_level (index=0x7fad6004af58, level=0, tuple=0x7fad54021520, mode=PAGE_CUR_GE, latch_mode=1, cursor=0x7fada838a5b0, has_search_latch=0, file=0x559d387de8a8 "/data/src/10.2/storage/innobase/row/row0ins.cc", line=1714, mtr=0x7fada838a9d0, autoinc=0) at /data/src/10.2/storage/innobase/btr/btr0cur.cc:1309
      #9  0x0000559d3826dea1 in btr_pcur_open_low (index=0x7fad6004af58, level=0, tuple=0x7fad54021520, mode=PAGE_CUR_GE, latch_mode=1, cursor=0x7fada838a5b0, file=0x559d387de8a8 "/data/src/10.2/storage/innobase/row/row0ins.cc", line=1714, autoinc=0, mtr=0x7fada838a9d0) at /data/src/10.2/storage/innobase/include/btr0pcur.ic:459
      #10 0x0000559d38272224 in row_ins_check_foreign_constraint (check_ref=1, foreign=0x7fad54022ce8, table=0x7fad5401f1f8, entry=0x7fad54021520, thr=0x7fad54024470) at /data/src/10.2/storage/innobase/row/row0ins.cc:1714
      #11 0x0000559d38272a61 in row_ins_check_foreign_constraints (table=0x7fad5401f1f8, index=0x7fad540232d8, entry=0x7fad54021520, thr=0x7fad54024470) at /data/src/10.2/storage/innobase/row/row0ins.cc:1984
      #12 0x0000559d38275c4d in row_ins_sec_index_entry (index=0x7fad540232d8, entry=0x7fad54021520, thr=0x7fad54024470, dup_chk_only=false) at /data/src/10.2/storage/innobase/row/row0ins.cc:3245
      #13 0x0000559d38275e78 in row_ins_index_entry (index=0x7fad540232d8, entry=0x7fad54021520, thr=0x7fad54024470) at /data/src/10.2/storage/innobase/row/row0ins.cc:3307
      #14 0x0000559d38276369 in row_ins_index_entry_step (node=0x7fad540241d8, thr=0x7fad54024470) at /data/src/10.2/storage/innobase/row/row0ins.cc:3455
      #15 0x0000559d3827671e in row_ins (node=0x7fad540241d8, thr=0x7fad54024470) at /data/src/10.2/storage/innobase/row/row0ins.cc:3597
      #16 0x0000559d38276d1a in row_ins_step (thr=0x7fad54024470) at /data/src/10.2/storage/innobase/row/row0ins.cc:3781
      #17 0x0000559d38293fc0 in row_insert_for_mysql (mysql_rec=0x7fad5401ec38 "\376\003foo", prebuilt=0x7fad54023cb8) at /data/src/10.2/storage/innobase/row/row0mysql.cc:1486
      #18 0x0000559d38157505 in ha_innobase::write_row (this=0x7fad5401e448, record=0x7fad5401ec38 "\376\003foo") at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:8663
      #19 0x0000559d37e51721 in handler::ha_write_row (this=0x7fad5401e448, buf=0x7fad5401ec38 "\376\003foo") at /data/src/10.2/sql/handler.cc:5950
      #20 0x0000559d37cab396 in copy_data_between_tables (thd=0x7fad54000b00, from=0x7fad6003b590, to=0x7fad5401d840, create=..., ignore=false, order_num=0, order=0x0, copied=0x7fada838c598, deleted=0x7fada838c5a0, keys_onoff=Alter_info::LEAVE_AS_IS, alter_ctx=0x7fada838d260) at /data/src/10.2/sql/sql_table.cc:9873
      #21 0x0000559d37ca9a13 in mysql_alter_table (thd=0x7fad54000b00, new_db=0x7fad54011760 "test", new_name=0x0, create_info=0x7fada838de70, table_list=0x7fad54011150, alter_info=0x7fada838ddc0, order_num=0, order=0x0, ignore=false) at /data/src/10.2/sql/sql_table.cc:9375
      #22 0x0000559d37d2187a in Sql_cmd_alter_table::execute (this=0x7fad54011960, thd=0x7fad54000b00) at /data/src/10.2/sql/sql_alter.cc:324
      #23 0x0000559d37bdfb84 in mysql_execute_command (thd=0x7fad54000b00) at /data/src/10.2/sql/sql_parse.cc:6211
      #24 0x0000559d37be4444 in mysql_parse (thd=0x7fad54000b00, rawbuf=0x7fad54011038 "ALTER TABLE t3 ADD FOREIGN KEY (c) REFERENCES t2 (c)", length=52, parser_state=0x7fada838f200, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:7879
      #25 0x0000559d37bd24f1 in dispatch_command (command=COM_QUERY, thd=0x7fad54000b00, packet=0x7fad540087c1 "ALTER TABLE t3 ADD FOREIGN KEY (c) REFERENCES t2 (c)", packet_length=52, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1817
      #26 0x0000559d37bd0e32 in do_command (thd=0x7fad54000b00) at /data/src/10.2/sql/sql_parse.cc:1362
      #27 0x0000559d37d1c57d in do_handle_one_connection (connect=0x559d3a8dc690) at /data/src/10.2/sql/sql_connect.cc:1354
      #28 0x0000559d37d1c30a in handle_one_connection (arg=0x559d3a8dc690) at /data/src/10.2/sql/sql_connect.cc:1260
      #29 0x0000559d38136f8a in pfs_spawn_thread (arg=0x559d3a83ff20) at /data/src/10.2/storage/perfschema/pfs.cc:1862
      #30 0x00007fadb76f4494 in start_thread (arg=0x7fada8390700) at pthread_create.c:333
      #31 0x00007fadb586c93f in clone () from /lib/x86_64-linux-gnu/libc.so.6
      

      Attachments

        Issue Links

          Activity

            This should share the root cause with MDEV-13205. Once that fix is pushed to 10.0 and merged to 10.2, we should be able to close this one as a duplicate.

            marko Marko Mäkelä added a comment - This should share the root cause with MDEV-13205 . Once that fix is pushed to 10.0 and merged to 10.2, we should be able to close this one as a duplicate.

            I can still get a different crash:

            bb-10.2-marko ed02dff1569019f8d0a64d6351aa6cb5e0a73aa0 based on 10.2 ba10ffe0f4c94c0fd2b1e42615a0c8d1a7f88ab9

            CURRENT_TEST: innodb.mdev-13200
            mysqltest: At line 12: query 'ALTER TABLE t3 ADD FOREIGN KEY (c) REFERENCES t2 (c)' failed with wrong errno 2013: 'Lost connection to MySQL server during query', instead of 0...
            …
            mysqld: /mariadb/10.2/storage/innobase/sync/sync0rw.cc:890: bool rw_lock_validate(const rw_lock_t*): Assertion `lock->magic_n == 22643' failed.
            …
            #8  0x0000562be1c13303 in rw_lock_validate (lock=0x7f66281806d8) at /mariadb/10.2/storage/innobase/sync/sync0rw.cc:890
            #9  0x0000562be1c13789 in rw_lock_own_flagged (lock=0x7f66281806d8, flags=3) at /mariadb/10.2/storage/innobase/sync/sync0rw.cc:1058
            #10 0x0000562be1b7fdd5 in rw_lock_s_lock_func (lock=0x7f66281806d8, pass=0, file_name=0x562be222d470 "/mariadb/10.2/storage/innobase/btr/btr0cur.cc", line=1119) at /mariadb/10.2/storage/innobase/include/sync0rw.ic:284
            #11 0x0000562be1b7ffa3 in mtr_t::s_lock (this=0x7f66803eeb30, lock=0x7f66281806d8, file=0x562be222d470 "/mariadb/10.2/storage/innobase/btr/btr0cur.cc", line=1119) at /mariadb/10.2/storage/innobase/include/mtr0mtr.ic:238
            #12 0x0000562be1c8c8b8 in btr_cur_search_to_nth_level (index=0x7f6628180508, level=0, tuple=0x7f662c026000, mode=PAGE_CUR_GE, latch_mode=1, cursor=0x7f66803ee6d0, has_search_latch=0, file=0x562be21c35e0 "/mariadb/10.2/storage/innobase/row/row0ins.cc", line=1687, mtr=0x7f66803eeb30, autoinc=0) at /mariadb/10.2/storage/innobase/btr/btr0cur.cc:1119
            #13 0x0000562be1b768e3 in btr_pcur_open_low (index=0x7f6628180508, level=0, tuple=0x7f662c026000, mode=PAGE_CUR_GE, latch_mode=1, cursor=0x7f66803ee6d0, file=0x562be21c35e0 "/mariadb/10.2/storage/innobase/row/row0ins.cc", line=1687, autoinc=0, mtr=0x7f66803eeb30) at /mariadb/10.2/storage/innobase/include/btr0pcur.ic:483
            #14 0x0000562be1b7afa1 in row_ins_check_foreign_constraint (check_ref=1, foreign=0x7f662c066428, table=0x7f662c01e7a8, entry=0x7f662c026000, thr=0x7f662c05f360) at /mariadb/10.2/storage/innobase/row/row0ins.cc:1686
            #15 0x0000562be1b7b816 in row_ins_check_foreign_constraints (table=0x7f662c01e7a8, index=0x7f662c021c88, entry=0x7f662c026000, thr=0x7f662c05f360) at /mariadb/10.2/storage/innobase/row/row0ins.cc:1952
            #16 0x0000562be1b7ea59 in row_ins_sec_index_entry (index=0x7f662c021c88, entry=0x7f662c026000, thr=0x7f662c05f360, dup_chk_only=false) at /mariadb/10.2/storage/innobase/row/row0ins.cc:3228
            #17 0x0000562be1b7ecd7 in row_ins_index_entry (index=0x7f662c021c88, entry=0x7f662c026000, thr=0x7f662c05f360) at /mariadb/10.2/storage/innobase/row/row0ins.cc:3305
            #18 0x0000562be1b7f1c4 in row_ins_index_entry_step (node=0x7f662c05f0c0, thr=0x7f662c05f360) at /mariadb/10.2/storage/innobase/row/row0ins.cc:3453
            #19 0x0000562be1b7f582 in row_ins (node=0x7f662c05f0c0, thr=0x7f662c05f360) at /mariadb/10.2/storage/innobase/row/row0ins.cc:3595
            #20 0x0000562be1b7fba3 in row_ins_step (thr=0x7f662c05f360) at /mariadb/10.2/storage/innobase/row/row0ins.cc:3830
            #21 0x0000562be1b9afbb in row_insert_for_mysql (mysql_rec=0x7f662c0af9a0 "\376\003foo", prebuilt=0x7f662c05eba8) at /mariadb/10.2/storage/innobase/row/row0mysql.cc:1412
            #22 0x0000562be1a62fea in ha_innobase::write_row (this=0x7f662c060f70, record=0x7f662c0af9a0 "\376\003foo") at /mariadb/10.2/storage/innobase/handler/ha_innodb.cc:8355
            #23 0x0000562be1868ff5 in handler::ha_write_row (this=0x7f662c060f70, buf=0x7f662c0af9a0 "\376\003foo") at /mariadb/10.2/sql/handler.cc:5959
            #24 0x0000562be16ca34c in copy_data_between_tables (thd=0x7f662c000cf8, from=0x7f6628032378, to=0x7f662c062d48, create=..., ignore=false, order_num=0, order=0x0, copied=0x7f66803f0588, deleted=0x7f66803f0590, keys_onoff=Alter_info::LEAVE_AS_IS, alter_ctx=0x7f66803f1250) at /mariadb/10.2/sql/sql_table.cc:10042
            #25 0x0000562be16c87b8 in mysql_alter_table (thd=0x7f662c000cf8, new_db=0x7f662c010d78 "test", new_name=0x0, create_info=0x7f66803f1e70, table_list=0x7f662c010768, alter_info=0x7f66803f1dc0, order_num=0, order=0x0, ignore=false) at /mariadb/10.2/sql/sql_table.cc:9522
            …
            (gdb) frame 12
            (gdb) p *index
            $1 = {id = 36, heap = 0x7f6628038830, name = {m_name = 0x7f66280389b8 "c"}, 
              table_name = 0x7f662810e2d0 "test/t2", table = 0x7f66280c26a8, space = 13, 
              page = 4, merge_threshold = 50, type = 18, trx_id_offset = 0, 
              n_user_defined_cols = 1, nulls_equal = 0, n_uniq = 1, n_def = 2, 
              n_fields = 2, n_nullable = 1, cached = 1, to_be_dropped = 0, 
              online_status = 0, uncommitted = 1, is_dummy = false, magic_n = 76789786, 
              fields = 0x7f66280389c0, parser = 0x0, has_new_v_col = false, 
              index_fts_syncing = false, indexes = {prev = 0x0, next = 0x0}, 
              search_info = 0x7f6628038a28, online_log = 0x0, 
              stat_n_diff_key_vals = 0x7f6628038a10, 
              stat_n_sample_sizes = 0x7f6628038a18, 
              stat_n_non_null_key_vals = 0x7f6628038a20, stat_index_size = 1, 
              stat_n_leaf_pages = 1, stats_error_printed = false, 
              stat_defrag_modified_counter = 0, stat_defrag_n_pages_freed = 0, 
              stat_defrag_n_page_split = 0, stat_defrag_data_size_sample = {0, 0, 0, 0, 
                0, 0, 0, 0, 0, 0}, stat_defrag_sample_next_slot = 0, rtr_ssn = {mutex = {
                  m_impl = {m_lock_word = 0, m_event = 0x0, 
                    m_policy = {<MutexDebug<TTASEventMutex<GenericPolicy> >> = {
                        _vptr.MutexDebug = 0x0, m_magic_n = 0, m_context = {<latch_t> = {
                            _vptr.latch_t = 0x0, m_id = LATCH_ID_NONE, m_rw_lock = false, 
                            m_temp_fsp = false}, m_mutex = 0x0, m_filename = 0x0, 
                          m_line = 0, m_thread_id = 0}}, m_count = {m_spins = 0, 
                        m_waits = 0, m_calls = 0, m_enabled = false}, 
                      m_id = LATCH_ID_NONE}}}, seq_no = 0}, rtr_track = 0x0, 
              trx_id = 1369, zip_pad = {mutex = 0x0, pad = 0, success = 0, failure = 0, 
                n_rounds = 0, mutex_created = 0}, lock = {<latch_t> = {
                  _vptr.latch_t = 0x562be2704cd8 <vtable for latch_t+16>, 
                  m_id = LATCH_ID_INDEX_TREE, m_rw_lock = true, m_temp_fsp = false}, 
                lock_word = 536870912, waiters = 0, sx_recursive = 0, 
                writer_is_wait_ex = false, writer_thread = 0, event = 0x0, 
                wait_ex_event = 0x0, 
                cfile_name = 0x562be225d920 "/mariadb/10.2/storage/innobase/dict/dict0dict.cc", 
                last_s_file_name = 0x562be21c35e0 "/mariadb/10.2/storage/innobase/row/row0ins.cc", 
                last_x_file_name = 0x562be21d7258 "/mariadb/10.2/storage/innobase/row/row0log.cc", cline = 2521, is_block_lock = 0, last_s_line = 2771, 
                last_x_line = 3766, count_os_wait = 0, list = {prev = 0x0, next = 0x0}, 
                magic_n = 0, debug_list = {count = 0, start = 0x0, end = 0x0, 
                  node = &rw_lock_debug_t::list, init = 51966}, level = SYNC_INDEX_TREE}}
            

            The problem is that the index->lock.magic_n == 0 (in the second-last line). When repeating the exercise with ASAN, I get an error earlier:

            ==21504==ERROR: AddressSanitizer: heap-use-after-free on address 0x618000038d48 at pc 0x55ec7a7da08e bp 0x7f182eda4c40 sp 0x7f182eda4c38
            READ of size 4 at 0x618000038d48 thread T28
                #0 0x55ec7a7da08d in dict_index_is_spatial /mariadb/10.2/storage/innobase/include/dict0dict.ic:313
                #1 0x55ec7a7df41f in btr_pcur_open_low /mariadb/10.2/storage/innobase/include/btr0pcur.ic:481
                #2 0x55ec7a7e9a97 in row_ins_check_foreign_constraint(unsigned long, dict_foreign_t*, dict_table_t*, dtuple_t*, que_thr_t*) /mariadb/10.2/storage/innobase/row/row0ins.cc:1686
                #3 0x55ec7a7eac8b in row_ins_check_foreign_constraints /mariadb/10.2/storage/innobase/row/row0ins.cc:1952
                #4 0x55ec7a7f1b41 in row_ins_sec_index_entry(dict_index_t*, dtuple_t*, que_thr_t*, bool) /mariadb/10.2/storage/innobase/row/row0ins.cc:3228
            …
            0x618000038d48 is located 200 bytes inside of 784-byte region [0x618000038c80,0x618000038f90)
            freed by thread T27 here:
                #0 0x7f18429a3b50 in __interceptor_free (/usr/lib/x86_64-linux-gnu/libasan.so.5+0xe8b50)
                #1 0x55ec7a6e0c05 in mem_heap_block_free(mem_block_info_t*, mem_block_info_t*) /mariadb/10.2/storage/innobase/mem/mem0mem.cc:442
                #2 0x55ec7abeb170 in mem_heap_free /mariadb/10.2/storage/innobase/include/mem0mem.ic:529
                #3 0x55ec7abf2c6a in dict_mem_index_free(dict_index_t*) /mariadb/10.2/storage/innobase/dict/dict0mem.cc:1038
                #4 0x55ec7aba429d in dict_index_remove_from_cache_low /mariadb/10.2/storage/innobase/dict/dict0dict.cc:2593
                #5 0x55ec7aba42c8 in dict_index_remove_from_cache(dict_table_t*, dict_index_t*) /mariadb/10.2/storage/innobase/dict/dict0dict.cc:2604
                #6 0x55ec7a81b5ff in row_merge_drop_indexes(trx_t*, dict_table_t*, unsigned long) /mariadb/10.2/storage/innobase/row/row0merge.cc:3900
                #7 0x55ec7a5d9cd8 in innobase_rollback_sec_index /mariadb/10.2/storage/innobase/handler/handler0alter.cc:6692
                #8 0x55ec7a5e2cee in ha_innobase::commit_inplace_alter_table(TABLE*, Alter_inplace_info*, bool) /mariadb/10.2/storage/innobase/handler/handler0alter.cc:8808
            

            marko Marko Mäkelä added a comment - I can still get a different crash: bb-10.2-marko ed02dff1569019f8d0a64d6351aa6cb5e0a73aa0 based on 10.2 ba10ffe0f4c94c0fd2b1e42615a0c8d1a7f88ab9 CURRENT_TEST: innodb.mdev-13200 mysqltest: At line 12: query 'ALTER TABLE t3 ADD FOREIGN KEY (c) REFERENCES t2 (c)' failed with wrong errno 2013: 'Lost connection to MySQL server during query', instead of 0... … mysqld: /mariadb/10.2/storage/innobase/sync/sync0rw.cc:890: bool rw_lock_validate(const rw_lock_t*): Assertion `lock->magic_n == 22643' failed. … #8 0x0000562be1c13303 in rw_lock_validate (lock=0x7f66281806d8) at /mariadb/10.2/storage/innobase/sync/sync0rw.cc:890 #9 0x0000562be1c13789 in rw_lock_own_flagged (lock=0x7f66281806d8, flags=3) at /mariadb/10.2/storage/innobase/sync/sync0rw.cc:1058 #10 0x0000562be1b7fdd5 in rw_lock_s_lock_func (lock=0x7f66281806d8, pass=0, file_name=0x562be222d470 "/mariadb/10.2/storage/innobase/btr/btr0cur.cc", line=1119) at /mariadb/10.2/storage/innobase/include/sync0rw.ic:284 #11 0x0000562be1b7ffa3 in mtr_t::s_lock (this=0x7f66803eeb30, lock=0x7f66281806d8, file=0x562be222d470 "/mariadb/10.2/storage/innobase/btr/btr0cur.cc", line=1119) at /mariadb/10.2/storage/innobase/include/mtr0mtr.ic:238 #12 0x0000562be1c8c8b8 in btr_cur_search_to_nth_level (index=0x7f6628180508, level=0, tuple=0x7f662c026000, mode=PAGE_CUR_GE, latch_mode=1, cursor=0x7f66803ee6d0, has_search_latch=0, file=0x562be21c35e0 "/mariadb/10.2/storage/innobase/row/row0ins.cc", line=1687, mtr=0x7f66803eeb30, autoinc=0) at /mariadb/10.2/storage/innobase/btr/btr0cur.cc:1119 #13 0x0000562be1b768e3 in btr_pcur_open_low (index=0x7f6628180508, level=0, tuple=0x7f662c026000, mode=PAGE_CUR_GE, latch_mode=1, cursor=0x7f66803ee6d0, file=0x562be21c35e0 "/mariadb/10.2/storage/innobase/row/row0ins.cc", line=1687, autoinc=0, mtr=0x7f66803eeb30) at /mariadb/10.2/storage/innobase/include/btr0pcur.ic:483 #14 0x0000562be1b7afa1 in row_ins_check_foreign_constraint (check_ref=1, foreign=0x7f662c066428, table=0x7f662c01e7a8, entry=0x7f662c026000, thr=0x7f662c05f360) at /mariadb/10.2/storage/innobase/row/row0ins.cc:1686 #15 0x0000562be1b7b816 in row_ins_check_foreign_constraints (table=0x7f662c01e7a8, index=0x7f662c021c88, entry=0x7f662c026000, thr=0x7f662c05f360) at /mariadb/10.2/storage/innobase/row/row0ins.cc:1952 #16 0x0000562be1b7ea59 in row_ins_sec_index_entry (index=0x7f662c021c88, entry=0x7f662c026000, thr=0x7f662c05f360, dup_chk_only=false) at /mariadb/10.2/storage/innobase/row/row0ins.cc:3228 #17 0x0000562be1b7ecd7 in row_ins_index_entry (index=0x7f662c021c88, entry=0x7f662c026000, thr=0x7f662c05f360) at /mariadb/10.2/storage/innobase/row/row0ins.cc:3305 #18 0x0000562be1b7f1c4 in row_ins_index_entry_step (node=0x7f662c05f0c0, thr=0x7f662c05f360) at /mariadb/10.2/storage/innobase/row/row0ins.cc:3453 #19 0x0000562be1b7f582 in row_ins (node=0x7f662c05f0c0, thr=0x7f662c05f360) at /mariadb/10.2/storage/innobase/row/row0ins.cc:3595 #20 0x0000562be1b7fba3 in row_ins_step (thr=0x7f662c05f360) at /mariadb/10.2/storage/innobase/row/row0ins.cc:3830 #21 0x0000562be1b9afbb in row_insert_for_mysql (mysql_rec=0x7f662c0af9a0 "\376\003foo", prebuilt=0x7f662c05eba8) at /mariadb/10.2/storage/innobase/row/row0mysql.cc:1412 #22 0x0000562be1a62fea in ha_innobase::write_row (this=0x7f662c060f70, record=0x7f662c0af9a0 "\376\003foo") at /mariadb/10.2/storage/innobase/handler/ha_innodb.cc:8355 #23 0x0000562be1868ff5 in handler::ha_write_row (this=0x7f662c060f70, buf=0x7f662c0af9a0 "\376\003foo") at /mariadb/10.2/sql/handler.cc:5959 #24 0x0000562be16ca34c in copy_data_between_tables (thd=0x7f662c000cf8, from=0x7f6628032378, to=0x7f662c062d48, create=..., ignore=false, order_num=0, order=0x0, copied=0x7f66803f0588, deleted=0x7f66803f0590, keys_onoff=Alter_info::LEAVE_AS_IS, alter_ctx=0x7f66803f1250) at /mariadb/10.2/sql/sql_table.cc:10042 #25 0x0000562be16c87b8 in mysql_alter_table (thd=0x7f662c000cf8, new_db=0x7f662c010d78 "test", new_name=0x0, create_info=0x7f66803f1e70, table_list=0x7f662c010768, alter_info=0x7f66803f1dc0, order_num=0, order=0x0, ignore=false) at /mariadb/10.2/sql/sql_table.cc:9522 … (gdb) frame 12 (gdb) p *index $1 = {id = 36, heap = 0x7f6628038830, name = {m_name = 0x7f66280389b8 "c"}, table_name = 0x7f662810e2d0 "test/t2", table = 0x7f66280c26a8, space = 13, page = 4, merge_threshold = 50, type = 18, trx_id_offset = 0, n_user_defined_cols = 1, nulls_equal = 0, n_uniq = 1, n_def = 2, n_fields = 2, n_nullable = 1, cached = 1, to_be_dropped = 0, online_status = 0, uncommitted = 1, is_dummy = false, magic_n = 76789786, fields = 0x7f66280389c0, parser = 0x0, has_new_v_col = false, index_fts_syncing = false, indexes = {prev = 0x0, next = 0x0}, search_info = 0x7f6628038a28, online_log = 0x0, stat_n_diff_key_vals = 0x7f6628038a10, stat_n_sample_sizes = 0x7f6628038a18, stat_n_non_null_key_vals = 0x7f6628038a20, stat_index_size = 1, stat_n_leaf_pages = 1, stats_error_printed = false, stat_defrag_modified_counter = 0, stat_defrag_n_pages_freed = 0, stat_defrag_n_page_split = 0, stat_defrag_data_size_sample = {0, 0, 0, 0, 0, 0, 0, 0, 0, 0}, stat_defrag_sample_next_slot = 0, rtr_ssn = {mutex = { m_impl = {m_lock_word = 0, m_event = 0x0, m_policy = {<MutexDebug<TTASEventMutex<GenericPolicy> >> = { _vptr.MutexDebug = 0x0, m_magic_n = 0, m_context = {<latch_t> = { _vptr.latch_t = 0x0, m_id = LATCH_ID_NONE, m_rw_lock = false, m_temp_fsp = false}, m_mutex = 0x0, m_filename = 0x0, m_line = 0, m_thread_id = 0}}, m_count = {m_spins = 0, m_waits = 0, m_calls = 0, m_enabled = false}, m_id = LATCH_ID_NONE}}}, seq_no = 0}, rtr_track = 0x0, trx_id = 1369, zip_pad = {mutex = 0x0, pad = 0, success = 0, failure = 0, n_rounds = 0, mutex_created = 0}, lock = {<latch_t> = { _vptr.latch_t = 0x562be2704cd8 <vtable for latch_t+16>, m_id = LATCH_ID_INDEX_TREE, m_rw_lock = true, m_temp_fsp = false}, lock_word = 536870912, waiters = 0, sx_recursive = 0, writer_is_wait_ex = false, writer_thread = 0, event = 0x0, wait_ex_event = 0x0, cfile_name = 0x562be225d920 "/mariadb/10.2/storage/innobase/dict/dict0dict.cc", last_s_file_name = 0x562be21c35e0 "/mariadb/10.2/storage/innobase/row/row0ins.cc", last_x_file_name = 0x562be21d7258 "/mariadb/10.2/storage/innobase/row/row0log.cc", cline = 2521, is_block_lock = 0, last_s_line = 2771, last_x_line = 3766, count_os_wait = 0, list = {prev = 0x0, next = 0x0}, magic_n = 0, debug_list = {count = 0, start = 0x0, end = 0x0, node = &rw_lock_debug_t::list, init = 51966}, level = SYNC_INDEX_TREE}} The problem is that the index->lock.magic_n == 0 (in the second-last line). When repeating the exercise with ASAN, I get an error earlier: ==21504==ERROR: AddressSanitizer: heap-use-after-free on address 0x618000038d48 at pc 0x55ec7a7da08e bp 0x7f182eda4c40 sp 0x7f182eda4c38 READ of size 4 at 0x618000038d48 thread T28 #0 0x55ec7a7da08d in dict_index_is_spatial /mariadb/10.2/storage/innobase/include/dict0dict.ic:313 #1 0x55ec7a7df41f in btr_pcur_open_low /mariadb/10.2/storage/innobase/include/btr0pcur.ic:481 #2 0x55ec7a7e9a97 in row_ins_check_foreign_constraint(unsigned long, dict_foreign_t*, dict_table_t*, dtuple_t*, que_thr_t*) /mariadb/10.2/storage/innobase/row/row0ins.cc:1686 #3 0x55ec7a7eac8b in row_ins_check_foreign_constraints /mariadb/10.2/storage/innobase/row/row0ins.cc:1952 #4 0x55ec7a7f1b41 in row_ins_sec_index_entry(dict_index_t*, dtuple_t*, que_thr_t*, bool) /mariadb/10.2/storage/innobase/row/row0ins.cc:3228 … 0x618000038d48 is located 200 bytes inside of 784-byte region [0x618000038c80,0x618000038f90) freed by thread T27 here: #0 0x7f18429a3b50 in __interceptor_free (/usr/lib/x86_64-linux-gnu/libasan.so.5+0xe8b50) #1 0x55ec7a6e0c05 in mem_heap_block_free(mem_block_info_t*, mem_block_info_t*) /mariadb/10.2/storage/innobase/mem/mem0mem.cc:442 #2 0x55ec7abeb170 in mem_heap_free /mariadb/10.2/storage/innobase/include/mem0mem.ic:529 #3 0x55ec7abf2c6a in dict_mem_index_free(dict_index_t*) /mariadb/10.2/storage/innobase/dict/dict0mem.cc:1038 #4 0x55ec7aba429d in dict_index_remove_from_cache_low /mariadb/10.2/storage/innobase/dict/dict0dict.cc:2593 #5 0x55ec7aba42c8 in dict_index_remove_from_cache(dict_table_t*, dict_index_t*) /mariadb/10.2/storage/innobase/dict/dict0dict.cc:2604 #6 0x55ec7a81b5ff in row_merge_drop_indexes(trx_t*, dict_table_t*, unsigned long) /mariadb/10.2/storage/innobase/row/row0merge.cc:3900 #7 0x55ec7a5d9cd8 in innobase_rollback_sec_index /mariadb/10.2/storage/innobase/handler/handler0alter.cc:6692 #8 0x55ec7a5e2cee in ha_innobase::commit_inplace_alter_table(TABLE*, Alter_inplace_info*, bool) /mariadb/10.2/storage/innobase/handler/handler0alter.cc:8808

            The problem seems to be that the ALTER TABLE t3 ADD FOREIGN KEY is prematurely attaching the ADD UNIQUE index of table t2, before it has been committed. I was able to repeat this with 10.0 as well:

            10.0 9dfef6e29b98459a5077adb95d5b989d39e0db24

            ==27025==ERROR: AddressSanitizer: heap-use-after-free on address 0x61900013a528 at pc 0x5561955c58e3 bp 0x7f0064ffbd70 sp 0x7f0064ffbd68
            READ of size 8 at 0x61900013a528 thread T28
                #0 0x5561955c58e2 in dict_index_get_n_unique_in_tree /mariadb/10.0/storage/xtradb/include/dict0dict.ic:984
                #1 0x5561955c58e2 in dict_index_check_search_tuple(dict_index_t const*, dtuple_t const*) /mariadb/10.0/storage/xtradb/dict/dict0dict.cc:5455
                #2 0x5561954f7d89 in btr_cur_search_to_nth_level(dict_index_t*, unsigned long, dtuple_t const*, unsigned long, unsigned long, btr_cur_t*, unsigned long, char const*, unsigned long, mtr_t*) /mariadb/10.0/storage/xtradb/btr/btr0cur.cc:457
                #3 0x55619532d1ac in btr_pcur_open_low /mariadb/10.0/storage/xtradb/include/btr0pcur.ic:439
                #4 0x55619532d1ac in row_ins_check_foreign_constraint(unsigned long, dict_foreign_t*, dict_table_t*, dtuple_t*, que_thr_t*) /mariadb/10.0/storage/xtradb/row/row0ins.cc:1560
                #5 0x556195334b2b in row_ins_check_foreign_constraints /mariadb/10.0/storage/xtradb/row/row0ins.cc:1836
                #6 0x5561953351a5 in row_ins_sec_index_entry(dict_index_t*, dtuple_t*, que_thr_t*) /mariadb/10.0/storage/xtradb/row/row0ins.cc:2998
                #7 0x556195337692 in row_ins_index_entry /mariadb/10.0/storage/xtradb/row/row0ins.cc:3060
                #8 0x556195337692 in row_ins_index_entry_step /mariadb/10.0/storage/xtradb/row/row0ins.cc:3135
                #9 0x556195337692 in row_ins /mariadb/10.0/storage/xtradb/row/row0ins.cc:3275
                #10 0x556195337692 in row_ins_step(que_thr_t*) /mariadb/10.0/storage/xtradb/row/row0ins.cc:3400
                #11 0x5561953678cd in row_insert_for_mysql(unsigned char*, row_prebuilt_t*) /mariadb/10.0/storage/xtradb/row/row0mysql.cc:1379
                #12 0x55619515b1e2 in ha_innobase::write_row(unsigned char*) /mariadb/10.0/storage/xtradb/handler/ha_innodb.cc:7979
                #13 0x5561949273b3 in handler::ha_write_row(unsigned char*) /mariadb/10.0/sql/handler.cc:6033
                #14 0x5561945e145f in copy_data_between_tables /mariadb/10.0/sql/sql_table.cc:9612
                #15 0x5561945ed587 in mysql_alter_table(THD*, char*, char*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool) /mariadb/10.0/sql/sql_table.cc:9090
            

            The uncommitted index would be freed when the ADD UNIQUE INDEX operation fails.

            This should be prevented if the
            ADD FOREIGN KEY operation acquired a transactional shared lock on the parent table for the duration of the copying.

            Unfortunately, I can repeat this also with bb-10.0-serg 2c8226ba2fbe75284ba42f4b5c4310b946c55b67, which contains a fix for MDEV-16465.

            marko Marko Mäkelä added a comment - The problem seems to be that the ALTER TABLE t3 ADD FOREIGN KEY is prematurely attaching the ADD UNIQUE index of table t2, before it has been committed. I was able to repeat this with 10.0 as well: 10.0 9dfef6e29b98459a5077adb95d5b989d39e0db24 ==27025==ERROR: AddressSanitizer: heap-use-after-free on address 0x61900013a528 at pc 0x5561955c58e3 bp 0x7f0064ffbd70 sp 0x7f0064ffbd68 READ of size 8 at 0x61900013a528 thread T28 #0 0x5561955c58e2 in dict_index_get_n_unique_in_tree /mariadb/10.0/storage/xtradb/include/dict0dict.ic:984 #1 0x5561955c58e2 in dict_index_check_search_tuple(dict_index_t const*, dtuple_t const*) /mariadb/10.0/storage/xtradb/dict/dict0dict.cc:5455 #2 0x5561954f7d89 in btr_cur_search_to_nth_level(dict_index_t*, unsigned long, dtuple_t const*, unsigned long, unsigned long, btr_cur_t*, unsigned long, char const*, unsigned long, mtr_t*) /mariadb/10.0/storage/xtradb/btr/btr0cur.cc:457 #3 0x55619532d1ac in btr_pcur_open_low /mariadb/10.0/storage/xtradb/include/btr0pcur.ic:439 #4 0x55619532d1ac in row_ins_check_foreign_constraint(unsigned long, dict_foreign_t*, dict_table_t*, dtuple_t*, que_thr_t*) /mariadb/10.0/storage/xtradb/row/row0ins.cc:1560 #5 0x556195334b2b in row_ins_check_foreign_constraints /mariadb/10.0/storage/xtradb/row/row0ins.cc:1836 #6 0x5561953351a5 in row_ins_sec_index_entry(dict_index_t*, dtuple_t*, que_thr_t*) /mariadb/10.0/storage/xtradb/row/row0ins.cc:2998 #7 0x556195337692 in row_ins_index_entry /mariadb/10.0/storage/xtradb/row/row0ins.cc:3060 #8 0x556195337692 in row_ins_index_entry_step /mariadb/10.0/storage/xtradb/row/row0ins.cc:3135 #9 0x556195337692 in row_ins /mariadb/10.0/storage/xtradb/row/row0ins.cc:3275 #10 0x556195337692 in row_ins_step(que_thr_t*) /mariadb/10.0/storage/xtradb/row/row0ins.cc:3400 #11 0x5561953678cd in row_insert_for_mysql(unsigned char*, row_prebuilt_t*) /mariadb/10.0/storage/xtradb/row/row0mysql.cc:1379 #12 0x55619515b1e2 in ha_innobase::write_row(unsigned char*) /mariadb/10.0/storage/xtradb/handler/ha_innodb.cc:7979 #13 0x5561949273b3 in handler::ha_write_row(unsigned char*) /mariadb/10.0/sql/handler.cc:6033 #14 0x5561945e145f in copy_data_between_tables /mariadb/10.0/sql/sql_table.cc:9612 #15 0x5561945ed587 in mysql_alter_table(THD*, char*, char*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool) /mariadb/10.0/sql/sql_table.cc:9090 The uncommitted index would be freed when the ADD UNIQUE INDEX operation fails. This should be prevented if the ADD FOREIGN KEY operation acquired a transactional shared lock on the parent table for the duration of the copying. Unfortunately, I can repeat this also with bb-10.0-serg 2c8226ba2fbe75284ba42f4b5c4310b946c55b67, which contains a fix for MDEV-16465 .

            serg, I believe that your MDEV-16465 fix in bb-10.0-serg is a step to the right direction, but instead of only acquiring MDL on the parent table, ADD FOREIGN KEY should acquire a shared InnoDB table lock on the parent table.
            With mdev-13200.test, your initial MDEV-16465 fix produces a different heap-use-after-free error:

            bb-10.0-serg 2c8226ba2fbe75284ba42f4b5c4310b946c55b67

            CURRENT_TEST: innodb.mdev-13200
            mysqltest: At line 12: query 'ALTER TABLE t3 ADD FOREIGN KEY (c) REFERENCES t2 (c)' failed with wrong errno 2013: 'Lost connection to MySQL server during query', instead of 0...
            …
            ==38675==ERROR: AddressSanitizer: heap-use-after-free on address 0x61900014ce18 at pc 0x55d52f2e8b8c bp 0x7f64943551e0 sp 0x7f64943551d8
            READ of size 8 at 0x61900014ce18 thread T28
            …
            #9  0x00007f64a7aeaee8 in __asan_report_load8 () from /usr/lib/x86_64-linux-gnu/libasan.so.5
            #10 0x000055d52f2e8b8c in get_foreign_key_info (thd=thd@entry=0x62a000090208, foreign=0x61100005e6b8) at /mariadb/10.0/storage/xtradb/handler/ha_innodb.cc:13311
            #11 0x000055d52f2f94fc in ha_innobase::get_foreign_key_list (this=<optimized out>, thd=<optimized out>, f_key_list=0x7f6494355ee0) at /mariadb/10.0/storage/xtradb/handler/ha_innodb.cc:13431
            #12 0x000055d52e7af2f0 in mysql_alter_table (thd=thd@entry=0x62a000090208, new_db=<optimized out>, new_name=<optimized out>, create_info=create_info@entry=0x7f64943588a0, table_list=<optimized out>, table_list@entry=0x62500027da38, alter_info=alter_info@entry=0x7f64943587e0, order_num=<optimized out>, order=<optimized out>, ignore=<optimized out>) at /mariadb/10.0/sql/sql_table.cc:9091
            #13 0x000055d52e8ced97 in Sql_cmd_alter_table::execute (this=<optimized out>, thd=0x62a000090208) at /mariadb/10.0/sql/sql_alter.cc:306
            #14 0x000055d52e5ad0f4 in mysql_execute_command (thd=thd@entry=0x62a000090208) at /mariadb/10.0/sql/sql_parse.cc:5118
            #15 0x000055d52e5af920 in mysql_parse (thd=thd@entry=0x62a000090208, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7f649435c870) at /mariadb/10.0/sql/sql_parse.cc:6637
            #16 0x000055d52e5b3beb in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x62a000090208, packet=packet@entry=0x62900026c209 "ALTER TABLE t3 ADD FOREIGN KEY (c) REFERENCES t2 (c)", packet_length=packet_length@entry=52) at /mariadb/10.0/sql/sql_class.h:972
            

            marko Marko Mäkelä added a comment - serg , I believe that your MDEV-16465 fix in bb-10.0-serg is a step to the right direction, but instead of only acquiring MDL on the parent table, ADD FOREIGN KEY should acquire a shared InnoDB table lock on the parent table. With mdev-13200.test , your initial MDEV-16465 fix produces a different heap-use-after-free error: bb-10.0-serg 2c8226ba2fbe75284ba42f4b5c4310b946c55b67 CURRENT_TEST: innodb.mdev-13200 mysqltest: At line 12: query 'ALTER TABLE t3 ADD FOREIGN KEY (c) REFERENCES t2 (c)' failed with wrong errno 2013: 'Lost connection to MySQL server during query', instead of 0... … ==38675==ERROR: AddressSanitizer: heap-use-after-free on address 0x61900014ce18 at pc 0x55d52f2e8b8c bp 0x7f64943551e0 sp 0x7f64943551d8 READ of size 8 at 0x61900014ce18 thread T28 … #9 0x00007f64a7aeaee8 in __asan_report_load8 () from /usr/lib/x86_64-linux-gnu/libasan.so.5 #10 0x000055d52f2e8b8c in get_foreign_key_info (thd=thd@entry=0x62a000090208, foreign=0x61100005e6b8) at /mariadb/10.0/storage/xtradb/handler/ha_innodb.cc:13311 #11 0x000055d52f2f94fc in ha_innobase::get_foreign_key_list (this=<optimized out>, thd=<optimized out>, f_key_list=0x7f6494355ee0) at /mariadb/10.0/storage/xtradb/handler/ha_innodb.cc:13431 #12 0x000055d52e7af2f0 in mysql_alter_table (thd=thd@entry=0x62a000090208, new_db=<optimized out>, new_name=<optimized out>, create_info=create_info@entry=0x7f64943588a0, table_list=<optimized out>, table_list@entry=0x62500027da38, alter_info=alter_info@entry=0x7f64943587e0, order_num=<optimized out>, order=<optimized out>, ignore=<optimized out>) at /mariadb/10.0/sql/sql_table.cc:9091 #13 0x000055d52e8ced97 in Sql_cmd_alter_table::execute (this=<optimized out>, thd=0x62a000090208) at /mariadb/10.0/sql/sql_alter.cc:306 #14 0x000055d52e5ad0f4 in mysql_execute_command (thd=thd@entry=0x62a000090208) at /mariadb/10.0/sql/sql_parse.cc:5118 #15 0x000055d52e5af920 in mysql_parse (thd=thd@entry=0x62a000090208, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7f649435c870) at /mariadb/10.0/sql/sql_parse.cc:6637 #16 0x000055d52e5b3beb in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x62a000090208, packet=packet@entry=0x62900026c209 "ALTER TABLE t3 ADD FOREIGN KEY (c) REFERENCES t2 (c)", packet_length=packet_length@entry=52) at /mariadb/10.0/sql/sql_class.h:972

            This was fixed by the final version of MDEV-16465.

            marko Marko Mäkelä added a comment - This was fixed by the final version of MDEV-16465 .

            People

              serg Sergei Golubchik
              elenst Elena Stepanova
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.