Bug #69127 InnoDB: possible regression in 5.5.31, Bug#16004999
Submitted: 2 May 2013 18:49 Modified: 29 May 2013 23:51
Reporter: Calvin Sun Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S2 (Serious)
Version:5.5.31 OS:Any
Assigned to: CPU Architecture:Any
Tags: regression, RQG

[2 May 2013 18:49] Calvin Sun
Description:
Running RQG engine_stress test against debug version of mysql 5.5.31, mysqld hits assert. It looks to me a regression introduced in 5.5.31. We never had such failure in previous versions.

Version: '5.5.31.t11-dev-debug-log'  socket:
'/tmp/var-randgen/tmp/1/mysqld.1.sock'  port: 6100  Twitter MySQL;
5.5.31.t11-dev; 609c30c4
2013-05-01 22:26:08 15264 [ERROR] /usr/sbin/mysqld-debug: Deadlock
found when trying to get lock; try restarting transaction
2013-05-01 22:26:08 15264 [ERROR] /usr/sbin/mysqld-debug: Sort
aborted: Deadlock found when trying to get lock; try restarting
transaction
2013-05-01 22:26:08 15264 [ERROR] /usr/sbin/mysqld-debug: Deadlock
found when trying to get lock; try restarting transaction
2013-05-01 22:26:08 15264 [ERROR] /usr/sbin/mysqld-debug: Sort
aborted: Deadlock found when trying to get lock; try restarting
transaction
2013-05-01 22:26:08 15264 [ERROR] /usr/sbin/mysqld-debug: Deadlock
found when trying to get lock; try restarting transaction
2013-05-01 22:26:08 15264 [ERROR] /usr/sbin/mysqld-debug: Sort
aborted: Deadlock found when trying to get lock; try restarting
transaction
2013-05-01 22:26:08 15264 [ERROR] /usr/sbin/mysqld-debug: Deadlock
found when trying to get lock; try restarting transaction
2013-05-01 22:26:08 15264 [ERROR] /usr/sbin/mysqld-debug: Sort
aborted: Deadlock found when trying to get lock; try restarting
transaction
2013-05-01 22:26:08 15264 [ERROR] /usr/sbin/mysqld-debug: Deadlock
found when trying to get lock; try restarting transaction
2013-05-01 22:26:08 15264 [ERROR] /usr/sbin/mysqld-debug: Sort
aborted: Deadlock found when trying to get lock; try restarting
transaction
2013-05-01 22:26:08 15264 [ERROR] /usr/sbin/mysqld-debug: Deadlock
found when trying to get lock; try restarting transaction
2013-05-01 22:26:08 15264 [ERROR] /usr/sbin/mysqld-debug: Sort
aborted: Deadlock found when trying to get lock; try restarting
transaction
2013-05-01 22:26:08 15264 [ERROR] /usr/sbin/mysqld-debug: Deadlock
found when trying to get lock; try restarting transaction
2013-05-01 22:26:08 15264 [ERROR] /usr/sbin/mysqld-debug: Sort
aborted: Deadlock found when trying to get lock; try restarting
transaction
2013-05-01 22:26:08 15264  InnoDB: Assertion failure in thread
140022369454400 in file ha_innodb.cc line 5974

The assert is at the following code:

ha_innobase::unlock_row(void)
/*=========================*/
{
   DBUG_ENTER("ha_innobase::unlock_row");

   ut_ad(prebuilt->trx->conc_state == TRX_ACTIVE);

Note, the stack is from Twitter version of 5.5.31. According to Marko, this assertion was added in a recent bug fix (Bug #16004999 ASSERT STATE == TRX_STATE_NOT_STARTED, UNLOCK_ROW()).

How to repeat:
Running RQG engine_stress test against debug version of mysql.

Suggested fix:
no assertion.
[2 May 2013 23:15] MySQL Verification Team
Thank you for the bug report. Running against source server 5.5.32 I got a little different error message:

130503  2:09:48 [ERROR] /home/miguel/build20130426/mysql-5.5/sql/mysqld: Sort aborted: Deadlock found when trying to get lock; try restarting transaction       
130503  2:09:49 [ERROR] /home/miguel/build20130426/mysql-5.5/sql/mysqld: Deadlock found when trying to get lock; try restarting transaction                     
130503  2:09:49 [ERROR] /home/miguel/build20130426/mysql-5.5/sql/mysqld: Sort aborted: Deadlock found when trying to get lock; try restarting transaction       
130503  2:09:53 [ERROR] /home/miguel/build20130426/mysql-5.5/sql/mysqld: Deadlock found when trying to get lock; try restarting transaction                     
130503  2:09:53 [ERROR] /home/miguel/build20130426/mysql-5.5/sql/mysqld: Sort aborted: Deadlock found when trying to get lock; try restarting transaction       
130503  2:09:54  InnoDB: Assertion failure in thread 139760589625088 in file ha_innodb.cc line 5622                                                             
InnoDB: Failing assertion: prebuilt->trx->conc_state == 1
[24 May 2013 13:40] Paul DuBois
Changes for test suite. No changelog entry needed.

Will note in refman that INFORMATION_SCHEMA.INNODB_TRX is updated once per second.
[24 May 2013 13:46] Calvin Sun
The newly added comment does not make any sense for this bug. Need explanation why it is closed. Reopen it.
[24 May 2013 15:00] Paul DuBois
Correction: Table updates are each .1 second, not each second.
[24 May 2013 15:06] Paul DuBois
Noted in 5.5.32, 5.6.13, 5.7.2 changelogs.

If an UPDATE with a subquery caused a deadlock inside InnoDB, the
deadlock was not properly handled by the SQL layer. The SQL layer
then tried to unlock the row after InnoDB rolled back the
transaction, raising an assertion inside InnoDB.