[MDEV-29507] InnoDB: Failing assertion: table->n_rec_locks == 0 in dict_sys_t::remove and dict_table_remove_from_cache_low Created: 2022-09-10  Updated: 2022-09-15  Resolved: 2022-09-12

Status: Closed
Project: MariaDB Server
Component/s: Data Definition - Temporary, Data Manipulation - Delete, GIS, Storage Engine - InnoDB, XA
Affects Version/s: 10.3, 10.4, 10.5, 10.6, 10.7, 10.8, 10.9, 10.10, 10.11
Fix Version/s: 10.3.37, 10.4.27, 10.5.18, 10.6.11, 10.7.7, 10.8.6, 10.9.4, 10.10.2

Type: Bug Priority: Major
Reporter: Roel Van de Paar Assignee: Marko Mäkelä
Resolution: Fixed Votes: 0
Labels: None


 Description   

CREATE TEMPORARY TABLE t (c POINT NOT NULL,SPATIAL (c));
INSERT INTO t SELECT POINTFROMTEXT ('POINT(0 0)') FROM seq_1_to_500;
XA BEGIN 'a';
DELETE FROM t ORDER BY c;

Leads to:

10.10.2 87e8463e0454a04c2bbaa38d44227c491fb07dc1 (Debug)

InnoDB: Failing assertion: table->n_rec_locks == 0

10.10.2 87e8463e0454a04c2bbaa38d44227c491fb07dc1 (Debug)

Core was generated by `/test/MD200822-mariadb-10.10.2-linux-x86_64-dbg/bin/mysqld --no-defaults --core'.
Program terminated with signal SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
[Current thread is 1 (Thread 0x1490d6e12700 (LWP 1822186))]
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x0000149103d95859 in __GI_abort () at abort.c:79
#2  0x00005613f5ab3301 in ut_dbg_assertion_failed (expr=expr@entry=0x5613f60e80f0 "table->n_rec_locks == 0", file=file@entry=0x5613f60e81d8 "/test/10.10_dbg/storage/innobase/dict/dict0dict.cc", line=line@entry=1855) at /test/10.10_dbg/storage/innobase/ut/ut0dbg.cc:60
#3  0x00005613f5b75f5e in dict_sys_t::remove (this=this@entry=0x5613f6766a00 <dict_sys>, table=0x14909001d820, lru=lru@entry=false, keep=keep@entry=true) at /test/10.10_dbg/storage/innobase/dict/dict0dict.cc:1855
#4  0x00005613f588f5e0 in ha_innobase::delete_table (this=<optimized out>, name=0x14909001ca88 "/test/MD200822-mariadb-10.10.2-linux-x86_64-dbg/data/#sql-temptable-1bcab4-4-0") at /test/10.10_dbg/storage/innobase/handler/ha_innodb.cc:13409
#5  0x00005613f556799e in hton_drop_table (hton=<optimized out>, path=<optimized out>) at /test/10.10_dbg/sql/handler.cc:576
#6  0x00005613f54bd993 in THD::rm_temporary_table (this=<optimized out>, base=0x5613f8e16578, path=0x14909001ca88 "/test/MD200822-mariadb-10.10.2-linux-x86_64-dbg/data/#sql-temptable-1bcab4-4-0") at /test/10.10_dbg/sql/temporary_tables.cc:706
#7  0x00005613f54be115 in THD::free_tmp_table_share (this=this@entry=0x149090000db8, share=0x14909001c4c8, delete_table=delete_table@entry=true) at /test/10.10_dbg/sql/handler.h:1688
#8  0x00005613f54beb8a in THD::close_temporary_tables (this=this@entry=0x149090000db8) at /test/10.10_dbg/sql/temporary_tables.cc:545
#9  0x00005613f520de0b in THD::cleanup (this=this@entry=0x149090000db8) at /test/10.10_dbg/sql/sql_class.cc:1526
#10 0x00005613f51440d9 in unlink_thd (thd=0x149090000db8) at /test/10.10_dbg/sql/mysqld.cc:2752
#11 0x00005613f53dd3b4 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x5613f91ce5b8, put_in_cache=put_in_cache@entry=true) at /test/10.10_dbg/sql/sql_connect.cc:1429
#12 0x00005613f53dd6e3 in handle_one_connection (arg=0x5613f91ce5b8) at /test/10.10_dbg/sql/sql_connect.cc:1312
#13 0x00001491042a6609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#14 0x0000149103e92133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

10.5.18 5fc172fd43375b392a8c8adfb9038c279e578d83 (Optimized)

InnoDB: Failing assertion: table->n_rec_locks == 0

10.5.18 5fc172fd43375b392a8c8adfb9038c279e578d83 (Optimized)

Core was generated by `/test/MD200822-mariadb-10.5.18-linux-x86_64-opt/bin/mysqld --no-defaults --core'.
Program terminated with signal SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
[Current thread is 1 (Thread 0x14adc810a700 (LWP 1822202))]
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x000014addfce1859 in __GI_abort () at abort.c:79
#2  0x000056479cb414a4 in ut_dbg_assertion_failed (expr=expr@entry=0x56479d6d6c71 "table->n_rec_locks == 0", file=file@entry=0x56479d6d6398 "/test/10.5_opt/storage/innobase/dict/dict0dict.cc", line=line@entry=1888) at /test/10.5_opt/storage/innobase/ut/ut0dbg.cc:60
#3  0x000056479cb4da38 in dict_sys_t::remove (this=0x56479dc6d780 <dict_sys>, table=0x14ad400190d8, lru=lru@entry=false, keep=keep@entry=false) at /test/10.5_opt/storage/innobase/dict/dict0dict.cc:1888
#4  0x000056479d1d768c in row_drop_table_for_mysql (name=name@entry=0x14adc8109430 "data/#sql-temptable-1bcae3-4-0", trx=trx@entry=0x14addde02118, sqlcom=sqlcom@entry=SQLCOM_END, create_failed=create_failed@entry=false, nonatomic=<optimized out>, nonatomic@entry=true) at /test/10.5_opt/storage/innobase/row/row0mysql.cc:3352
#5  0x000056479d125bf4 in ha_innobase::delete_table (this=<optimized out>, name=0x14ad40018150 "/test/MD200822-mariadb-10.5.18-linux-x86_64-opt/data/#sql-temptable-1bcae3-4-0", sqlcom=SQLCOM_END) at /test/10.5_opt/storage/innobase/handler/ha_innodb.cc:13346
#6  0x000056479ce6b515 in hton_drop_table (hton=<optimized out>, path=<optimized out>) at /test/10.5_opt/sql/handler.cc:564
#7  0x000056479cdee438 in THD::rm_temporary_table (this=<optimized out>, base=0x56479f56c9c8, path=0x14ad40018150 "/test/MD200822-mariadb-10.5.18-linux-x86_64-opt/data/#sql-temptable-1bcae3-4-0") at /test/10.5_opt/sql/temporary_tables.cc:705
#8  0x000056479cdee8f1 in THD::free_tmp_table_share (this=this@entry=0x14ad40000c58, share=0x14ad40017ca8, delete_table=delete_table@entry=true) at /test/10.5_opt/sql/table.h:778
#9  0x000056479cdef321 in THD::close_temporary_tables (this=this@entry=0x14ad40000c58) at /test/10.5_opt/sql/temporary_tables.cc:544
#10 0x000056479cc1177a in THD::cleanup (this=this@entry=0x14ad40000c58) at /test/10.5_opt/sql/sql_class.cc:1539
#11 0x000056479cb96bf9 in unlink_thd (thd=0x14ad40000c58) at /test/10.5_opt/sql/mysqld.cc:2607
#12 0x000056479cd610c1 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x56479f923d38, put_in_cache=put_in_cache@entry=true) at /test/10.5_opt/sql/sql_connect.cc:1429
#13 0x000056479cd6157d in handle_one_connection (arg=0x56479f923d38) at /test/10.5_opt/sql/sql_connect.cc:1312
#14 0x000014ade01f2609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#15 0x000014addfdde133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

10.3.37 a1055ab35d29437b717e83b1a388eaa02901c42f (Optimized)

InnoDB: Failing assertion: table->n_rec_locks == 0

10.3.37 a1055ab35d29437b717e83b1a388eaa02901c42f (Optimized)

Core was generated by `/test/MD200822-mariadb-10.3.37-linux-x86_64-opt/bin/mysqld --no-defaults --core'.
Program terminated with signal SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
[Current thread is 1 (Thread 0x1511140ff700 (LWP 1822197))]
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x0000151129dc3859 in __GI_abort () at abort.c:79
#2  0x00005642a5f880e8 in ut_dbg_assertion_failed (expr=expr@entry=0x5642a693e44d "table->n_rec_locks == 0", file=file@entry=0x5642a693cd48 "/test/10.3_opt/storage/innobase/dict/dict0dict.cc", line=line@entry=1803) at /test/10.3_opt/storage/innobase/ut/ut0dbg.cc:60
#3  0x00005642a5f96c31 in dict_table_remove_from_cache_low (table=0x1510c8017fd8, lru_evict=0, lru_evict=0) at /test/10.3_opt/storage/innobase/dict/dict0dict.cc:1803
#4  0x00005642a64b5b0a in row_drop_table_for_mysql (name=name@entry=0x1511140fe6b0 "data/#sql1bcac7_9_0", trx=trx@entry=0x151114f6f0a8, sqlcom=sqlcom@entry=SQLCOM_END, create_failed=create_failed@entry=false, nonatomic=<optimized out>, nonatomic@entry=true) at /test/10.3_opt/storage/innobase/row/row0mysql.cc:3396
#5  0x00005642a640bc54 in ha_innobase::delete_table (this=<optimized out>, name=0x1510c8017150 "/test/MD200822-mariadb-10.3.37-linux-x86_64-opt/data/#sql1bcac7_9_0", sqlcom=SQLCOM_END) at /test/10.3_opt/storage/innobase/handler/ha_innodb.cc:13277
#6  0x00005642a61e3531 in THD::rm_temporary_table (this=<optimized out>, base=<optimized out>, path=0x1510c8017150 "/test/MD200822-mariadb-10.3.37-linux-x86_64-opt/data/#sql1bcac7_9_0") at /test/10.3_opt/sql/temporary_tables.cc:703
#7  0x00005642a61e39f1 in THD::free_tmp_table_share (this=this@entry=0x1510c8000c48, share=0x1510c8016d08, delete_table=delete_table@entry=true) at /test/10.3_opt/sql/table.h:751
#8  0x00005642a61e4401 in THD::close_temporary_tables (this=this@entry=0x1510c8000c48) at /test/10.3_opt/sql/temporary_tables.cc:544
#9  0x00005642a6037465 in THD::cleanup (this=this@entry=0x1510c8000c48) at /test/10.3_opt/sql/sql_class.cc:1473
#10 0x00005642a5fc0e44 in unlink_thd (thd=thd@entry=0x1510c8000c48) at /test/10.3_opt/sql/mysqld.cc:2981
#11 0x00005642a5fc0f3c in one_thread_per_connection_end (thd=0x1510c8000c48, put_in_cache=<optimized out>) at /test/10.3_opt/sql/mysqld.cc:3128
#12 0x00005642a615fb5e in do_handle_one_connection (connect=<optimized out>) at /test/10.3_opt/sql/sql_connect.cc:1422
#13 0x00005642a615fcbd in handle_one_connection (arg=<optimized out>) at /test/10.3_opt/sql/sql_connect.cc:1308
#14 0x0000151129f9b609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#15 0x0000151129ec0133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

10.3.37 a1055ab35d29437b717e83b1a388eaa02901c42f (Debug)

InnoDB: Failing assertion: table->n_rec_locks == 0

10.3.37 a1055ab35d29437b717e83b1a388eaa02901c42f (Debug)

Core was generated by `/test/MD200822-mariadb-10.3.37-linux-x86_64-dbg/bin/mysqld --no-defaults --core'.
Program terminated with signal SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
[Current thread is 1 (Thread 0x14b6cc0d7700 (LWP 1822603))]
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x000014b6e39a9859 in __GI_abort () at abort.c:79
#2  0x000056015f037dd5 in ut_dbg_assertion_failed (expr=expr@entry=0x56015f61659d "table->n_rec_locks == 0", file=file@entry=0x56015f6167a0 "/test/10.3_dbg/storage/innobase/dict/dict0dict.cc", line=line@entry=1803) at /test/10.3_dbg/storage/innobase/ut/ut0dbg.cc:60
#3  0x000056015f123056 in dict_table_remove_from_cache_low (table=0x14b68000c970, lru_evict=lru_evict@entry=0) at /test/10.3_dbg/storage/innobase/dict/dict0dict.cc:1803
#4  0x000056015f123daf in dict_table_remove_from_cache (table=<optimized out>) at /test/10.3_dbg/storage/innobase/dict/dict0dict.cc:1906
#5  0x000056015ef51a4a in row_drop_table_for_mysql (name=name@entry=0x14b6cc0d6650 "data/#sql1bcac0_9_0", trx=trx@entry=0x14b6e0f0d168, sqlcom=sqlcom@entry=SQLCOM_END, create_failed=create_failed@entry=false, nonatomic=<optimized out>, nonatomic@entry=true) at /test/10.3_dbg/storage/innobase/row/row0mysql.cc:3396
#6  0x000056015ede8ba6 in ha_innobase::delete_table (this=this@entry=0x14b6800113d8, name=<optimized out>, name@entry=0x14b68001dd28 "/test/MD200822-mariadb-10.3.37-linux-x86_64-dbg/data/#sql1bcac0_9_0", sqlcom=sqlcom@entry=SQLCOM_END) at /test/10.3_dbg/storage/innobase/handler/ha_innodb.cc:13277
#7  0x000056015eddeaa6 in ha_innobase::delete_table (this=0x14b6800113d8, name=0x14b68001dd28 "/test/MD200822-mariadb-10.3.37-linux-x86_64-dbg/data/#sql1bcac0_9_0") at /test/10.3_dbg/storage/innobase/handler/ha_innodb.cc:13402
#8  0x000056015ebc5677 in handler::ha_delete_table (this=this@entry=0x14b6800113d8, name=name@entry=0x14b68001dd28 "/test/MD200822-mariadb-10.3.37-linux-x86_64-dbg/data/#sql1bcac0_9_0") at /test/10.3_dbg/sql/handler.cc:4722
#9  0x000056015eb1f931 in THD::rm_temporary_table (this=<optimized out>, base=<optimized out>, path=0x14b68001dd28 "/test/MD200822-mariadb-10.3.37-linux-x86_64-dbg/data/#sql1bcac0_9_0") at /test/10.3_dbg/sql/temporary_tables.cc:703
#10 0x000056015eb2006d in THD::free_tmp_table_share (this=this@entry=0x14b680000d90, share=0x14b68001d7e0, delete_table=delete_table@entry=true) at /test/10.3_dbg/sql/handler.h:1553
#11 0x000056015eb20ad6 in THD::close_temporary_tables (this=this@entry=0x14b680000d90) at /test/10.3_dbg/sql/temporary_tables.cc:544
#12 0x000056015e916e69 in THD::cleanup (this=this@entry=0x14b680000d90) at /test/10.3_dbg/sql/sql_class.cc:1473
#13 0x000056015e884dec in unlink_thd (thd=thd@entry=0x14b680000d90) at /test/10.3_dbg/sql/mysqld.cc:2981
#14 0x000056015e884f74 in one_thread_per_connection_end (thd=0x14b680000d90, put_in_cache=<optimized out>) at /test/10.3_dbg/sql/mysqld.cc:3128
#15 0x000056015ea7b200 in do_handle_one_connection (connect=<optimized out>) at /test/10.3_dbg/sql/sql_connect.cc:1422
#16 0x000056015ea7b2bf in handle_one_connection (arg=<optimized out>) at /test/10.3_dbg/sql/sql_connect.cc:1308
#17 0x000014b6e3b81609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#18 0x000014b6e3aa6133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.3.37 (dbg), 10.3.37 (opt), 10.4.27 (dbg), 10.4.27 (opt), 10.5.18 (dbg), 10.5.18 (opt), 10.6.10 (dbg), 10.6.10 (opt), 10.7.6 (dbg), 10.7.6 (opt), 10.8.5 (dbg), 10.8.5 (opt), 10.9.2 (dbg), 10.9.2 (opt), 10.10.2 (dbg), 10.10.2 (opt), 10.11.0 (dbg), 10.11.0 (opt)

Bug (or feature/syntax) confirmed not present in:
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.38 (dbg), 5.7.38 (opt), 8.0.29 (dbg), 8.0.29 (opt)



 Comments   
Comment by Roel Van de Paar [ 2022-09-10 ]

All UniqueID's seen thus far accross versions

table->n_rec_locks == 0|SIGABRT|ut_dbg_assertion_failed|dict_sys_t::remove|ha_innobase::delete_table|hton_drop_table
table->n_rec_locks == 0|SIGABRT|ut_dbg_assertion_failed|dict_sys_t::remove|row_drop_table_for_mysql|ha_innobase::delete_table
table->n_rec_locks == 0|SIGABRT|ut_dbg_assertion_failed|dict_table_remove_from_cache_low|dict_table_remove_from_cache|row_drop_table_for_mysql
table->n_rec_locks == 0|SIGABRT|ut_dbg_assertion_failed|dict_table_remove_from_cache_low|row_drop_table_for_mysql|ha_innobase::delete_table

Comment by Marko Mäkelä [ 2022-09-12 ]

I repeated this with ./mtr --rr and the following:

--source include/have_innodb.inc
--source include/have_sequence.inc
CREATE TEMPORARY TABLE t (c POINT NOT NULL,SPATIAL (c)) ENGINE=InnoDB;
INSERT INTO t SELECT POINTFROMTEXT ('POINT(0 0)') FROM seq_1_to_500;
XA BEGIN 'a';
DELETE FROM t ORDER BY c;

No locks should be acquired on temporary tables, because they are private to a connection. This rule is being violated in rtr_cur_search_with_match(), which is invoking lock_place_prdt_page_lock(). With the following patch, this particular crash will disappear:

diff --git a/storage/innobase/lock/lock0prdt.cc b/storage/innobase/lock/lock0prdt.cc
index 5a12d97411f..2975659138d 100644
--- a/storage/innobase/lock/lock0prdt.cc
+++ b/storage/innobase/lock/lock0prdt.cc
@@ -799,6 +799,9 @@ lock_place_prdt_page_lock(
 
 	ut_ad(index->is_spatial());
 	ut_ad(!dict_index_is_online_ddl(index));
+	if (index->table->is_temporary()) {
+		return DB_SUCCESS;
+	}
 
 	/* Another transaction cannot have an implicit lock on the record,
 	because when we come here, we already have modified the clustered

Here is a little better test, which can be part of a larger test file:

--source include/have_innodb.inc
--source include/have_sequence.inc
 
connect con1,localhost,root,,;
CREATE TEMPORARY TABLE t (c POINT NOT NULL,SPATIAL (c)) ENGINE=InnoDB;
INSERT INTO t SELECT POINTFROMTEXT ('POINT(0 0)') FROM seq_1_to_500;
XA BEGIN 'a';
DELETE FROM t ORDER BY c;
disconnect con1;

Comment by Marko Mäkelä [ 2022-09-12 ]

The function lock_prdt_lock() was already skipping locking for temporary tables.

Comment by Roel Van de Paar [ 2022-09-13 ]

10.11 with the patch applied behaves well against the testcase(s) given. Now doing broader test.

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