Bug #49251 deadlock/crash with concurrent truncate table and index statistics calculation
Submitted: 1 Dec 2009 8:23 Modified: 26 Aug 2010 1:21
Reporter: Oli Sennhauser Email Updates:
Status: Duplicate Impact on me:
Category:MySQL Server: InnoDB storage engine Severity:S1 (Critical)
Version:5.0.91,5.1.50, 5.5, 5.6.1 OS:Any
Assigned to: Assigned Account CPU Architecture:Any
Tags: crash, innodb, semaphore waits

[1 Dec 2009 8:23] Oli Sennhauser
A customer experiences a server crash after a semaphore wait followed by a corruption. The table which was corrupted was active during the problem:

InnoDB: Error: semaphore wait has lasted > 600 seconds
InnoDB: We intentionally crash the server, because it appears to be hung.
091124 22:16:15InnoDB: Assertion failure in thread 1147169120 in file srv0srv.c line 2095
OS WAIT ARRAY INFO: reservation count 2275483678, signal count 1995552505
--Thread 1158457696 has waited at fsp0fsp.c line 2185 for 945.00 seconds the semaphore:
X-lock on RW-latch at 0x2a9ac6e940 created in file fil0fil.c line 1048
a writer (thread id 1164048736) has reserved it in mode  exclusive
number of readers 0, waiters flag 1
Last time read locked in file not yet reserved line 0
Last time write locked in file fsp0fsp.c line 2732
Version: '5.0.54a-enterprise-gpl-log'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Enterprise Server (GPL)
InnoDB: Error: trying to load index PRIMARY for table czen/LUCENE_SEEKER_JOB
InnoDB: but the index tree has been freed!
091124 23:08:52 - mysqld got signal 11;

How to repeat:
Was not able to repeat yet.

Suggested fix:
Do not crash or at least do not corrupt data during crash.
[1 Dec 2009 8:32] Oli Sennhauser
2162 /**************************************************************************
   2163 Calculates the number of pages reserved by a segment, and how many pages are
   2164 currently used. */
   2167 fseg_n_reserved_pages(
   2173 {
   2178         space = buf_frame_get_space_id(header);
   2185         mtr_x_lock(fil_space_get_latch(space), mtr);
   2187         inode = fseg_inode_get(header, mtr);
   2189         ret = fseg_n_reserved_pages_low(inode, used, mtr);
   2191         return(ret);
   2192 }

   2700 fsp_reserve_free_extents(
   2710 {
   2722         ut_ad(mtr);
   2728         *n_reserved = n_ext;
   2730         latch = fil_space_get_latch(space);
   2732         mtr_x_lock(latch, mtr);
   2734         space_header = fsp_get_space_header(space, mtr);

   1361 Allocates a single free page from a space. The page is marked as used. */
   1364 fsp_alloc_free_page(
   1371 {
   1382         ut_ad(mtr);
   1384         header = fsp_get_space_header(space, mtr);
   1479         /* Initialize the allocated page to the buffer pool, so that it can
   1480         be obtained immediately with buf_page_get without need for a disk
   1481         read. */
   1483         buf_page_create(space, page_no, mtr);
   1485         page = buf_page_get(space, page_no, RW_X_LATCH, mtr);
   1490         /* Prior contents of the page should be ignored */
   1491         fsp_init_file_page(page, mtr);
   1493         return(page_no);
   1494 }
[10 Aug 2010 18:17] MySQL Verification Team
seen this during concurrent truncate table and show keys from an innodb table..
[11 Aug 2010 5:40] MySQL Verification Team
repeated a hangup in 5.0.80, and saved stack traces, etc.  there was FK keys created after starting the test.

Attachment: bug49251_5.0.80_hang_stack_traces.txt (text/plain), 25.00 KiB.

[11 Aug 2010 5:53] MySQL Verification Team
After the crash due to deadlock, and restart of mysqld, any attempt to access the partially truncated table will crash the server with stack trace:
show create table t1:


The only solution is to do DROP TABLE and then recreate it. No value of innodb_force_recovery will allow you to open the table. 

You will need to know the structure of it from backups, or a slave, etc.
[12 Aug 2010 6:27] MySQL Verification Team
repeated on 5.1.49 with innodb plugin 1.0.10

Attachment: bug49251_5.1.49.stack_traces.txt (text/plain), 29.86 KiB.

[20 Aug 2010 19:45] MySQL Verification Team
compile and run against a mysqld started with --innodb-lock-wait-timeout=1.  give it some minutes or hours to hang or crash

Attachment: bug49251.c (text/plain), 10.38 KiB.

[21 Aug 2010 5:23] MySQL Verification Team
the above testcase might provoke various problems.
5.0.91 1): saw the hangup oli reported.
5.0.91 2): got assertion on truncate [file lock0lock.c line 4006 Failing assertion: !lock_get_wait(lock)]

5.1.50 1): saw the hangup oli reported

5.5.5 1) : dies so quickly my error log grew too big :)
[24 Aug 2010 9:15] MySQL Verification Team
this hangup is still repeatable in this version:

sbester@box2:~/big/build/bzr/mysql-5.1-security> bzr revision-info
3483 georgi.kodinov@oracle.com-20100820122324-zhq53easgf6ke9wz
[24 Aug 2010 9:22] Calvin Sun
Change back to Verified based on Shane's latest comment.
[28 Sep 2010 8:48] Bugs System
Pushed into mysql-5.1 5.1.52 (revid:sunanda.menon@sun.com-20100928083322-wangbv97uobu7g66) (version source revid:sunanda.menon@sun.com-20100928083322-wangbv97uobu7g66) (merge vers: 5.1.52) (pib:21)
[14 Oct 2010 8:35] 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:50] 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 9:05] 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)
[9 Nov 2010 19:47] Bugs System
Pushed into mysql-5.5 5.5.7-rc (revid:sunanda.menon@sun.com-20101109182959-otkxq8vo2dcd13la) (version source revid:marko.makela@oracle.com-20100824081003-v4ecy0tga99cpxw2) (merge vers: 5.1.50) (pib:21)
[13 Nov 2010 16:14] Bugs System
Pushed into mysql-trunk 5.6.99-m5 (revid:alexander.nozdrin@oracle.com-20101113155825-czmva9kg4n31anmu) (version source revid:marko.makela@oracle.com-20100824081003-v4ecy0tga99cpxw2) (merge vers: 5.1.50) (pib:21)
[13 Nov 2010 16:37] Bugs System
Pushed into mysql-next-mr (revid:alexander.nozdrin@oracle.com-20101113160336-atmtmfb3mzm4pz4i) (version source revid:marko.makela@oracle.com-20100824081003-v4ecy0tga99cpxw2) (pib:21)
[27 Jul 2011 13:37] Chris Calender
What bug is this a "duplicate" of?  There is no mention of the other bug, and so there is no way to know if that has been fixed or not, and if so, what versions?
[27 Jul 2011 13:47] MySQL Verification Team
See http://bugs.mysql.com/bug.php?id=54678.