[MDEV-22442] Assertion `(lock_sys.mutex.is_owned())' failed upon killing query with WSREP enabled Created: 2020-05-03  Updated: 2022-01-18  Resolved: 2022-01-18

Status: Closed
Project: MariaDB Server
Component/s: Galera, Storage Engine - InnoDB, wsrep
Affects Version/s: 10.4, 10.5
Fix Version/s: 10.4.22, 10.5.13

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Jan Lindström (Inactive)
Resolution: Duplicate Votes: 0
Labels: None


 Description   

Note: The test case is non-deterministic and has a loop inside. Don't put it into the regression suite, create a properly synchronized one instead. On 10.5 with a rotating disk, it fails for me on the first iteration; but it takes several cycles on 10.4 and/or in shm, that's why the loop is there.

Put into galera suite, no extra options are needed

--source include/galera_cluster.inc
CREATE DATABASE db;
 
--let $run= 100
while ($run)
{
    --connect (con1,localhost,root,,test)
    DROP TABLE IF EXISTS db.t;
    --connection default
    --send
      CREATE DATABASE IF NOT EXISTS db;
 
    --connection con1
    CREATE TABLE db.t SELECT * FROM INFORMATION_SCHEMA.COLLATIONS LIMIT 0;
 
    --connection default
    --reap
 
    --connection con1
    --error ER_CONNECTION_KILLED,2013
    KILL CONNECTION_ID();
    --disconnect con1
    --dec $run
}
 
# Cleanup
--connection default
DROP DATABASE db;

Test case 2, same idea but with KILL QUERY instead of connection

--source include/galera_cluster.inc
CREATE DATABASE db;
--connect (con1,localhost,root,,test)
 
--let $run= 100
while ($run)
{
    DROP TABLE IF EXISTS db.t;
    --connection default
    --send
      CREATE DATABASE IF NOT EXISTS db;
 
    --connection con1
    CREATE TABLE db.t SELECT * FROM INFORMATION_SCHEMA.COLLATIONS LIMIT 0;
 
    --connection default
    --reap
 
    --connection con1
    --error ER_QUERY_INTERRUPTED,2013
    KILL QUERY CONNECTION_ID();
    --dec $run
}
 
# Cleanup
--connection default
DROP DATABASE db;

10.4 7f03a933

mysqld: /data/src/10.4/storage/innobase/lock/lock0lock.cc:6233: dberr_t lock_trx_handle_wait_low(trx_t*): Assertion `(lock_sys.mutex.is_owned())' failed.
200504  2:44:50 [ERROR] mysqld got signal 6 ;
 
#7  0x00007f7828cd2f12 in __GI___assert_fail (assertion=0x557e6492a314 "(lock_sys.mutex.is_owned())", file=0x557e6492a778 "/data/src/10.4/storage/innobase/lock/lock0lock.cc", line=6233, function=0x557e64931960 <lock_trx_handle_wait_low(trx_t*)::__PRETTY_FUNCTION__> "dberr_t lock_trx_handle_wait_low(trx_t*)") at assert.c:101
#8  0x0000557e64051ee2 in lock_trx_handle_wait_low (trx=0x7f7806897268) at /data/src/10.4/storage/innobase/lock/lock0lock.cc:6233
#9  0x0000557e64051fca in lock_trx_handle_wait (trx=0x7f7806897268) at /data/src/10.4/storage/innobase/lock/lock0lock.cc:6261
#10 0x0000557e63f957db in innobase_kill_query (thd=0x7f77b4001d40) at /data/src/10.4/storage/innobase/handler/ha_innodb.cc:5123
#11 0x0000557e63d4f198 in kill_handlerton (thd=0x7f77b4001d40, plugin=0x7f77b40639f0, level=0x7f7805d66994) at /data/src/10.4/sql/handler.cc:847
#12 0x0000557e63a1576b in plugin_foreach_with_mask (thd=0x7f77b4001d40, func=0x557e63d4f11a <kill_handlerton(THD*, plugin_ref, void*)>, type=1, state_mask=8, arg=0x7f7805d66994) at /data/src/10.4/sql/sql_plugin.cc:2438
#13 0x0000557e63d4f1f2 in ha_kill_query (thd=0x7f77b4001d40, level=THD_ABORT_ASAP) at /data/src/10.4/sql/handler.cc:854
#14 0x0000557e63982852 in THD::awake_no_mutex (this=0x7f77b4001d40, state_to_set=KILL_CONNECTION_HARD) at /data/src/10.4/sql/sql_class.cc:1902
#15 0x0000557e63a09398 in kill_one_thread (thd=0x7f77b4001d40, id=18, kill_signal=KILL_CONNECTION_HARD, type=KILL_TYPE_ID) at /data/src/10.4/sql/sql_parse.cc:9083
#16 0x0000557e63a098c9 in sql_kill (thd=0x7f77b4001d40, id=18, state=KILL_CONNECTION_HARD, type=KILL_TYPE_ID) at /data/src/10.4/sql/sql_parse.cc:9202
#17 0x0000557e639ff093 in mysql_execute_command (thd=0x7f77b4001d40) at /data/src/10.4/sql/sql_parse.cc:5531
#18 0x0000557e63a06923 in mysql_parse (thd=0x7f77b4001d40, rawbuf=0x7f77b4013028 "KILL CONNECTION_ID()", length=20, parser_state=0x7f7805d67570, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:7900
#19 0x0000557e63a06023 in wsrep_mysql_parse (thd=0x7f77b4001d40, rawbuf=0x7f77b4013028 "KILL CONNECTION_ID()", length=20, parser_state=0x7f7805d67570, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:7704
#20 0x0000557e639f2dcd in dispatch_command (command=COM_QUERY, thd=0x7f77b4001d40, packet=0x7f77b40095f1 "KILL CONNECTION_ID()", packet_length=20, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1827
#21 0x0000557e639f1675 in do_command (thd=0x7f77b4001d40) at /data/src/10.4/sql/sql_parse.cc:1360
#22 0x0000557e63b7912e in do_handle_one_connection (connect=0x557e67009b80) at /data/src/10.4/sql/sql_connect.cc:1412
#23 0x0000557e63b78e7d in handle_one_connection (arg=0x557e67009b80) at /data/src/10.4/sql/sql_connect.cc:1316
#24 0x0000557e64578b55 in pfs_spawn_thread (arg=0x557e670ba1f0) at /data/src/10.4/storage/perfschema/pfs.cc:1869
#25 0x00007f782ac5b4a4 in start_thread (arg=0x7f7805d68700) at pthread_create.c:456
#26 0x00007f7828d8fd0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Reproducible on 10.4, 10.5 debug builds.
Couldn't reproduce on 10.3.
No obvious effect on a non-debug build.
Not reproducible without wsrep_on.



 Comments   
Comment by Elena Stepanova [ 2022-01-15 ]

jplindst,

It is closed as fixed, but there are no linked commits, no comments and no linked issues which could be interpreted as duplicates.
Can you clarify?

Comment by Jan Lindström (Inactive) [ 2022-01-18 ]

MDEV-25114

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