[MDEV-23332] Assertion failure in file innobase/btr/btr0sea.cc, btr_search_drop_page_hash_index Created: 2020-07-29  Updated: 2020-08-03  Resolved: 2020-07-30

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.2, 10.3, 10.4
Fix Version/s: 10.2.33, 10.3.24, 10.4.14, 10.5.5

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Thirunarayanan Balathandayuthapani
Resolution: Fixed Votes: 0
Labels: rr-profile-analyzed

Issue Links:
Duplicate
is duplicated by MDEV-23370 innodb_fts.innodb_fts_misc failed in ... Closed
Problem/Incident
is caused by MDEV-22456 Dropping the adaptive hash index may ... Closed
Relates
relates to MDEV-23233 Race condition for btr_search_drop_pa... Closed

 Description   

The patch for MDEV-23233 is already in the tree

The test case is non-deterministic, run with --repeat. Remarkably and contrary to the usual, at least on two machines it reproduces the problem significantly easier when it's run with rr.
Recommended to run with --mysqld=--performance-schema=off. It is many times faster.
The rr profile is available.

--source include/have_sequence.inc
 
--source include/have_innodb.inc
 
 
 
CREATE TABLE t1 (pk INT AUTO_INCREMENT PRIMARY KEY, a VARCHAR(512), KEY(a)) ENGINE=InnoDB;
 
INSERT INTO t1 SELECT seq, CONCAT('seq',REPEAT(seq,100)) FROM seq_1_to_2500;
 
 
 
--connect (con1,localhost,root,,test)
 
SET lock_wait_timeout= 1;
 
--send
 
  ALTER TABLE t1 ADD INDEX (a);
 
 
 
--connection default
 
SELECT a INTO OUTFILE 'load_1' FROM t1;
 
LOAD DATA INFILE 'load_1' IGNORE INTO TABLE t1 (a);
 
SELECT a INTO OUTFILE 'load_2' FROM t1 ;
 
LOAD DATA INFILE 'load_2' IGNORE INTO TABLE t1 (a);
 
 
 
# Cleanup
 
--disconnect con1
 
DROP TABLE t1;
 
--let $datadir= `select @@datadir`
 
--remove_file $datadir/test/load_1
 
--remove_file $datadir/test/load_2

10.2 3c3f172f

 
#10 <signal handler called>
 
#11 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
 
#12 0x00007f2349ca342a in __GI_abort () at abort.c:89
 
#13 0x000055bcc69ff1d3 in ut_dbg_assertion_failed (expr=0x0, file=0x55bcc700c060 "/data/src/10.2/storage/innobase/btr/btr0sea.cc", line=1180) at /data/src/10.2/storage/innobase/ut/ut0dbg.cc:60
 
#14 0x000055bcc6a482c7 in btr_search_drop_page_hash_index (block=0x7f2344189900) at /data/src/10.2/storage/innobase/btr/btr0sea.cc:1180
 
#15 0x000055bcc6a65811 in buf_page_create (page_id=..., page_size=..., mtr=0x7f233c05f5e0) at /data/src/10.2/storage/innobase/buf/buf0buf.cc:5605
 
#16 0x000055bcc6afeca6 in fsp_page_create (space=0x7f22dc00b8c0, offset=285, page_size=..., rw_latch=RW_X_LATCH, mtr=0x7f233c05f5e0, init_mtr=0x7f233c05f5e0) at /data/src/10.2/storage/innobase/fsp/fsp0fsp.cc:1288
 
#17 0x000055bcc6b03105 in fseg_alloc_free_page_low (space=0x7f22dc00b8c0, page_size=..., seg_inode=0x7f23446ac0f2 "", hint=285, direction=111 'o', rw_latch=RW_X_LATCH, mtr=0x7f233c05f5e0, init_mtr=0x7f233c05f5e0, has_done_reservation=1) at /data/src/10.2/storage/innobase/fsp/fsp0fsp.cc:2581
 
#18 0x000055bcc6b0326e in fseg_alloc_free_page_general (seg_header=0x7f23446b004a "", hint=285, direction=111 'o', has_done_reservation=1, mtr=0x7f233c05f5e0, init_mtr=0x7f233c05f5e0) at /data/src/10.2/storage/innobase/fsp/fsp0fsp.cc:2634
 
#19 0x000055bcc6a092e0 in btr_page_alloc_low (index=0x7f22dc183770, hint_page_no=285, file_direction=111 'o', level=0, mtr=0x7f233c05f5e0, init_mtr=0x7f233c05f5e0) at /data/src/10.2/storage/innobase/btr/btr0btr.cc:529
 
#20 0x000055bcc6a0935c in btr_page_alloc (index=0x7f22dc183770, hint_page_no=285, file_direction=111 'o', level=0, mtr=0x7f233c05f5e0, init_mtr=0x7f233c05f5e0) at /data/src/10.2/storage/innobase/btr/btr0btr.cc:579
 
#21 0x000055bcc6a0f5f3 in btr_page_split_and_insert (flags=0, cursor=0x7f233c05f280, offsets=0x7f233c05f228, heap=0x7f233c05f220, tuple=0x7f22dc0545e0, n_ext=0, mtr=0x7f233c05f5e0) at /data/src/10.2/storage/innobase/btr/btr0btr.cc:2845
 
#22 0x000055bcc6a2f3df in btr_cur_pessimistic_insert (flags=0, cursor=0x7f233c05f280, offsets=0x7f233c05f228, heap=0x7f233c05f220, entry=0x7f22dc0545e0, rec=0x7f233c05f230, big_rec=0x7f233c05f218, n_ext=0, thr=0x7f22dc059fd0, mtr=0x7f233c05f5e0) at /data/src/10.2/storage/innobase/btr/btr0cur.cc:3437
 
#23 0x000055bcc69135a1 in row_ins_clust_index_entry_low (flags=0, mode=33, index=0x7f22dc183770, n_uniq=1, entry=0x7f22dc0545e0, n_ext=0, thr=0x7f22dc059fd0) at /data/src/10.2/storage/innobase/row/row0ins.cc:2712
 
#24 0x000055bcc69149db in row_ins_clust_index_entry (index=0x7f22dc183770, entry=0x7f22dc0545e0, thr=0x7f22dc059fd0, n_ext=0) at /data/src/10.2/storage/innobase/row/row0ins.cc:3159
 
#25 0x000055bcc6914cfb in row_ins_index_entry (index=0x7f22dc183770, entry=0x7f22dc0545e0, thr=0x7f22dc059fd0) at /data/src/10.2/storage/innobase/row/row0ins.cc:3263
 
#26 0x000055bcc691521f in row_ins_index_entry_step (node=0x7f22dc059b80, thr=0x7f22dc059fd0) at /data/src/10.2/storage/innobase/row/row0ins.cc:3414
 
#27 0x000055bcc69155f5 in row_ins (node=0x7f22dc059b80, thr=0x7f22dc059fd0) at /data/src/10.2/storage/innobase/row/row0ins.cc:3551
 
#28 0x000055bcc69159a2 in row_ins_step (thr=0x7f22dc059fd0) at /data/src/10.2/storage/innobase/row/row0ins.cc:3671
 
#29 0x000055bcc69332f6 in row_insert_for_mysql (mysql_rec=0x7f22dc0591a8 "\376\356\022", prebuilt=0x7f22dc059650) at /data/src/10.2/storage/innobase/row/row0mysql.cc:1411
 
#30 0x000055bcc67f422f in ha_innobase::write_row (this=0x7f22dc058a18, record=0x7f22dc0591a8 "\376\356\022") at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:8178
 
#31 0x000055bcc6601c26 in handler::ha_write_row (this=0x7f22dc058a18, buf=0x7f22dc0591a8 "\376\356\022") at /data/src/10.2/sql/handler.cc:6108
 
#32 0x000055bcc6357731 in write_record (thd=0x7f22dc000af0, table=0x7f22dc057e10, info=0x7f233c0604a0) at /data/src/10.2/sql/sql_insert.cc:1941
 
#33 0x000055bcc6788ab5 in read_sep_field (thd=0x7f22dc000af0, info=..., table_list=0x7f22dc0125c8, fields_vars=..., set_fields=..., set_values=..., read_info=..., enclosed=..., skip_lines=0, ignore_check_option_errors=true) at /data/src/10.2/sql/sql_load.cc:1175
 
#34 0x000055bcc6787120 in mysql_load (thd=0x7f22dc000af0, ex=0x7f22dc012540, table_list=0x7f22dc0125c8, fields_vars=..., set_fields=..., set_values=..., handle_duplicates=DUP_ERROR, ignore=true, read_file_from_client=false) at /data/src/10.2/sql/sql_load.cc:682
 
#35 0x000055bcc637d2c8 in mysql_execute_command (thd=0x7f22dc000af0) at /data/src/10.2/sql/sql_parse.cc:4572
 
#36 0x000055bcc63871a9 in mysql_parse (thd=0x7f22dc000af0, rawbuf=0x7f22dc012458 "LOAD DATA INFILE 'load_1' IGNORE INTO TABLE t1 (a)", length=50, parser_state=0x7f233c061610, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:7733
 
#37 0x000055bcc63754d5 in dispatch_command (command=COM_QUERY, thd=0x7f22dc000af0, packet=0x7f22dc095a51 "", packet_length=50, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1824
 
#38 0x000055bcc6373f50 in do_command (thd=0x7f22dc000af0) at /data/src/10.2/sql/sql_parse.cc:1377
 
#39 0x000055bcc64c9fb1 in do_handle_one_connection (connect=0x55bcca005ec0) at /data/src/10.2/sql/sql_connect.cc:1336
 
#40 0x000055bcc64c9d1c in handle_one_connection (arg=0x55bcca005ec0) at /data/src/10.2/sql/sql_connect.cc:1241
 
#41 0x000055bcc6ce0396 in pfs_spawn_thread (arg=0x55bcc9fe3ba0) at /data/src/10.2/storage/perfschema/pfs.cc:1869
 
#42 0x00007f234bc234a4 in start_thread (arg=0x7f233c062700) at pthread_create.c:456
 
#43 0x00007f2349d57d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Also fails on 10.3-10.4, but those branches don't have the bugfix for MDEV-23233 yet, so I don't know if it's important.

Alternative stack trace from the same test case:

10.4 423de1e5

 
#10 <signal handler called>
 
#11 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
 
#12 0x00007f05a633242a in __GI_abort () at abort.c:89
 
#13 0x0000561690fecba8 in ut_dbg_assertion_failed (expr=0x0, file=0x5616917b89b0 "/data/src/10.4/storage/innobase/btr/btr0sea.cc", line=1162) at /data/src/10.4/storage/innobase/ut/ut0dbg.cc:60
 
#14 0x0000561691052781 in btr_search_drop_page_hash_index (block=0x7f059f40c270) at /data/src/10.4/storage/innobase/btr/btr0sea.cc:1162
 
#15 0x00005616910a0ea6 in buf_LRU_free_page (bpage=0x7f059f40c270, zip=true) at /data/src/10.4/storage/innobase/buf/buf0lru.cc:1608
 
#16 0x0000561691090e08 in buf_flush_LRU_list_batch (buf_pool=0x5616940589a0, max=100, n=0x7f058adfcc20) at /data/src/10.4/storage/innobase/buf/buf0flu.cc:1621
 
#17 0x000056169109133b in buf_do_LRU_batch (buf_pool=0x5616940589a0, max=100, n=0x7f058adfcc20) at /data/src/10.4/storage/innobase/buf/buf0flu.cc:1692
 
#18 0x0000561691091bd7 in buf_flush_batch (buf_pool=0x5616940589a0, flush_type=BUF_FLUSH_LRU, min_n=100, lsn_limit=0, n=0x7f058adfcc20) at /data/src/10.4/storage/innobase/buf/buf0flu.cc:1821
 
#19 0x00005616910923e3 in buf_flush_do_batch (buf_pool=0x5616940589a0, type=BUF_FLUSH_LRU, min_n=100, lsn_limit=0, n=0x7f058adfcc20) at /data/src/10.4/storage/innobase/buf/buf0flu.cc:1982
 
#20 0x0000561691092eb9 in buf_flush_LRU_list (buf_pool=0x5616940589a0) at /data/src/10.4/storage/innobase/buf/buf0flu.cc:2245
 
#21 0x0000561691095154 in pc_flush_slot () at /data/src/10.4/storage/innobase/buf/buf0flu.cc:2765
 
#22 0x00005616910962a1 in buf_flush_page_cleaner_coordinator () at /data/src/10.4/storage/innobase/buf/buf0flu.cc:3194
 
#23 0x00007f05a82b24a4 in start_thread (arg=0x7f058adfd700) at pthread_create.c:456
 
#24 0x00007f05a63e6d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Doesn't seem to fail on 10.5.

 Comments   
Comment by Thirunarayanan Balathandayuthapani [ 2020-07-30 ]

In row_merge_drop_indexes(), InnoDB have to drop the index later if the table is being
used by some other thread. In that case, InnoDB removes the index from dictionary
and frees the index pages but it maintains the index object and it doesn't
remove the respective ahi entries also. (could be related to MDEV-22456)

                                
					rw_lock_x_lock(
 
                                                dict_index_get_lock(index));
 
                                        dict_index_set_online_status(
 
                                                index, ONLINE_INDEX_ABORTED);
 
                                        index->type |= DICT_CORRUPT;
 
                                        table->drop_aborted = TRUE;
 
                                        goto drop_aborted;
 
 
 
				........................
 
				........................
 
				.........................                        
 
 
drop_aborted:
 
                                rw_lock_x_unlock(dict_index_get_lock(index));
 
 
 
                                DEBUG_SYNC_C("merge_drop_index_after_abort");
 
                                /* covered by dict_sys->mutex */
 
                                MONITOR_INC(MONITOR_BACKGROUND_DROP_INDEX);
 
                                /* fall through */
 
                        case ONLINE_INDEX_ABORTED:
 
                                /* Drop the index tree from the
 
                                data dictionary and free it from
 
                                the tablespace, but keep the object
 
                                in the data dictionary cache. */
 
                                row_merge_drop_index_dict(trx, index->id);
 
                                rw_lock_x_lock(dict_index_get_lock(index));
 
                                dict_index_set_online_status(
 
                                        index, ONLINE_INDEX_ABORTED_DROPPED);
 
                                rw_lock_x_unlock(dict_index_get_lock(index));
 
                                table->drop_aborted = TRUE;
 
                                continue;

This leads to assert failure when we use the existing page from buffer pool.
IMO, there is no need to check index online status in btr_search_drop_page_hash_index() and removing it completely
would make sense

Comment by Marko Mäkelä [ 2020-07-30 ]

I do not see a call to dict_index_t::set_freed(), so this cannot be caused by MDEV-22456. There are the following transitions on dict_index_t::online_status:

10.2 3c3f172f17de217389bc51053c555a5d7e91ddff

 
Thread 2 hit Hardware watchpoint 2: -location block.index.online_status
 
 
 
Old value = 0
 
New value = 1
 
dict_index_set_online_status (index=0x7f683c021d50, 
    status=ONLINE_INDEX_CREATION)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/include/dict0dict.ic:1263
 
1263		ut_ad(dict_index_get_online_status(index) == status);
 
(rr) when
 
Current event: 22199
 
(rr) bt
 
#0  dict_index_set_online_status (index=0x7f683c021d50, 
    status=ONLINE_INDEX_CREATION)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/include/dict0dict.ic:1263
 
#1  0x000055a3c6373a81 in row_log_allocate (index=0x7f683c021d50, table=0x0, 
    same_pk=true, add_cols=0x0, col_map=0x0, path=0x0)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/row/row0log.cc:3003
 
#2  0x000055a3c625679c in prepare_inplace_alter_table_dict (
 
    ha_alter_info=0x7f688c0f6060, altered_table=0x7f683c01b240, 
    old_table=0x7f684809d180, table_name=0x7f684802c8ad "t1", flags=33, 
    flags2=80, fts_doc_id_col=18446744073709551615, add_fts_doc_id=false, 
    add_fts_doc_id_idx=false)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/handler/handler0alter.cc:4895
 
…
 
#9  0x000055a3c5db03d7 in mysql_parse (thd=0x7f683c000d50, 
    rawbuf=0x7f683c0112f8 "ALTER TABLE t1 ADD INDEX (a)", length=28, 
    parser_state=0x7f688c0f8640, is_com_multi=false, is_next_command=false)
 
    at /home/mariadb/MDEV-23332/10.2/sql/sql_parse.cc:7733
 
…
 
(rr) c
 
Continuing.
 
 
 
Thread 2 hit Hardware watchpoint 2: -location block.index.online_status
 
 
 
Old value = 1
 
New value = 0
 
dict_index_set_online_status (index=0x7f683c021d50, 
    status=ONLINE_INDEX_COMPLETE)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/include/dict0dict.ic:1263
 
1263		ut_ad(dict_index_get_online_status(index) == status);
 
(rr) watch -l index.uncommitted
 
Hardware watchpoint 3: -location index.uncommitted
 
(rr) c
 
Continuing.
 
 
 
Thread 2 hit Hardware watchpoint 2: -location block.index.online_status
 
 
 
Old value = 0
 
New value = 2
 
dict_index_set_online_status (index=0x7f683c021d50, 
    status=ONLINE_INDEX_ABORTED)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/include/dict0dict.ic:1263
 
1263		ut_ad(dict_index_get_online_status(index) == status);
 
(rr) p index.uncommitted
 
$3 = 1
 
(rr) bt
 
#0  dict_index_set_online_status (index=0x7f683c021d50, 
    status=ONLINE_INDEX_ABORTED)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/include/dict0dict.ic:1263
 
#1  0x000055a3c6351659 in row_merge_drop_indexes (trx=0x7f68ad799390, 
    table=0x7f684818b000, locked=0)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/row/row0merge.cc:3791
 
#2  0x000055a3c625b395 in innobase_rollback_sec_index (
 
    user_table=0x7f684818b000, table=0x7f684809d180, locked=0, 
    trx=0x7f68ad799390)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/handler/handler0alter.cc:6467
 
#3  0x000055a3c6261979 in rollback_inplace_alter_table (
 
    ha_alter_info=0x7f688c0f6060, table=0x7f684809d180, 
    prebuilt=0x7f684802ddd0)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/handler/handler0alter.cc:6560
 
#4  0x000055a3c625ded2 in ha_innobase::commit_inplace_alter_table (
 
    this=0x7f684809dd88, altered_table=0x7f683c01b240, 
    ha_alter_info=0x7f688c0f6060, commit=false)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/handler/handler0alter.cc:8215
 
#5  0x000055a3c602767c in handler::ha_commit_inplace_alter_table (
 
    this=0x7f684809dd88, altered_table=0x7f683c01b240, 
    ha_alter_info=0x7f688c0f6060, commit=false)
 
    at /home/mariadb/MDEV-23332/10.2/sql/handler.cc:4378
 
#6  0x000055a3c5e764f2 in mysql_inplace_alter_table (thd=0x7f683c000d50, 
    table_list=0x7f683c0113e0, table=0x7f684809d180, 
    altered_table=0x7f683c01b240, ha_alter_info=0x7f688c0f6060, 
    inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, 
    target_mdl_request=0x7f688c0f60f0, alter_ctx=0x7f688c0f66a0)
 
    at /home/mariadb/MDEV-23332/10.2/sql/sql_table.cc:7573
 
#7  0x000055a3c5e7be12 in mysql_alter_table (thd=0x7f683c000d50, 
    new_db=0x7f683c0119f8 "test", new_name=0x0, create_info=0x7f688c0f72c0, 
    table_list=0x7f683c0113e0, alter_info=0x7f688c0f7210, order_num=0, 
    order=0x0, ignore=false)
 
    at /home/mariadb/MDEV-23332/10.2/sql/sql_table.cc:9622
 
#8  0x000055a3c5ef877d in Sql_cmd_alter_table::execute (this=0x7f683c011ac0, 
    thd=0x7f683c000d50) at /home/mariadb/MDEV-23332/10.2/sql/sql_alter.cc:333
 
#9  0x000055a3c5dab43f in mysql_execute_command (thd=0x7f683c000d50)
 
    at /home/mariadb/MDEV-23332/10.2/sql/sql_parse.cc:5964
 
#10 0x000055a3c5db03d7 in mysql_parse (thd=0x7f683c000d50, 
    rawbuf=0x7f683c0112f8 "ALTER TABLE t1 ADD INDEX (a)", length=28, 
    parser_state=0x7f688c0f8640, is_com_multi=false, is_next_command=false)
 
    at /home/mariadb/MDEV-23332/10.2/sql/sql_parse.cc:7733
 
…
 
(rr) c
 
Continuing.
 
 
 
Thread 2 hit Hardware watchpoint 2: -location block.index.online_status
 
 
 
Old value = 2
 
New value = 3
 
dict_index_set_online_status (index=0x7f683c021d50, status=ONLINE_INDEX_ABORTED_DROPPED)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/include/dict0dict.ic:1263
 
1263		ut_ad(dict_index_get_online_status(index) == status);
 
(rr) bt
 
#0  dict_index_set_online_status (index=0x7f683c021d50, status=ONLINE_INDEX_ABORTED_DROPPED)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/include/dict0dict.ic:1263
 
#1  0x000055a3c63517fc in row_merge_drop_indexes (trx=0x7f68ad799390, table=0x7f684818b000, locked=0)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/row/row0merge.cc:3816
 
#2  0x000055a3c625b395 in innobase_rollback_sec_index (user_table=0x7f684818b000, table=0x7f684809d180, 
    locked=0, trx=0x7f68ad799390)
 
(rr) c
 
Continuing.
 
 
 
Thread 28 received signal SIGABRT, Aborted.
 
[Switching to Thread 18779.18881]
 
__GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
 
51	../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
 
(rr) up 4
 
#4  0x000055a3c648f1cf in buf_page_create (page_id=..., page_size=..., mtr=0x7f68a405c640)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/buf/buf0buf.cc:5605
 
5605				btr_search_drop_page_hash_index(block);
 
(rr) p *block.index
 
$4 = {id = 23, heap = 0x7f683c021be0, name = {m_name = 0x7f683c022000 "a_2"}, 
  table_name = 0x7f6848028ba0 "test/t1", table = 0x7f684818b000, space = 4, page = 136, 
…
 
(rr) p block.index.table.indexes
 
$5 = {count = 3, start = 0x7f684802cdb0, end = 0x7f683c021d50, node = &dict_index_t::indexes, 
  init = 51966}
 
(rr) p block.index
 
$6 = (dict_index_t *) 0x7f683c021d50

I agree that the debug check is meaningless and should be removed. The index creation was completed, but the index had not been committed yet, because concurrent DML is holding MDL. Therefore, the ALTER TABLE was rolled back. The concurrent DML would also update the uncommitted index. Had it been a UNIQUE index, the concurrent DML would report the duplicate key error to the ALTER TABLE transaction only, leading it to be rolled back.

As we can see from the end of the above output, the index is still attached to dict_table_t::indexes, and MDEV-22456 is not involved in this. If it were, we would have block->index->page==1.

Comment by Thirunarayanan Balathandayuthapani [ 2020-07-30 ]

The following stack trace proves that MDEV-22456 is the root cause of the issue:

#0  buf_page_set_file_page_was_freed (page_id=...) at /home/mariadb/MDEV-23332/10.2/storage/innobase/buf/buf0buf.cc:3624
 
#1  0x000055a3c652e7e6 in fseg_free_extent (seg_inode=0x7f68ad39c3f2 "", space=0x7f684802b180, page_size=..., page=256, mtr=0x7f688c0f4130)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/fsp/fsp0fsp.cc:3180
 
#2  0x000055a3c652eb2a in fseg_free_step (header=0x7f68ad5f804a "", mtr=0x7f688c0f4130) at /home/mariadb/MDEV-23332/10.2/storage/innobase/fsp/fsp0fsp.cc:3239
 
#3  0x000055a3c6434a80 in btr_free_but_not_root (block=0x7f68acec3e00, log_mode=MTR_LOG_ALL)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/btr/btr0btr.cc:1258
 
#4  0x000055a3c6434c4a in btr_free_if_exists (page_id=..., page_size=..., index_id=23, mtr=0x7f688c0f49a0)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/btr/btr0btr.cc:1307
 
#5  0x000055a3c64c3971 in dict_drop_index_tree (rec=0x7f68ad1ac3b8 "", pcur=0x7f683c023f70, trx=0x7f68ad799390, mtr=0x7f688c0f49a0)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/dict/dict0crea.cc:1025
 
#6  0x000055a3c63b641c in row_upd_clust_step (node=0x7f683c023b30, thr=0x7f683c024338) at /home/mariadb/MDEV-23332/10.2/storage/innobase/row/row0upd.cc:3126
 
#7  0x000055a3c63b6b3e in row_upd (node=0x7f683c023b30, thr=0x7f683c024338) at /home/mariadb/MDEV-23332/10.2/storage/innobase/row/row0upd.cc:3292
 
#8  0x000055a3c63b7015 in row_upd_step (thr=0x7f683c024338) at /home/mariadb/MDEV-23332/10.2/storage/innobase/row/row0upd.cc:3438
 
#9  0x000055a3c630e55f in que_thr_step (thr=0x7f683c024338) at /home/mariadb/MDEV-23332/10.2/storage/innobase/que/que0que.cc:1024
 
#10 0x000055a3c630e841 in que_run_threads_low (thr=0x7f683c024338) at /home/mariadb/MDEV-23332/10.2/storage/innobase/que/que0que.cc:1104
 
#11 0x000055a3c630e9f3 in que_run_threads (thr=0x7f683c024338) at /home/mariadb/MDEV-23332/10.2/storage/innobase/que/que0que.cc:1144
 
#12 0x000055a3c630ec8e in que_eval_sql (info=0x7f683c020570, 
    sql=0x55a3c699e080 <row_merge_drop_index_dict(trx_t*, unsigned long)::sql> "PROCEDURE DROP_INDEX_PROC () IS\nBEGIN\nDELETE FROM SYS_FIELDS WHERE INDEX_ID=:indexid;\nDELETE FROM SYS_INDEXES WHERE ID=:indexid;\nEND;\n", reserve_dict_mutex=0, trx=0x7f68ad799390)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/que/que0que.cc:1221
 
#13 0x000055a3c6350f81 in row_merge_drop_index_dict (trx=0x7f68ad799390, index_id=23) at /home/mariadb/MDEV-23332/10.2/storage/innobase/row/row0merge.cc:3614
 
#14 0x000055a3c63517c6 in row_merge_drop_indexes (trx=0x7f68ad799390, table=0x7f684818b000, locked=0)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/row/row0merge.cc:3814
 
#15 0x000055a3c625b395 in innobase_rollback_sec_index (user_table=0x7f684818b000, table=0x7f684809d180, locked=0, trx=0x7f68ad799390)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/handler/handler0alter.cc:6467
 
#16 0x000055a3c6261979 in rollback_inplace_alter_table (ha_alter_info=0x7f688c0f6060, table=0x7f684809d180, prebuilt=0x7f684802ddd0)
 
    at /home/mariadb/MDEV-23332/10.2/storage/innobase/handler/handler0alter.cc:6560
 
#17 0x000055a3c625ded2 in ha_innobase::commit_inplace_alter_table (this=0x7f684809dd88, altered_table=0x7f683c01b240, ha_alter_info=0x7f688c0f6060, 
    commit=false) at /home/mariadb/MDEV-23332/10.2/storage/innobase/handler/handler0alter.cc:8215
 
#18 0x000055a3c602767c in handler::ha_commit_inplace_alter_table (this=0x7f684809dd88, altered_table=0x7f683c01b240, ha_alter_info=0x7f688c0f6060, 
    commit=false) at /home/mariadb/MDEV-23332/10.2/sql/handler.cc:4378
 
#19 0x000055a3c5e764f2 in mysql_inplace_alter_table (thd=0x7f683c000d50, table_list=0x7f683c0113e0, table=0x7f684809d180, altered_table=0x7f683c01b240, 
    ha_alter_info=0x7f688c0f6060, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7f688c0f60f0, alter_ctx=0x7f688c0f66a0)
 
    at /home/mariadb/MDEV-23332/10.2/sql/sql_table.cc:7573
 
#20 0x000055a3c5e7be12 in mysql_alter_table (thd=0x7f683c000d50, new_db=0x7f683c0119f8 "test", new_name=0x0, create_info=0x7f688c0f72c0, 
    table_list=0x7f683c0113e0, alter_info=0x7f688c0f7210, order_num=0, order=0x0, ignore=false) at /home/mariadb/MDEV-23332/10.2/sql/sql_table.cc:9622
 
#21 0x000055a3c5ef877d in Sql_cmd_alter_table::execute (this=0x7f683c011ac0, thd=0x7f683c000d50) at /home/mariadb/MDEV-23332/10.2/sql/sql_alter.cc:333
 
#22 0x000055a3c5dab43f in mysql_execute_command (thd=0x7f683c000d50) at /home/mariadb/MDEV-23332/10.2/sql/sql_parse.cc:5964
 
#23 0x000055a3c5db03d7 in mysql_parse (thd=0x7f683c000d50, rawbuf=0x7f683c0112f8 "ALTER TABLE t1 ADD INDEX (a)", length=28, parser_state=0x7f688c0f8640, 
    is_com_multi=false, is_next_command=false) at /home/mariadb/MDEV-23332/10.2/sql/sql_parse.cc:7733
 
---Type <return> to continue, or q <return> to quit---
 
#24 0x000055a3c5d9e6e3 in dispatch_command (command=COM_QUERY, thd=0x7f683c000d50, packet=0x7f683c008b11 "ALTER TABLE t1 ADD INDEX (a)", packet_length=28, 
    is_com_multi=false, is_next_command=false) at /home/mariadb/MDEV-23332/10.2/sql/sql_parse.cc:1823
 
#25 0x000055a3c5d9d160 in do_command (thd=0x7f683c000d50) at /home/mariadb/MDEV-23332/10.2/sql/sql_parse.cc:1377
 
#26 0x000055a3c5ef3303 in do_handle_one_connection (connect=0x55a3c94334f0) at /home/mariadb/MDEV-23332/10.2/sql/sql_connect.cc:1336
 
#27 0x000055a3c5ef306e in handle_one_connection (arg=0x55a3c94334f0) at /home/mariadb/MDEV-23332/10.2/sql/sql_connect.cc:1241
 
#28 0x00007f68af51e6db in start_thread (arg=0x7f688c0f9700) at pthread_create.c:463
 
#29 0x00007f68ae908a3f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

MDEV-22456 removes ahi removal from fseg_free_extent.

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