Bug #38231 Innodb crash in lock_reset_all_on_table() on TRUNCATE + LOCK / UNLOCK
Submitted: 18 Jul 2008 19:15 Modified: 18 Jun 2010 22:56
Reporter: Philip Stoev Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S1 (Critical)
Version:5.0.22, 5.0.42, 5.0.66a, 5.1.23, 5.1.28, 6.0.5 OS:Any
Assigned to: Vasil Dimov CPU Architecture:Any

[18 Jul 2008 19:15] Philip Stoev
Description:
When executing a concurrent workload involving simple queries and TRUNCATE TABLE, innodb crashed as follows:

#0  0x00110416 in __kernel_vsyscall ()
#1  0x00581c78 in pthread_kill () from /lib/libpthread.so.0
#2  0x085786bb in my_write_core (sig=6) at stacktrace.c:310
#3  0x08245c05 in handle_segfault (sig=6) at mysqld.cc:2507
#4  <signal handler called>
#5  0x00110416 in __kernel_vsyscall ()
#6  0x003e6660 in raise () from /lib/libc.so.6
#7  0x003e8028 in abort () from /lib/libc.so.6
#8  0x08484dd6 in lock_reset_all_on_table (table=0xb73be868) at lock/lock0lock.c:3976
#9  0x084abe8b in row_truncate_table_for_mysql (table=0xb73be868, trx=0x9179e00) at row/row0mysql.c:2784
#10 0x0844d9e0 in ha_innobase::delete_all_rows (this=0x922a818) at handler/ha_innodb.cc:5222
#11 0x08366a29 in handler::ha_delete_all_rows (this=0x922a818) at handler.cc:3004
#12 0x082f7b6f in mysql_delete (thd=0x912d8d0, table_list=0x9183560, conds=0x0, order=0x0, limit=18446744073709551615, options=0, reset_auto_increment=true)
    at sql_delete.cc:136
#13 0x082f9108 in mysql_truncate (thd=0x912d8d0, table_list=0x9183560, dont_send_ok=false) at sql_delete.cc:1063
#14 0x08259b35 in mysql_execute_command (thd=0x912d8d0) at sql_parse.cc:3063
#15 0x0825f8c2 in mysql_parse (thd=0x912d8d0, inBuf=0x91834c8 "TRUNCATE TABLE A", length=16, found_semicolon=0xb2a0425c) at sql_parse.cc:5645
#16 0x08260499 in dispatch_command (command=COM_QUERY, thd=0x912d8d0, packet=0x912f259 "TRUNCATE TABLE A", packet_length=16) at sql_parse.cc:1137
#17 0x082615f8 in do_command (thd=0x912d8d0) at sql_parse.cc:794
#18 0x0824ed76 in handle_one_connection (arg=0x912d8d0) at sql_connect.cc:1115
#19 0x0057d32f in start_thread () from /lib/libpthread.so.0
#20 0x0049a27e in clone () from /lib/libc.so.6

The crash is here:

(gdb) list
3971            mutex_enter(&kernel_mutex);
3972
3973            lock = UT_LIST_GET_FIRST(table->locks);
3974
3975            while (lock) {
3976                    ut_a(!lock_get_wait(lock)); <<<<<<<
3977
3978                    lock_reset_all_on_table_for_trx(table, lock->trx);
3979
3980                    lock = UT_LIST_GET_FIRST(table->locks);

Maybe the compiler inlined lock_get_wait ?

How to repeat:
If this happens again, a simplifed test case will be provided.
[18 Jul 2008 19:38] Philip Stoev
Test case below. Crash should happen within 10 seconds with 8 threads involved, 110 queries total. 

use strict;
use DBI;

my $dsn = 'dbi:mysql:host=127.0.0.1:port=9306:user=root:database=test';

my @queries = (
        'START TRANSACTION',
        'COMMIT',
        'LOCK TABLE t1 WRITE ; UNLOCK TABLES',
        'TRUNCATE TABLE t1'
);

fork();
fork();

my $dbh = DBI->connect($dsn, undef, undef, { mysql_multi_statements => 1 , RaiseError => 1} );
$dbh->do("SET AUTOCOMMIT=OFF");
$dbh->do("SET SQL_MODE='NO_ENGINE_SUBSTITUTION'");
$dbh->do("CREATE TABLE IF NOT EXISTS t1 (f1 integer) Engine = Innodb");

while (1) {
        my $query = $queries[int(rand($#queries+1))];
        my $sth = $dbh->prepare($query);
        $sth->execute();
}
[19 Jul 2008 9:18] Valeriy Kravchuk
Thank you for a problem report. What exact 5.1.x version (current from bzr?), gcc version and configure command line you had used?
[19 Jul 2008 13:52] Philip Stoev
I just cloned a fresh mysql-5.1 bzr copy and compiled with ./BUILD/compile-pentium-debug-max and still got the crash.

>C compiler:    gcc (GCC) 4.3.0 20080428 (Red Hat 4.3.0-8)
>C++ compiler:  gcc (GCC) 4.3.0 20080428 (Red Hat 4.3.0-8)
>Environment:
        <machine, os, target, libraries (multiple lines)>
System: Linux fedora9.stoev.org 2.6.25.3-18.fc9.i686 #1 SMP Tue May 13 05:38:53 EDT 2008 i686 i686 i386 GNU/Linux
Architecture: i686

Some paths:  /usr/bin/perl /usr/bin/make /usr/bin/gmake /usr/lib/ccache/gcc /usr/lib/ccache/cc
GCC: Using built-in specs.
Target: i386-redhat-linux
Configured with: ../configure --prefix=/usr --mandir=/usr/share/man --infodir=/usr/share/info --with-bugurl=http://bugzilla.redhat.com/bugzilla --enable-bootstrap --enable-shared --enable-threads=posix --enable-checking=release --with-system-zlib --enable-__cxa_atexit --disable-libunwind-exceptions --enable-languages=c,c++,objc,obj-c++,java,fortran,ada --enable-java-awt=gtk --disable-dssi --enable-plugin --with-java-home=/usr/lib/jvm/java-1.5.0-gcj-1.5.0.0/jre --enable-libgcj-multifile --enable-java-maintainer-mode --with-ecj-jar=/usr/share/java/eclipse-ecj.jar --disable-libjava-multilib --with-cpu=generic --build=i386-redhat-linux
Thread model: posix
gcc version 4.3.0 20080428 (Red Hat 4.3.0-8) (GCC)
Compilation info (call): CC='ccache gcc'  CFLAGS='-Wimplicit -Wreturn-type -Wswitch -Wtrigraphs -Wcomment -W -Wchar-subscripts -Wformat -Wparentheses -Wsign-compare -Wwrite-strings -Wunused-function -Wunused-label -Wunused-value -Wunused-variable -Wunused-parameter -mtune=native -DUNIV_MUST_NOT_INLINE -DEXTRA_DEBUG -DFORCE_INIT_OF_VARS  -DSAFEMALLOC -DPEDANTIC_SAFEMALLOC -DSAFE_MUTEX'  CXX='ccache gcc'  CXXFLAGS='-Wimplicit -Wreturn-type -Wswitch -Wtrigraphs -Wcomment -W -Wchar-subscripts -Wformat -Wparentheses -Wsign-compare -Wwrite-strings -Wunused-function -Wunused-label -Wunused-value -Wunused-variable -Wreorder -Wctor-dtor-privacy -Wnon-virtual-dtor -felide-constructors -fno-exceptions -fno-rtti -mtune=native -DUNIV_MUST_NOT_INLINE -DEXTRA_DEBUG -DFORCE_INIT_OF_VARS  -DSAFEMALLOC -DPEDANTIC_SAFEMALLOC -DSAFE_MUTEX'  LDFLAGS=''  ASFLAGS=''
Compilation info (used): CC='ccache gcc'  CFLAGS='-g -DSAFE_MUTEX -DSAFEMALLOC -Wimplicit -Wreturn-type -Wswitch -Wtrigraphs -Wcomment -W -Wchar-subscripts -Wformat -Wparentheses -Wsign-compare -Wwrite-strings -Wunused-function -Wunused-label -Wunused-value -Wunused-variable -Wunused-parameter -mtune=native -DUNIV_MUST_NOT_INLINE -DEXTRA_DEBUG -DFORCE_INIT_OF_VARS  -DSAFEMALLOC -DPEDANTIC_SAFEMALLOC -DSAFE_MUTEX   -DUNIV_LINUX'  CXX='ccache gcc'  CXXFLAGS='-g -DSAFE_MUTEX -DSAFEMALLOC -Wimplicit -Wreturn-type -Wswitch -Wtrigraphs -Wcomment -W -Wchar-subscripts -Wformat -Wparentheses -Wsign-compare -Wwrite-strings -Wunused-function -Wunused-label -Wunused-value -Wunused-variable -Wreorder -Wctor-dtor-privacy -Wnon-virtual-dtor -felide-constructors -fno-exceptions -fno-rtti -mtune=native -DUNIV_MUST_NOT_INLINE -DEXTRA_DEBUG -DFORCE_INIT_OF_VARS  -DSAFEMALLOC -DPEDANTIC_SAFEMALLOC -DSAFE_MUTEX   -fno-implicit-templates -fno-exceptions -fno-rtti'  LDFLAGS=' -rdynamic '  ASFLAGS=''
LIBC:
lrwxrwxrwx 1 root root 11 2008-05-24 22:10 /lib/libc.so.6 -> libc-2.8.so
-rwxr-xr-x 1 root root 1758468 2008-05-05 15:56 /lib/libc-2.8.so
-rw-r--r-- 1 root root 3105764 2008-05-05 15:34 /usr/lib/libc.a
-rw-r--r-- 1 root root 238 2008-05-05 15:18 /usr/lib/libc.so
Configure command: ./configure  '--prefix=/usr/local/mysql' '--enable-assembler' '--with-extra-charsets=complex' '--enable-thread-safe-client' '--with-big-tables' '--with-readline' '--with-debug=full' '--with-ssl' '--with-plugins=max-no-ndb' '--with-embedded-server' '--enable-local-infile' 'CC=ccache gcc' 'CFLAGS=-Wimplicit -Wreturn-type -Wswitch -Wtrigraphs -Wcomment -W -Wchar-subscripts -Wformat -Wparentheses -Wsign-compare -Wwrite-strings -Wunused-function -Wunused-label -Wunused-value -Wunused-variable -Wunused-parameter -mtune=native -DUNIV_MUST_NOT_INLINE -DEXTRA_DEBUG -DFORCE_INIT_OF_VARS  -DSAFEMALLOC -DPEDANTIC_SAFEMALLOC -DSAFE_MUTEX' 'CXX=ccache gcc' 'CXXFLAGS=-Wimplicit -Wreturn-type -Wswitch -Wtrigraphs -Wcomment -W -Wchar-subscripts -Wformat -Wparentheses -Wsign-compare -Wwrite-strings -Wunused-function -Wunused-label -Wunused-value -Wunused-variable -Wreorder -Wctor-dtor-privacy -Wnon-virtual-dtor -felide-constructors -fno-exceptions -fno-rtti -mtune=native -DUNIV_MUST_NOT_INLINE -DEXTRA_DEBUG -DFORCE_INIT_OF_VARS  -DSAFEMALLOC -DPEDANTIC_SAFEMALLOC -DSAFE_MUTEX'
[22 Jul 2008 11:39] Valeriy Kravchuk
Verified just as described with recent 5.1.28 from bzr. Crashed on "TRUNCATE TABLE t1".
[29 Jul 2008 8:01] MySQL Verification Team
5.0.66a also crashed.   

5.1.23-debug crashed like this:
080729  9:56:40  InnoDB: Assertion failure in thread 1892 in file .\lock\lock0lock.c line 3976
InnoDB: Failing assertion: !lock_get_wait(lock)
InnoDB: We intentionally generate a memory trap.

mysqld.exe!lock_reset_all_on_table
mysqld.exe!row_truncate_table_for_mysql
mysqld.exe!ha_innobase::delete_all_rows
mysqld.exe!mysql_delete
mysqld.exe!mysql_truncate
mysqld.exe!mysql_execute_command
mysqld.exe!mysql_parse
mysqld.exe!dispatch_command
mysqld.exe!do_command
mysqld.exe!handle_one_connection
mysqld.exe!pthread_start
mysqld.exe!_callthreadstart

it's enough to run the following in a few threads:

set autocommit=off;
lock table t1 write ; unlock tables;
truncate table t1;
[29 Jul 2008 8:11] MySQL Verification Team
6.0.5 crashed after hanging for a while.
[10 Sep 2008 19:57] Omer Barnir
triage: Updating tag from CHECKED to SR51MRU and increasing priority tpo P2 based on applying MRU criteria "GA Qualifying D1/D2, W1/W2/W3, I1/I2/I3, (R1/R2, E1/E2)"
[12 Mar 2009 21:31] Paul DuBois
Noted in 5.1.31, 6.0.10 changelogs.

A mix of TRUNCATE TABLE with LOCK TABLES and UNLOCK TABLES for an
InnoDB could cause a server crash.
[5 May 2010 15:04] Bugs System
Pushed into 5.1.47 (revid:joro@sun.com-20100505145753-ivlt4hclbrjy8eye) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[6 May 2010 15:53] Paul DuBois
Push resulted from incorporation of InnoDB tree. No changes pertinent to this bug.
Re-closing.
[28 May 2010 5:53] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100524190136-egaq7e8zgkwb9aqi) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (pib:16)
[28 May 2010 6:22] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20100524190941-nuudpx60if25wsvx) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[28 May 2010 6:50] Bugs System
Pushed into 5.5.5-m3 (revid:alik@sun.com-20100524185725-c8k5q7v60i5nix3t) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[29 May 2010 15:09] Paul DuBois
Push resulted from incorporation of InnoDB tree. No changes pertinent to this bug.
Re-closing.
[17 Jun 2010 11:54] Bugs System
Pushed into 5.1.47-ndb-7.0.16 (revid:martin.skold@mysql.com-20100617114014-bva0dy24yyd67697) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[17 Jun 2010 12:31] Bugs System
Pushed into 5.1.47-ndb-6.2.19 (revid:martin.skold@mysql.com-20100617115448-idrbic6gbki37h1c) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[17 Jun 2010 13:19] Bugs System
Pushed into 5.1.47-ndb-6.3.35 (revid:martin.skold@mysql.com-20100617114611-61aqbb52j752y116) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)