MySQL Bugs: #49988: MDL deadlocks with mysql_create_db, reload_acl_and

Bug #49988	MDL deadlocks with mysql_create_db, reload_acl_and_cache
Submitted:	30 Dec 2009 9:25	Modified:	7 Mar 2010 1:20
Reporter:	Philip Stoev	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Locking	Severity:	S2 (Serious)
Version:	4.1, 5.0, 5.1, 5.5.99, next-4284	OS:	Any
Assigned to:	Jon Olav Hauglid	CPU Architecture:	Any

Description:
Even after the patch from bug #48940, the next-4284 tree deadlocks with various threads in MDL, and the following outside of MDL:

#3  0x00000000009c4e5c in safe_mutex_lock (mp=0xfb22a0, try_lock=0 '\0', file=0xb42d85 "sql_db.cc", line=646) at thr_mutex.c:149

#4  0x000000000078ba39 in mysql_create_db (thd=0x7fba380c9518, db=0x2188b60 "testdb_N", create_info=0x7fba3f737380, silent=false) at sql_db.cc:646
#5  0x0000000000647ae9 in mysql_execute_command (thd=0x7fba380c9518) at sql_parse.cc:3406
#6  0x000000000064b846 in mysql_parse (thd=0x7fba380c9518, inBuf=0x2188a68 "CREATE SCHEMA IF NOT EXISTS testdb_N DEFAULT CHARACTER SET = utf8", length=65,
    found_semicolon=0x7fba3f738f10) at sql_parse.cc:5587
#7  0x000000000064c496 in dispatch_command (command=COM_QUERY, thd=0x7fba380c9518,
    packet=0x7fba380fec69 "CREATE SCHEMA IF NOT EXISTS testdb_N DEFAULT CHARACTER SET = utf8", packet_length=65) at sql_parse.cc:1011

#8  0x000000000064d967 in do_command (thd=0x7fba380c9518) at sql_parse.cc:695
#9  0x000000000063c275 in handle_one_connection (arg=0x7fba380c9518) at sql_connect.cc:1163
#10 0x000000315b0073da in start_thread () from /lib64/libpthread.so.0
#11 0x000000315a4e627d in clone () from /lib64/libc.so.6

#1  0x00000000009c51ce in safe_cond_wait (cond=0xfb2da0, mp=0xfb2320, file=0xb1bc8d "sql_base.cc", line=1066) at thr_mutex.c:237
#2  0x00000000006985b6 in close_cached_tables (thd=0x7fba380ed468, tables=0x2216c38, have_lock=false, wait_for_refresh=true) at sql_base.cc:1066
#3  0x000000000063ea60 in reload_acl_and_cache (thd=0x7fba380ed468, options=4, tables=0x2216c38, write_to_binlog=0x7fba3f42af1f) at sql_parse.cc:6567
#4  0x00000000006490f7 in mysql_execute_command (thd=0x7fba380ed468) at sql_parse.cc:3764
#5  0x000000000064b846 in mysql_parse (thd=0x7fba380ed468, inBuf=0x2216b28 "FLUSH TABLE testdb_N . t1_base2_N", length=33, found_semicolon=0x7fba3f42bf10)
    at sql_parse.cc:5587
#6  0x000000000064c496 in dispatch_command (command=COM_QUERY, thd=0x7fba380ed468, packet=0x7fba3801b239 "FLUSH TABLE testdb_N . t1_base2_N ",
---Type <return> to continue, or q <return> to quit---
    packet_length=34) at sql_parse.cc:1011
#7  0x000000000064d967 in do_command (thd=0x7fba380ed468) at sql_parse.cc:695
#8  0x000000000063c275 in handle_one_connection (arg=0x7fba380ed468) at sql_connect.cc:1163
#9  0x000000315b0073da in start_thread () from /lib64/libpthread.so.0
#10 0x000000315a4e627d in clone () from /lib64/libc.so.6

How to repeat:
This was observed only once so far. The thread stacks, core and binary will be uploaded.

c:\docs\mysql\bugs\bug49988.stacks

Attachment: bug49988.stacks.txt (text/plain), 30.28 KiB.

Core and binary:

http://mysql-systemqa.s3.amazonaws.com/var-bug49988.zip

source:

revision-id: kostja@sun.com-20091229121905-q27v9932ho9as2ws
date: 2009-12-29 15:19:05 +0300
build-date: 2009-12-29 22:16:46 +0200
revno: 3044
branch-nick: mysql-next-4284

The relevant threads from the thread stacks above seem to be:

Thread 11:
#3  0x00000000009c4e5c in safe_mutex_lock (mp=0xfb22a0, try_lock=0 '\0', file=0xb42d85 "sql_db.cc", line=646) at thr_mutex.c:149
#4  0x000000000078ba39 in mysql_create_db (thd=0x7fba380c9518, db=0x2188b60 "testdb_N", create_info=0x7fba3f737380, silent=false) at sql_db.cc:646
#5  0x0000000000647ae9 in mysql_execute_command (thd=0x7fba380c9518) at sql_parse.cc:3406
#6  0x000000000064b846 in mysql_parse (thd=0x7fba380c9518, inBuf=0x2188a68 "CREATE SCHEMA IF NOT EXISTS testdb_N DEFAULT CHARACTER SET = utf8", length=65,
    found_semicolon=0x7fba3f738f10) at sql_parse.cc:5587
#7  0x000000000064c496 in dispatch_command (command=COM_QUERY, thd=0x7fba380c9518,
    packet=0x7fba380fec69 "CREATE SCHEMA IF NOT EXISTS testdb_N DEFAULT CHARACTER SET = utf8", packet_length=65) at sql_parse.cc:1011

Thread 4:
#1  0x00000000009c5366 in safe_cond_timedwait (cond=0xfc2340, mp=0xfc22c0, abstime=0x7fba3f673370, file=0xb61360 "mdl.cc", line=961) at thr_mutex.c:275
#2  0x00000000008404b8 in MDL_context::acquire_exclusive_locks (this=0x7fba38062608, mdl_requests=0x7fba3f673420) at mdl.cc:961
#3  0x000000000062886b in lock_table_names (thd=0x7fba38062538, table_list=0x23c36a8) at lock.cc:961
#4  0x000000000079c62e in mysql_rm_table_part2 (thd=0x7fba38062538, tables=0x23c36a8, if_exists=true, drop_temporary=false, drop_view=true,
    dont_log_query=true) at sql_table.cc:1898
#5  0x000000000078abc4 in mysql_rm_known_files (thd=0x7fba38062538, dirp=0x2156e08, db=0x23c3698 "testdb_N", org_path=0x7fba3f673d20 "./testdb_N/", level=0,
    dropped_tables=0x7fba3f674048) at sql_db.cc:1166
#6  0x000000000078af9f in mysql_rm_db (thd=0x7fba38062538, db=0x23c3698 "testdb_N", if_exists=false, silent=false) at sql_db.cc:929
#7  0x0000000000647cbd in mysql_execute_command (thd=0x7fba38062538) at sql_parse.cc:3441
#8  0x000000000064b846 in mysql_parse (thd=0x7fba38062538, inBuf=0x23c35f8 "DROP SCHEMA  testdb_N", length=21, found_semicolon=0x7fba3f675f10)
    at sql_parse.cc:5587

Thread 11: Holds a shared-upgradable MDL lock, tries to lock LOCK_mysql_create_db
Thread 4: Holds LOCK_mysql_create_db, tries to get exclusive MDL lock.

MTR test case:

--disable_warnings
DROP DATABASE IF EXISTS db1;
--enable_warnings

connect (con2, localhost, root);

--echo # Connection default
connection default;
CREATE DATABASE db1;
CREATE TABLE db1.t1 (id INT);
LOCK TABLE db1.t1 WRITE;

--echo # Connection con2
connection con2;
--send DROP DATABASE db1

--echo # Connection default
connection default;
--sleep 1
--send CREATE DATABASE IF NOT EXISTS db1

Please re-verify. The MTR test case attached below is repeatable in 5.1.
Our guess is that the bug has been around all along, just masked by more common deadlocks, Bug#48940 in particular.
This is too risky to fix in 5.1. For next-4284 tree the risk/effort is medium/medium.

s/below/above/

Thank you for the report.

Verified as described.

Last string in MTR test case could be without "send" to see problem more clearly.

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/96621

3050 Jon Olav Hauglid	2010-01-12
      Bug #49988 MDL deadlocks with mysql_create_db, reload_acl_and_cache
      
      This was a deadlock between LOCK TABLES/CREATE DATABASE in one connection
      and DROP DATABASE in another. It only happened if the table locked by 
      LOCK TABLES was in the database to be dropped. The deadlock is similar
      to the one in Bug#48940, but with LOCK TABLES instead of an active
      transaction.
      
      The order of events needed to trigger the deadlock was:
      1) Connection 1 locks table db1.t1 using LOCK TABLES. It will now
      have a metadata lock on the table name.
      2) Connection 2 issues DROP DATABASE db1. This will wait inside
      the MDL subsystem for the lock on db1.t1 to go away. While waiting, it
      will hold the LOCK_mysql_create_db mutex.
      3) Connection 1 issues CREATE DATABASE (database name irrelevant).
      This will hang trying to lock the same mutex. Since this is the connection
      holding the metadata lock blocking Connection 2, we have a deadlock.
      
      This deadlock would also happen for earlier trees without MDL, but 
      there DROP DATABASE would wait for a table to be removed from the
      table definition cache.
      
      This patch fixes the problem by prohibiting CREATE DATABASE in LOCK TABLES
      mode. In the example above, this prevents Connection 1 from hanging trying
      to get the LOCK_mysql_create_db mutex. Note that other commands that use
      LOCK_mysql_create_db (ALTER/DROP DATABASE) are already prohibited in 
      LOCK TABLES mode.
      
      Incompatible change: CREATE DATABASE is now disallowed in LOCK TABLES mode.
      
      Test case added to schema.test.
     @ mysql-test/t/drop.test
        Updates the test for Bug#21216 by swapping the order of CREATE DATABASE
        and LOCK TABLES. This is now needed as CREATE DATABASE is prohibited in
        LOCK TABLES mode.
     @ mysql-test/t/schema.test
        Test case for Bug#49988 added.
        Also fixes a problem with the test for Bug#48940 where the result 
        would differ for embedded server.

Pushed to mysql-next-4284 and merged to mysql-6.0-codebase-4284.

Pushed into 6.0.14-alpha (revid:alik@sun.com-20100216101445-2ofzkh48aq2e0e8o) (version source revid:jon.hauglid@sun.com-20100112185035-caoyjze52yh8dp7n) (merge vers: 6.0.14-alpha) (pib:16)

Pushed into mysql-next-mr (revid:alik@sun.com-20100216101208-33qkfwdr0tep3pf2) (version source revid:jon.hauglid@sun.com-20100112151521-lq2d9pb893hz7oru) (pib:16)

Noted in 6.0.14 changelog.

A deadlock occurred for this sequence of events: Thread 1 locked a
table using LOCK TABLES; thread 2 dropped the database containing the
table; thread 1 created any database.

A consequence of this bug fix is that CREATE DATABASE is disallowed
within a thread that has an active LOCK TABLES statement.

Setting report to Need Merge pending push of Celosia to release tree.

Pushed into 5.5.3-m3 (revid:alik@sun.com-20100306103849-hha31z2enhh7jwt3) (version source revid:vvaintroub@mysql.com-20100216221947-luyhph0txl2c5tc8) (merge vers: 5.5.99-m3) (pib:16)

Noted in 5.5.3 changelog.