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

InnoDB lock->index refers to a freed object after failed ADD INDEX

Details

    Description

      The test case mentioned in MDEV-16063 occasionally causes a crash in AddressSanitizer-enabled builds. I have tested and repeated this in 10.0, 10.2, and 10.3 so far.

      10.0 7b9486d2eb3876d55edc05173235e6ccad2e6ae3

      AddressSanitizer: heap-use-after-free
      …
      #8  0x00000000006730a8 in __asan_report_load8 ()
      #9  0x00007fded9d437bc in lock_release (trx=<optimized out>) at /mariadb/10.0/storage/innobase/lock/lock0lock.cc:4803
      #10 0x00007fded9d432d1 in lock_trx_release_locks (trx=0x61b00003fef8) at /mariadb/10.0/storage/innobase/lock/lock0lock.cc:7047
      #11 0x00007fded9ebe384 in trx_commit_in_memory (trx=0x61b00003fef8, lsn=1639442) at /mariadb/10.0/storage/innobase/trx/trx0trx.cc:1182
      #12 0x00007fded9ebf173 in trx_commit (trx=0x61b00003fef8) at /mariadb/10.0/storage/innobase/trx/trx0trx.cc:1410
      #13 0x00007fded9eb1915 in trx_rollback_finish (trx=0x61b00003fef8) at /mariadb/10.0/storage/innobase/trx/trx0roll.cc:1339
      

      This rollback is executed when a client disconnects. The index name is uidx, and that object has been freed. lock->index->table->indexes contains only one index, the clustered index. The freed index object was an uncommitted index, created by ADD UNIQUE INDEX.
      Next, I will try to create a DEBUG_SYNC test case for this.

      Attachments

        Issue Links

          Activity

            I added some debug instrumentation to find out when a lock is being created for an uncommitted index:

            10.0 7b9486d2eb3876d55edc05173235e6ccad2e6ae3

            #6  0x0000562f33c4133c in lock_rec_create (type_mode=type_mode@entry=1059, block=block@entry=0x7f5a9e91e5d0, heap_no=heap_no@entry=2, index=index@entry=0x6190000e1ff8, trx=trx@entry=0x61c0000400f8, caller_owns_trx_mutex=caller_owns_trx_mutex@entry=0) at /mariadb/10.0/storage/xtradb/lock/lock0lock.cc:1869
            #7  0x0000562f33c41b46 in lock_rec_add_to_queue (type_mode=type_mode@entry=1059, block=block@entry=0x7f5a9e91e5d0, heap_no=heap_no@entry=2, index=index@entry=0x6190000e1ff8, trx=trx@entry=0x61c0000400f8, caller_owns_trx_mutex=caller_owns_trx_mutex@entry=0) at /mariadb/10.0/storage/xtradb/lock/lock0lock.cc:2182
            #8  0x0000562f33c46c8b in lock_rec_convert_impl_to_expl (block=block@entry=0x7f5a9e91e5d0, rec=rec@entry=0x7f5a9ee9c07e "\200", index=index@entry=0x6190000e1ff8, offsets=offsets@entry=0x6190000d16f8) at /mariadb/10.0/storage/xtradb/lock/lock0lock.cc:6349
            #9  0x0000562f33c50838 in lock_sec_rec_read_check_and_lock (flags=flags@entry=0, block=block@entry=0x7f5a9e91e5d0, rec=rec@entry=0x7f5a9ee9c07e "\200", index=index@entry=0x6190000e1ff8, offsets=offsets@entry=0x6190000d16f8, mode=mode@entry=LOCK_S, gap_mode=0, thr=0x620000031828) at /mariadb/10.0/storage/xtradb/lock/lock0lock.cc:6573
            #10 0x0000562f33d755f5 in row_ins_set_shared_rec_lock (type=type@entry=0, block=block@entry=0x7f5a9e91e5d0, rec=rec@entry=0x7f5a9ee9c07e "\200", index=index@entry=0x6190000e1ff8, offsets=offsets@entry=0x6190000d16f8, thr=thr@entry=0x620000031828) at /mariadb/10.0/storage/xtradb/row/row0ins.cc:1373
            #11 0x0000562f33d7a0ad in row_ins_scan_sec_index_for_duplicate (offsets_heap=<optimized out>, mtr=0x7f5a9478acf0, s_latch=<optimized out>, thr=0x620000031828, entry=0x6160000706a8, index=0x6190000e1ff8, flags=0) at /mariadb/10.0/storage/xtradb/row/row0ins.cc:2004
            #12 row_ins_sec_index_entry_low (flags=flags@entry=0, mode=mode@entry=2, index=index@entry=0x6190000e1ff8, offsets_heap=<optimized out>, offsets_heap@entry=0x6190000d1680, heap=heap@entry=0x6190000d1b80, entry=entry@entry=0x6160000706a8, trx_id=<optimized out>, thr=<optimized out>) at /mariadb/10.0/storage/xtradb/row/row0ins.cc:2759
            #13 0x0000562f33d8a64e in row_ins_sec_index_entry (index=index@entry=0x6190000e1ff8, entry=entry@entry=0x6160000706a8, thr=thr@entry=0x620000031828) at /mariadb/10.0/storage/xtradb/row/row0ins.cc:3015
            #14 0x0000562f33d8ccdd in row_ins_index_entry (thr=0x620000031828, entry=0x6160000706a8, index=0x6190000e1ff8) at /mariadb/10.0/storage/xtradb/row/row0ins.cc:3060
            #15 row_ins_index_entry_step (thr=0x620000031828, node=0x6200000315e8) at /mariadb/10.0/storage/xtradb/row/row0ins.cc:3135
            #16 row_ins (thr=<optimized out>, node=<optimized out>) at /mariadb/10.0/storage/xtradb/row/row0ins.cc:3275
            #17 row_ins_step (thr=thr@entry=0x620000031828) at /mariadb/10.0/storage/xtradb/row/row0ins.cc:3400
            #18 0x0000562f33dbd3c9 in row_insert_for_mysql (mysql_rec=mysql_rec@entry=0x6190000d07a0 "\371\002", prebuilt=<optimized out>) at /mariadb/10.0/storage/xtradb/row/row0mysql.cc:1379
            #19 0x0000562f33bb5c1d in ha_innobase::write_row (this=0x61c0000410a0, record=<optimized out>) at /mariadb/10.0/storage/xtradb/handler/ha_innodb.cc:7979
            #20 0x0000562f33389129 in handler::ha_write_row (this=0x61c0000410a0, buf=<optimized out>) at /mariadb/10.0/sql/handler.cc:6033
            #21 0x0000562f32deff83 in write_record (thd=thd@entry=0x62a000072208, table=0x61e000070888, info=info@entry=0x7f5a9478c1a0) at /mariadb/10.0/sql/sql_insert.cc:1848
            #22 0x0000562f32e05bdf in mysql_insert (thd=thd@entry=0x62a000072208, table_list=0x6250000eda10, fields=..., values_list=..., update_fields=..., update_values=..., duplic=<optimized out>, ignore=<optimized out>) at /mariadb/10.0/sql/sql_insert.cc:964
            #23 0x0000562f32e57387 in mysql_execute_command (thd=thd@entry=0x62a000072208) at /mariadb/10.0/sql/sql_parse.cc:3447
            #24 0x0000562f32e672c1 in mysql_parse (thd=thd@entry=0x62a000072208, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7f5a9478f870) at /mariadb/10.0/sql/sql_parse.cc:6573
            #25 0x0000562f32e6b633 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x62a000072208, packet=packet@entry=0x6290000f5209 "INSERT INTO t1 VALUES (2,2),(2,2)", packet_length=packet_length@entry=33) at /mariadb/10.0/sql/sql_parse.cc:1296
            

            I think that it is risky to remove such locking. It is better to modify the code that is responsible for freeing the index stub. Either the stub will have to remain in memory until no locks are referring to it, or the locks will have to be removed. I think that it is safer to keep the stub in memory.

            marko Marko Mäkelä added a comment - I added some debug instrumentation to find out when a lock is being created for an uncommitted index: 10.0 7b9486d2eb3876d55edc05173235e6ccad2e6ae3 #6 0x0000562f33c4133c in lock_rec_create (type_mode=type_mode@entry=1059, block=block@entry=0x7f5a9e91e5d0, heap_no=heap_no@entry=2, index=index@entry=0x6190000e1ff8, trx=trx@entry=0x61c0000400f8, caller_owns_trx_mutex=caller_owns_trx_mutex@entry=0) at /mariadb/10.0/storage/xtradb/lock/lock0lock.cc:1869 #7 0x0000562f33c41b46 in lock_rec_add_to_queue (type_mode=type_mode@entry=1059, block=block@entry=0x7f5a9e91e5d0, heap_no=heap_no@entry=2, index=index@entry=0x6190000e1ff8, trx=trx@entry=0x61c0000400f8, caller_owns_trx_mutex=caller_owns_trx_mutex@entry=0) at /mariadb/10.0/storage/xtradb/lock/lock0lock.cc:2182 #8 0x0000562f33c46c8b in lock_rec_convert_impl_to_expl (block=block@entry=0x7f5a9e91e5d0, rec=rec@entry=0x7f5a9ee9c07e "\200", index=index@entry=0x6190000e1ff8, offsets=offsets@entry=0x6190000d16f8) at /mariadb/10.0/storage/xtradb/lock/lock0lock.cc:6349 #9 0x0000562f33c50838 in lock_sec_rec_read_check_and_lock (flags=flags@entry=0, block=block@entry=0x7f5a9e91e5d0, rec=rec@entry=0x7f5a9ee9c07e "\200", index=index@entry=0x6190000e1ff8, offsets=offsets@entry=0x6190000d16f8, mode=mode@entry=LOCK_S, gap_mode=0, thr=0x620000031828) at /mariadb/10.0/storage/xtradb/lock/lock0lock.cc:6573 #10 0x0000562f33d755f5 in row_ins_set_shared_rec_lock (type=type@entry=0, block=block@entry=0x7f5a9e91e5d0, rec=rec@entry=0x7f5a9ee9c07e "\200", index=index@entry=0x6190000e1ff8, offsets=offsets@entry=0x6190000d16f8, thr=thr@entry=0x620000031828) at /mariadb/10.0/storage/xtradb/row/row0ins.cc:1373 #11 0x0000562f33d7a0ad in row_ins_scan_sec_index_for_duplicate (offsets_heap=<optimized out>, mtr=0x7f5a9478acf0, s_latch=<optimized out>, thr=0x620000031828, entry=0x6160000706a8, index=0x6190000e1ff8, flags=0) at /mariadb/10.0/storage/xtradb/row/row0ins.cc:2004 #12 row_ins_sec_index_entry_low (flags=flags@entry=0, mode=mode@entry=2, index=index@entry=0x6190000e1ff8, offsets_heap=<optimized out>, offsets_heap@entry=0x6190000d1680, heap=heap@entry=0x6190000d1b80, entry=entry@entry=0x6160000706a8, trx_id=<optimized out>, thr=<optimized out>) at /mariadb/10.0/storage/xtradb/row/row0ins.cc:2759 #13 0x0000562f33d8a64e in row_ins_sec_index_entry (index=index@entry=0x6190000e1ff8, entry=entry@entry=0x6160000706a8, thr=thr@entry=0x620000031828) at /mariadb/10.0/storage/xtradb/row/row0ins.cc:3015 #14 0x0000562f33d8ccdd in row_ins_index_entry (thr=0x620000031828, entry=0x6160000706a8, index=0x6190000e1ff8) at /mariadb/10.0/storage/xtradb/row/row0ins.cc:3060 #15 row_ins_index_entry_step (thr=0x620000031828, node=0x6200000315e8) at /mariadb/10.0/storage/xtradb/row/row0ins.cc:3135 #16 row_ins (thr=<optimized out>, node=<optimized out>) at /mariadb/10.0/storage/xtradb/row/row0ins.cc:3275 #17 row_ins_step (thr=thr@entry=0x620000031828) at /mariadb/10.0/storage/xtradb/row/row0ins.cc:3400 #18 0x0000562f33dbd3c9 in row_insert_for_mysql (mysql_rec=mysql_rec@entry=0x6190000d07a0 "\371\002", prebuilt=<optimized out>) at /mariadb/10.0/storage/xtradb/row/row0mysql.cc:1379 #19 0x0000562f33bb5c1d in ha_innobase::write_row (this=0x61c0000410a0, record=<optimized out>) at /mariadb/10.0/storage/xtradb/handler/ha_innodb.cc:7979 #20 0x0000562f33389129 in handler::ha_write_row (this=0x61c0000410a0, buf=<optimized out>) at /mariadb/10.0/sql/handler.cc:6033 #21 0x0000562f32deff83 in write_record (thd=thd@entry=0x62a000072208, table=0x61e000070888, info=info@entry=0x7f5a9478c1a0) at /mariadb/10.0/sql/sql_insert.cc:1848 #22 0x0000562f32e05bdf in mysql_insert (thd=thd@entry=0x62a000072208, table_list=0x6250000eda10, fields=..., values_list=..., update_fields=..., update_values=..., duplic=<optimized out>, ignore=<optimized out>) at /mariadb/10.0/sql/sql_insert.cc:964 #23 0x0000562f32e57387 in mysql_execute_command (thd=thd@entry=0x62a000072208) at /mariadb/10.0/sql/sql_parse.cc:3447 #24 0x0000562f32e672c1 in mysql_parse (thd=thd@entry=0x62a000072208, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7f5a9478f870) at /mariadb/10.0/sql/sql_parse.cc:6573 #25 0x0000562f32e6b633 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x62a000072208, packet=packet@entry=0x6290000f5209 "INSERT INTO t1 VALUES (2,2),(2,2)", packet_length=packet_length@entry=33) at /mariadb/10.0/sql/sql_parse.cc:1296 I think that it is risky to remove such locking. It is better to modify the code that is responsible for freeing the index stub. Either the stub will have to remain in memory until no locks are referring to it, or the locks will have to be removed. I think that it is safer to keep the stub in memory.

            This is possibly a regression introduced in a change in MySQL 5.6.8.
            This patch seems to fix it:

            diff --git a/storage/innobase/dict/dict0dict.cc b/storage/innobase/dict/dict0dict.cc
            index 0c8a278586d..7575a4aed62 100644
            --- a/storage/innobase/dict/dict0dict.cc
            +++ b/storage/innobase/dict/dict0dict.cc
            @@ -507,7 +507,8 @@ dict_table_try_drop_aborted(
             		ut_ad(table->id == table_id);
             	}
             
            -	if (table && table->n_ref_count == ref_count && table->drop_aborted) {
            +	if (table && table->n_ref_count == ref_count && table->drop_aborted
            +	    && !UT_LIST_GET_FIRST(table->locks)) {
             		/* Silence a debug assertion in row_merge_drop_indexes(). */
             		ut_d(table->n_ref_count++);
             		row_merge_drop_indexes(trx, table, TRUE);
            diff --git a/storage/innobase/row/row0merge.cc b/storage/innobase/row/row0merge.cc
            index 49c9aa4b51f..4090e388610 100644
            --- a/storage/innobase/row/row0merge.cc
            +++ b/storage/innobase/row/row0merge.cc
            @@ -2907,7 +2907,8 @@ row_merge_drop_indexes(
             
             	A concurrent purge will be prevented by dict_operation_lock. */
             
            -	if (!locked && table->n_ref_count > 1) {
            +	if (!locked && (table->n_ref_count > 1
            +			|| UT_LIST_GET_FIRST(table->locks))) {
             		/* We will have to drop the indexes later, when the
             		table is guaranteed to be no longer in use.  Mark the
             		indexes as incomplete and corrupted, so that other
            

            Unfortunately I did not come up with a reduced test case. My test for repeating is relying on a XA MDL bug that occurs after invoking DDL in a XA transaction (see for example MDEV-15518):

            --source include/have_innodb.inc
            CREATE TABLE t1 (col1 INT, col2 INT) ENGINE = InnoDB;
            INSERT INTO t1 VALUES (1,1);
            --connect(con1,localhost,root,,test)
            XA BEGIN 'xid';
            INSERT INTO t1 VALUES (1,0);
            --connection default
            send DELETE FROM t1;
            --connection con1
            send DELETE FROM t1;
            --connect(con2,localhost,root,,test)
            SET innodb_lock_wait_timeout= 1;
            send ALTER TABLE t1 ADD UNIQUE KEY uidx(col1);
            --connection con1
            --error 0,ER_LOCK_DEADLOCK
            --reap
            --error 0,ER_DUP_ENTRY
            INSERT INTO t1 VALUES (2,2),(2,2);
            --error ER_XAER_RMFAIL
            ALTER TABLE t1 FORCE;
            SELECT * FROM t1 FOR UPDATE;
            UPDATE t1 SET col2 = 3;
            # Cleanup
            --disconnect con1
            --connection con2
            --error 0,ER_LOCK_WAIT_TIMEOUT,ER_DUP_ENTRY,ER_DUP_UNKNOWN_IN_INDEX,ER_LOCK_WAIT_TIMEOUT
            --reap
            --disconnect con2
            --connection default
            --error 0,ER_LOCK_DEADLOCK,ER_LOCK_WAIT_TIMEOUT
            --reap
            DROP TABLE t1;
            

            With the above patch applied, the bug will not trigger.

            marko Marko Mäkelä added a comment - This is possibly a regression introduced in a change in MySQL 5.6.8 . This patch seems to fix it: diff --git a/storage/innobase/dict/dict0dict.cc b/storage/innobase/dict/dict0dict.cc index 0c8a278586d..7575a4aed62 100644 --- a/storage/innobase/dict/dict0dict.cc +++ b/storage/innobase/dict/dict0dict.cc @@ -507,7 +507,8 @@ dict_table_try_drop_aborted( ut_ad(table->id == table_id); } - if (table && table->n_ref_count == ref_count && table->drop_aborted) { + if (table && table->n_ref_count == ref_count && table->drop_aborted + && !UT_LIST_GET_FIRST(table->locks)) { /* Silence a debug assertion in row_merge_drop_indexes(). */ ut_d(table->n_ref_count++); row_merge_drop_indexes(trx, table, TRUE); diff --git a/storage/innobase/row/row0merge.cc b/storage/innobase/row/row0merge.cc index 49c9aa4b51f..4090e388610 100644 --- a/storage/innobase/row/row0merge.cc +++ b/storage/innobase/row/row0merge.cc @@ -2907,7 +2907,8 @@ row_merge_drop_indexes( A concurrent purge will be prevented by dict_operation_lock. */ - if (!locked && table->n_ref_count > 1) { + if (!locked && (table->n_ref_count > 1 + || UT_LIST_GET_FIRST(table->locks))) { /* We will have to drop the indexes later, when the table is guaranteed to be no longer in use. Mark the indexes as incomplete and corrupted, so that other Unfortunately I did not come up with a reduced test case. My test for repeating is relying on a XA MDL bug that occurs after invoking DDL in a XA transaction (see for example MDEV-15518 ): --source include/have_innodb.inc CREATE TABLE t1 (col1 INT , col2 INT ) ENGINE = InnoDB; INSERT INTO t1 VALUES (1,1); --connect(con1,localhost,root,,test) XA BEGIN 'xid' ; INSERT INTO t1 VALUES (1,0); --connection default send DELETE FROM t1; --connection con1 send DELETE FROM t1; --connect(con2,localhost,root,,test) SET innodb_lock_wait_timeout= 1; send ALTER TABLE t1 ADD UNIQUE KEY uidx(col1); --connection con1 --error 0,ER_LOCK_DEADLOCK --reap --error 0,ER_DUP_ENTRY INSERT INTO t1 VALUES (2,2),(2,2); --error ER_XAER_RMFAIL ALTER TABLE t1 FORCE ; SELECT * FROM t1 FOR UPDATE ; UPDATE t1 SET col2 = 3; # Cleanup --disconnect con1 --connection con2 --error 0,ER_LOCK_WAIT_TIMEOUT,ER_DUP_ENTRY,ER_DUP_UNKNOWN_IN_INDEX,ER_LOCK_WAIT_TIMEOUT --reap --disconnect con2 --connection default --error 0,ER_LOCK_DEADLOCK,ER_LOCK_WAIT_TIMEOUT --reap DROP TABLE t1; With the above patch applied, the bug will not trigger.

            People

              marko Marko Mäkelä
              marko Marko Mäkelä
              Votes:
              0 Vote for this issue
              Watchers:
              2 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.