SHOW ENGINE INNODB STATUS displayed ROLLING BACK for a transaction that later continued on
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
Percona Server moved to https://jira.percona.com/projects/PS |
New
|
Undecided
|
Unassigned | ||
5.5 |
New
|
Undecided
|
Unassigned | ||
5.6 |
New
|
Undecided
|
Unassigned |
Bug Description
From a customer's SHOW ENGINE INNODB STATUS samples, we found one transaction first in ROLLING BACK and then continued on. I never encountered this before and don't know how to reproduce it. But the customer sees ROLLING BACK in the transaction section for this query from time to time.
Server version: PS 5.5.28
17:07:10
---TRANSACTION 182AC2408, ACTIVE 8 sec inserting
mysql tables in use 1, locked 1
ROLLING BACK 461 lock struct(s), heap size 63928, 1435 row lock(s), undo log entries 1217
MySQL thread id 225564, OS thread handle 0x7f45dd7e2700, query id 1383215000 myserver 10.1.13.82 tungsten update
INSERT INTO mydb.mytable (c1, c2, c3, c4, c5, c6...) VALUES (1339,1136,
17:07:10
---TRANSACTION 182AC2408, ACTIVE 8 sec starting index read
mysql tables in use 1, locked 1
489 lock struct(s), heap size 80312, 1463 row lock(s), undo log entries 1231
MySQL thread id 225564, OS thread handle 0x7f45dd7e2700, query id 1383215000 myserver 10.1.13.82 tungsten update
INSERT INTO mydb.mytable (c1, c2, c3, c4, c5, c6...) VALUES
So, what is the bug here? Undocumented "ROLLING BACK" message? Or the fact that transaction continued?
I see the following in the code:
trx_get_ que_state_ str( ======= ======* / STATE_STR_ MAX_LEN if you change this */ que_state) {
return( "RUNNING" );
return( "LOCK WAIT"); ROLLING_ BACK:
return( "ROLLING BACK");
return( "COMMITTING" );
return( "UNKNOWN" );
/*=====
const trx_t* trx) /*!< in: transaction */
{
/* be sure to adjust TRX_QUE_
switch (trx->lock.
case TRX_QUE_RUNNING:
case TRX_QUE_LOCK_WAIT:
case TRX_QUE_
case TRX_QUE_COMMITTING:
default:
}
}
And then:
Percona- Server/ storage/ innobase/ trx/trx0trx. cc:2040: case TRX_QUE_ ROLLING_ BACK:
Here we have:
/* trx->lock.que_state of an ACTIVE transaction may change
while we are not holding trx->mutex. We perform a dirty read
for performance reasons. */
switch (trx->lock. que_state) {
newline = FALSE; break;
fputs( "LOCK WAIT ", f); break; ROLLING_ BACK:
fputs( "ROLLING BACK ", f); break;
fputs( "COMMITTING ", f); break;
fprintf( f, "que state %lu ", (ulong) trx->lock. que_state) ;
case TRX_QUE_RUNNING:
case TRX_QUE_LOCK_WAIT:
case TRX_QUE_
case TRX_QUE_COMMITTING:
default:
}
Percona- Server/ storage/ innobase/ trx/trx0roll. cc:1300: trx->lock.que_state = TRX_QUE_ ROLLING_ BACK;
Here we have:
/****** ******* ******* ******* ******* ******* ******* ******* ******* ******* //**
partial undo), 0 if we are rolling back
the entire transaction */
Starts a rollback operation, creates the UNDO graph that will do the
actual undo operation.
@return query graph thread that will perform the UNDO operations. */
static
que_thr_t*
trx_rollback_start(
/*===============*/
trx_t* trx, /*!< in: transaction */
ib_id_t roll_limit) /*!< in: rollback to undo no (for
{
...
/* Build a 'query' graph which will perform the undo operations */
roll_graph = trx_roll_ graph_build( trx);
trx->graph = roll_graph;
}
So, my idea is that maybe transaction had to do some "mini rollback" to get data for the table at the moment statement execution began, to check some constraint maybe?
Just a speculation for now.