[MDEV-24231] Assertion `lock_rec_get_first( lock_hash, receiver, receiver_heap_no) == __null || lock_hash == &lock_sys.prdt_hash || lock_hash == &lock_sys.prdt_page_hash' failed in lock_rec_move_low Created: 2020-11-17  Updated: 2022-06-23

Status: Open
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.5.9
Fix Version/s: 10.5

Type: Bug Priority: Major
Reporter: Matthias Leich Assignee: Marko Mäkelä
Resolution: Unresolved Votes: 0
Labels: need_rr

Issue Links:
Relates
relates to MDEV-24914 Assertion `lock_rec_get_first( lock_h... Closed

 Description   

Workflow
=======
1. Start the DB Server
2. Generate some initial data
3. 33 sessions run concurrent DDL/DML
 
mysqld: /Server/bb-10.5-MDEV-24188/storage/innobase/lock/lock0lock.cc:2389: void lock_rec_move_low(hash_table_t*, const buf_block_t*, const buf_block_t*, ulint, ulint): Assertion `lock_rec_get_first( lock_hash, receiver, receiver_heap_no) == __null || lock_hash == &lock_sys.prdt_hash || lock_hash == &lock_sys.prdt_page_hash' failed.
...
# 2020-11-13T07:34:31 [240372] | Query (0x62b000206238): INSERT INTO t1 (col1,col2, col_int, col_string, col_text) VALUES ( 39, 39, 39, REPEAT(SUBSTR(CAST( 39 AS CHAR),1,1), 10), REPEAT(SUBSTR(CAST( 39 - 1 AS CHAR),1,1), @fill_amount) ) /* E_R Thread22 QNO 324 CON_ID 121 */
...
# 2020-11-13T07:34:31 [240372] | Connection ID (thread ID): 121
# 2020-11-13T07:34:31 [240372] | Status: NOT_KILLED
 
(rr) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00006dfb4bfdb859 in __GI_abort () at abort.c:79
#2  0x00006dfb4bfdb729 in __assert_fail_base (fmt=0x6dfb4c171588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", 
    assertion=0x55733c0a0080 "lock_rec_get_first( lock_hash, receiver, receiver_heap_no) == __null || lock_hash == &lock_sys.prdt_hash || lock_hash == &lock_sys.prdt_page_hash", 
    file=0x55733c094ec0 "/Server/bb-10.5-MDEV-24188/storage/innobase/lock/lock0lock.cc", line=2389, function=<optimized out>) at assert.c:92
#3  0x00006dfb4bfecf36 in __GI___assert_fail (assertion=assertion@entry=0x55733c0a0080 "lock_rec_get_first( lock_hash, receiver, receiver_heap_no) == __null || lock_hash == &lock_sys.prdt_hash || lock_hash == &lock_sys.prdt_page_hash", 
    file=file@entry=0x55733c094ec0 "/Server/bb-10.5-MDEV-24188/storage/innobase/lock/lock0lock.cc", line=line@entry=2389, 
    function=function@entry=0x55733c0a0000 "void lock_rec_move_low(hash_table_t*, const buf_block_t*, const buf_block_t*, ulint, ulint)") at assert.c:101
#4  0x000055733acf5b6d in lock_rec_move_low (lock_hash=lock_hash@entry=0x55733d93e958 <lock_sys+216>, receiver=receiver@entry=0x152f7925a4b8, donator=donator@entry=0x152f79244f00, receiver_heap_no=receiver_heap_no@entry=1, 
    donator_heap_no=donator_heap_no@entry=1) at /Server/bb-10.5-MDEV-24188/storage/innobase/lock/lock0lock.cc:2389
#5  0x000055733acfaed2 in lock_rec_move (donator_heap_no=1, receiver_heap_no=1, donator=0x152f79244f00, receiver=0x152f7925a4b8) at /Server/bb-10.5-MDEV-24188/storage/innobase/lock/lock0lock.cc:2999
#6  lock_update_root_raise (block=block@entry=0x152f7925a4b8, root=root@entry=0x152f79244f00) at /Server/bb-10.5-MDEV-24188/storage/innobase/lock/lock0lock.cc:2999
#7  0x000055733b1e9840 in btr_root_raise_and_insert (flags=flags@entry=0, cursor=cursor@entry=0x7ff300378420, offsets=offsets@entry=0x7ff300378300, heap=heap@entry=0x7ff3003782e0, tuple=tuple@entry=0x6170001876a0, n_ext=<optimized out>, 
    mtr=<optimized out>) at /Server/bb-10.5-MDEV-24188/storage/innobase/btr/btr0btr.cc:1962
#8  0x000055733b22bc8f in btr_cur_pessimistic_insert (flags=flags@entry=0, cursor=cursor@entry=0x7ff300378420, offsets=offsets@entry=0x7ff300378300, heap=heap@entry=0x7ff3003782e0, entry=entry@entry=0x6170001876a0, rec=rec@entry=0x7ff300378320, 
    big_rec=<optimized out>, n_ext=0, thr=<optimized out>, mtr=<optimized out>) at /Server/bb-10.5-MDEV-24188/storage/innobase/btr/btr0cur.cc:3746
#9  0x000055733aeea7c2 in row_ins_clust_index_entry_low (flags=flags@entry=0, mode=mode@entry=33, index=index@entry=0x617000047620, n_uniq=n_uniq@entry=1, entry=entry@entry=0x6170001876a0, n_ext=n_ext@entry=0, thr=<optimized out>)
    at /Server/bb-10.5-MDEV-24188/storage/innobase/row/row0ins.cc:2743
#10 0x000055733aefd906 in row_ins_clust_index_entry (index=index@entry=0x617000047620, entry=entry@entry=0x6170001876a0, thr=thr@entry=0x6210007d6000, n_ext=n_ext@entry=0) at /Server/bb-10.5-MDEV-24188/storage/innobase/row/row0ins.cc:3213
#11 0x000055733aefeb8a in row_ins_index_entry (index=0x617000047620, entry=0x6170001876a0, thr=thr@entry=0x6210007d6000) at /Server/bb-10.5-MDEV-24188/storage/innobase/row/row0ins.cc:3321
#12 0x000055733aefeea6 in row_ins_index_entry_step (node=node@entry=0x6210007d5ac0, thr=thr@entry=0x6210007d6000) at /usr/include/c++/9/bits/stl_iterator.h:819
#13 0x000055733af006ec in row_ins (node=node@entry=0x6210007d5ac0, thr=thr@entry=0x6210007d6000) at /Server/bb-10.5-MDEV-24188/storage/innobase/row/row0ins.cc:3627
#14 0x000055733af013e1 in row_ins_step (thr=thr@entry=0x6210007d6000) at /Server/bb-10.5-MDEV-24188/storage/innobase/row/row0ins.cc:3766
#15 0x000055733af57bc6 in row_insert_for_mysql (mysql_rec=mysql_rec@entry=0x61a000684cb8 "h'", prebuilt=0x6210007d51a0, ins_mode=<optimized out>) at /Server/bb-10.5-MDEV-24188/storage/innobase/row/row0mysql.cc:1421
#16 0x000055733ab27cef in ha_innobase::write_row (this=0x61d0018344b8, record=<optimized out>) at /Server/bb-10.5-MDEV-24188/storage/innobase/handler/ha_innodb.cc:7592
#17 0x0000557339eb2954 in handler::ha_write_row (this=0x61d0018344b8, buf=<optimized out>) at /Server/bb-10.5-MDEV-24188/sql/handler.cc:7143
#18 0x00005573394abff3 in write_record (thd=thd@entry=0x62b0001ff218, table=table@entry=0x6190006a6d98, info=info@entry=0x7ff30037a6b0, sink=sink@entry=0x0) at /Server/bb-10.5-MDEV-24188/sql/sql_insert.cc:2104
#19 0x00005573394d4386 in mysql_insert (thd=thd@entry=0x62b0001ff218, table_list=0x62b0002064c8, fields=..., values_list=..., update_fields=..., update_values=..., duplic=<optimized out>, ignore=<optimized out>, result=<optimized out>)
    at /Server/bb-10.5-MDEV-24188/sql/sql_insert.cc:1099
#20 0x00005573395c527d in mysql_execute_command (thd=thd@entry=0x62b0001ff218) at /Server/bb-10.5-MDEV-24188/sql/sql_parse.cc:4587
#21 0x000055733957c284 in mysql_parse (thd=thd@entry=0x62b0001ff218, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7ff30037bed0, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false)
    at /Server/bb-10.5-MDEV-24188/sql/sql_parse.cc:8044
#22 0x00005573395adb47 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x62b0001ff218, 
    packet=packet@entry=0x629000749219 " INSERT INTO t1 (col1,col2, col_int, col_string, col_text) VALUES ( 39, 39, 39, REPEAT(SUBSTR(CAST( 39 AS CHAR),1,1), 10), REPEAT(SUBSTR(CAST( 39 - 1 AS CHAR),1,1), @fill_amount) ) /* E_R Thread22 QNO"..., 
    packet_length=packet_length@entry=219, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /Server/bb-10.5-MDEV-24188/sql/sql_class.h:1252
#23 0x00005573395b8ff8 in do_command (thd=0x62b0001ff218) at /Server/bb-10.5-MDEV-24188/sql/sql_parse.cc:1353
#24 0x0000557339a5287e in do_handle_one_connection (connect=<optimized out>, connect@entry=0x6080000098b8, put_in_cache=put_in_cache@entry=true) at /Server/bb-10.5-MDEV-24188/sql/sql_connect.cc:1410
#25 0x0000557339a53abe in handle_one_connection (arg=arg@entry=0x6080000098b8) at /Server/bb-10.5-MDEV-24188/sql/sql_connect.cc:1312
#26 0x000055733a8e5598 in pfs_spawn_thread (arg=0x61500000fd18) at /Server/bb-10.5-MDEV-24188/storage/perfschema/pfs.cc:2201
#27 0x000027a203b40609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#28 0x00006dfb4c0d8293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
(rr)
 
origin/bb-10.5-MDEV-24188 e598f98d028dad53b5765d87230a5761f118caf8 2020-11-13
build with  debug+asan+Og
 
RQG
====
git clone https://github.com/mleich1/rqg --branch experimental RQG
 
perl rqg.pl \            
--grammar=conf/mariadb/table_stress_innodb_nocopy1.yy \
--gendata=conf/mariadb/table_stress.zz \
--gendata_sql=conf/mariadb/table_stress.sql \
--redefine=conf/mariadb/xa.yy \
--max_gd_duration=1000 \
--mysqld=--innodb_use_native_aio=1 \
--mysqld=--innodb_lock_schedule_algorithm=fcfs \
--mysqld=--loose-idle_write_transaction_timeout=0 \
--mysqld=--loose-idle_transaction_timeout=0 \
--mysqld=--loose-idle_readonly_transaction_timeout=0 \
--mysqld=--connect_timeout=60 \
--mysqld=--interactive_timeout=28800 \
--mysqld=--slave_net_timeout=60 \
--mysqld=--net_read_timeout=30 \
--mysqld=--net_write_timeout=60 \
--mysqld=--loose-table_lock_wait_timeout=50 \
--mysqld=--wait_timeout=28800 \
--mysqld=--lock-wait-timeout=86400 \
--mysqld=--innodb-lock-wait-timeout=50 \
--no-mask \
--queries=10000000 \
--seed=random \
--reporters=Backtrace \
--reporters=ErrorLog \
--reporters=Deadlock1 \
--validators=None \
--mysqld=--log_output=none \
--mysqld=--log-bin \
--mysqld=--log_bin_trust_function_creators=1 \
--mysqld=--loose-debug_assert_on_not_freed_memory=0 \
--engine=InnoDB \
--restart_timeout=120 \
--mysqld=--plugin-load-add=file_key_management.so \
--mysqld=--loose-file-key-management-filename=/home/mleich/RQG/conf/mariadb/encryption_keys.txt \
--duration=300 \
--mysqld=--loose-innodb_fatal_semaphore_wait_threshold=300 \
--mysqld=--loose-innodb-sync-debug \
--mysqld=--innodb_stats_persistent=off \
--mysqld=--loose-max-statement-time=30 \
--threads=33 \
--mysqld=--innodb_page_size=4K \
--mysqld=--innodb-buffer-pool-size=8M \
--duration=300 \
--no_mask \
--workdir=<local settings> \
--vardir=<local settings> \
--mtr-build-thread=<local settings> \
--basedir1=<local settings> \
--script_debug=_nix_ \
--rr=Extended \
--rr_options=--chaos



 Comments   
Comment by Matthias Leich [ 2020-11-17 ]

sdp:/RQG/storage/1605280113/tmp/dev/shm/vardir/1605280113/61/1/rr
_RR_TRACE_DIR="." rr replay --mark-stdio

Comment by Marko Mäkelä [ 2021-04-13 ]

mleich, sorry, the trace is no longer available. Can you still reproduce this one and generate a new trace?

Comment by Matthias Leich [ 2022-06-23 ]

The current problem was replayed last time 2021-02-08 on a bb-10.6-MDEV-20612.
It is quite likely that the problem was fixed by side effect of another fix.

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