[MDEV-23265] Assertion `!expl_lock || expl_lock->trx == arg->impl_trx' failed in lock_rec_other_trx_holds_expl_callback upon concurrent UPDATE with unique blobs Created: 2020-07-22  Updated: 2023-11-28

Status: Confirmed
Project: MariaDB Server
Component/s: Server
Affects Version/s: 10.4, 10.5, 10.6, 10.7, 10.8, 10.9, 10.10, 10.11, 11.0
Fix Version/s: 10.4, 10.5, 10.6, 10.11

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Sergei Golubchik
Resolution: Unresolved Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-23264 Unique blobs allow duplicate values u... Closed

 Description   

This problem can be a side-effect of MDEV-23264, or a separate one which MDEV-23264 just helps to reproduce. I expect it to be clarified after development analysis

The test case is non-deterministic. It currently fails every time for me, but it can vary on different machines and builds. Try running with --repeat if it doesn't fail right away.

--source include/have_innodb.inc
 
CREATE TABLE t1 (a INT, b TEXT UNIQUE) ENGINE=InnoDB;
INSERT INTO t1 () VALUES (),();
UPDATE IGNORE t1 SET b = '';
 
--connect (con1,localhost,root,,test)
--let $conid= `SELECT CONNECTION_ID()`
--delimiter $
--send
LOOP
  UPDATE t1 SET a = 1;
END LOOP $
--delimiter ;
 
--connection default
UPDATE t1 SET b = NULL;
--error ER_DUP_ENTRY
INSERT INTO t1 VALUES (1,''),(1,'');
 
# Cleanup
--eval KILL $conid
DROP TABLE t1;

10.4 b1538f4d

mysqld: /data/src/10.4/storage/innobase/lock/lock0lock.cc:5437: my_bool lock_rec_other_trx_holds_expl_callback(rw_trx_hash_element_t*, lock_rec_other_trx_holds_expl_arg*): Assertion `!expl_lock || expl_lock->trx == arg->impl_trx' failed.
200722 21:36:43 [ERROR] mysqld got signal 6 ;
 
#7  0x00007f8334780f12 in __GI___assert_fail (assertion=0x55e90b20bc30 "!expl_lock || expl_lock->trx == arg->impl_trx", file=0x55e90b209718 "/data/src/10.4/storage/innobase/lock/lock0lock.cc", line=5437, function=0x55e90b2102c0 <lock_rec_other_trx_holds_expl_callback(rw_trx_hash_element_t*, lock_rec_other_trx_holds_expl_arg*)::__PRETTY_FUNCTION__> "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  0x000055e90a930752 in lock_rec_other_trx_holds_expl_callback (element=0x7f82dc06c170, arg=0x7f832db27350) at /data/src/10.4/storage/innobase/lock/lock0lock.cc:5437
#9  0x000055e90a9378b0 in rw_trx_hash_t::debug_iterator (element=0x7f82dc06c170, arg=0x7f832db27300) at /data/src/10.4/storage/innobase/include/trx0sys.h:535
#10 0x000055e90aed4f13 in l_find (head=0x55e90e743700, cs=0x0, hashnr=0, key=0x7f832db27300 "t\005\223\n\351U", keylen=0, cursor=0x7f832db272a0, pins=0x55e90e73b610, callback=0x55e90a937827 <rw_trx_hash_t::debug_iterator(rw_trx_hash_element_t*, rw_trx_hash_t::debug_iterator_arg*)>) at /data/src/10.4/mysys/lf_hash.c:127
#11 0x000055e90aed5c0b in lf_hash_iterate (hash=0x55e90babbfc0 <trx_sys+2496>, pins=0x55e90e73b610, action=0x55e90a937827 <rw_trx_hash_t::debug_iterator(rw_trx_hash_element_t*, rw_trx_hash_t::debug_iterator_arg*)>, argument=0x7f832db27300) at /data/src/10.4/mysys/lf_hash.c:519
#12 0x000055e90a937c9b in rw_trx_hash_t::iterate (this=0x55e90babbfc0 <trx_sys+2496>, caller_trx=0x7f832e5c2140, action=0x55e90a937827 <rw_trx_hash_t::debug_iterator(rw_trx_hash_element_t*, rw_trx_hash_t::debug_iterator_arg*)>, argument=0x7f832db27300) at /data/src/10.4/storage/innobase/include/trx0sys.h:753
#13 0x000055e90a9309c6 in lock_rec_other_trx_holds_expl (caller_trx=0x7f832e5c2140, trx=0x7f832e5c3268, rec=0x7f832e2f4096 "", block=0x7f832ddee620) at /data/src/10.4/storage/innobase/lock/lock0lock.cc:5483
#14 0x000055e90a930e3e in lock_rec_convert_impl_to_expl (caller_trx=0x7f832e5c2140, block=0x7f832ddee620, rec=0x7f832e2f4096 "", index=0x7f82dc148c40, offsets=0x7f832db277e0) at /data/src/10.4/storage/innobase/lock/lock0lock.cc:5549
#15 0x000055e90a931e85 in lock_sec_rec_read_check_and_lock (flags=0, block=0x7f832ddee620, rec=0x7f832e2f4096 "", index=0x7f82dc148c40, offsets=0x7f832db277e0, mode=LOCK_X, gap_mode=0, thr=0x7f82dc14b338) at /data/src/10.4/storage/innobase/lock/lock0lock.cc:5759
#16 0x000055e90aa653fb in sel_set_rec_lock (pcur=0x7f82dc14aac8, rec=0x7f832e2f4096 "", index=0x7f82dc148c40, offsets=0x7f832db277e0, mode=3, type=0, thr=0x7f82dc14b338, mtr=0x7f832db28040) at /data/src/10.4/storage/innobase/row/row0sel.cc:1279
#17 0x000055e90aa6fc35 in row_search_mvcc (buf=0x7f82dc147870 "\370\001", mode=PAGE_CUR_GE, prebuilt=0x7f82dc14a8f0, match_mode=1, direction=0) at /data/src/10.4/storage/innobase/row/row0sel.cc:5046
#18 0x000055e90a87eec8 in ha_innobase::index_read (this=0x7f82dc00ae38, buf=0x7f82dc147870 "\370\001", key_ptr=0x7f832db2873f "", key_len=9, find_flag=HA_READ_KEY_EXACT) at /data/src/10.4/storage/innobase/handler/ha_innodb.cc:9273
#19 0x000055e90a643a6c in handler::index_read_map (this=0x7f82dc00ae38, buf=0x7f82dc147870 "\370\001", key=0x7f832db2873f "", keypart_map=18446744073709551615, find_flag=HA_READ_KEY_EXACT) at /data/src/10.4/sql/handler.h:3627
#20 0x000055e90a633cba in handler::ha_index_read_map (this=0x7f82dc00ae38, buf=0x7f82dc147870 "\370\001", key=0x7f832db2873f "", keypart_map=18446744073709551615, find_flag=HA_READ_KEY_EXACT) at /data/src/10.4/sql/handler.cc:2919
#21 0x000055e90a63e549 in check_duplicate_long_entry_key (table=0x7f82dc149630, h=0x7f82dc00ae38, new_rec=0x7f82dc147870 "\370\001", key_no=0) at /data/src/10.4/sql/handler.cc:6588
#22 0x000055e90a63ec0e in check_duplicate_long_entries (table=0x7f82dc149630, h=0x7f82dc00ae38, new_rec=0x7f82dc147870 "\370\001") at /data/src/10.4/sql/handler.cc:6658
#23 0x000055e90a63ef58 in handler::ha_write_row (this=0x7f82dc00ae38, buf=0x7f82dc147870 "\370\001") at /data/src/10.4/sql/handler.cc:6739
#24 0x000055e90a28cca1 in write_record (thd=0x7f82dc000af0, table=0x7f82dc149630, info=0x7f832db28a90) at /data/src/10.4/sql/sql_insert.cc:2060
#25 0x000055e90a289bf1 in mysql_insert (thd=0x7f82dc000af0, table_list=0x7f82dc013290, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=false) at /data/src/10.4/sql/sql_insert.cc:1078
#26 0x000055e90a2d6f51 in mysql_execute_command (thd=0x7f82dc000af0) at /data/src/10.4/sql/sql_parse.cc:4518
#27 0x000055e90a2e289b in mysql_parse (thd=0x7f82dc000af0, rawbuf=0x7f82dc013198 "INSERT INTO t1 VALUES (1,''),(1,'')", length=35, parser_state=0x7f832db29570, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:7895
#28 0x000055e90a2cedd0 in dispatch_command (command=COM_QUERY, thd=0x7f82dc000af0, packet=0x7f82dc156cd1 "INSERT INTO t1 VALUES (1,''),(1,'')", packet_length=35, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1834
#29 0x000055e90a2cd572 in do_command (thd=0x7f82dc000af0) at /data/src/10.4/sql/sql_parse.cc:1352
#30 0x000055e90a45662e in do_handle_one_connection (connect=0x55e90e83b580) at /data/src/10.4/sql/sql_connect.cc:1412
#31 0x000055e90a45637d in handle_one_connection (arg=0x55e90e83b580) at /data/src/10.4/sql/sql_connect.cc:1316
#32 0x000055e90ae569bb in pfs_spawn_thread (arg=0x55e90e7b9530) at /data/src/10.4/storage/perfschema/pfs.cc:1869
#33 0x00007f83367094a4 in start_thread (arg=0x7f832db2a700) at pthread_create.c:456
#34 0x00007f833483dd0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Reproducible on 10.4/10.5 debug builds.
Release builds don't crash, but they're still affected by MDEV-23264.
The test case is not applicable to earlier versions due to unique blobs.



 Comments   
Comment by Sachin Setiya (Inactive) [ 2020-08-13 ]

This happens even if I fixed MDEV-23264

Comment by Alice Sherepa [ 2023-04-26 ]

mariadbd: /11.0/src/storage/innobase/lock/lock0lock.cc:5228: my_bool lock_rec_other_trx_holds_expl_callback(rw_trx_hash_element_t*, lock_rec_other_trx_holds_expl_arg*): Assertion `!expl_lock || expl_lock->trx == &arg->impl_trx' failed.
230426 16:29:14 [ERROR] mysqld got signal 6 ;
 
Server version: 11.0.2-MariaDB-debug-log source revision: c7fe8e51de4e67f8515b3cf8b6bcd1c5bf1d184b
 
lock/lock0lock.cc:5229(lock_rec_other_trx_holds_expl_callback(rw_trx_hash_element_t*, lock_rec_other_trx_holds_expl_arg*))[0x560f54773325]
include/trx0sys.h:528(char rw_trx_hash_t::debug_iterator<lock_rec_other_trx_holds_expl_arg>(rw_trx_hash_element_t*, rw_trx_hash_t::debug_iterator_arg<lock_rec_other_trx_holds_expl_arg>*))[0x560f5478bbf7]
mysys/lf_hash.cc:134(l_find(LF_SLIST**, charset_info_st const*, unsigned int, unsigned char const*, unsigned long, CURSOR*, LF_PINS*, char (*)(void*, void*)))[0x560f55013347]
mysys/lf_hash.cc:531(lf_hash_iterate)[0x560f55015684]
include/trx0sys.h:743(int rw_trx_hash_t::iterate<lock_rec_other_trx_holds_expl_arg>(trx_t*, char (*)(rw_trx_hash_element_t*, lock_rec_other_trx_holds_expl_arg*), lock_rec_other_trx_holds_expl_arg*))[0x560f54785528]
lock/lock0lock.cc:5265(lock_rec_other_trx_holds_expl(trx_t*, trx_t*, unsigned char const*, page_id_t))[0x560f54773703]
lock/lock0lock.cc:5335(bool lock_rec_convert_impl_to_expl<false>(trx_t*, page_id_t, unsigned char const*, dict_index_t*, unsigned short const*))[0x560f5477bfa9]
lock/lock0lock.cc:5542(lock_sec_rec_read_check_and_lock(unsigned long, buf_block_t const*, unsigned char const*, dict_index_t*, unsigned short const*, lock_mode, unsigned int, que_thr_t*))[0x560f54774f90]
row/row0sel.cc:1369(sel_set_rec_lock(btr_pcur_t*, unsigned char const*, dict_index_t*, unsigned short const*, unsigned int, unsigned int, que_thr_t*, mtr_t*))[0x560f549ef799]
row/row0sel.cc:5238(row_search_mvcc(unsigned char*, page_cur_mode_t, row_prebuilt_t*, unsigned long, unsigned long))[0x560f54a06ac8]
handler/ha_innodb.cc:9001(ha_innobase::index_read(unsigned char*, unsigned char const*, unsigned int, ha_rkey_function))[0x560f545ee3b3]
sql/handler.h:4066(handler::index_read_map(unsigned char*, unsigned char const*, unsigned long, ha_rkey_function))[0x560f53a41ee3]
sql/handler.cc:3648(handler::ha_index_read_map(unsigned char*, unsigned char const*, unsigned long, ha_rkey_function))[0x560f53c057a6]
sql/handler.cc:7411(handler::check_duplicate_long_entry_key(unsigned char const*, unsigned int))[0x560f53c26867]
sql/handler.cc:7492(handler::check_duplicate_long_entries(unsigned char const*))[0x560f53c27f78]
sql/handler.cc:7769(handler::ha_write_row(unsigned char const*))[0x560f53c2a1a1]
sql/sql_insert.cc:2204(write_record(THD*, TABLE*, st_copy_info*, select_result*))[0x560f53211fcb]
sql/sql_insert.cc:1154(mysql_insert(THD*, TABLE_LIST*, List<Item>&, List<List<Item> >&, List<Item>&, List<Item>&, enum_duplicates, bool, select_result*))[0x560f532091c9]
sql/sql_parse.cc:4569(mysql_execute_command(THD*, bool))[0x560f532d73ed]
sql/sql_parse.cc:8014(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x560f532efbda]
sql/sql_parse.cc:1896(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x560f532c5b24]
sql/sql_parse.cc:1407(do_command(THD*, bool))[0x560f532c2854]
sql/sql_connect.cc:1416(do_handle_one_connection(CONNECT*, bool))[0x560f5379ab77]
sql/sql_connect.cc:1320(handle_one_connection)[0x560f5379a4d4]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x560f543cee38]
nptl/pthread_create.c:478(start_thread)[0x7f5ca578f609]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x43)[0x7f5ca5360133]
 
 
Query (0x6290001092a8): INSERT INTO t1 VALUES (1,''),(1,'')

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