Digging into MySQL InnoDB Transactions

A week ago I faced a really difficult situation: one of our MySQL innodb databases was slowing down in response times really a lot. With a bit of debugging, I figure out that there were some X-locks (eXclusive locks) that did not allowed some of the later transactions to finish. Here is the procedure I followed:

1. Use MySQL processlist to find out slow operations. The first one show us the slow queries on a specific database:

select * from information_schema.processlist 
              where db='alfresco' and command='Query' order by 'time' desc; 

Since I understood that the specific slow queries are utilizing two tables I also used:

select * from information_schema.processlist 
      where db='alfresco' and info like '%alf_%_assoc%' 

2. Now since we have one idea about heavy MySQL threads, lets take a look to the transactions:
First of all see all transactions that have placed an exclusive lock on one of the tables:
Second find the lock wait transactions

select * from information_schema.INNODB_TRX 
         where trx_id in ( 
             select Lock_trx_id from information_schema.INNODB_LOCKS where lock_mode='X'  )

select * from information_schema.INNODB_TRX where trx_id in (
         select distinct blocking_trx_id 
            from information_schema.INNODB_LOCK_WAITS ) 

3. Finally find the threads along with conflicting transactions with the following query:

SELECT r.trx_id waiting_trx_id,  
       r.trx_mysql_thread_id waiting_thread,
       r.trx_query waiting_query,
       b.trx_id blocking_trx_id, 
       b.trx_mysql_thread_id blocking_thread,
       b.trx_query blocking_query
   FROM       information_schema.innodb_lock_waits w
   INNER JOIN information_schema.innodb_trx b  ON  
    b.trx_id = w.blocking_trx_id
  INNER JOIN information_schema.innodb_trx r  ON  
    r.trx_id = w.requesting_trx_id;

Beware: The thread ID (waiting and blocking) is the ID in the information_schema.processlist

In this case, clearly the transaction with id 194D110F is the blocker!
To inspect the transaction use this query:

select * from information_schema.INNODB_TRX where trx_id='194D110F'

From what we see, there is a transaction running since 19:10:57 with id 194D110F. The query or operation carried out of this transaction is null because it was deleted from the transaction cache since it is very old. To retrieve the information about the SQL statement carried from this transaction we have to use the MySQL binlog.

The transaction 194D110F was observed during a  load test performed on our system. The lock was not released for 2 h.
The locking thread in MySQL was seen as follows from the slow.log:

---TRANSACTION 194D110F, ACTIVE 7431 sec
74 lock struct(s), heap size 14776, 101 row lock(s), undo log entries 64
MySQL thread id 7526, OS thread handle 0x7fd28ec38700, query id 10005877 application-host X.X.44.28 alfresco
Trx read view will not see trx with id >= 194D1110, sees < 194C03CD