[MDEV-25010] Assertion `!lock_sys_t::get_first(receiver_cell, receiver_id, receiver_heap_no)' failed in lock_rec_move Created: 2021-02-27  Updated: 2021-04-23  Resolved: 2021-04-23

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.6
Fix Version/s: 10.6.0

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Marko Mäkelä
Resolution: Fixed Votes: 0
Labels: regression

Issue Links:
Problem/Incident
is caused by MDEV-515 innodb bulk insert Closed
Relates
relates to MDEV-20612 Improve InnoDB lock_sys scalability Closed
relates to MDEV-25487 Assertion `!lock_sys_t::get_first(rec... Closed
relates to MDEV-24914 Assertion `lock_rec_get_first( lock_h... Closed

 Description   

--source include/have_innodb.inc
--source include/have_sequence.inc
 
CREATE TABLE t1 (pk INT PRIMARY KEY) ENGINE=InnoDB;
START TRANSACTION;
DELETE FROM t1;
SAVEPOINT A;
INSERT t1 SELECT seq FROM seq_1_to_1000;
ROLLBACK TO SAVEPOINT A;
INSERT INTO t1 SELECT seq FROM seq_1_to_1000;
 
# Cleanup
COMMIT;
DROP TABLE t1;

10.6 b47304eb

mariadbd: /data/src/10.6/storage/innobase/lock/lock0lock.cc:2141: void lock_rec_move(hash_cell_t&, const buf_block_t&, page_id_t, const hash_cell_t&, page_id_t, ulint, ulint): Assertion `!lock_sys_t::get_first(receiver_cell, receiver_id, receiver_heap_no)' failed.
210228  1:08:41 [ERROR] mysqld got signal 6 ;
 
#7  0x00007f2cd4ddaf36 in __GI___assert_fail (assertion=0x55b31b760378 "!lock_sys_t::get_first(receiver_cell, receiver_id, receiver_heap_no)", file=0x55b31b75eaf0 "/data/src/10.6/storage/innobase/lock/lock0lock.cc", line=2141, function=0x55b31b7603c0 "void lock_rec_move(hash_cell_t&, const buf_block_t&, page_id_t, const hash_cell_t&, page_id_t, ulint, ulint)") at assert.c:101
#8  0x000055b31af26dba in lock_rec_move (receiver_cell=..., receiver=..., receiver_id=..., donator_cell=..., donator_id=..., receiver_heap_no=1, donator_heap_no=1) at /data/src/10.6/storage/innobase/lock/lock0lock.cc:2141
#9  0x000055b31af29079 in lock_update_split_right (right_block=0x7f2cca40dd80, left_block=0x7f2cca40dca0) at /data/src/10.6/storage/innobase/lock/lock0lock.cc:2684
#10 0x000055b31b105e60 in btr_page_split_and_insert (flags=0, cursor=0x7f2cca1639b0, offsets=0x7f2cca163938, heap=0x7f2cca163930, tuple=0x7f2c98042428, n_ext=0, mtr=0x7f2cca163d10) at /data/src/10.6/storage/innobase/btr/btr0btr.cc:3049
#11 0x000055b31b102d2f in btr_root_raise_and_insert (flags=0, cursor=0x7f2cca1639b0, offsets=0x7f2cca163938, heap=0x7f2cca163930, tuple=0x7f2c98042428, n_ext=0, mtr=0x7f2cca163d10) at /data/src/10.6/storage/innobase/btr/btr0btr.cc:2067
#12 0x000055b31b13025f in btr_cur_pessimistic_insert (flags=0, cursor=0x7f2cca1639b0, offsets=0x7f2cca163938, heap=0x7f2cca163930, entry=0x7f2c98042428, rec=0x7f2cca163940, big_rec=0x7f2cca163928, n_ext=0, thr=0x7f2c98214638, mtr=0x7f2cca163d10) at /data/src/10.6/storage/innobase/btr/btr0cur.cc:3770
#13 0x000055b31b006647 in row_ins_clust_index_entry_low (flags=0, mode=33, index=0x7f2c98226608, n_uniq=1, entry=0x7f2c98042428, n_ext=0, thr=0x7f2c98214638) at /data/src/10.6/storage/innobase/row/row0ins.cc:2803
#14 0x000055b31b007e75 in row_ins_clust_index_entry (index=0x7f2c98226608, entry=0x7f2c98042428, thr=0x7f2c98214638, n_ext=0) at /data/src/10.6/storage/innobase/row/row0ins.cc:3273
#15 0x000055b31b0082aa in row_ins_index_entry (index=0x7f2c98226608, entry=0x7f2c98042428, thr=0x7f2c98214638) at /data/src/10.6/storage/innobase/row/row0ins.cc:3381
#16 0x000055b31b008b80 in row_ins_index_entry_step (node=0x7f2c98214418, thr=0x7f2c98214638) at /data/src/10.6/storage/innobase/row/row0ins.cc:3550
#17 0x000055b31b0090a2 in row_ins (node=0x7f2c98214418, thr=0x7f2c98214638) at /data/src/10.6/storage/innobase/row/row0ins.cc:3696
#18 0x000055b31b009984 in row_ins_step (thr=0x7f2c98214638) at /data/src/10.6/storage/innobase/row/row0ins.cc:3838
#19 0x000055b31b02e0c6 in row_insert_for_mysql (mysql_rec=0x7f2c98213018 "\377\245\002", prebuilt=0x7f2c98213cd8, ins_mode=ROW_INS_NORMAL) at /data/src/10.6/storage/innobase/row/row0mysql.cc:1384
#20 0x000055b31ae7a0f2 in ha_innobase::write_row (this=0x7f2c98213480, record=0x7f2c98213018 "\377\245\002") at /data/src/10.6/storage/innobase/handler/ha_innodb.cc:7382
#21 0x000055b31aa0cbf7 in handler::ha_write_row (this=0x7f2c98213480, buf=0x7f2c98213018 "\377\245\002") at /data/src/10.6/sql/handler.cc:7153
#22 0x000055b31a63fb53 in write_record (thd=0x7f2c98000db8, table=0x7f2c98212b88, info=0x7f2c98016f28, sink=0x0) at /data/src/10.6/sql/sql_insert.cc:2106
#23 0x000055b31a6456e7 in select_insert::send_data (this=0x7f2c98016ed8, values=...) at /data/src/10.6/sql/sql_insert.cc:4060
#24 0x000055b31a72ddfd in select_result_sink::send_data_with_check (this=0x7f2c98016ed8, items=..., u=0x7f2c98004f88, sent=676) at /data/src/10.6/sql/sql_class.h:5529
#25 0x000055b31a713f7e in end_send (join=0x7f2c98016f90, join_tab=0x7f2c98018558, end_of_records=false) at /data/src/10.6/sql/sql_select.cc:21858
#26 0x000055b31a71156c in evaluate_join_record (join=0x7f2c98016f90, join_tab=0x7f2c980181a8, error=0) at /data/src/10.6/sql/sql_select.cc:20881
#27 0x000055b31a710fe5 in sub_select (join=0x7f2c98016f90, join_tab=0x7f2c980181a8, end_of_records=false) at /data/src/10.6/sql/sql_select.cc:20697
#28 0x000055b31a71032e in do_select (join=0x7f2c98016f90, procedure=0x0) at /data/src/10.6/sql/sql_select.cc:20205
#29 0x000055b31a6e3cfe in JOIN::exec_inner (this=0x7f2c98016f90) at /data/src/10.6/sql/sql_select.cc:4477
#30 0x000055b31a6e2e1f in JOIN::exec (this=0x7f2c98016f90) at /data/src/10.6/sql/sql_select.cc:4257
#31 0x000055b31a6e4653 in mysql_select (thd=0x7f2c98000db8, tables=0x7f2c98015f50, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2202245794560, result=0x7f2c98016ed8, unit=0x7f2c98004f88, select_lex=0x7f2c98015948) at /data/src/10.6/sql/sql_select.cc:4730
#32 0x000055b31a6d4047 in handle_select (thd=0x7f2c98000db8, lex=0x7f2c98004ec0, result=0x7f2c98016ed8, setup_tables_done_option=1073741824) at /data/src/10.6/sql/sql_select.cc:417
#33 0x000055b31a69052d in mysql_execute_command (thd=0x7f2c98000db8) at /data/src/10.6/sql/sql_parse.cc:4665
#34 0x000055b31a69b7a4 in mysql_parse (thd=0x7f2c98000db8, rawbuf=0x7f2c98015170 "INSERT INTO t1 SELECT seq FROM seq_1_to_1000", length=44, parser_state=0x7f2cca165510) at /data/src/10.6/sql/sql_parse.cc:7972
#35 0x000055b31a687c67 in dispatch_command (command=COM_QUERY, thd=0x7f2c98000db8, packet=0x7f2c9800b429 "INSERT INTO t1 SELECT seq FROM seq_1_to_1000", packet_length=44, blocking=true) at /data/src/10.6/sql/sql_parse.cc:1886
#36 0x000055b31a68660e in do_command (thd=0x7f2c98000db8, blocking=true) at /data/src/10.6/sql/sql_parse.cc:1397
#37 0x000055b31a834288 in do_handle_one_connection (connect=0x55b31e151818, put_in_cache=true) at /data/src/10.6/sql/sql_connect.cc:1410
#38 0x000055b31a833fe6 in handle_one_connection (arg=0x55b31e20adb8) at /data/src/10.6/sql/sql_connect.cc:1312
#39 0x000055b31ad9387b in pfs_spawn_thread (arg=0x55b31e1f1658) at /data/src/10.6/storage/perfschema/pfs.cc:2201
#40 0x00007f2cd52f2609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#41 0x00007f2cd4ec6293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Not reproducible on 10.5.

The test case first started failing from this commit:

commit 3cef4f8f0fc88ae5bfae4603d8d600ec84cc70a9
Author: Marko Mäkelä
Date:   Mon Jan 25 18:41:27 2021 +0200
 
    MDEV-515 Reduce InnoDB undo logging for insert into empty table

However, the failure was different then:

mariadbd: /data/src/10.6-bug/storage/innobase/lock/lock0lock.cc:2089: 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.

In its current form the failure appeared in 10.6 with this commit:

commit 21987e5919afba29a7a7a537d3567909c7b4b9ff
Author: Marko Mäkelä
Date:   Mon Feb 22 18:32:51 2021 +0200
 
    MDEV-20612 fixup: Reduce hash table lookups



 Comments   
Comment by Roel Van de Paar [ 2021-04-22 ]

Not repeatable for me in 10.6.0 a3e3225cd3b816d47621e749e21a71b6a864a96a debug (Ubuntu 20.04.2).

Comment by Elena Stepanova [ 2021-04-22 ]

Of course not. After later changes one needs to unset unique_checks and foreign_key_checks to trigger the bulk insert. marko will know it when he gets to fixing it (or maybe by that time something else will be triggering the logic).
So, MDEV-25487 is likely to be still the same, unless there are two different problems causing the same assertion failure.

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

Sorry, I overlooked the fact that MDEV-25487 duplicated this report. I verified by appending the test case to the end of mysql-test/suite/innodb/t/insert_into_empty.test and running it that the bug was fixed by the fix of MDEV-25487.

The fix simply is that we will keep using row-level undo logging if any record locks exist on the table.

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