MySQL update blocked by unknown transaction

Question

When i try to update a table using the query

 UPDATE person.heroes
   SET passwd = 'f662da7b9bd166ded69337a7f618da89'
 WHERE heroes_id = 283703

this particular thread(3086C6) is made to wait on lock as another thread(3086C0) has the same lock. the table is unique on alias and primary index on heroes_id. I am not running any other processes and "show processlist;" confirms it.

The two threads show they are locking on the same data item "283703" (which is the account_id and is primary index )with X lock. How 3086C0 got generated?

There is one trigger on the person.heroes which updates another table.

    sql>show engine innodb status;
    SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 388, signal count 394
Mutex spin waits 128, rounds 1354, OS waits 39
RW-shared spins 365, rounds 10714, OS waits 345
RW-excl spins 0, rounds 144, OS waits 4
Spin rounds per wait: 10.58 mutex, 29.35 RW-shared, 144.00 RW-excl
------------
TRANSACTIONS
------------
Trx id counter 3086C7
Purge done for trx's n:o < 3086B4 undo n:o < 0
History list length 1690
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 3086C3, not started
MySQL thread id 191, OS thread handle 0x7ff590948700, query id 48008 192.168.104.19 game
---TRANSACTION 3086C4, not started
MySQL thread id 192, OS thread handle 0x7ff58fd18700, query id 48012 192.168.104.19 game
---TRANSACTION 3079C4, not started
MySQL thread id 164, OS thread handle 0x7ff590885700, query id 44155 192.168.0.12 game
---TRANSACTION 308597, not started
MySQL thread id 167, OS thread handle 0x7ff5908c6700, query id 47224 192.168.0.12 game
---TRANSACTION 307FCF, not started
MySQL thread id 166, OS thread handle 0x7ff624054700, query id 45727 192.168.0.12 game
---TRANSACTION 307FC9, not started
MySQL thread id 163, OS thread handle 0x7ff590b91700, query id 45717 192.168.0.12 game
---TRANSACTION 307A1C, not started
MySQL thread id 155, OS thread handle 0x7ff62692d700, query id 45722 192.168.0.11 game
---TRANSACTION 3085ED, not started
MySQL thread id 146, OS thread handle 0x7ff590b50700, query id 47411 192.168.0.11 game
---TRANSACTION 308677, not started
MySQL thread id 130, OS thread handle 0x7ff590b0f700, query id 48016 localhost root
show engine innodb status
---TRANSACTION 303B8E, not started
MySQL thread id 125, OS thread handle 0x7ff590a4c700, query id 13780 localhost root
---TRANSACTION 308615, not started
MySQL thread id 122, OS thread handle 0x7ff590a8d700, query id 47458 192.168.0.11 game
---TRANSACTION 30865E, not started
MySQL thread id 120, OS thread handle 0x7ff590a0b700, query id 47545 192.168.0.11 game
---TRANSACTION 3086C6, ACTIVE 3 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
MySQL thread id 193, OS thread handle 0x7ff6268ec700, query id 48015 192.168.104.19 game Updating
UPDATE person.heroes
   SET passwd = 'f662da7b9bd166ded69337a7f618da89'
 WHERE heroes_id = 283703
Trx read view will not see trx with id >= 3086C7, sees < 3086C0
------- TRX HAS BEEN WAITING 3 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 783 page no 20 n bits 160 index `PRIMARY` of table `person`.`heroes` trx id 3086C6 lock_mode X locks rec but not gap waiting
Record lock, heap no 20 PHYSICAL RECORD: n_fields 29; compact format; info bits 0
 0: len 4; hex 80045437; asc   T7;;
 1: len 6; hex 0000003086c0; asc    0  ;;
 2: len 7; hex 25000002630e5d; asc %   c ];;
 3: len 3; hex 543120; asc T1 ;;
 4: SQL NULL;
 5: SQL NULL;
 6: SQL NULL;
 7: SQL NULL;
 8: SQL NULL;
 9: len 2; hex 494e; asc IN;;
 10: SQL NULL;
 11: SQL NULL;
 12: len 28; hex 746573746f6965776e31323334406d61696c696e61746f722e636f6d; asc testoiewn1234@mailinator.com;;
 13: len 13; hex 746573746f6965776e31323334; asc testoiewn1234;;
 14: len 30; hex 346464376565616238306135633231663033303138666166366462666363; asc 4dd7eeab80a5c21f03018faf6dbfcc; (total 32 bytes);
 15: SQL NULL;
 16: SQL NULL;
 17: SQL NULL;
 18: SQL NULL;
 19: SQL NULL;
 20: len 1; hex 80; asc  ;;
 21: len 4; hex 80000000; asc     ;;
 22: len 6; hex 353030303831; asc 500081;;
 23: SQL NULL;
 24: len 1; hex 80; asc  ;;
 25: len 4; hex 80000200; asc     ;;
 26: len 3; hex 800000; asc    ;;
 27: len 1; hex 80; asc  ;;
 28: len 3; hex 494e52; asc INR;;

------------------
TABLE LOCK table `person`.`heroes` trx id 3086C6 lock mode IX
RECORD LOCKS space id 783 page no 20 n bits 160 index `PRIMARY` of table `person`.`heroes` trx id 3086C6 lock_mode X locks rec but not gap waiting
Record lock, heap no 20 PHYSICAL RECORD: n_fields 29; compact format; info bits 0
 0: len 4; hex 80045437; asc   T7;;
 1: len 6; hex 0000003086c0; asc    0  ;;
 2: len 7; hex 25000002630e5d; asc %   c ];;
 3: len 3; hex 543120; asc T1 ;;
 4: SQL NULL;
 5: SQL NULL;
 6: SQL NULL;
 7: SQL NULL;
 8: SQL NULL;
 9: len 2; hex 494e; asc IN;;
 10: SQL NULL;
 11: SQL NULL;
 12: len 28; hex 746573746f6965776e31323334406d61696c696e61746f722e636f6d; asc testoiewn1234@mailinator.com;;
 13: len 13; hex 746573746f6965776e31323334; asc testoiewn1234;;
 14: len 30; hex 346464376565616238306135633231663033303138666166366462666363; asc 4dd7eeab80a5c21f03018faf6dbfcc; (total 32 bytes);
 15: SQL NULL;
 16: SQL NULL;
 17: SQL NULL;
 18: SQL NULL;
 19: SQL NULL;
 20: len 1; hex 80; asc  ;;
 21: len 4; hex 80000000; asc     ;;
 22: len 6; hex 353030303831; asc 500081;;
 23: SQL NULL;
 24: len 1; hex 80; asc  ;;
 25: len 4; hex 80000200; asc     ;;
 26: len 3; hex 800000; asc    ;;
 27: len 1; hex 80; asc  ;;
 28: len 3; hex 494e52; asc INR;;

---TRANSACTION 3086C0, ACTIVE 3 sec
3 lock struct(s), heap size 1248, 2 row lock(s), undo log entries 1
MySQL thread id 190, OS thread handle 0x7ff590ace700, query id 47999 192.168.104.19 game
TABLE LOCK table `person`.`heroes` trx id 3086C0 lock mode IX
RECORD LOCKS space id 783 page no 18 n bits 624 index `alias` of table `person`.`heroes` trx id 3086C0 lock_mode X locks rec but not gap
Record lock, heap no 508 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 13; hex 746573746f6965776e31323334; asc testoiewn1234;;
 1: len 4; hex 80045437; asc   T7;;

RECORD LOCKS space id 783 page no 20 n bits 160 index `PRIMARY` of table `person`.`heroes` trx id 3086C0 lock_mode X locks rec but not gap
Record lock, heap no 20 PHYSICAL RECORD: n_fields 29; compact format; info bits 0
 0: len 4; hex 80045437; asc   T7;;
 1: len 6; hex 0000003086c0; asc    0  ;;
 2: len 7; hex 25000002630e5d; asc %   c ];;
 3: len 3; hex 543120; asc T1 ;;
 4: SQL NULL;
 5: SQL NULL;
 6: SQL NULL;
 7: SQL NULL;
 8: SQL NULL;
 9: len 2; hex 494e; asc IN;;
 10: SQL NULL;
 11: SQL NULL;
 12: len 28; hex 746573746f6965776e31323334406d61696c696e61746f722e636f6d; asc testoiewn1234@mailinator.com;;
 13: len 13; hex 746573746f6965776e31323334; asc testoiewn1234;;
 14: len 30; hex 346464376565616238306135633231663033303138666166366462666363; asc 4dd7eeab80a5c21f03018faf6dbfcc; (total 32 bytes);
 15: SQL NULL;
 16: SQL NULL;
 17: SQL NULL;
 18: SQL NULL;
 19: SQL NULL;
 20: len 1; hex 80; asc  ;;
 21: len 4; hex 80000000; asc     ;;
 22: len 6; hex 353030303831; asc 500081;;
 23: SQL NULL;
 24: len 1; hex 80; asc  ;;
 25: len 4; hex 80000200; asc     ;;
 26: len 3; hex 800000; asc    ;;
 27: len 1; hex 80; asc  ;;
 28: len 3; hex 494e52; asc INR;;

--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (read thread)
I/O thread 4 state: waiting for i/o request (read thread)
I/O thread 5 state: waiting for i/o request (read thread)
I/O thread 6 state: waiting for i/o request (write thread)
I/O thread 7 state: waiting for i/o request (write thread)
I/O thread 8 state: waiting for i/o request (write thread)
I/O thread 9 state: waiting for i/o request (write thread)
Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,
 ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
1343 OS file reads, 6867 OS file writes, 2731 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 0.45 writes/s, 0.09 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 30 merges
merged operations:
 insert 30, delete mark 0, delete 0
discarded operations:
 insert 0, delete mark 0, delete 0
Hash table size 4425293, node heap has 17 buffer(s)
29.09 hash searches/s, 3.91 non-hash searches/s
---
LOG
---
Log sequence number 682871332
Log flushed up to   682871332
Last checkpoint at  682869899
0 pending log writes, 0 pending chkp writes
2311 log i/o's done, 0.45 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 2197815296; in additional pool allocated 0
Dictionary memory allocated 714369
Buffer pool size   131071
Free buffers       129785
Database pages     1269
Old database pages 488
Modified db pages  14
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 2, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1228, created 41, written 4623
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1269, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
2 read views open inside InnoDB
Main thread process no. 1460, id 140692705335040, state: sleeping
Number of rows inserted 1366, updated 709, deleted 191, read 912575
0.09 inserts/s, 0.36 updates/s, 0.09 deletes/s, 33.72 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
 |
+--------+------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)

mysql> SELECT * FROM INFORMATION_SCHEMA.INNODB_LOCKS;
+------------------+-------------+-----------+-----------+--------------------+------------+------------+-----------+----------+-----------+
| lock_id          | lock_trx_id | lock_mode | lock_type | lock_table         | lock_index | lock_space | lock_page | lock_rec | lock_data |
+------------------+-------------+-----------+-----------+--------------------+------------+------------+-----------+----------+-----------+
| 3086C6:783:20:20 | 3086C6      | X         | RECORD    | `person`.`heroes` | `PRIMARY`  |        783 |        20 |       20 | 283703    |
| 3086C0:783:20:20 | 3086C0      | X         | RECORD    | `person`.`heroes` | `PRIMARY`  |        783 |        20 |       20 | 283703    |
+------------------+-------------+-----------+-----------+--------------------+------------+------------+-----------+----------+-----------+
2 rows in set (0.00 sec)

mysql> SELECT * FROM INFORMATION_SCHEMA.INNODB_TRX\G
*************************** 1. row ***************************
                trx_id: 3086C6
             trx_state: LOCK WAIT
           trx_started: 2013-06-27 15:28:46
     trx_requested_lock_id: 3086C6:783:20:20
      trx_wait_started: 2013-06-27 15:28:46
            trx_weight: 2
       trx_mysql_thread_id: 193
             trx_query: UPDATE person.heroes
   SET passwd = 'f662da7b9bd166ded69337a7f618da89'
 WHERE heroes_id = 283703
       trx_operation_state: starting index read
     trx_tables_in_use: 1
     trx_tables_locked: 1
      trx_lock_structs: 2
     trx_lock_memory_bytes: 376
       trx_rows_locked: 1
     trx_rows_modified: 0
   trx_concurrency_tickets: 0
       trx_isolation_level: REPEATABLE READ
     trx_unique_checks: 1
    trx_foreign_key_checks: 1
trx_last_foreign_key_error: NULL
 trx_adaptive_hash_latched: 0
 trx_adaptive_hash_timeout: 9999
*************************** 2. row ***************************
                trx_id: 3086C0
             trx_state: RUNNING
           trx_started: 2013-06-27 15:28:46
     trx_requested_lock_id: NULL
      trx_wait_started: NULL
            trx_weight: 4
       trx_mysql_thread_id: 190
             trx_query: NULL
       trx_operation_state: NULL
     trx_tables_in_use: 0
     trx_tables_locked: 0
      trx_lock_structs: 3
     trx_lock_memory_bytes: 1248
       trx_rows_locked: 2
     trx_rows_modified: 1
   trx_concurrency_tickets: 0
       trx_isolation_level: REPEATABLE READ
     trx_unique_checks: 1
    trx_foreign_key_checks: 1
trx_last_foreign_key_error: NULL
 trx_adaptive_hash_latched: 0
 trx_adaptive_hash_timeout: 10000
2 rows in set (0.00 sec)

mysql> SELECT * FROM INFORMATION_SCHEMA.INNODB_LOCK_WAITS;
+-------------------+-------------------+-----------------+------------------+
| requesting_trx_id | requested_lock_id | blocking_trx_id | blocking_lock_id |
+-------------------+-------------------+-----------------+------------------+
| 3086C6            | 3086C6:783:20:20  | 3086C0          | 3086C0:783:20:20 |
+-------------------+-------------------+-----------------+------------------+
1 row in set (0.00 sec)

mysql version is: 5.5.31

Can anyone please shed light?

You didn't try it in multiple windows and forgot to type `COMMIT` in the first one? :) — Joachim Isaksson, Jun 26 '13 at 12:41
`show processlist;` might show what the other thread (trx_mysql_thread_id: 112) is doing at the time. Is it one of yours or something else? — oh7lzb, Jun 26 '13 at 12:43
@oh7lzb show processlist does not show any query except the update query and some sleep process. — Neil, Jun 27 '13 at 05:24
@KlausByskovPedersen there is one and it does not update the person.heroes table. — Neil, Jun 27 '13 at 05:25
@Neil Does the update run ok from the mysql prompt, or is that where you're having trouble? How is the query run currently? — Joachim Isaksson, Jun 27 '13 at 05:32
@JoachimIsaksson the problem is occurring only during application run, not when the query is run in sql shell. I am using sqlalchemy in Python for the application. — Neil, Jun 28 '13 at 04:51

score 4 · Accepted Answer · edited May 23 '17 at 11:45

Another MySQL has apparently accessed the same record, or one close to it, in a transaction and left a record lock open on it, preventing other threads from modifying the record until the transaction is either committed or rolled back.

To determine the other mysql thread, you're already on the right track:

SELECT * FROM INFORMATION_SCHEMA.INNODB_TRX\G

will show your blocked InnoDB transaction (30250F in the example above), and the other transaction (302509). Check the mysql process/thread list:

show processlist;

Each thread has a thread id:

mysql> show processlist;
+------------+---------+--------------------+------+-------------+---------+-----------------------------------------------------------------------+------------------+
| Id         | User    | Host               | db   | Command     | Time    | State                                                                 | Info             |
+------------+---------+--------------------+------+-------------+---------+-----------------------------------------------------------------------+------------------+
|        112 | myuser  | localhost          | mydb | Sleep       |      95 |                                                                       | NULL             |

and the thread id (112) of the blocking transaction is visible as trx_mysql_thread_id in the INNODB_TRX list.

If you would now terminate thread 112 with the kill 112; command, its transaction should be rolled back (any changes made by it in its current transaction would be reverted), the locks freed, and the blocked thread should be able to proceed.

That thread is probably sleeping now, as you said in a comment: It has modified a row earlier (trx_rows_modified: 1) which has caused two rows to be locked (trx_rows_locked: 2), one of which is the row you're trying to modify now. It just hasn't committed the transaction yet, which is why the locks are still in place.

As for the real fix: your application should perform a COMMIT; after every transaction. If you are not using transactions and don't wish to learn them right now, you might want to enable auto-commit with SET autocommit=1; after connecting to the database and before performing any operations. MySQL has autocommit enabled by default, so it might also be that you're currently disabling it in your code. Note that you'll have to do this separately for each connection.

When autocommit is enabled, COMMIT is not necessary if you just issue simple statements, but you can still explicitly start a transaction by issuing a BEGIN or START TRANSACTION command, in which case you need to terminate it with either a COMMIT or ROLLBACK. Check your code for BEGIN or START TRANSACTION statements, remove them if you're not doing the COMMITs.

Autocommit can also be adjusted as a global option (how to set autocommit false globally), but then your application will be dependent on the database server configuration having that setting.

When using transactions you'll have to make sure that you always do one of these in the end of an operation:

Commit
Rollback
Close connection (causes rollback if not committed)

With persistent connections on a web service, HTTP client connections closing unexpectedly can potentially terminate your script execution without either a commit or rollback, and leave the connection open in the middle of a transaciton.

Related question, basic intro to transactions: What is a database transaction?

http://dev.mysql.com/doc/refman/5.6/en/commit.html

yes, there is commit after every transaction and autocommit is also true — Neil, Jun 27 '13 at 11:10
Ok, then probably your script execution is getting terminated for some reason before the commit. Autocommit won't have any effect if you're doing a BEGIN to start a transaction. — oh7lzb, Jun 27 '13 at 19:51
thanks, i overlooked an update and it does not have commit, the code is working fine now. — Neil, Jun 28 '13 at 05:08

MySQL update blocked by unknown transaction

1 Answers1