[MDEV-22634] Assertion `dict_index_is_clust(index) || !dict_index_is_online_ddl(index)' failed in lock_rec_create_low Created: 2020-05-19  Updated: 2023-10-24  Resolved: 2023-10-24

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.2.33, 10.3, 10.4, 10.5, 10.6
Fix Version/s: N/A

Type: Bug Priority: Critical
Reporter: Matthias Leich Assignee: Matthias Leich
Resolution: Cannot Reproduce Votes: 0
Labels: need_rr

Issue Links:
Relates
relates to MDEV-20605 Awaken transaction can miss inserted ... Closed
relates to MDEV-22618 Assertion `!dict_index_is_online_ddl(... Closed

 Description    

commit 4c0f3b3be76343c155b00feff3309d91e1e11441 origin/bb-10.2-marko
 
containing a fix for MDEV-19114 but IIRC I have seen that assert some time ago
 
 
 
Version: '10.2.33-MariaDB-debug-log'  socket:...
 
mysqld: /home/mleich/bb-10.2-marko_2/storage/innobase/lock/lock0lock.cc:1408: ib_lock_t* lock_rec_create_low(ib_lock_t*, que_thr_t*, ulint, ulint, ulint, const ib_page_t*, ulint, dict_index_t*, trx_t*, bool): Assertion `dict_index_is_clust(index) || !dict_index_is_online_ddl(index)' failed.
 
...
 
lock/lock0lock.cc:1414(lock_rec_create_low(ib_lock_t*, que_thr_t*, unsigned long, unsigned long, unsigned long, unsigned char const*, unsigned long, dict_index_t*, trx_t*, bool))[0x5607fc95ac08]
 
include/lock0lock.ic:133(lock_rec_create(ib_lock_t*, que_thr_t*, unsigned long, buf_block_t const*, unsigned long, dict_index_t*, trx_t*, bool))[0x5607fc9785ec]
 
lock/lock0lock.cc:1954(lock_rec_add_to_queue(unsigned long, buf_block_t const*, unsigned long, dict_index_t*, trx_t*, bool))[0x5607fc83dc32]
 
page/page0page.cc:777(page_copy_rec_list_end(buf_block_t*, buf_block_t*, unsigned char*, dict_index_t*, mtr_t*))[0x5607fc64a0e2]
 
/home/mleich/Server_bin/bb-10.2-marko_2_debug/bin/mysqld(_Z12write_recordP3THDP5TABLEP12st_copy_info+0xdd1)[0x5607fc3a0cfc]
 
/home/mleich/Server_bin/bb-10.2-marko_2_debug/bin/mysqld(_Z12mysql_insertP3THDP10TABLE_LISTR4ListI4ItemERS3_IS5_ES6_S6_15enum_duplicatesb+0x10fe)[0x5607fc39e7b8]
 
btr/btr0btr.cc:2995(btr_page_split_and_insert(unsigned long, btr_cur_t*, unsigned short**, mem_block_info_t**, dtuple_t const*, unsigned long, mtr_t*))[0x5607fc3c50ab]
 
btr/btr0cur.cc:3414(btr_cur_pessimistic_insert(unsigned long, btr_cur_t*, unsigned short**, mem_block_info_t**, dtuple_t*, unsigned char**, big_rec_t**, unsigned long, que_thr_t*, mtr_t*))[0x5607fc3d07f1]
 
row/row0ins.cc:2723(row_ins_clust_index_entry_low(unsigned long, unsigned long, dict_index_t*, unsigned long, dtuple_t*, unsigned long, que_thr_t*))[0x5607fc3beb24]
 
row/row0ins.cc:3274(row_ins_index_entry(dict_index_t*, dtuple_t*, que_thr_t*))[0x5607fc3bd5a1]
 
row/row0ins.cc:3425(row_ins_index_entry_step(ins_node_t*, que_thr_t*))[0x5607fc512317]
 
row/row0ins.cc:3562(row_ins(ins_node_t*, que_thr_t*))[0x5607fc512082]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x76db)[0x7fc67459c6db]
 
/lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7fc67398688f]
 
 
 
Query: INSERT INTO t3 (col1,col2, col_int, col_string, col_text) VALUES ....
 
Connection ID (thread ID): 46
 
Status: NOT_KILLED
 
 
 
RQG branch:
 
git clone https://github.com/mleich1/rqg --branch experimental RQG_mleich
 
 
 
perl rqg.pl \                    
--mysqld=--loose-innodb_lock_schedule_algorithm=fcfs \
 
--grammar=conf/mariadb/table_stress_innodb.yy \
 
--gendata=conf/mariadb/table_stress.zz \
 
--gendata_sql=conf/mariadb/table_stress.sql \
 
--engine=Innodb \
 
--reporters=Deadlock1,ErrorLog,Backtrace \
 
--mysqld=--connect_timeout=60 \
 
--mysqld=--net_read_timeout=30 \
 
--mysqld=--net_write_timeout=60 \
 
--mysqld=--loose-idle_readonly_transaction_timeout=0 \
 
--mysqld=--loose-idle_transaction_timeout=0 \
 
--mysqld=--loose-idle_write_transaction_timeout=0 \
 
--mysqld=--interactive_timeout=28800 \
 
--mysqld=--lock_wait_timeout=86400 \
 
--mysqld=--innodb-lock-wait-timeout=50 \
 
--mysqld=--loose-table_lock_wait_timeout=50 \
 
--mysqld=--wait_timeout=28800 \
 
--mysqld=--slave_net_timeout=60 \
 
--mysqld=--loose-max-statement-time=30 \
 
--mysqld=--loose-debug_assert_on_not_freed_memory=0 \
 
--mysqld=--log-output=none \
 
--duration=300 \
 
--seed=random \
 
--sqltrace=MarkErrors \
 
--threads=33 \
 
--mysqld=--innodb_adaptive_hash_index=OFF \
 
--mysqld=--innodb_page_size=8K \
 
--mysqld=--innodb-buffer-pool-size=256M \
 
--no_mask \
 
--workdir=<local settings> \
 
 
 
--vardir=<local settings> \
 
--mtr-build-thread=<local settings> \
 
--basedir1=<local settings> \
 
--basedir2=<local settings> \
 
--script_debug=_nix_ \
 
--rr=Server



 Comments   
Comment by Marko Mäkelä [ 2020-05-19 ]

I believe that the scenario is similar to MDEV-22618. I do not think that we should skip any explicit record locking on an index whose creation has been aborted (index->online_status is ONLINE_INDEX_ABORTED or ONLINE_INDEX_ABORTED_DROPPED). When creating the lock, we should assert that index->online_status == ONLINE_INDEX_COMPLETE.

Comment by Eugene Kosov (Inactive) [ 2020-05-21 ] 

#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
 
#1  0x00007fc6738a5801 in __GI_abort () at abort.c:79
 
#2  0x00007fc67389539a in __assert_fail_base (fmt=0x7fc673a1c7d8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", 
    assertion=assertion@entry=0x5607fcfe0720 "dict_index_is_clust(index) || !dict_index_is_online_ddl(index)", 
    file=file@entry=0x5607fcfe00a8 "/home/mleich/bb-10.2-marko_2/storage/innobase/lock/lock0lock.cc", line=line@entry=1408, 
    function=function@entry=0x5607fcfe4f00 <lock_rec_create_low(ib_lock_t*, que_thr_t*, unsigned long, unsigned long, unsigned long, unsigned char const*, unsigned long, dict_index_t*, trx_t*, bool)::__PRETTY_FUNCTION__> "ib_lock_t* lock_rec_create_low(ib_lock_t*, que_thr_t*, ulint, ulint, ulint, const ib_page_t*, ulint, dict_index_t*, trx_t*, bool)") at assert.c:92
 
#3  0x00007fc673895412 in __GI___assert_fail (assertion=0x5607fcfe0720 "dict_index_is_clust(index) || !dict_index_is_online_ddl(index)", 
    file=0x5607fcfe00a8 "/home/mleich/bb-10.2-marko_2/storage/innobase/lock/lock0lock.cc", line=1408, 
    function=0x5607fcfe4f00 <lock_rec_create_low(ib_lock_t*, que_thr_t*, unsigned long, unsigned long, unsigned long, unsigned char const*, unsigned long, dict_index_t*, trx_t*, bool)::__PRETTY_FUNCTION__> "ib_lock_t* lock_rec_create_low(ib_lock_t*, que_thr_t*, ulint, ulint, ulint, const ib_page_t*, ulint, dict_index_t*, trx_t*, bool)")
 
    at assert.c:101
 
#4  0x00005607fc8b3810 in lock_rec_create_low (c_lock=0x0, thr=0x0, type_mode=546, space=92, page_no=11, page=0x7fc65e1ae000 "", heap_no=3, index=0x7fc56802db20, 
    trx=0x7fc67111e298, holds_trx_mutex=false) at /home/mleich/bb-10.2-marko_2/storage/innobase/lock/lock0lock.cc:1408
 
#5  0x00005607fc8af0a4 in lock_rec_create (c_lock=0x0, thr=0x0, type_mode=546, block=0x7fc65cc33750, heap_no=3, index=0x7fc56802db20, trx=0x7fc67111e298, 
    caller_owns_trx_mutex=false) at /home/mleich/bb-10.2-marko_2/storage/innobase/include/lock0lock.ic:133
 
#6  0x00005607fc8b5804 in lock_rec_add_to_queue (type_mode=546, block=0x7fc65cc33750, heap_no=3, index=0x7fc56802db20, trx=0x7fc67111e298, caller_owns_trx_mutex=false)
 
    at /home/mleich/bb-10.2-marko_2/storage/innobase/lock/lock0lock.cc:1954
 
#7  0x00005607fc8b82cf in lock_move_rec_list_end (new_block=0x7fc65cc33750, block=0x7fc65cc21758, rec=0x7fc65e0f0da1 "\200")
 
    at /home/mleich/bb-10.2-marko_2/storage/innobase/lock/lock0lock.cc:2970
 
#8  0x00005607fc908dcd in page_copy_rec_list_end (new_block=0x7fc65cc33750, block=0x7fc65cc21758, rec=0x7fc65e0f0da1 "\200", index=0x7fc598036cd0, mtr=0x7fc589ba4b20)
 
    at /home/mleich/bb-10.2-marko_2/storage/innobase/page/page0page.cc:774
 
#9  0x00005607fc90a4b0 in page_move_rec_list_end (new_block=0x7fc65cc33750, block=0x7fc65cc21758, split_rec=0x7fc65e0f0da1 "\200", index=0x7fc598036cd0, mtr=0x7fc589ba4b20)
 
    at /home/mleich/bb-10.2-marko_2/storage/innobase/page/page0page.cc:1367
 
#10 0x00005607fca53c5c in btr_page_split_and_insert (flags=0, cursor=0x7fc589ba47c0, offsets=0x7fc589ba4768, heap=0x7fc589ba4760, tuple=0x7fc57802cff0, n_ext=1, 
    mtr=0x7fc589ba4b20) at /home/mleich/bb-10.2-marko_2/storage/innobase/btr/btr0btr.cc:2995
 
#11 0x00005607fca513cf in btr_root_raise_and_insert (flags=0, cursor=0x7fc589ba47c0, offsets=0x7fc589ba4768, heap=0x7fc589ba4760, tuple=0x7fc57802cff0, n_ext=1, 
    mtr=0x7fc589ba4b20) at /home/mleich/bb-10.2-marko_2/storage/innobase/btr/btr0btr.cc:2025
 
#12 0x00005607fca723d0 in btr_cur_pessimistic_insert (flags=0, cursor=0x7fc589ba47c0, offsets=0x7fc589ba4768, heap=0x7fc589ba4760, entry=0x7fc57802cff0, 
    rec=0x7fc589ba4770, big_rec=0x7fc589ba4758, n_ext=1, thr=0x7fc578030f38, mtr=0x7fc589ba4b20) at /home/mleich/bb-10.2-marko_2/storage/innobase/btr/btr0cur.cc:3414
 
#13 0x00005607fc958803 in row_ins_clust_index_entry_low (flags=0, mode=33, index=0x7fc598036cd0, n_uniq=2, entry=0x7fc57802cff0, n_ext=0, thr=0x7fc578030f38)
 
    at /home/mleich/bb-10.2-marko_2/storage/innobase/row/row0ins.cc:2723
 
#14 0x00005607fc959c43 in row_ins_clust_index_entry (index=0x7fc598036cd0, entry=0x7fc57802cff0, thr=0x7fc578030f38, n_ext=0)
 
    at /home/mleich/bb-10.2-marko_2/storage/innobase/row/row0ins.cc:3170
 
#15 0x00005607fc959f63 in row_ins_index_entry (index=0x7fc598036cd0, entry=0x7fc57802cff0, thr=0x7fc578030f38)
 
    at /home/mleich/bb-10.2-marko_2/storage/innobase/row/row0ins.cc:3274
 
#16 0x00005607fc95a485 in row_ins_index_entry_step (node=0x7fc5780309d0, thr=0x7fc578030f38) at /home/mleich/bb-10.2-marko_2/storage/innobase/row/row0ins.cc:3425
 
#17 0x00005607fc95a85b in row_ins (node=0x7fc5780309d0, thr=0x7fc578030f38) at /home/mleich/bb-10.2-marko_2/storage/innobase/row/row0ins.cc:3562
 
#18 0x00005607fc95ac08 in row_ins_step (thr=0x7fc578030f38) at /home/mleich/bb-10.2-marko_2/storage/innobase/row/row0ins.cc:3682
 
#19 0x00005607fc9785ec in row_insert_for_mysql (mysql_rec=0x7fc5780374c0 "\364\n3333333333", prebuilt=0x7fc5780302f0)
 
    at /home/mleich/bb-10.2-marko_2/storage/innobase/row/row0mysql.cc:1414
 
#20 0x00005607fc83dc32 in ha_innobase::write_row (this=0x7fc578036da0, record=0x7fc5780374c0 "\364\n3333333333")
 
    at /home/mleich/bb-10.2-marko_2/storage/innobase/handler/ha_innodb.cc:8177
 
#21 0x00005607fc64a0e2 in handler::ha_write_row (this=0x7fc578036da0, buf=0x7fc5780374c0 "\364\n3333333333") at /home/mleich/bb-10.2-marko_2/sql/handler.cc:6095
 
#22 0x00005607fc3a0cfc in write_record (thd=0x7fc558000ce8, table=0x7fc57802b5b8, info=0x7fc589ba5900) at /home/mleich/bb-10.2-marko_2/sql/sql_insert.cc:1941
 
#23 0x00005607fc39e7b8 in mysql_insert (thd=0x7fc558000ce8, table_list=0x7fc558010a68, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, 
    ignore=false) at /home/mleich/bb-10.2-marko_2/sql/sql_insert.cc:1066
 
#24 0x00005607fc3c50ab in mysql_execute_command (thd=0x7fc558000ce8) at /home/mleich/bb-10.2-marko_2/sql/sql_parse.cc:4167
 
#25 0x00005607fc3d07f1 in mysql_parse (thd=0x7fc558000ce8, 
    rawbuf=0x7fc558010720 "INSERT INTO t3 (col1,col2, col_int, col_string, col_text) VALUES /* 344 */ (344,344,344,REPEAT(SUBSTR(CAST( 344 AS CHAR),1,1), 10),REPEAT(SUBSTR(CAST( 344 AS CHAR),1,1), @fill_amount) ), (344,344,344,"..., length=334, parser_state=0x7fc589ba6640, is_com_multi=false, is_next_command=false)
 
    at /home/mleich/bb-10.2-marko_2/sql/sql_parse.cc:7740
 
#26 0x00005607fc3beb24 in dispatch_command (command=COM_QUERY, thd=0x7fc558000ce8, 
    packet=0x7fc5580083e9 " INSERT INTO t3 (col1,col2, col_int, col_string, col_text) VALUES /* 344 */ (344,344,344,REPEAT(SUBSTR(CAST( 344 AS CHAR),1,1), 10),REPEAT(SUBSTR(CAST( 344 AS CHAR),1,1), @fill_amount) ), (344,344,344"..., packet_length=336, is_com_multi=false, is_next_command=false)
 
    at /home/mleich/bb-10.2-marko_2/sql/sql_parse.cc:1831
 
#27 0x00005607fc3bd5a1 in do_command (thd=0x7fc558000ce8) at /home/mleich/bb-10.2-marko_2/sql/sql_parse.cc:1385
 
#28 0x00005607fc512317 in do_handle_one_connection (connect=0x5608014802a8) at /home/mleich/bb-10.2-marko_2/sql/sql_connect.cc:1336
 
#29 0x00005607fc512082 in handle_one_connection (arg=0x5608014802a8) at /home/mleich/bb-10.2-marko_2/sql/sql_connect.cc:1241
 
#30 0x00007fc67459c6db in start_thread (arg=0x7fc589ba7700) at pthread_create.c:463
 
#31 0x00007fc67398688f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

At the assertion failure index->online_status == ONLINE_INDEX_ABORTED_DROPPED. It was previously set at:

#0  0x00005607fc95ec0c in dict_index_set_online_status (index=0x7fc56802db20, status=ONLINE_INDEX_ABORTED_DROPPED)
 
    at /home/mleich/bb-10.2-marko_2/storage/innobase/include/dict0dict.ic:1260
 
#1  0x00005607fc96ba2a in row_merge_drop_indexes (trx=0x7fc671131768, table=0x7fc598037790, locked=0) at /home/mleich/bb-10.2-marko_2/storage/innobase/row/row0merge.cc:3809
 
#2  0x00005607fc8792d5 in innobase_rollback_sec_index (user_table=0x7fc598037790, table=0x7fc568021288, locked=0, trx=0x7fc671131768)
 
    at /home/mleich/bb-10.2-marko_2/storage/innobase/handler/handler0alter.cc:6464
 
#3  0x00005607fc87f8c7 in rollback_inplace_alter_table (ha_alter_info=0x7fc58a8d0060, table=0x7fc568021288, prebuilt=0x7fc568019de0)
 
    at /home/mleich/bb-10.2-marko_2/storage/innobase/handler/handler0alter.cc:6557
 
#4  0x00005607fc87be12 in ha_innobase::commit_inplace_alter_table (this=0x7fc56801f140, altered_table=0x7fc5680281a8, ha_alter_info=0x7fc58a8d0060, commit=false)
 
    at /home/mleich/bb-10.2-marko_2/storage/innobase/handler/handler0alter.cc:8211
 
#5  0x00005607fc645ccc in handler::ha_commit_inplace_alter_table (this=0x7fc56801f140, altered_table=0x7fc5680281a8, ha_alter_info=0x7fc58a8d0060, commit=false)
 
    at /home/mleich/bb-10.2-marko_2/sql/handler.cc:4365
 
#6  0x00005607fc495a85 in mysql_inplace_alter_table (thd=0x7fc568000ce8, table_list=0x7fc5680108a0, table=0x7fc568021288, altered_table=0x7fc5680281a8, 
    ha_alter_info=0x7fc58a8d0060, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7fc58a8d00f0, alter_ctx=0x7fc58a8d06a0)
 
    at /home/mleich/bb-10.2-marko_2/sql/sql_table.cc:7554
 
#7  0x00005607fc49b34c in mysql_alter_table (thd=0x7fc568000ce8, new_db=0x7fc568010eb8 "test", new_name=0x0, create_info=0x7fc58a8d12c0, table_list=0x7fc5680108a0, 
    alter_info=0x7fc58a8d1210, order_num=0, order=0x0, ignore=false) at /home/mleich/bb-10.2-marko_2/sql/sql_table.cc:9594
 
#8  0x00005607fc517791 in Sql_cmd_alter_table::execute (this=0x7fc568010fa0, thd=0x7fc568000ce8) at /home/mleich/bb-10.2-marko_2/sql/sql_alter.cc:333
 
#9  0x00005607fc3cb880 in mysql_execute_command (thd=0x7fc568000ce8) at /home/mleich/bb-10.2-marko_2/sql/sql_parse.cc:5972
 
#10 0x00005607fc3d07f1 in mysql_parse (thd=0x7fc568000ce8, 
    rawbuf=0x7fc568010720 "ALTER TABLE t3 ADD UNIQUE INDEX IF NOT EXISTS `uidX3` ( col_string )  /* E_R Thread26 QNO 63 CON_ID 42 */", length=105, 
    parser_state=0x7fc58a8d2640, is_com_multi=false, is_next_command=false) at /home/mleich/bb-10.2-marko_2/sql/sql_parse.cc:7740

ALTER TABLE query is completely done when assertion failure happens.

Comment by Matthias Leich [ 2021-07-21 ] 

Observed again on various tress. Some example
 
origin/10.5 b4ec3313f6bb3a222b3528b5a8a6dca73b870c20 2021-07-20T09:32:11+03:00
 
10.5.12
 
 
 
pluto:/RQG/storage/1626796774/TBR-574-MDEV-22634/dev/shm/vardir/1626796774/180/1/rr

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