[MDEV-24914] 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: 2021-02-18  Updated: 2021-04-22  Resolved: 2021-04-01

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

Type: Bug Priority: Blocker
Reporter: Roel Van de Paar Assignee: Marko Mäkelä
Resolution: Fixed Votes: 0
Labels: not-10.2, not-10.3, not-10.4, not-10.5, regression

Issue Links:
Relates
relates to MDEV-25010 Assertion `!lock_sys_t::get_first(rec... Closed
relates to MDEV-24231 Assertion `lock_rec_get_first( lock_h... Open
relates to MDEV-24818 Concurrent use of InnoDB table is imp... Closed
relates to MDEV-25315 Assertion `ptr' failed in ut_align_do... Closed
relates to MDEV-25487 Assertion `!lock_sys_t::get_first(rec... Closed

 Description   

Very alike to MDEV-24231, but this one reproduces on 10.6 only, and 10.5 does not fail.

SET GLOBAL innodb_limit_optimistic_insert_debug=2;
CREATE TABLE t (c INT(1)UNSIGNED AUTO_INCREMENT PRIMARY KEY,c2 CHAR(1)) ENGINE=InnoDB;
XA START 'a';
DELETE FROM t;
INSERT INTO t VALUES(0,0), (0,0), (0,0), (0,0), (0,0), (0,0), (0,0), (0,0), (0,0), (0,0), (0,0), (0,0), (0,0), (1,1);
INSERT INTO t VALUES(0,0), (0,0), (0,0), (0,0);

Leads to:

10.6.0 bfb4761ca04704d68dba51f76d7c9967f880a6ee (Debug)

mysqld: /test/10.6_dbg/storage/innobase/lock/lock0lock.cc:2192: 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.

10.6.0 bfb4761ca04704d68dba51f76d7c9967f880a6ee (Debug)

Core was generated by `/test/MD110221-mariadb-10.6.0-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
Program terminated with signal SIGABRT, Aborted.
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6)
    at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
[Current thread is 1 (Thread 0x14a8804a0700 (LWP 3692569))]
(gdb) bt
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
#1  0x000055e2accc155c in my_write_core (sig=sig@entry=6) at /test/10.6_dbg/mysys/stacktrace.c:424
#2  0x000055e2ac4594de in handle_fatal_signal (sig=6) at /test/10.6_dbg/sql/signal_handler.cc:330
#3  <signal handler called>
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#5  0x000014a88405e859 in __GI_abort () at abort.c:79
#6  0x000014a88405e729 in __assert_fail_base (fmt=0x14a8841f4588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55e2ad08bab0 "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=0x55e2ad089768 "/test/10.6_dbg/storage/innobase/lock/lock0lock.cc", line=2192, function=<optimized out>) at assert.c:92
#7  0x000014a88406ff36 in __GI___assert_fail (assertion=assertion@entry=0x55e2ad08bab0 "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=0x55e2ad089768 "/test/10.6_dbg/storage/innobase/lock/lock0lock.cc", line=line@entry=2192, function=function@entry=0x55e2ad08bb48 "void lock_rec_move_low(hash_table_t*, const buf_block_t*, const buf_block_t*, ulint, ulint)") at assert.c:101
#8  0x000055e2ac8f1773 in lock_rec_move_low (lock_hash=lock_hash@entry=0x55e2adfec8b0 <lock_sys+240>, receiver=receiver@entry=0x14a860011e20, donator=donator@entry=0x14a860011d40, receiver_heap_no=receiver_heap_no@entry=1, donator_heap_no=donator_heap_no@entry=1) at /test/10.6_dbg/storage/innobase/lock/lock0lock.cc:2192
#9  0x000055e2ac8f2257 in lock_rec_move (donator_heap_no=1, receiver_heap_no=1, donator=0x14a860011d40, receiver=0x14a860011e20) at /test/10.6_dbg/storage/innobase/lock/lock0lock.cc:2739
#10 lock_update_split_right (right_block=right_block@entry=0x14a860011e20, left_block=left_block@entry=0x14a860011d40) at /test/10.6_dbg/storage/innobase/lock/lock0lock.cc:2739
#11 0x000055e2acab99db in btr_page_split_and_insert (flags=flags@entry=0, cursor=cursor@entry=0x14a88049d5c0, offsets=offsets@entry=0x14a88049d588, heap=heap@entry=0x14a88049d580, tuple=tuple@entry=0x14a83c020b88, n_ext=n_ext@entry=0, mtr=0x14a88049db80) at /test/10.6_dbg/storage/innobase/btr/btr0btr.cc:3047
#12 0x000055e2acabad2b in btr_root_raise_and_insert (flags=flags@entry=0, cursor=cursor@entry=0x14a88049d5c0, offsets=offsets@entry=0x14a88049d588, heap=heap@entry=0x14a88049d580, tuple=tuple@entry=0x14a83c020b88, n_ext=0, mtr=0x14a88049db80) at /test/10.6_dbg/storage/innobase/btr/btr0btr.cc:2065
#13 0x000055e2acad47cc in btr_cur_pessimistic_insert (flags=flags@entry=0, cursor=cursor@entry=0x14a88049d5c0, offsets=offsets@entry=0x14a88049d588, heap=heap@entry=0x14a88049d580, entry=entry@entry=0x14a83c020b88, rec=rec@entry=0x14a88049d598, big_rec=0x14a88049d578, n_ext=<optimized out>, thr=0x14a83c030950, mtr=0x14a88049db80) at /test/10.6_dbg/storage/innobase/btr/btr0cur.cc:3747
#14 0x000055e2ac9b1969 in row_ins_clust_index_entry_low (flags=flags@entry=0, mode=<optimized out>, mode@entry=33, index=index@entry=0x14a83c0214d8, n_uniq=n_uniq@entry=1, entry=entry@entry=0x14a83c020b88, n_ext=n_ext@entry=0, thr=<optimized out>) at /test/10.6_dbg/storage/innobase/row/row0ins.cc:2802
#15 0x000055e2ac9b2633 in row_ins_clust_index_entry (index=index@entry=0x14a83c0214d8, entry=entry@entry=0x14a83c020b88, thr=thr@entry=0x14a83c030950, n_ext=n_ext@entry=0) at /test/10.6_dbg/storage/innobase/row/row0ins.cc:3272
#16 0x000055e2ac9b70b5 in row_ins_index_entry (thr=0x14a83c030950, entry=0x14a83c020b88, index=0x14a83c0214d8) at /test/10.6_dbg/storage/innobase/row/row0ins.cc:3380
#17 row_ins_index_entry_step (thr=0x14a83c030950, node=0x14a83c030718) at /test/10.6_dbg/storage/innobase/row/row0ins.cc:3549
#18 row_ins (thr=0x14a83c030950, node=0x14a83c030718) at /test/10.6_dbg/storage/innobase/row/row0ins.cc:3695
#19 row_ins_step (thr=thr@entry=0x14a83c030950) at /test/10.6_dbg/storage/innobase/row/row0ins.cc:3837
#20 0x000055e2ac9db754 in row_insert_for_mysql (mysql_rec=mysql_rec@entry=0x14a83c025158 "\375\021", prebuilt=0x14a83c02ffa8, ins_mode=ROW_INS_NORMAL) at /test/10.6_dbg/storage/innobase/row/row0mysql.cc:1384
#21 0x000055e2ac8655dd in ha_innobase::write_row (this=0x14a83c0255c0, record=0x14a83c025158 "\375\021") at /test/10.6_dbg/storage/innobase/handler/ha_innodb.cc:7361
#22 0x000055e2ac46d826 in handler::ha_write_row (this=0x14a83c0255c0, buf=0x14a83c025158 "\375\021") at /test/10.6_dbg/sql/handler.cc:7151
#23 0x000055e2ac143547 in write_record (thd=thd@entry=0x14a83c000db8, table=table@entry=0x14a83c01fd08, info=info@entry=0x14a88049ec60, sink=sink@entry=0x0) at /test/10.6_dbg/sql/sql_insert.cc:2106
#24 0x000055e2ac14fc0a in mysql_insert (thd=thd@entry=0x14a83c000db8, table_list=0x14a83c0127c0, fields=@0x14a83c005e30: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x55e2ad762300 <end_of_list>, last = 0x14a83c005e30, elements = 0}, <No data fields>}, values_list=@0x14a83c005e78: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x14a83c013478, last = 0x14a83c013910, elements = 4}, <No data fields>}, update_fields=@0x14a83c005e60: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x55e2ad762300 <end_of_list>, last = 0x14a83c005e60, elements = 0}, <No data fields>}, update_values=@0x14a83c005e48: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x55e2ad762300 <end_of_list>, last = 0x14a83c005e48, elements = 0}, <No data fields>}, duplic=DUP_ERROR, ignore=false, result=0x0) at /test/10.6_dbg/sql/sql_insert.cc:1099
#25 0x000055e2ac1967a2 in mysql_execute_command (thd=thd@entry=0x14a83c000db8) at /test/10.6_dbg/sql/sql_parse.cc:4453
#26 0x000055e2ac18121a in mysql_parse (thd=thd@entry=0x14a83c000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x14a88049f3d0) at /test/10.6_dbg/sql/sql_parse.cc:7906
#27 0x000055e2ac18f30b in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14a83c000db8, packet=packet@entry=0x14a83c01aac9 "INSERT INTO t VALUES(0,0), (0,0), (0,0), (0,0)", packet_length=packet_length@entry=46) at /test/10.6_dbg/sql/sql_class.h:1295
#28 0x000055e2ac19263d in do_command (thd=0x14a83c000db8) at /test/10.6_dbg/sql/sql_parse.cc:1365
#29 0x000055e2ac2ee1ab in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55e2af42b848, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1410
#30 0x000055e2ac2ee8af in handle_one_connection (arg=arg@entry=0x55e2af42b848) at /test/10.6_dbg/sql/sql_connect.cc:1312
#31 0x000055e2ac7a227d in pfs_spawn_thread (arg=0x55e2af35fef8) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201
#32 0x000014a88456c609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#33 0x000014a88415b293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.6.0 (dbg)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.2.37 (dbg), 10.2.37 (opt), 10.3.28 (dbg), 10.3.28 (opt), 10.4.18 (dbg), 10.4.18 (opt), 10.5.9 (dbg), 10.5.9 (opt), 10.6.0 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.33 (dbg), 5.7.33 (opt), 8.0.23 (dbg), 8.0.23 (opt)

10.5.9 927a882341eb1087e71d64de4e8cd89ab520de89 (Debug)

10.5.9>SET GLOBAL innodb_limit_optimistic_insert_debug=2;
Query OK, 0 rows affected (0.000 sec)
 
10.5.9>CREATE TABLE t (c INT(1)UNSIGNED AUTO_INCREMENT PRIMARY KEY,c2 CHAR(1));
Query OK, 0 rows affected (0.021 sec)
 
10.5.9>XA START 'a';
Query OK, 0 rows affected (0.000 sec)
 
10.5.9>DELETE FROM t;
Query OK, 0 rows affected (0.002 sec)
 
10.5.9>INSERT INTO t VALUES(0,0), (0,0), (0,0), (0,0), (0,0), (0,0), (0,0), (0,0), (0,0), (0,0), (0,0), (0,0), (0,0), (1,1);
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'
10.5.9>INSERT INTO t VALUES(0,0), (0,0), (0,0), (0,0);
Query OK, 4 rows affected (0.001 sec)
Records: 4  Duplicates: 0  Warnings: 0
 
10.5.9>exit
Bye



 Comments   
Comment by Marko Mäkelä [ 2021-03-19 ]

Roel, I tried to adjust your test case for the opt-in mechanism that was implemented in MDEV-24818, but I cannot repeat any failure:

diff --git a/mysql-test/suite/innodb/t/insert_into_empty.test b/mysql-test/suite/innodb/t/insert_into_empty.test
index 8d3685b4f05..1ddf6e547be 100644
--- a/mysql-test/suite/innodb/t/insert_into_empty.test
+++ b/mysql-test/suite/innodb/t/insert_into_empty.test
@@ -1,5 +1,6 @@
 --source include/have_innodb.inc
 --source include/have_sequence.inc
+--source include/maybe_debug.inc
 
 # Enable MDEV-515 table-level undo logging for insert into empty table
 SET foreign_key_checks=0, unique_checks=0;
@@ -99,3 +100,32 @@ SELECT * FROM t1;
 DROP TABLE t1;
 
 SET foreign_key_checks=0;
+
+--echo #
+--echo # MDEV-24914 Crash when moving a gap lock
+--echo #
+
+SET foreign_key_checks=0, unique_checks=0;
+
+CREATE TABLE t1(a INT PRIMARY KEY) ENGINE=InnoDB;
+
+if ($have_debug) {
+--disable_query_log
+SET @save_limit=@@GLOBAL.innodb_limit_optimistic_insert_debug;
+SET GLOBAL innodb_limit_optimistic_insert_debug=2;
+--enable_query_log
+}
+
+BEGIN;
+DELETE FROM t1;
+INSERT INTO t1 SELECT * FROM seq_1_to_10;
+ROLLBACK;
+SELECT * FROM t1;
+
+DROP TABLE t1;
+
+if ($have_debug) {
+--disable_query_log
+SET GLOBAL innodb_limit_optimistic_insert_debug = @save_limit;
+--enable_query_log
+}

Can you still repeat this?

Comment by Roel Van de Paar [ 2021-04-01 ]

Confirmed that the issue is no longer reproducible using 10.6, debug, at revision 1bd4115841ecded24217e5d753ed4d9822b4cffd, build 1/4/21.

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