[MDEV-29711] INSERT fails to convert implicit to explicit lock as UPDATE owns explicit lock - Jira

Details

Type: Bug
Status: Open (View Workflow)
Priority: Major
Resolution: Unresolved
Affects Version/s: 10.3(EOL)
Fix Version/s: 10.3(EOL)
Component/s: Storage Engine - InnoDB
Labels:
None

Description

During RQG testing we found the following assertion failure:

#7  0x00007f984d534f36 in __GI___assert_fail (assertion=0x55b00bfe93c0 "!expl_lock || expl_lock->trx == arg->impl_trx",

    file=0x55b00bfe1c40 "./storage/innobase/lock/lock0lock.cc", line=5468,

    function=0x55b00bfe9320 "my_bool lock_rec_other_trx_holds_expl_callback(rw_trx_hash_element_t*, lock_rec_other_trx_holds_expl_arg*)")

    at assert.c:101

#8  0x000055b00ae3081e in lock_rec_other_trx_holds_expl_callback (element=0x60f000117ed8, arg=0x7f982361e7b0)

    at ./storage/innobase/lock/lock0lock.cc:5468

#9  0x000055b00ae3ce2c in rw_trx_hash_t::debug_iterator (element=0x60f000117ed8, arg=0x7f982361e6f0)

    at ./storage/innobase/include/trx0sys.h:540

#10 0x000055b00b9695f9 in l_find (head=0x604000055158, cs=0x0, hashnr=0, key=0x7f982361e6f0 "h\003\343\n\260U", keylen=0, cursor=0x7f982361e610,

    pins=0x62c000010978, callback=0x55b00ae3ccd6 <rw_trx_hash_t::debug_iterator(rw_trx_hash_element_t*, rw_trx_hash_t::debug_iterator_arg*)>)

    at ./mysys/lf_hash.c:129

#11 0x000055b00b96b894 in lf_hash_iterate (hash=0x55b00cc6b080 <trx_sys+2432>, pins=0x62c000010978,

    action=0x55b00ae3ccd6 <rw_trx_hash_t::debug_iterator(rw_trx_hash_element_t*, rw_trx_hash_t::debug_iterator_arg*)>, argument=0x7f982361e6f0)

    at ./mysys/lf_hash.c:521

#12 0x000055b00ae3d670 in rw_trx_hash_t::iterate (this=0x55b00cc6b080 <trx_sys+2432>, caller_trx=0x7f983859da68,

    action=0x55b00ae3ccd6 <rw_trx_hash_t::debug_iterator(rw_trx_hash_element_t*, rw_trx_hash_t::debug_iterator_arg*)>, argument=0x7f982361e6f0)

    at ./storage/innobase/include/trx0sys.h:762

#13 0x000055b00ae30d01 in lock_rec_other_trx_holds_expl (caller_trx=0x7f983859da68, trx=0x7f9838591288, rec=0x7f98374900da "\200",

    block=0x7f9836c70158) at ./storage/innobase/lock/lock0lock.cc:5511

#14 0x000055b00ae31266 in lock_rec_convert_impl_to_expl (caller_trx=0x7f983859da68, block=0x7f9836c70158, rec=0x7f98374900da "\200",

    index=0x618000428908, offsets=0x7f982361eb80) at ./storage/innobase/lock/lock0lock.cc:5579

#15 0x000055b00ae32a40 in lock_sec_rec_read_check_and_lock (flags=0, block=0x7f9836c70158, rec=0x7f98374900da "\200", index=0x618000428908,

    offsets=0x7f982361eb80, mode=LOCK_S, gap_mode=0, thr=0x6210001129b8)

    at ./storage/innobase/lock/lock0lock.cc:5808

#16 0x000055b00afaceb6 in row_ins_set_shared_rec_lock (type=0, block=0x7f9836c70158, rec=0x7f98374900da "\200", index=0x618000428908,

    offsets=0x7f982361eb80, thr=0x6210001129b8) at ./storage/innobase/row/row0ins.cc:1403

#17 0x000055b00afaff71 in row_ins_scan_sec_index_for_duplicate (flags=0, index=0x618000428908, entry=0x61a00076d1d0, thr=0x6210001129b8,

    s_latch=true, mtr=0x7f982361f2f0, offsets_heap=0x61900104fa80)

    at ./storage/innobase/row/row0ins.cc:2159

#18 0x000055b00afb4df7 in row_ins_sec_index_entry_low (flags=0, mode=2, index=0x618000428908, offsets_heap=0x61900104fa80, heap=0x61900104d280,

    entry=0x61a00076d1d0, trx_id=0, thr=0x6210001129b8) at ./storage/innobase/row/row0ins.cc:3038

#19 0x000055b00afb61fa in row_ins_sec_index_entry (index=0x618000428908, entry=0x61a00076d1d0, thr=0x6210001129b8, check_foreign=true)

    at ./storage/innobase/row/row0ins.cc:3292

#20 0x000055b00afb65d3 in row_ins_index_entry (index=0x618000428908, entry=0x61a00076d1d0, thr=0x6210001129b8)

    at ./storage/innobase/row/row0ins.cc:3340

#21 0x000055b00afb718c in row_ins_index_entry_step (node=0x621000112460, thr=0x6210001129b8)

    at ./storage/innobase/row/row0ins.cc:3489

#22 0x000055b00afb7b4f in row_ins (node=0x621000112460, thr=0x6210001129b8)

    at ./storage/innobase/row/row0ins.cc:3648

#23 0x000055b00afb8d06 in row_ins_step (thr=0x6210001129b8) at ./storage/innobase/row/row0ins.cc:3798

#24 0x000055b00b00127f in row_insert_for_mysql (mysql_rec=0x61a0006846a8 "\220\377\002", prebuilt=0x621000111d88, ins_mode=ROW_INS_NORMAL)

    at ./storage/innobase/row/row0mysql.cc:1419

#25 0x000055b00acddfd0 in ha_innobase::write_row (this=0x61c00053d0a8, record=0x61a0006846a8 "\220\377\002")

    at ./storage/innobase/handler/ha_innodb.cc:8196

#26 0x000055b00a7e3361 in handler::ha_write_row (this=0x61c00053d0a8, buf=0x61a0006846a8 "\220\377\002")

    at ./sql/handler.cc:6495

#27 0x000055b00a04bbbf in write_record (thd=0x62a0002a0208, table=0x61f000283288, info=0x7f9823620ea0)

    at ./sql/sql_insert.cc:2054

#28 0x000055b00a044d9e in mysql_insert (thd=0x62a0002a0208, table_list=0x62b00018f4a0, fields=

        @0x62a0002a4d28: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x62b00018fc68, last = 0x62b000190178, elements = 5}, <No data fields>}, values_list=

        @0x62a0002a4d70: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x62b0001910f0, last = 0x62b0001910f0, elements = 1}, <No data fields>}, update_fields=

        @0x62a0002a4d58: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x55b00cfe9820 <end_of_list>, last = 0x62a0002a4d58, elements = 0}, <No data fields>}, update_values=

        @0x62a0002a4d40: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x55b00cfe9820 <end_of_list>, last = 0x62a0002a4d40, elements = 0}, <No data fields>}, duplic=DUP_ERROR, ignore=false) at ./sql/sql_insert.cc:1077

#29 0x000055b00a0e0c85 in mysql_execute_command (thd=0x62a0002a0208) at ./sql/sql_parse.cc:4505

#30 0x000055b00a0f7845 in mysql_parse (thd=0x62a0002a0208,

    rawbuf=0x62b00018f228 "INSERT INTO t1 (col1,col2, col_int, col_string, col_text) VALUES ( 2, 2, 2, REPEAT(SUBSTR(CAST( 2 AS CHAR),1,1), 10), REPEAT(SUBSTR(CAST( 2 AS CHAR),1,1), @fill_amount) ) /* E_R Thread19 QNO 1092 CON_"..., length=209, parser_state=0x7f9823622930, is_com_multi=false,

    is_next_command=false) at ./sql/sql_parse.cc:7855

I.e. the INSERT tries to convert it's implicit lock to explicit one. But the following transaction has already held(non-waiting) explicit LOCK_ORDINARY|LOCK_S lock:

#3  0x000055b00aecd888 in os_event::wait (this=0x60b00014b430) at ./storage/innobase/os/os0event.cc:158

#4  0x000055b00aeccf49 in os_event::wait_low (this=0x60b00014b430, reset_sig_count=392)

    at ./storage/innobase/os/os0event.cc:325

#5  0x000055b00aecd514 in os_event_wait_low (event=0x60b00014b430, reset_sig_count=0)

    at ./storage/innobase/os/os0event.cc:502

#6  0x000055b00ae4b731 in lock_wait_suspend_thread (thr=0x6210002d3788)

    at ./storage/innobase/lock/lock0wait.cc:337

#7  0x000055b00affcd53 in row_mysql_handle_errors (new_err=0x7f9823206580, trx=0x7f9838591288, thr=0x6210002d3788, savept=0x7f9823206590)

    at ./storage/innobase/row/row0mysql.cc:739

#8  0x000055b00b00434e in row_update_for_mysql (prebuilt=0x6210002d2988)

    at ./storage/innobase/row/row0mysql.cc:1846

#9  0x000055b00ace2577 in ha_innobase::update_row (this=0x61c00023b0a8, old_row=0x61a000a6d6e0 "\220\377\006",

    new_row=0x61a000a6d4a8 "\220\377\001") at ./storage/innobase/handler/ha_innodb.cc:8970

#10 0x000055b00a7e39f2 in handler::ha_update_row (this=0x61c00023b0a8, old_data=0x61a000a6d6e0 "\220\377\006",

    new_data=0x61a000a6d4a8 "\220\377\001") at ./sql/handler.cc:6527

#11 0x000055b00a34fd44 in mysql_update (thd=0x62a0002fa208, table_list=0x62b0001ff388, fields=

        @0x62a0002fe810: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x62b0001ffc10, last = 0x62b0001ffc10, elements = 1}, <No data fields>}, values=

        @0x62a0002fed40: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x62b0001ffc28, last = 0x62b0001ffc28, elements = 1}, <No data fields>}, conds=0x0, order_num=0, order=0x0, limit=2, ignore=false, found_return=0x7f98232072c0, updated_return=0x7f98232072e0)

    at ./sql/sql_update.cc:963

#12 0x000055b00a0dfd7b in mysql_execute_command (thd=0x62a0002fa208) at ./sql/sql_parse.cc:4344

#13 0x000055b00a0f7845 in mysql_parse (thd=0x62a0002fa208,

    rawbuf=0x62b0001ff228 "UPDATE t1 SET col1 = 1 LIMIT 2  /* E_R Thread21 QNO 1096 CON_ID 196 */", length=70, parser_state=0x7f9823208930,

    is_com_multi=false, is_next_command=false) at ./sql/sql_parse.cc:7855

Unfortunately, we don't have rr trace for the bug, and the chances to reproduce it are very low. So we don't know why the UPDATE set explicit lock while the INSERT held implicit lock, or why the INSERT set implicit lock while UPDATE held explicit lock.

I suppose there can be something related to semi-consistent read during the UPDATE, it might be lock_trx_handle_wait_low() returned false DB_SUCCESS, like in ~~MDEV-29635~~.

We have only 10.3 core dump, so we don't know if the other versions are affected.

Attachments

Issue Links

relates to

MDEV-29635 race on trx->lock.wait_lock in deadlock resolution

Closed

INSERT fails to convert implicit to explicit lock as UPDATE owns explicit lock

Details

Description

Attachments

Issue Links

Activity

People

Dates

Git Integration