[MDEV-19384] Deadlock between FTWRL under open HANDLER, LOCK TABLE and DROP DATABASE Created: 2019-05-02  Updated: 2023-12-05

Status: Stalled
Project: MariaDB Server
Component/s: Backup
Affects Version/s: 10.4.5, 10.4, 10.5, 10.6
Fix Version/s: 10.4, 10.5, 10.6

Type: Bug Priority: Major
Reporter: Sergey Vojtovich Assignee: Michael Widenius
Resolution: Unresolved Votes: 0
Labels: regression


 Description   

Regression after https://github.com/MariaDB/server/commit/186635392dd530867dd3f84fca2fe451915e039b

mtr test:

CREATE TABLE t1(a INT);
 
HANDLER t1 OPEN;
 
 
 
connect (con1,localhost,root,,);
 
SET DEBUG_SYNC= 'mdl_acquire_lock_wait SIGNAL ready';
 
--send LOCK TABLE t1 WRITE
 
 
 
connect (con2,localhost,root,,);
 
SET DEBUG_SYNC= 'now WAIT_FOR ready';
 
SET DEBUG_SYNC= 'mdl_acquire_lock_wait SIGNAL ready';
 
--send DROP DATABASE test
 
 
 
connect (con3,localhost,root,,);
 
SET DEBUG_SYNC= 'now WAIT_FOR ready';
 
disconnect con3;
 
 
 
connection default;
 
FLUSH TABLES WITH READ LOCK;
 
UNLOCK TABLES;
 
HANDLER t1 CLOSE;
 
 
 
connection con1;
 
--error 0,ER_NO_SUCH_TABLE
 
reap;
 
UNLOCK TABLES;
 
disconnect con1;
 
 
 
connection con2;
 
reap;
 
disconnect con2;
 
 
 
connection default;
 
SET DEBUG_SYNC= 'RESET';
 
CREATE DATABASE test;

threads are waiting for each other:

thr1: HANDLER test.t1 OPEN; -- acquires TABLE(t1)
 
thr2: LOCK TABLES test.t1 WRITE; -- acquires SCHEMA(test), waits for TABLE(t1)
 
thr3: DROP DATABASE test; -- acquires BACKUP, waits for SCHEMA(test)
 
thr1: FTWRL; -- waits for BACKUP

in gdb:

Thread 29 (Thread 0x7f35752a3700 (LWP 4610)):
 
#0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:225
 
#1  0x00005614d6251341 in safe_cond_timedwait (cond=0x7f3518000cd0, mp=0x7f3518000c20, abstime=0x7f35752a0970, file=0x5614d6388660 "/home/svoj/devel/maria/mariadb/include/mysql/psi/mysql_thread.h", line=1204) at /home/svoj/devel/maria/mariadb/mysys/thr_mutex.c:546
 
#2  0x00005614d58b968c in inline_mysql_cond_timedwait (that=0x7f3518000cd0, mutex=0x7f3518000c20, abstime=0x7f35752a0970, src_file=0x5614d6388cb8 "/home/svoj/devel/maria/mariadb/sql/mdl.cc", src_line=1148)
 
    at /home/svoj/devel/maria/mariadb/include/mysql/psi/mysql_thread.h:1204
 
#3  0x00005614d58baad3 in MDL_wait::timed_wait (this=0x7f3518000c20, owner=0x7f3518000bd0, abs_timeout=0x7f35752a0970, set_status_on_timeout=false, wait_state_name=0x5614d6dc8f18 <MDL_key::m_namespace_to_wait_state_name+24>)
 
    at /home/svoj/devel/maria/mariadb/sql/mdl.cc:1148
 
#4  0x00005614d58bc795 in MDL_context::acquire_lock (this=0x7f3518000c20, mdl_request=0x7f35752a0c30, lock_wait_timeout=86400) at /home/svoj/devel/maria/mariadb/sql/mdl.cc:2326
 
#5  0x00005614d58bcc3b in MDL_context::acquire_locks (this=0x7f3518000c20, mdl_requests=0x7f35752a0a70, lock_wait_timeout=86400) at /home/svoj/devel/maria/mariadb/sql/mdl.cc:2447
 
#6  0x00005614d5babc49 in lock_schema_name (thd=0x7f3518000b00, db=0x7f35180142a8 "test") at /home/svoj/devel/maria/mariadb/sql/lock.cc:872
 
#7  0x00005614d56e344d in mysql_rm_db_internal (thd=0x7f3518000b00, db=0x7f35180056a8, if_exists=false, silent=false) at /home/svoj/devel/maria/mariadb/sql/sql_db.cc:825
 
#8  0x00005614d56e4012 in mysql_rm_db (thd=0x7f3518000b00, db=0x7f35180056a8, if_exists=false) at /home/svoj/devel/maria/mariadb/sql/sql_db.cc:1055
 
#9  0x00005614d5741af3 in mysql_execute_command (thd=0x7f3518000b00) at /home/svoj/devel/maria/mariadb/sql/sql_parse.cc:5313
 
#10 0x00005614d574b706 in mysql_parse (thd=0x7f3518000b00, rawbuf=0x7f3518014218 "DROP DATABASE test", length=18, parser_state=0x7f35752a2000, is_com_multi=false, is_next_command=false) at /home/svoj/devel/maria/mariadb/sql/sql_parse.cc:8149
 
#11 0x00005614d5736b8a in dispatch_command (command=COM_QUERY, thd=0x7f3518000b00, packet=0x7f351800a891 "DROP DATABASE test", packet_length=18, is_com_multi=false, is_next_command=false) at /home/svoj/devel/maria/mariadb/sql/sql_parse.cc:1828
 
#12 0x00005614d573528e in do_command (thd=0x7f3518000b00) at /home/svoj/devel/maria/mariadb/sql/sql_parse.cc:1361
 
#13 0x00005614d58add18 in do_handle_one_connection (connect=0x5614d7f893e0) at /home/svoj/devel/maria/mariadb/sql/sql_connect.cc:1398
 
#14 0x00005614d58ada29 in handle_one_connection (arg=0x5614d7f893e0) at /home/svoj/devel/maria/mariadb/sql/sql_connect.cc:1301
 
#15 0x00005614d5cbf80b in pfs_spawn_thread (arg=0x5614d807c3a0) at /home/svoj/devel/maria/mariadb/storage/perfschema/pfs.cc:1862
 
#16 0x00007f357ddff6ba in start_thread (arg=0x7f35752a3700) at pthread_create.c:333
 
#17 0x00007f357d09041d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109
 
 
 
Thread 28 (Thread 0x7f35752ed700 (LWP 4609)):
 
#0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:225
 
#1  0x00005614d6251341 in safe_cond_timedwait (cond=0x7f3524000cd0, mp=0x7f3524000c20, abstime=0x7f35752eaf00, file=0x5614d6388660 "/home/svoj/devel/maria/mariadb/include/mysql/psi/mysql_thread.h", line=1204) at /home/svoj/devel/maria/mariadb/mysys/thr_mutex.c:546
 
#2  0x00005614d58b968c in inline_mysql_cond_timedwait (that=0x7f3524000cd0, mutex=0x7f3524000c20, abstime=0x7f35752eaf00, src_file=0x5614d6388cb8 "/home/svoj/devel/maria/mariadb/sql/mdl.cc", src_line=1148)
 
    at /home/svoj/devel/maria/mariadb/include/mysql/psi/mysql_thread.h:1204
 
#3  0x00005614d58baad3 in MDL_wait::timed_wait (this=0x7f3524000c20, owner=0x7f3524000bd0, abs_timeout=0x7f35752eaf00, set_status_on_timeout=false, wait_state_name=0x5614d6dc8f30 <MDL_key::m_namespace_to_wait_state_name+48>)
 
    at /home/svoj/devel/maria/mariadb/sql/mdl.cc:1148
 
#4  0x00005614d58bc795 in MDL_context::acquire_lock (this=0x7f3524000c20, mdl_request=0x7f3524014720, lock_wait_timeout=86400) at /home/svoj/devel/maria/mariadb/sql/mdl.cc:2326
 
#5  0x00005614d58bcc3b in MDL_context::acquire_locks (this=0x7f3524000c20, mdl_requests=0x7f35752eb040, lock_wait_timeout=86400) at /home/svoj/devel/maria/mariadb/sql/mdl.cc:2447
 
#6  0x00005614d56a290c in lock_table_names (thd=0x7f3524000b00, options=..., tables_start=0x7f35240142e0, tables_end=0x0, lock_wait_timeout=86400, flags=0) at /home/svoj/devel/maria/mariadb/sql/sql_base.cc:4046
 
#7  0x00005614d56a2e92 in open_tables (thd=0x7f3524000b00, options=..., start=0x7f35752eb3a0, counter=0x7f35752eb3b8, flags=0, prelocking_strategy=0x7f35752eb3c0) at /home/svoj/devel/maria/mariadb/sql/sql_base.cc:4251
 
#8  0x00005614d57310ce in open_tables (thd=0x7f3524000b00, tables=0x7f35752eb3a0, counter=0x7f35752eb3b8, flags=0, prelocking_strategy=0x7f35752eb3c0) at /home/svoj/devel/maria/mariadb/sql/sql_base.h:257
 
#9  0x00005614d5739b8f in lock_tables_open_and_lock_tables (thd=0x7f3524000b00, tables=0x7f35240142e0) at /home/svoj/devel/maria/mariadb/sql/sql_parse.cc:2873
 
#10 0x00005614d574168e in mysql_execute_command (thd=0x7f3524000b00) at /home/svoj/devel/maria/mariadb/sql/sql_parse.cc:5265
 
#11 0x00005614d574b706 in mysql_parse (thd=0x7f3524000b00, rawbuf=0x7f3524014218 "LOCK TABLE t1 WRITE", length=19, parser_state=0x7f35752ec000, is_com_multi=false, is_next_command=false) at /home/svoj/devel/maria/mariadb/sql/sql_parse.cc:8149
 
#12 0x00005614d5736b8a in dispatch_command (command=COM_QUERY, thd=0x7f3524000b00, packet=0x7f352400a891 "LOCK TABLE t1 WRITE", packet_length=19, is_com_multi=false, is_next_command=false) at /home/svoj/devel/maria/mariadb/sql/sql_parse.cc:1828
 
#13 0x00005614d573528e in do_command (thd=0x7f3524000b00) at /home/svoj/devel/maria/mariadb/sql/sql_parse.cc:1361
 
#14 0x00005614d58add18 in do_handle_one_connection (connect=0x5614d7f893e0) at /home/svoj/devel/maria/mariadb/sql/sql_connect.cc:1398
 
#15 0x00005614d58ada29 in handle_one_connection (arg=0x5614d7f893e0) at /home/svoj/devel/maria/mariadb/sql/sql_connect.cc:1301
 
#16 0x00005614d5cbf80b in pfs_spawn_thread (arg=0x5614d807bfd0) at /home/svoj/devel/maria/mariadb/storage/perfschema/pfs.cc:1862
 
#17 0x00007f357ddff6ba in start_thread (arg=0x7f35752ed700) at pthread_create.c:333
 
#18 0x00007f357d09041d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109
 
 
 
Thread 27 (Thread 0x7f3575337700 (LWP 4606)):
 
#0  0x00005614d62571e1 in l_find (head=0x5614d7feb310, cs=0x0, hashnr=0, key=0x7f3575334ff0 "\253\344\213\325\024V", keylen=0, cursor=0x7f3575334fa0, pins=0x5614d7f2d100, callback=0x5614d58b9ab3 <mdl_iterate_lock(MDL_lock*, mdl_iterate_arg*)>)
 
    at /home/svoj/devel/maria/mariadb/mysys/lf_hash.c:153
 
#1  0x00005614d6257d7a in lf_hash_iterate (hash=0x5614d6fb61c0 <mdl_locks>, pins=0x5614d7f2d100, action=0x5614d58b9ab3 <mdl_iterate_lock(MDL_lock*, mdl_iterate_arg*)>, argument=0x7f3575334ff0) at /home/svoj/devel/maria/mariadb/mysys/lf_hash.c:518
 
#2  0x00005614d58b9c97 in mdl_iterate (callback=0x5614d58be4ab <mdl_dbug_print_lock(MDL_ticket*, void*, bool)>, arg=0x7f3575335040) at /home/svoj/devel/maria/mariadb/sql/mdl.cc:740
 
#3  0x00005614d58be628 in mdl_dbug_print_locks () at /home/svoj/devel/maria/mariadb/sql/mdl.cc:3268
 
#4  0x00005614d58bc95d in MDL_context::acquire_lock (this=0x7f3520000c20, mdl_request=0x7f3575335190, lock_wait_timeout=86400) at /home/svoj/devel/maria/mariadb/sql/mdl.cc:2361
 
#5  0x00005614d5bac229 in Global_read_lock::lock_global_read_lock (this=0x7f3520004240, thd=0x7f3520000b00) at /home/svoj/devel/maria/mariadb/sql/lock.cc:1049
 
#6  0x00005614d58ea4b0 in reload_acl_and_cache (thd=0x7f3520000b00, options=16388, tables=0x0, write_to_binlog=0x7f3575335780) at /home/svoj/devel/maria/mariadb/sql/sql_reload.cc:254
 
#7  0x00005614d57439e3 in mysql_execute_command (thd=0x7f3520000b00) at /home/svoj/devel/maria/mariadb/sql/sql_parse.cc:5700
 
#8  0x00005614d574b706 in mysql_parse (thd=0x7f3520000b00, rawbuf=0x7f35200155d8 "FLUSH TABLES WITH READ LOCK", length=27, parser_state=0x7f3575336000, is_com_multi=false, is_next_command=false) at /home/svoj/devel/maria/mariadb/sql/sql_parse.cc:8149
 
#9  0x00005614d5736b8a in dispatch_command (command=COM_QUERY, thd=0x7f3520000b00, packet=0x7f35201a03e1 "FLUSH TABLES WITH READ LOCK", packet_length=27, is_com_multi=false, is_next_command=false) at /home/svoj/devel/maria/mariadb/sql/sql_parse.cc:1828
 
#10 0x00005614d573528e in do_command (thd=0x7f3520000b00) at /home/svoj/devel/maria/mariadb/sql/sql_parse.cc:1361
 
#11 0x00005614d58add18 in do_handle_one_connection (connect=0x5614d7f893e0) at /home/svoj/devel/maria/mariadb/sql/sql_connect.cc:1398
 
#12 0x00005614d58ada29 in handle_one_connection (arg=0x5614d7f893e0) at /home/svoj/devel/maria/mariadb/sql/sql_connect.cc:1301
 
#13 0x00005614d5cbf80b in pfs_spawn_thread (arg=0x5614d807bc00) at /home/svoj/devel/maria/mariadb/storage/perfschema/pfs.cc:1862
 
#14 0x00007f357ddff6ba in start_thread (arg=0x7f3575337700) at pthread_create.c:333
 
#15 0x00007f357d09041d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109



 Comments   
Comment by Michael Widenius [ 2019-05-05 ]

Fixed by reverting the previous fix for handler open in lock_global_read_lock()
Fixed the original (wrong) test case in flush_read_lock.test to be repeatable.

Comment by Julien Fritsch [ 2023-12-05 ]

Automated message:
----------------------------
Since this issue has not been updated since 6 weeks, it's time to move it back to Stalled.

Comment by JiraAutomate [ 2023-12-05 ]

Automated message:
----------------------------
Since this issue has not been updated since 6 weeks, it's time to move it back to Stalled.

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