[MDEV-32272] lock_release_on_prepare_try() does not release lock if supremum bit is set along with other bits set in lock's bitmap - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Critical
Resolution: Fixed
Affects Version/s: 10.5, 10.6, 10.9(EOL), 10.10(EOL), 10.11, 11.0(EOL), 11.1(EOL), 11.2(EOL), 11.3(EOL)
Fix Version/s: 10.6.16, 10.10.7, 10.11.6, 11.0.4, 11.1.3
Component/s: Locking, Replication, Storage Engine - InnoDB, XA
Labels:
- affects-tests

Description

Seems related to MDEV-30941. While it is not caused by MDEV-31949, it causes interference with testing of MDEV-31949 and re-testing of ~~MDEV-32257~~.

--source include/have_innodb.inc

CREATE TABLE t2 (t1_a INT,b INT) ENGINE=InnoDB;

SET SESSION pseudo_slave_mode=1;

CREATE TABLE t1 (a INT KEY,b LONG) ENGINE=InnoDB;

XA START 'a';

INSERT INTO t1 SELECT * FROM t1;

INSERT INTO t2 VALUES (0,0);

XA END 'a';

XA PREPARE 'a';

DROP TABLE t1,t2;

The outcomes for the final query differs significantly from version to version:

10.4.32 47f0135d7aba57d160d1d95ff7f1f6b7bb07c2fb (Optimized + Debug)
10.4.32>DROP TABLE t1,t2;
ERROR 1399 (XAE07): XAER_RMFAIL: The command cannot be executed when global transaction is in the PREPARED state

10.5.23 6b343de8ef51e4c92f0ea2bf62f27f0aab32204d (Optimized)
10.5.23-opt>DROP TABLE t1,t2;
Query OK, 0 rows affected (0.008 sec)

10.6.16 076df87b4c1dc5123d66600b82201050c45aa9d9 (Debug)
10.6.16-dbg>DROP TABLE t1,t2;
ERROR 2013 (HY000): Lost connection to server during query

10.9.8 3e0009dc3a771e4dbf2fa4a4cf87e750453fb2eb (Debug)
10.9.8-dbg>DROP TABLE t1,t2;
ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction

10.10+ versions all show the ERROR 1205 Lock wait timeout.
An example of the process list during before the timeout happens:

10.9.8 3e0009dc3a771e4dbf2fa4a4cf87e750453fb2eb (Debug)
10.9.8-dbg>SHOW PROCESSLIST;
+----+------+-----------+------+---------+------+----------------+------------------+----------+
\| Id \| User \| Host \| db \| Command \| Time \| State \| Info \| Progress \|
+----+------+-----------+------+---------+------+----------------+------------------+----------+
\| 4 \| root \| localhost \| test \| Query \| 29 \| closing tables \| DROP TABLE t1,t2 \| 0.000 \|
\| 5 \| root \| localhost \| test \| Query \| 0 \| starting \| SHOW PROCESSLIST \| 0.000 \|
+----+------+-----------+------+---------+------+----------------+------------------+----------+
2 rows in set (0.000 sec)

MySQL 5.5 to 5.7 show the ERROR 1399:

MySQL 5.7.40 c4f63caa8d9f30b2850672291e0ad0928dd89d0e (Debug) and MS 5.5, MS 5.6
5.7.40-dbg>DROP TABLE t1,t2;
ERROR 1399 (XAE07): XAER_RMFAIL: The command cannot be executed when global transaction is in the PREPARED state

MySQL 8 is different again, it waits much longer and the process list shows:

MySQL 8.0.33 ea7087d885006918ad54458e7aad215b1650312c (Optimized)
mysql> SHOW PROCESSLIST;
+----+-----------------+-----------+------+---------+------+---------------------------------+------------------+
\| Id \| User \| Host \| db \| Command \| Time \| State \| Info \|
+----+-----------------+-----------+------+---------+------+---------------------------------+------------------+
\| 5 \| event_scheduler \| localhost \| NULL \| Daemon \| 476 \| Waiting on empty queue \| NULL \|
\| 9 \| root \| localhost \| test \| Query \| 474 \| Waiting for table metadata lock \| DROP TABLE t1,t2 \|
\| 10 \| root \| localhost \| test \| Query \| 0 \| init \| SHOW PROCESSLIST \|
+----+-----------------+-----------+------+---------+------+---------------------------------+------------------+
3 rows in set (0.00 sec)

The stacks for the crash on 10.6 opt/dbg:

10.6.16 076df87b4c1dc5123d66600b82201050c45aa9d9 (Optimized)
2023-09-28 09:49:54 0x149808da3640 InnoDB: Assertion failure in file /test/10.6_opt/storage/innobase/dict/dict0dict.cc line 1862
InnoDB: Failing assertion: table->n_rec_locks == 0

10.6.16 076df87b4c1dc5123d66600b82201050c45aa9d9 (Optimized)
Core was generated by `/test/MD270923-mariadb-10.6.16-linux-x86_64-opt/bin/mariadbd --no-defaults --co'.
Program terminated with signal SIGABRT, Aborted.
#0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=22643216102976)
at ./nptl/pthread_kill.c:44
[Current thread is 1 (Thread 0x149808da3640 (LWP 4001869))]
(gdb) bt
#0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=22643216102976) at ./nptl/pthread_kill.c:44
#1 __pthread_kill_internal (signo=6, threadid=22643216102976) at ./nptl/pthread_kill.c:78
#2 __GI___pthread_kill (threadid=22643216102976, signo=signo@entry=6) at ./nptl/pthread_kill.c:89
#3 0x0000149813642476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
#4 0x00001498136287f3 in __GI_abort () at ./stdlib/abort.c:79
#5 0x00005627b9753f5f in ut_dbg_assertion_failed (expr=expr@entry=0x5627ba412374 "table->n_rec_locks == 0", file=file@entry=0x5627ba412390 "/test/10.6_opt/storage/innobase/dict/dict0dict.cc", line=line@entry=1862) at /test/10.6_opt/storage/innobase/ut/ut0dbg.cc:60
#6 0x00005627b9760a48 in dict_sys_t::remove (this=0x5627baa0a500 <dict_sys>, table=table@entry=0x1497a401f520, lru=lru@entry=false, keep=keep@entry=false) at /test/10.6_opt/storage/innobase/dict/dict0dict.cc:1862
#7 0x00005627b9f9e214 in trx_t::commit (this=this@entry=0x14980a05d180, deleted=std::vector of length 0, capacity 0) at /test/10.6_opt/storage/innobase/dict/drop.cc:276
#8 0x00005627b9e329d4 in ha_innobase::delete_table (this=<optimized out>, name=<optimized out>) at /test/10.6_opt/storage/innobase/handler/ha_innodb.cc:13782
#9 0x00005627b9af2245 in hton_drop_table (hton=<optimized out>, path=<optimized out>) at /test/10.6_opt/sql/handler.cc:573
#10 0x00005627b9af8bb9 in ha_delete_table (thd=thd@entry=0x1497a4000c68, hton=hton@entry=0x5627bbbbb658, path=path@entry=0x149808da1160 "./test/t1", db=db@entry=0x149808da0f50, alias=alias@entry=0x149808da0f60, generate_warning=generate_warning@entry=true) at /test/10.6_opt/sql/handler.cc:3163
#11 0x00005627b9942cbe in mysql_rm_table_no_locks (thd=0x1497a4000c68, tables=<optimized out>, current_db=<optimized out>, ddl_log_state=<optimized out>, if_exists=<optimized out>, drop_temporary=<optimized out>, drop_view=<optimized out>, drop_sequence=<optimized out>, dont_log_query=<optimized out>, dont_free_locks=<optimized out>) at /test/10.6_opt/sql/sql_table.cc:1464
#12 0x00005627b994425c in mysql_rm_table (thd=thd@entry=0x1497a4000c68, tables=tables@entry=0x1497a40109c8, if_exists=<optimized out>, drop_temporary=<optimized out>, drop_sequence=<optimized out>, dont_log_query=dont_log_query@entry=false) at /test/10.6_opt/sql/sql_table.cc:1041
#13 0x00005627b98a719a in mysql_execute_command (thd=0x1497a4000c68, is_called_from_prepared_stmt=<optimized out>) at /test/10.6_opt/sql/sql_parse.cc:4978
#14 0x00005627b98ab6e6 in mysql_parse (thd=0x1497a4000c68, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at /test/10.6_opt/sql/sql_parse.cc:8050
#15 0x00005627b98ade85 in dispatch_command (command=COM_QUERY, thd=0x1497a4000c68, packet=<optimized out>, packet_length=<optimized out>, blocking=<optimized out>) at /test/10.6_opt/sql/sql_parse.cc:1995
#16 0x00005627b98afbf0 in do_command (thd=0x1497a4000c68, blocking=blocking@entry=true) at /test/10.6_opt/sql/sql_parse.cc:1409
#17 0x00005627b99c024f in do_handle_one_connection (connect=<optimized out>, put_in_cache=true) at /test/10.6_opt/sql/sql_connect.cc:1416
#18 0x00005627b99c059d in handle_one_connection (arg=arg@entry=0x5627bc0317c8) at /test/10.6_opt/sql/sql_connect.cc:1318
#19 0x00005627b9d724f1 in pfs_spawn_thread (arg=0x5627bbfc1e28) at /test/10.6_opt/storage/perfschema/pfs.cc:2201
#20 0x0000149813694b43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#21 0x0000149813726a00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

10.6.16 076df87b4c1dc5123d66600b82201050c45aa9d9 (Debug)
2023-09-28 10:04:17 0x152fa0953640 InnoDB: Assertion failure in file /test/10.6_dbg/storage/innobase/dict/dict0dict.cc line 1862
InnoDB: Failing assertion: table->n_rec_locks == 0

10.6.16 076df87b4c1dc5123d66600b82201050c45aa9d9 (Debug)
Core was generated by `/test/MD270923-mariadb-10.6.16-linux-x86_64-dbg/bin/mariadbd --no-defaults --co'.
Program terminated with signal SIGABRT, Aborted.
#0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=23294301779520)
at ./nptl/pthread_kill.c:44
[Current thread is 1 (Thread 0x152fa0953640 (LWP 2586101))]
(gdb) bt
#0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=23294301779520) at ./nptl/pthread_kill.c:44
#1 __pthread_kill_internal (signo=6, threadid=23294301779520) at ./nptl/pthread_kill.c:78
#2 __GI___pthread_kill (threadid=23294301779520, signo=signo@entry=6) at ./nptl/pthread_kill.c:89
#3 0x0000152fb6c42476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
#4 0x0000152fb6c287f3 in __GI_abort () at ./stdlib/abort.c:79
#5 0x000055e0d4e591a4 in ut_dbg_assertion_failed (expr=expr@entry=0x55e0d54838a4 "table->n_rec_locks == 0", file=file@entry=0x55e0d5483988 "/test/10.6_dbg/storage/innobase/dict/dict0dict.cc", line=line@entry=1862) at /test/10.6_dbg/storage/innobase/ut/ut0dbg.cc:60
#6 0x000055e0d4f0ba5b in dict_sys_t::remove (this=0x55e0d5a95a00 <dict_sys>, table=table@entry=0x152f6401d548, lru=lru@entry=false, keep=keep@entry=false) at /test/10.6_dbg/storage/innobase/dict/dict0dict.cc:1862
#7 0x000055e0d4f3b9e9 in trx_t::commit (this=this@entry=0x152fa1956180, deleted=std::vector of length 0, capacity 0) at /test/10.6_dbg/storage/innobase/dict/drop.cc:276
#8 0x000055e0d4c55c54 in ha_innobase::delete_table (this=<optimized out>, name=<optimized out>) at /test/10.6_dbg/storage/innobase/handler/ha_innodb.cc:13782
#9 0x000055e0d48ba4e1 in hton_drop_table (hton=<optimized out>, path=<optimized out>) at /test/10.6_dbg/sql/handler.cc:573
#10 0x000055e0d48c2f5f in ha_delete_table (thd=thd@entry=0x152f64000d58, hton=hton@entry=0x55e0d7edfb28, path=path@entry=0x152fa09517b0 "./test/t1", db=db@entry=0x152fa09515a0, alias=alias@entry=0x152fa09515b0, generate_warning=generate_warning@entry=true) at /test/10.6_dbg/sql/handler.cc:3163
#11 0x000055e0d46b6d20 in mysql_rm_table_no_locks (thd=thd@entry=0x152f64000d58, tables=tables@entry=0x152f64013388, current_db=current_db@entry=0x152f64000df8, ddl_log_state=0x152fa09515d0, ddl_log_state@entry=0x0, if_exists=if_exists@entry=false, drop_temporary=drop_temporary@entry=false, drop_view=false, drop_sequence=false, dont_log_query=false, dont_free_locks=false) at /test/10.6_dbg/sql/sql_table.cc:1464
#12 0x000055e0d46b8bb4 in mysql_rm_table (thd=thd@entry=0x152f64000d58, tables=tables@entry=0x152f64013388, if_exists=<optimized out>, drop_temporary=<optimized out>, drop_sequence=<optimized out>, dont_log_query=dont_log_query@entry=false) at /test/10.6_dbg/sql/sql_table.cc:1041
#13 0x000055e0d460287d in mysql_execute_command (thd=thd@entry=0x152f64000d58, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.6_dbg/sql/sql_parse.cc:4978
#14 0x000055e0d4607164 in mysql_parse (thd=thd@entry=0x152f64000d58, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x152fa09521f0) at /test/10.6_dbg/sql/sql_parse.cc:8050
#15 0x000055e0d46094da in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x152f64000d58, packet=packet@entry=0x152f6400af29 "DROP TABLE t1,t2", packet_length=packet_length@entry=16, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_class.h:241
#16 0x000055e0d460b5f7 in do_command (thd=0x152f64000d58, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_parse.cc:1409
#17 0x000055e0d474a1fd in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55e0d83b4fa8, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1416
#18 0x000055e0d474a4f2 in handle_one_connection (arg=arg@entry=0x55e0d83b4fa8) at /test/10.6_dbg/sql/sql_connect.cc:1318
#19 0x000055e0d4b9608c in pfs_spawn_thread (arg=0x55e0d8399708) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201
#20 0x0000152fb6c94b43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#21 0x0000152fb6d26a00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

Attachments

Issue Links

blocks

MDEV-31949 slow parallel replication of user xa

Stalled

MDEV-32257 Assertion `thd->is_killed()' failed in XID_cache_element::acquired_to_recovered (opt) or acquire_xid (dbg) on XA ROLLBACK or XA COMMIT

Closed

is caused by

MDEV-26682 slave lock timeout with xa and gap locks

Closed

MDEV-30165 X-lock on supremum for prepared transaction for RR

Closed

is duplicated by

MDEV-32353 lock_release_on_prepare_try() does not release lock if supremum bit is set along with other bits set in lock's bitmap

Closed

relates to

MDEV-30941 ASAN: heap-use-after-free in std::__atomic_base from trx_t::commit_tables on XA COMMIT with pseudo_slave_mode enabled

Confirmed

MDEV-32262 InnoDB: Failing assertion: m_prebuilt->trx == thd_to_trx(m_user_thd) in ha_innobase::change_active_index

Confirmed

MDEV-32471 Backport MDEV-32272 test cases from 10.6 to 10.5

Open

(3 relates to)

Activity

Ascending order - Click to sort in descending order

View 5 older comments

Andrei Elkin added a comment - 2023-10-07 17:16

This looks very much as underfixed ~~MDEV-21602~~ without which fixes this test also hangs.
marko, could you please check how the one-table-in-transaction case test of ~~MDEV-21602~~ description, also here

--connection crash_me

CREATE TABLE t1 (pk INT PRIMARY KEY) ENGINE=InnoDB;

xa start '1'; insert into t1 set pk=1; xa end '1'; xa prepare '1';

# KILL server_process & restart

xa recover; # =>

+----------+--------------+--------------+------+

| formatID | gtrid_length | bqual_length | data |

+----------+--------------+--------------+------+

|        1 |            1 |            0 | 1    |

+----------+--------------+--------------+------+

1 row in set (0.00 sec)

--connection default

--error 0

DROP TABLE t1;

passes, but a two-table version of the test, which is also a simplified (away SET SESSION pseudo_slave_mode=1) current description one, here

--source include/have_innodb.inc

CREATE TABLE t2 (t1_a INT,b INT) ENGINE=InnoDB;

SET SESSION pseudo_slave_mode=1;

CREATE TABLE t1 (a INT KEY,b LONG) ENGINE=InnoDB;

XA START 'a';

INSERT INTO t1 SELECT * FROM t1;

INSERT INTO t2 VALUES (0,0);

XA END 'a';

XA PREPARE 'a';

--connection default

DROP TABLE t1,t2;

asserts as pasted above under 10.6.16 076df87b4c1dc512?

Andrei Elkin added a comment - 2023-10-07 17:16 This looks very much as underfixed MDEV-21602 without which fixes this test also hangs. marko , could you please check how the one-table-in-transaction case test of MDEV-21602 description, also here --connection crash_me CREATE TABLE t1 (pk INT PRIMARY KEY) ENGINE=InnoDB; xa start '1' ; insert into t1 set pk= 1 ; xa end '1' ; xa prepare '1' ; # KILL server_process & restart xa recover; # => +----------+--------------+--------------+------+ | formatID | gtrid_length | bqual_length | data | +----------+--------------+--------------+------+ | 1 | 1 | 0 | 1 | +----------+--------------+--------------+------+ 1 row in set ( 0.00 sec) --connection default --error 0 DROP TABLE t1; passes, but a two-table version of the test, which is also a simplified (away SET SESSION pseudo_slave_mode=1 ) current description one, here --source include/have_innodb.inc CREATE TABLE t2 (t1_a INT,b INT) ENGINE=InnoDB; SET SESSION pseudo_slave_mode= 1 ; CREATE TABLE t1 (a INT KEY,b LONG) ENGINE=InnoDB; XA START 'a' ; INSERT INTO t1 SELECT * FROM t1; INSERT INTO t2 VALUES ( 0 , 0 ); XA END 'a' ; XA PREPARE 'a' ; --connection default DROP TABLE t1,t2; asserts as pasted above under 10.6.16 076df87b4c1dc512 ?

Marko Mäkelä added a comment - 2023-10-08 09:13

Elkin, does the SQL that you posted crash? If yes, please post the stack traces.

I would expect the DROP TABLE statement to fail due to lock wait timeout, because IX locks are being held on the tables by the XA PREPARE transaction.

Marko Mäkelä added a comment - 2023-10-08 09:13 Elkin , does the SQL that you posted crash? If yes, please post the stack traces. I would expect the DROP TABLE statement to fail due to lock wait timeout, because IX locks are being held on the tables by the XA PREPARE transaction.

Marko Mäkelä added a comment - 2023-10-09 08:02

I confirmed an assertion failure. The assertion fails because a record locks exist on the table t1:

10.6 8941bdc4748a94c1207723d86a8e46df8ae129b3
#0 ut_dbg_assertion_failed (expr=expr@entry=0x56078a0540bd "table->n_rec_locks == 0", file=file@entry=0x56078a10e728 "/mariadb/10.6/storage/innobase/dict/dict0dict.cc", line=line@entry=1862)
at /mariadb/10.6/storage/innobase/ut/ut0dbg.cc:39
#1 0x000056078ad99fa5 in dict_sys_t::remove (this=0x56078b27dd40 <dict_sys>, table=table@entry=0x7fb540111248, lru=lru@entry=false, keep=keep@entry=false)
at /mariadb/10.6/storage/innobase/dict/dict0dict.cc:1862
#2 0x000056078ae65308 in trx_t::commit (this=this@entry=0x7fb5680ed180, deleted=std::vector of length 0, capacity 0) at /mariadb/10.6/storage/innobase/dict/drop.cc:276
#3 0x000056078ad71057 in ha_innobase::delete_table (this=<optimized out>, name=<optimized out>) at /mariadb/10.6/storage/innobase/handler/ha_innodb.cc:13782
#4 0x000056078a857036 in hton_drop_table (hton=<optimized out>, path=<optimized out>) at /mariadb/10.6/sql/handler.cc:573
#5 0x000056078a85db82 in ha_delete_table (thd=thd@entry=0x7fb540001ac8, hton=hton@entry=0x56078ccd0578, path=path@entry=0x7fb568052810 "./test/t1", db=db@entry=0x7fb568052600,
alias=alias@entry=0x7fb568052610, generate_warning=generate_warning@entry=true) at /mariadb/10.6/sql/handler.cc:3163
#6 0x000056078aafb586 in mysql_rm_table_no_locks (thd=thd@entry=0x7fb540001ac8, tables=tables@entry=0x7fb540015458, current_db=current_db@entry=0x7fb540001b68, ddl_log_state=0x7fb568052630,
ddl_log_state@entry=0x0, if_exists=if_exists@entry=false, drop_temporary=false, drop_view=false, drop_sequence=false, dont_log_query=false, dont_free_locks=false) at /mariadb/10.6/sql/sql_table.cc:1464
#7 0x000056078aafc852 in mysql_rm_table (thd=thd@entry=0x7fb540001ac8, tables=tables@entry=0x7fb540015458, if_exists=if_exists@entry=false, drop_temporary=<optimized out>, drop_sequence=<optimized out>,
dont_log_query=dont_log_query@entry=false) at /mariadb/10.6/sql/sql_table.cc:1041
#8 0x000056078aa51260 in mysql_execute_command (thd=thd@entry=0x7fb540001ac8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /mariadb/10.6/sql/sql_parse.cc:4978
#9 0x000056078aa54b6e in mysql_parse (thd=thd@entry=0x7fb540001ac8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7fb568053270) at /mariadb/10.6/sql/sql_parse.cc:8050
#10 0x000056078aa56440 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7fb540001ac8, packet=packet@entry=0x7fb540113329 "DROP TABLE t1,t2", packet_length=packet_length@entry=16,
blocking=blocking@entry=true) at /mariadb/10.6/sql/sql_parse.cc:1896

It turns out that the intention-shared table lock on t1 was released in lock_release_on_prepare() (~~MDEV-26682~~). The actual bug seems to be that no intention-exclusive lock was acquired by the INSERT…SELECT. That lock should prevent the DROP TABLE from executing.

I was also able to reproduce the crash with a two-connection test case:

--source include/have_innodb.inc

CREATE TABLE t2 (t1_a INT,b INT) ENGINE=InnoDB;

SET SESSION pseudo_slave_mode=1;

CREATE TABLE t1 (a INT KEY,b LONG) ENGINE=InnoDB;

XA START 'a';

INSERT INTO t1 SELECT * FROM t1;

INSERT INTO t2 VALUES (0,0);

XA END 'a';

XA PREPARE 'a';

-- connect(drop, localhost, root,,)

DROP TABLE t1,t2;

--connection default

XA COMMIT 'a';

--connection drop

DROP TABLE t1,t2;

--disconnect drop

Marko Mäkelä added a comment - 2023-10-09 08:02 I confirmed an assertion failure. The assertion fails because a record locks exist on the table t1 : 10.6 8941bdc4748a94c1207723d86a8e46df8ae129b3 #0 ut_dbg_assertion_failed (expr=expr@entry=0x56078a0540bd "table->n_rec_locks == 0", file=file@entry=0x56078a10e728 "/mariadb/10.6/storage/innobase/dict/dict0dict.cc", line=line@entry=1862) at /mariadb/10.6/storage/innobase/ut/ut0dbg.cc:39 #1 0x000056078ad99fa5 in dict_sys_t::remove (this=0x56078b27dd40 <dict_sys>, table=table@entry=0x7fb540111248, lru=lru@entry=false, keep=keep@entry=false) at /mariadb/10.6/storage/innobase/dict/dict0dict.cc:1862 #2 0x000056078ae65308 in trx_t::commit (this=this@entry=0x7fb5680ed180, deleted=std::vector of length 0, capacity 0) at /mariadb/10.6/storage/innobase/dict/drop.cc:276 #3 0x000056078ad71057 in ha_innobase::delete_table (this=<optimized out>, name=<optimized out>) at /mariadb/10.6/storage/innobase/handler/ha_innodb.cc:13782 #4 0x000056078a857036 in hton_drop_table (hton=<optimized out>, path=<optimized out>) at /mariadb/10.6/sql/handler.cc:573 #5 0x000056078a85db82 in ha_delete_table (thd=thd@entry=0x7fb540001ac8, hton=hton@entry=0x56078ccd0578, path=path@entry=0x7fb568052810 "./test/t1", db=db@entry=0x7fb568052600, alias=alias@entry=0x7fb568052610, generate_warning=generate_warning@entry=true) at /mariadb/10.6/sql/handler.cc:3163 #6 0x000056078aafb586 in mysql_rm_table_no_locks (thd=thd@entry=0x7fb540001ac8, tables=tables@entry=0x7fb540015458, current_db=current_db@entry=0x7fb540001b68, ddl_log_state=0x7fb568052630, ddl_log_state@entry=0x0, if_exists=if_exists@entry=false, drop_temporary=false, drop_view=false, drop_sequence=false, dont_log_query=false, dont_free_locks=false) at /mariadb/10.6/sql/sql_table.cc:1464 #7 0x000056078aafc852 in mysql_rm_table (thd=thd@entry=0x7fb540001ac8, tables=tables@entry=0x7fb540015458, if_exists=if_exists@entry=false, drop_temporary=<optimized out>, drop_sequence=<optimized out>, dont_log_query=dont_log_query@entry=false) at /mariadb/10.6/sql/sql_table.cc:1041 #8 0x000056078aa51260 in mysql_execute_command (thd=thd@entry=0x7fb540001ac8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /mariadb/10.6/sql/sql_parse.cc:4978 #9 0x000056078aa54b6e in mysql_parse (thd=thd@entry=0x7fb540001ac8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7fb568053270) at /mariadb/10.6/sql/sql_parse.cc:8050 #10 0x000056078aa56440 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7fb540001ac8, packet=packet@entry=0x7fb540113329 "DROP TABLE t1,t2", packet_length=packet_length@entry=16, blocking=blocking@entry=true) at /mariadb/10.6/sql/sql_parse.cc:1896 It turns out that the intention-shared table lock on t1 was released in lock_release_on_prepare() ( MDEV-26682 ). The actual bug seems to be that no intention-exclusive lock was acquired by the INSERT…SELECT . That lock should prevent the DROP TABLE from executing. I was also able to reproduce the crash with a two-connection test case: --source include/have_innodb.inc CREATE TABLE t2 (t1_a INT ,b INT ) ENGINE=InnoDB; SET SESSION pseudo_slave_mode=1; CREATE TABLE t1 (a INT KEY ,b LONG) ENGINE=InnoDB; XA START 'a' ; INSERT INTO t1 SELECT * FROM t1; INSERT INTO t2 VALUES (0,0); XA END 'a' ; XA PREPARE 'a' ; -- connect(drop, localhost, root,,) DROP TABLE t1,t2; --connection default XA COMMIT 'a' ; --connection drop DROP TABLE t1,t2; --disconnect drop

Vladislav Lesin added a comment - 2023-10-13 11:37

I have just checked, and ~~MDEV-32353~~ fix solves the issue.

INSERT…SELECT acquires table X-lock when the result of SELECT subquery is not empty(see row_ins_clust_index_entry_low()), SELECT subquery is also responsible for table locks and acquires the corresponding lock type(see lock_table() call in row_search_mvcc()). For our case this is IS lock, which is released then during XA PREPARE execution.

So, there should not be any locks for t1 table after XA PREPARE, as nothing was inserted. The reason of why table->n_rec_locks was not equal to 0 during the table deletion is that ~~MDEV-30165~~ fix did not release the whole lock, but just reset supremum bit and rebuilt waiting queue.

Vladislav Lesin added a comment - 2023-10-13 11:37 I have just checked, and MDEV-32353 fix solves the issue. INSERT…SELECT acquires table X-lock when the result of SELECT subquery is not empty(see row_ins_clust_index_entry_low()), SELECT subquery is also responsible for table locks and acquires the corresponding lock type(see lock_table() call in row_search_mvcc()). For our case this is IS lock, which is released then during XA PREPARE execution. So, there should not be any locks for t1 table after XA PREPARE, as nothing was inserted. The reason of why table->n_rec_locks was not equal to 0 during the table deletion is that MDEV-30165 fix did not release the whole lock, but just reset supremum bit and rebuilt waiting queue.

Vladislav Lesin added a comment - 2023-10-13 12:09

See ~~MDEV-32353~~ comments for details.

Vladislav Lesin added a comment - 2023-10-13 12:09 See MDEV-32353 comments for details.

People

Assignee:: Vladislav Lesin

Reporter:: Roel Van de Paar

Votes:: 0 Vote for this issue

Watchers:: 5 Start watching this issue

Dates

Created:: 2023-09-28 00:13

Updated:: 2023-10-17 12:01

Resolved:: 2023-10-13 14:04

Git Integration

Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.

MariaDB Server