Bug #38822 Assertion failed in mdl_upgrade_shared_lock_to_exclusive() at mdl.cc:989
Submitted: 15 Aug 2008 14:09 Modified: 20 Feb 2009 11:06
Reporter: Philip Stoev Email Updates:
Status: Can't repeat Impact on me:
None 
Category:MySQL Server: Locking Severity:S3 (Non-critical)
Version:6.0 OS:Any
Assigned to: Philip Stoev CPU Architecture:Any

[15 Aug 2008 14:09] Philip Stoev
Description:
When executing a workload which creates tables, partitions, triggers and procedures, mysqld asserted as follows:

#8  0x003df57e in __assert_fail () from /lib/libc.so.6
#9  0x08492b21 in mdl_upgrade_shared_lock_to_exclusive (context=0xb8fe0cc, lock_data=0xb92fad0) at mdl.cc:989
#10 0x08302752 in wait_while_table_is_used (thd=0xb8fe058, table=0xb944580, function=HA_EXTRA_FORCE_REOPEN) at sql_base.cc:2038
#11 0x0846d34d in mysql_create_or_drop_trigger (thd=0xb8fe058, tables=0xb92f8d0, create=true) at sql_trigger.cc:468
#12 0x082c515e in mysql_execute_command (thd=0xb8fe058) at sql_parse.cc:4475
#13 0x082c63e1 in mysql_parse (thd=0xb8fe058,
    inBuf=0xb92f508 "CREATE TRIGGER h AFTER INSERT ON t7 FOR EACH ROW BEGIN INSERT INTO q ( `int` ) VALUES ( 5 ) , ( 4 ) , ( 6 ) ; END", length=113,
    found_semicolon=0xa7fc2270) at sql_parse.cc:5809
#14 0x082c6e55 in dispatch_command (command=COM_QUERY, thd=0xb8fe058,
    packet=0xb8ffab1 "CREATE TRIGGER h AFTER INSERT ON t7 FOR EACH ROW BEGIN INSERT INTO q ( `int` ) VALUES ( 5 ) , ( 4 ) , ( 6 ) ; END", packet_length=113)
    at sql_parse.cc:1050
#15 0x082c8145 in do_command (thd=0xb8fe058) at sql_parse.cc:723
#16 0x082b5e23 in handle_one_connection (arg=0xb8fe058) at sql_connect.cc:1153
#17 0x0057d32f in start_thread () from /lib/libpthread.so.0
#18 0x0049a27e in clone () from /lib/libc.so.6

The assertion is here:

984         There can be only one upgrader for this lock or we will have deadlock.
985         This invariant is ensured by code outside of metadata subsystem usually
986         by obtaining some sort of exclusive table-level lock (e.g. TL_WRITE,
987         TL_WRITE_ALLOW_READ) before performing upgrade of metadata lock.
988       */
989       DBUG_ASSERT(lock->active_shared_waiting_upgrade.is_empty());
990       lock->active_shared_waiting_upgrade.push_front(lock_data);
991
992       /*
993         Since we should have been already acquired intention exclusive global lock

(gdb) print lock->active_shared_waiting_upgrade.is_empty
$2 = {bool (const I_P_List<MDL_LOCK_DATA, MDL_LOCK_DATA_lock> *)} 0x8493f7e <I_P_List<MDL_LOCK_DATA, MDL_LOCK_DATA_lock>::is_empty() const>
(gdb) print (bool) lock->active_shared_waiting_upgrade.is_empty
$3 = false

How to repeat:
If this is repeatable, a test case will be provided.
[15 Aug 2008 15:52] Philip Stoev
The only thing required to trigger this assertion is concurrently trying to create triggers against the same table.

Here is the test case:

use strict;
use DBI;

my $dbh1 = DBI->connect('dbi:mysql:host=127.0.0.1:port=9306:user=root:database=test');
$dbh1->do("CREATE TABLE IF NOT EXISTS t1 SELECT 1");

fork();
fork();

my $dbh2 = DBI->connect('dbi:mysql:host=127.0.0.1:port=9306:user=root:database=test');

foreach my $i (1..5) {
        $dbh2->do('CREATE TRIGGER tr1 BEFORE INSERT ON t1 FOR EACH ROW BEGIN END')
}
[15 Aug 2008 15:59] MySQL Verification Team
On Windows:

080815 12:55:20 [Note] c:\dbs\6.0\bin\mysqld: ready for connections.
Version: '6.0.7-alpha-nt-debug-log'  socket: ''  port: 3600  Source distribution
Assertion failed: lock->active_shared_waiting_upgrade.is_empty(), file .\mdl.cc, line 990
080815 12:58:10 - mysqld got exception 0x80000003 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help diagnose
the problem, but since we have already crashed, something is definitely wrong
and this may fail.

key_buffer_size=8388572
read_buffer_size=131072
max_used_connections=5
max_threads=151
thread_count=5
connection_count=5
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 337737 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x3707258
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
00B8FED4    mysqld.exe!_NMSG_WRITE()[crt0msg.c:195]
00B7C00A    mysqld.exe!abort()[abort.c:44]
00B76C32    mysqld.exe!_assert()[assert.c:306]
0077D541    mysqld.exe!mdl_upgrade_shared_lock_to_exclusive()[mdl.cc:990]
006007CC    mysqld.exe!wait_while_table_is_used()[sql_base.cc:2041]
00711D73    mysqld.exe!mysql_create_or_drop_trigger()[sql_trigger.cc:468]
006646B6    mysqld.exe!mysql_execute_command()[sql_parse.cc:4502]
006680BD    mysqld.exe!mysql_parse()[sql_parse.cc:5845]
0065D3D5    mysqld.exe!dispatch_command()[sql_parse.cc:1120]
0065CC0D    mysqld.exe!do_command()[sql_parse.cc:807]
0076CBE7    mysqld.exe!handle_one_connection()[sql_connect.cc:1153]
008497CD    mysqld.exe!pthread_start()[my_winthread.c:86]
00B7F607    mysqld.exe!_threadstart()[thread.c:196]
7C80B713    kernel32.dll!GetModuleFileNameA()
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0371A2C8=CREATE TRIGGER tr1 BEFORE INSERT ON t1 FOR EACH ROW BEGIN END
thd->thread_id=4
thd->killed=NOT_KILLED
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
[15 Aug 2008 16:10] MySQL Verification Team
Thank you for the bug report, verified as described.
[7 Oct 2008 12:06] Jørgen Austvik
Also seen with ALTER TABLE ADD COLUMN:

#6  0x0000003e8ba29756 in __assert_fail () from /lib64/libc.so.6
#7  0x00000000007ce17f in mdl_upgrade_shared_lock_to_exclusive (context=0x11988408, lock_data=0x119e3020) at mdl.cc:994
#8  0x0000000000676b92 in wait_while_table_is_used (thd=0x11988330, table=0x11a23280, function=<value optimized out>) at sql_base.cc:2041
#9  0x0000000000746958 in mysql_alter_table (thd=0x11988330, new_db=0x119e3018 "test", new_name=0x119e2c78 "t1", create_info=0x474e3d50, 
    table_list=0x119e2cb0, alter_info=0x474e4670, order_num=0, order=0x0, ignore=false) at sql_table.cc:7013
#10 0x0000000000640d83 in mysql_execute_command (thd=0x11988330) at sql_parse.cc:2572
#11 0x0000000000641930 in mysql_parse (thd=0x11988330, inBuf=0x119e2938 "ALTER TABLE t1 ADD COLUMN c_44 CHAR(200) DEFAULT \"New column\"", 
    length=61, found_semicolon=0x474e5028) at sql_parse.cc:5491
#12 0x0000000000642783 in dispatch_command (command=COM_QUERY, thd=0x11988330, packet=<value optimized out>, packet_length=61)
    at sql_parse.cc:987
#13 0x00000000006436b7 in do_command (thd=0x11988330) at sql_parse.cc:674
#14 0x00000000006354ea in handle_one_connection (arg=<value optimized out>) at sql_connect.cc:1153
#15 0x0000003e8c6062e7 in start_thread () from /lib64/libpthread.so.0

(This is in a new (under development) stress test with concurrent DDL and DML statements)
[19 Feb 2009 13:41] Dmitry Lenev
Hello Philip, Miguel!

I wasn't able to repeat this bug on my system using recent server version (6.0.10-bzr). Could you please check if it is still repeatable for you?
[19 Feb 2009 13:42] Dmitry Lenev
Also quick code inspection hasn't shown anything suspicious.
[20 Feb 2009 11:06] Philip Stoev
This bug is no longer repeatable.