Bug #54117 crash in thr_multi_unlock, temporary table
Submitted: 31 May 2010 20:00 Modified: 14 Oct 2010 15:36
Reporter: Matthias Leich Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Locking Severity:S3 (Non-critical)
Version:5.6.99-m4-debug,5.5.5-m3-debug-log,5.1.48-debug OS:Any
Assigned to: Jon Olav Hauglid CPU Architecture:Any
Tags: locking

[31 May 2010 20:00] Matthias Leich
Description:
The crash happens in mysys/thr_lock.c line 1161:
    if ((*pos)->type != TL_UNLOCK)
      thr_unlock(*pos);
    else
    {
-->    DBUG_PRINT("lock",("Free lock: data: 0x%lx  thread: 0x%lx  lock: 0x%lx",
                         (long) *pos, (*pos)->owner->info->thread_id,
                         (long) (*pos)->lock));
    }

RQG test with
- 64 threads
- derivate of the WL5005_* grammars

Result on 5.6.99-m4-debug
mysql-next-mr revno: 3153 2010-05-31
------------------------------------
Thread 1 (process 16203):
#0  0x00007f049f11cce6 in pthread_kill () from /lib64/libpthread.so.0
#1  0x00000000009fb6a1 in my_write_core (sig=11)
                       at .../mysys/stacktrace.c:326
#2  0x000000000053cbf6 in handle_segfault (sig=11)
                       at .../sql/mysqld.cc:2787
#3  <signal handler called>
#4  0x0000000000a03ab1 in thr_multi_unlock (data=0x7f0490012fa0, count=1)
                       at .../mysys/thr_lock.c:1161
#5  0x00000000007d9ccb in mysql_unlock_tables (thd=0x24ae0d8, sql_lock=0x7f0490012f88)
                       at .../sql/lock.cc:384
#6  0x00000000005832dc in close_thread_tables (thd=0x24ae0d8)
                       at .../sql/sql_base.cc:1540
#7  0x00000000005835a1 in Locked_tables_list::unlock_locked_tables (this=0x24af938, thd=0x24ae0d8)
                       at .../sql/sql_base.cc:3208
#8  0x00000000005cf900 in mysql_execute_command (thd=0x24ae0d8)
                       at .../sql/sql_parse.cc:3507
#9  0x00000000005d385e in mysql_parse (thd=0x24ae0d8, inBuf=0x236ad98 "LOCK TABLES testdb_S . t1_view2_N  AS m READ LOCAL", length=50, parser_state=0x4786b9b0)
                       at .../sql/sql_parse.cc:5816
#10 0x00000000005d445d in dispatch_command (command=COM_QUERY, thd=0x24ae0d8, packet=0x24d9e09 "LOCK TABLES testdb_S . t1_view2_N  AS m READ LOCAL", packet_length=50)
                       at .../sql/sql_parse.cc:1085
#11 0x00000000005d5985 in do_command (thd=0x24ae0d8)
                       at .../sql/sql_parse.cc:771
#12 0x00000000006a0df0 in do_handle_one_connection (thd_arg=0x24ae0d8)
                       at .../sql/sql_connect.cc:1195
#13 0x00000000006a0eb5 in handle_one_connection (arg=0x24ae0d8)
                       at .../sql_connect.cc:1134
#14 0x00007f049f118040 in start_thread () from /lib64/libpthread.so.0
#15 0x00007f049e3d508d in clone () from /lib64/libc.so.6
#16 0x0000000000000000 in ?? ()
Waiting for mysqld with pid 16059 to terminate...

How to repeat:
I will try to come up with simplified grammars soon.
[2 Jun 2010 9:56] Matthias Leich
Archive with grammars and protocol of RQG run

Attachment: 54117.tgz (application/x-compressed-tar, text), 111.92 KiB.

[15 Jun 2010 11:15] Matthias Leich
Simplified test:
----------------
--source include/have_innodb.inc

let $engine= InnoDB;
SELECT VERSION();
eval CREATE TEMPORARY TABLE t1 ENGINE = $engine SELECT 1 col1;
eval ALTER TABLE t1 ENGINE = $engine;
LOCK TABLES t1 AS y READ;
eval ALTER TABLE t1 ENGINE = $engine;
LOCK TABLES t1 AS u READ;

Result on 5.5.5-m3-debug-log
mysql-trunk revno: 3026 2010-05-24
----------------------------------
...
mysqltest: At line 9: query 'LOCK TABLES t1 AS u READ' failed: 2013: Lost connection to MySQL server during query
...
Thread 1 (process 15191):
#0  0x00007f8ef3c3ace6 in pthread_kill () from /lib64/libpthread.so.0
#1  0x00000000009fa7d9 in my_write_core (sig=11) at .../mysys/stacktrace.c:326
#2  0x000000000053cb66 in handle_segfault (sig=11) at .../sql/mysqld.cc:2787
#3  <signal handler called>
#4  0x0000000000a0141a in thr_unlock (data=0x193c630) at .../mysys/thr_lock.c:843
#5  0x0000000000a0214f in thr_multi_unlock (data=0x193cb30, count=1) at .../mysys/thr_lock.c:1158
#6  0x00000000007d8d67 in mysql_unlock_tables (thd=0x1877738, sql_lock=0x193cb18) at .../sql/lock.cc:384
#7  0x0000000000582cfe in close_thread_tables (thd=0x1877738) at .../sql/sql_base.cc:1540
#8  0x0000000000582fc3 in Locked_tables_list::unlock_locked_tables (this=0x1878f98, thd=0x1877738) at .../sql/sql_base.cc:3208
#9  0x00000000005cefe8 in mysql_execute_command (thd=0x1877738) at .../sql/sql_parse.cc:3507
#10 0x00000000005d2f46 in mysql_parse (thd=0x1877738, inBuf=0x1906658 "LOCK TABLES t1 AS u READ", length=24, parser_state=0x41786960) at .../sql/sql_parse.cc:5816
#11 0x00000000005d3b45 in dispatch_command (command=COM_QUERY, thd=0x1877738, packet=0x18fa7f9 "LOCK TABLES t1 AS u READ", packet_length=24) at .../sql/sql_parse.cc:1085
#12 0x00000000005d506d in do_command (thd=0x1877738) at .../sql/sql_parse.cc:771
#13 0x00000000006a0260 in do_handle_one_connection (thd_arg=0x1877738) at .../sql/sql_connect.cc:1195
#14 0x00000000006a0325 in handle_one_connection (arg=0x1877738) at .../sql/sql_connect.cc:1134
#15 0x0000000000944ed3 in pfs_spawn_thread (arg=0x1947ce8) at .../storage/perfschema/pfs.cc:1011
#16 0x00007f8ef3c36040 in start_thread () from /lib64/libpthread.so.0
#17 0x00007f8ef2ef308d in clone () from /lib64/libc.so.6
#18 0x0000000000000000 in ?? ()

- mysql-trunk-runtime revno: 3055 2010-06-12
  show the same crash
- The crash disappears in case I use MyISAM or MEMORY for $engine

For mysql-trunk: The crash happens in mysys/thr_lock.c line 843
void thr_unlock(THR_LOCK_DATA *data)
{
  THR_LOCK *lock=data->lock;
  enum thr_lock_type lock_type=data->type;
  DBUG_ENTER("thr_unlock");
  DBUG_PRINT("lock",("data: 0x%lx  thread: 0x%lx  lock: 0x%lx",  <---------
                     (long) data, data->owner->info->thread_id, (long) lock));
  mysql_mutex_lock(&lock->mutex);
  check_locks(lock,"start of release lock",0);
[22 Jun 2010 13:20] Jon Olav Hauglid
This crash is also repeatable in 5.1 with the test case given above.
Tagging for re-triage.
[22 Jun 2010 13:56] Bugs System
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/111782

3438 Jon Olav Hauglid	2010-06-22
      Bug #54117 crash in thr_multi_unlock, temporary table
      
      This crash occured after ALTER TABLE was used on a temporary
      transactional table locked by LOCK TABLES. Any later attempts to
      execute LOCK/UNLOCK TABLES, caused the server to crash.
      
      The reason for the crash was the list of locked tables would
      end up having a pointer to a free'd table instance. This happened
      because ALTER TABLE deleted the table without also removing the
      table reference from the locked tables list.
      
      This patch fixes the problem by making sure ALTER TABLE also
      removes the table from the locked tables list.
      
      Test case added to innodb_mysql.test.
[7 Jul 2010 14:37] Jon Olav Hauglid
Pushed to mysql-5.1-security (5.1.50) and merged to mysql-trunk-security.
[23 Jul 2010 12:21] Bugs System
Pushed into mysql-trunk 5.5.6-m3 (revid:alik@sun.com-20100723121820-jryu2fuw3pc53q9w) (version source revid:alik@sun.com-20100723121820-jryu2fuw3pc53q9w) (merge vers: 5.5.6-m3) (pib:18)
[23 Jul 2010 12:29] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100723121929-90e9zemk3jkr2ocy) (version source revid:alik@sun.com-20100723121827-3bsh51m5sj6g4oma) (pib:18)
[26 Jul 2010 23:50] Paul DuBois
Noted in 5.5.6 changelog.

After ALTER TABLE was used on a temporary transactional table locked
by LOCK TABLES, any later attempts to execute LOCK TABLES or UNLOCK
TABLES caused a server crash.

Setting report to Need Merge pending push to 5.1.x.
[19 Aug 2010 15:40] Bugs System
Pushed into mysql-5.1 5.1.51 (revid:build@mysql.com-20100819151858-muaaor6jojb5ouzj) (version source revid:build@mysql.com-20100819151858-muaaor6jojb5ouzj) (merge vers: 5.1.51) (pib:20)
[24 Sep 2010 16:40] Paul DuBois
Noted in 5.1.51 changelog.
[14 Oct 2010 8:26] Bugs System
Pushed into mysql-5.1-telco-7.0 5.1.51-ndb-7.0.20 (revid:martin.skold@mysql.com-20101014082627-jrmy9xbfbtrebw3c) (version source revid:martin.skold@mysql.com-20101014082627-jrmy9xbfbtrebw3c) (merge vers: 5.1.51-ndb-7.0.20) (pib:21)
[14 Oct 2010 8:41] Bugs System
Pushed into mysql-5.1-telco-6.3 5.1.51-ndb-6.3.39 (revid:martin.skold@mysql.com-20101014083757-5qo48b86d69zjvzj) (version source revid:martin.skold@mysql.com-20101014083757-5qo48b86d69zjvzj) (merge vers: 5.1.51-ndb-6.3.39) (pib:21)
[14 Oct 2010 8:56] Bugs System
Pushed into mysql-5.1-telco-6.2 5.1.51-ndb-6.2.19 (revid:martin.skold@mysql.com-20101014084420-y54ecj85j5we27oa) (version source revid:martin.skold@mysql.com-20101014084420-y54ecj85j5we27oa) (merge vers: 5.1.51-ndb-6.2.19) (pib:21)
[14 Oct 2010 15:36] Jon Stephens
Already documented in the 5.1.51 changelog; no new changelog entries required. Setting back to Closed state.