Sperre wird nicht akquiriert, obwohl keine anderen Transaktionen das Schloss halten

Im Snippet der innodb lock logs unten habe ich 3 Transaktionen, die alle auf eine Sperre auf TABLE_C warten, um Zeilen einfügen zu können. Irgendetwas verhindert, dass einer von ihnen die Sperre erhält, so dass alle Abfragen eine Zeitüberschreitung aufweisen und die Transaktionen zurückgesetzt werden.Sperre wird nicht akquiriert, obwohl keine anderen Transaktionen das Schloss halten
Oct 31 17:23:40 QA mysqld: LIST OF TRANSACTIONS FOR EACH SESSION: 
Oct 31 17:23:40 QA mysqld: ---TRANSACTION 233954056, not started 
Oct 31 17:23:40 QA mysqld: MySQL thread id 3441099, OS thread handle 0x7efa609fcb00, query id 40620122 engineer-desktop <redacted ip> DBA cleaning up 
Oct 31 17:23:40 QA mysqld: ---TRANSACTION 0, not started 
Oct 31 17:23:40 QA mysqld: MySQL thread id 3441098, OS thread handle 0x7efd5427cb00, query id 4062engineer-desktop <redacted ip> DBA cleaning up 
Oct 31 17:23:40 QA mysqld: ---TRANSACTION 233958337, not started 
Oct 31 17:23:40 QA mysqld: MySQL thread id 3428078, OS thread handle 0x7efd54232b00, query id 40647553 localhost 127.0.0.1 DBUSER cleaning up 
Oct 31 17:23:40 QA mysqld: ---TRANSACTION 233953710, not started 
Oct 31 17:23:40 QA mysqld: MySQL thread id 3428079, OS thread handle 0x7efd508ceb00, query id 40618305 localhost 127.0.0.1 DBUSER cleaning up 
Oct 31 17:23:40 QA mysqld: ---TRANSACTION 233955212, not started 
Oct 31 17:23:40 QA mysqld: MySQL thread id 3428058, OS thread handle 0x7efc18e46b00, query id 40625733 localhost 127.0.0.1 DBUSER cleaning up 
Oct 31 17:23:40 QA mysqld: ---TRANSACTION 233942817, not started 
Oct 31 17:23:40 QA mysqld: MySQL thread id 3428059, OS thread handle 0x7efd509acb00, query id 40321943 localhost 127.0.0.1 DBUSER cleaning up 
Oct 31 17:23:40 QA mysqld: ---TRANSACTION 233955200, not started 
Oct 31 17:23:40 QA mysqld: MySQL thread id 3428056, OS thread handle 0x7efc18d1eb00, query id 40625656 localhost 127.0.0.1 DBUSER cleaning up 
Oct 31 17:23:40 QA mysqld: ---TRANSACTION 233954068, not started 
Oct 31 17:23:40 QA mysqld: MySQL thread id 3428060, OS thread handle 0x7efd3ddf7b00, query id 40620311 localhost 127.0.0.1 DBUSER cleaning up 
Oct 31 17:23:40 QA mysqld: ---TRANSACTION 233958779, not started 
Oct 31 17:23:40 QA mysqld: MySQL thread id 3428055, OS thread handle 0x7efd3dc85b00, query id 40650598 localhost 127.0.0.1 DBUSER cleaning up 
Oct 31 17:23:40 QA mysqld: ---TRANSACTION 233919171, not started 
Oct 31 17:23:40 QA mysqld: MySQL thread id 3428077, OS thread handle 0x7efd543a4b00, query id 40154345 localhost 127.0.0.1 DBUSER cleaning up 
Oct 31 17:23:40 QA mysqld: ---TRANSACTION 228166659, not started 
Oct 31 17:23:40 QA mysqld: MySQL thread id 3, OS thread handle 0x7efd9a435b00, query id 0 Waiting for background binlog tasks 
Oct 31 17:23:40 QA mysqld: ---TRANSACTION 233958942, ACTIVE (PREPARED) 0 sec flushing log 
Oct 31 17:23:40 QA mysqld: 3 lock struct(s), heap size 1184, 2 row lock(s), undo log entries 1 
Oct 31 17:23:40 QA mysqld: MySQL thread id 3428057, OS thread handle 0x7efd3ddadb00, query id 40651751 localhost 127.0.0.1 DBUSER init 
Oct 31 17:23:40 QA mysqld: COMMIT 
Oct 31 17:23:40 QA mysqld: Trx #rec lock waits 6222 #table lock waits 0 
Oct 31 17:23:40 QA mysqld: Trx total rec lock wait time 110 SEC 
Oct 31 17:23:40 QA mysqld: Trx total table lock wait time 0 SEC 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_A" trx id 233958942 lock mode IX lock hold time 0 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: RECORD LOCKS space id 81087 page no 4 n bits 88 index "TABLE_A_INDEX" of table "db"."TABLE_A" trx table locks 1 total table locks 1 trx id 233958942 lock_mode X locks rec but not gap lock hol d time 0 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: RECORD LOCKS space id 81087 page no 3 n bits 88 index "PRIMARY" of table "db"."TABLE_A" trx table locks 1 total table locks 1 trx id 233958942 lock_mode X locks rec but not gap lock hold time 0 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: ---TRANSACTION 233955000, ACTIVE 40 sec 
Oct 31 17:23:40 QA mysqld: 441 lock struct(s), heap size 63016, 983 row lock(s), undo log entries 1982 
Oct 31 17:23:40 QA mysqld: MySQL thread id 3428054, OS thread handle 0x7efd5419eb00, query id 40651737 localhost 127.0.0.1 DBUSER cleaning up 
Oct 31 17:23:40 QA mysqld: Trx #rec lock waits 1514 #table lock waits 0 
Oct 31 17:23:40 QA mysqld: Trx total rec lock wait time 24 SEC 
Oct 31 17:23:40 QA mysqld: Trx total table lock wait time 0 SEC 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_B" trx id 233955000 lock mode IX lock hold time 40 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_C" trx id 233955000 lock mode IX lock hold time 39 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_D" trx id 233955000 lock mode IS lock hold time 39 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: RECORD LOCKS space id 80862 page no 3 n bits 80 index "PRIMARY" of table "db"."TABLE_D" trx table locks 13 total table locks 4 trx id 233955000 lock mode S locks rec but not gap lock hold time 39 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_E" trx id 233955000 lock mode IS lock hold time 39 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: RECORD LOCKS space id 81053 page no 17 n bits 80 index "PRIMARY" of table "db"."TABLE_E" trx table locks 13 total table locks 4 trx id 233955000 lock mode S locks rec but not gap lock hold time 39 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_F" trx id 233955000 lock mode IX lock hold time 39 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_G" trx id 233955000 lock mode IS lock hold time 39 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: RECORD LOCKS space id 80850 page no 3 n bits 96 index "PRIMARY" of table "db"."TABLE_G" trx table locks 13 total table locks 4 trx id 233955000 lock mode S locks rec but not gap lock hold time 39 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_H" trx id 233955000 lock mode IS lock hold time 39 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TOO MANY LOCKS PRINTED FOR THIS TRX: SUPPRESSING FURTHER PRINTS 
Oct 31 17:23:40 QA mysqld: ---TRANSACTION 233954711, ACTIVE 41 sec inserting 
Oct 31 17:23:40 QA mysqld: mysql tables in use 1, locked 1 
Oct 31 17:23:40 QA mysqld: LOCK WAIT 19 lock struct(s), heap size 2936, 9 row lock(s), undo log entries 4 
Oct 31 17:23:40 QA mysqld: MySQL thread id 3428052, OS thread handle 0x7efd54076b00, query id 40623905 localhost 127.0.0.1 DBUSER 
Oct 31 17:23:40 QA mysqld: insert into TABLE_C (<redacted columns>) values (<redacted values> 
Oct 31 17:23:40 QA mysqld: Trx #rec lock waits 19 #table lock waits 0 
Oct 31 17:23:40 QA mysqld: Trx total rec lock wait time 2 SEC 
Oct 31 17:23:40 QA mysqld: Trx total table lock wait time 0 SEC 
Oct 31 17:23:40 QA mysqld: ------- TRX HAS BEEN WAITING 41 SEC FOR THIS LOCK TO BE GRANTED: 
Oct 31 17:23:40 QA mysqld: RECORD LOCKS space id 80947 page no 9930 n bits 72 index "PRIMARY" of table "db"."TABLE_C" trx table locks 10 total table locks 4 trx id 233954711 lock_mode X insert intention waiting lock hold time 41 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: ------------------ 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_B" trx id 233954711 lock mode IX lock hold time 41 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_C" trx id 233954711 lock mode IX lock hold time 41 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_D" trx id 233954711 lock mode IS lock hold time 41 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: RECORD LOCKS space id 80862 page no 3 n bits 80 index "PRIMARY" of table "db"."TABLE_D" trx table locks 10 total table locks 4 trx id 233954711 lock mode S locks rec but not gap lock hold time 41 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_E" trx id 233954711 lock mode IS lock hold time 41 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: RECORD LOCKS space id 81053 page no 17 n bits 80 index "PRIMARY" of table "db"."TABLE_E" trx table locks 10 total table locks 4 trx id 233954711 lock mode S locks rec but not gap lock hold time 41 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_F" trx id 233954711 lock mode IX lock hold time 41 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_G" trx id 233954711 lock mode IS lock hold time 41 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: RECORD LOCKS space id 80850 page no 3 n bits 96 index "PRIMARY" of table "db"."TABLE_G" trx table locks 10 total table locks 4 trx id 233954711 lock mode S locks rec but not gap lock hold time 41 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_H" trx id 233954711 lock mode IS lock hold time 41 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TOO MANY LOCKS PRINTED FOR THIS TRX: SUPPRESSING FURTHER PRINTS 
Oct 31 17:23:40 QA mysqld: ---TRANSACTION 233954594, ACTIVE 42 sec inserting 
Oct 31 17:23:40 QA mysqld: mysql tables in use 1, locked 1 
Oct 31 17:23:40 QA mysqld: LOCK WAIT 19 lock struct(s), heap size 2936, 9 row lock(s), undo log entries 4 
Oct 31 17:23:40 QA mysqld: MySQL thread id 3428053, OS thread handle 0x7efc18dfcb00, query id 40623090 localhost 127.0.0.1 DBUSER 
Oct 31 17:23:40 QA mysqld: insert into TABLE_C (<redacted columns>) values (<redacted values> 
Oct 31 17:23:40 QA mysqld: Trx #rec lock waits 5 #table lock waits 0 
Oct 31 17:23:40 QA mysqld: Trx total rec lock wait time 15 SEC 
Oct 31 17:23:40 QA mysqld: Trx total table lock wait time 0 SEC 
Oct 31 17:23:40 QA mysqld: ------- TRX HAS BEEN WAITING 42 SEC FOR THIS LOCK TO BE GRANTED: 
Oct 31 17:23:40 QA mysqld: RECORD LOCKS space id 80947 page no 9926 n bits 72 index "PRIMARY" of table "db"."TABLE_C" trx table locks 10 total table locks 4 trx id 233954594 lock_mode X insert intention waiting lock hold time 42 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: ------------------ 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_B" trx id 233954594 lock mode IX lock hold time 42 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_C" trx id 233954594 lock mode IX lock hold time 42 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_D" trx id 233954594 lock mode IS lock hold time 42 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: RECORD LOCKS space id 80862 page no 3 n bits 80 index "PRIMARY" of table "db"."TABLE_D" trx table locks 10 total table locks 4 trx id 233954594 lock mode S locks rec but not gap lock hold time 42 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_E" trx id 233954594 lock mode IS lock hold time 42 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: RECORD LOCKS space id 81053 page no 17 n bits 80 index "PRIMARY" of table "db"."TABLE_E" trx table locks 10 total table locks 4 trx id 233954594 lock mode S locks rec but not gap lock hold time 42 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_F" trx id 233954594 lock mode IX lock hold time 42 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_G" trx id 233954594 lock mode IS lock hold time 42 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: RECORD LOCKS space id 80850 page no 3 n bits 96 index "PRIMARY" of table "db"."TABLE_G" trx table locks 10 total table locks 4 trx id 233954594 lock mode S locks rec but not gap lock hold time 42 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_H" trx id 233954594 lock mode IS lock hold time 42 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TOO MANY LOCKS PRINTED FOR THIS TRX: SUPPRESSING FURTHER PRINTS 
Oct 31 17:23:40 QA mysqld: ---TRANSACTION 233954505, ACTIVE 43 sec inserting 
Oct 31 17:23:40 QA mysqld: mysql tables in use 1, locked 1 
Oct 31 17:23:40 QA mysqld: LOCK WAIT 54 lock struct(s), heap size 6544, 79 row lock(s), undo log entries 127 
Oct 31 17:23:40 QA mysqld: MySQL thread id 3428049, OS thread handle 0x7efcab51eb00, query id 40625375 localhost 127.0.0.1 DBUSER 
Oct 31 17:23:40 QA mysqld: insert into TABLE_C (<redacted columns>) values (<redacted values> 
Oct 31 17:23:40 QA mysqld: Trx #rec lock waits 1 #table lock waits 0 
Oct 31 17:23:40 QA mysqld: Trx total rec lock wait time 0 SEC 
Oct 31 17:23:40 QA mysqld: Trx total table lock wait time 0 SEC 
Oct 31 17:23:40 QA mysqld: ------- TRX HAS BEEN WAITING 39 SEC FOR THIS LOCK TO BE GRANTED: 
Oct 31 17:23:40 QA mysqld: RECORD LOCKS space id 80947 page no 9936 n bits 72 index "PRIMARY" of table "db"."TABLE_C" trx table locks 13 total table locks 4 trx id 233954505 lock_mode X insert intention waiting lock hold time 39 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: ------------------ 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_B" trx id 233954505 lock mode IX lock hold time 43 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_C" trx id 233954505 lock mode IX lock hold time 43 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_D" trx id 233954505 lock mode IS lock hold time 43 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: RECORD LOCKS space id 80862 page no 3 n bits 80 index "PRIMARY" of table "db"."TABLE_D" trx table locks 13 total table locks 4 trx id 233954505 lock mode S locks rec but not gap lock hold time 43 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_E" trx id 233954505 lock mode IS lock hold time 43 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: RECORD LOCKS space id 81053 page no 17 n bits 80 index "PRIMARY" of table "db"."TABLE_E" trx table locks 13 total table locks 4 trx id 233954505 lock mode S locks rec but not gap lock hold time 43 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_F" trx id 233954505 lock mode IX lock hold time 43 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_G" trx id 233954505 lock mode IS lock hold time 43 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: RECORD LOCKS space id 80850 page no 3 n bits 96 index "PRIMARY" of table "db"."TABLE_G" trx table locks 13 total table locks 4 trx id 233954505 lock mode S locks rec but not gap lock hold time 43 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TABLE LOCK table "db"."TABLE_H" trx id 233954505 lock mode IS lock hold time 43 wait time before grant 0 
Oct 31 17:23:40 QA mysqld: TOO MANY LOCKS PRINTED FOR THIS TRX: SUPPRESSING FURTHER PRINTS
Allerdings kann ich keine anderen Transaktionen sehen, die eine Sperre für die Tabelle, die Absicht zu halten oder auf andere Weise, so dass ich weiß nicht, was aus einem der Transaktionen verhindert die Sperre zu bekommen.
Gibt es etwas anderes als eine andere Transaktion, die eine Sperre verhindern kann?
Quelle
2017-10-31 ICR
Es kann ein Fall von einem Deadlock in der Lückensperre sein.
TABLE_C hat einen eindeutigen Schlüssel und jede Transaktion fügt mehrere Werte in TABLE_C ein. Jedes Mal, wenn eine Zeile eingefügt wird, erhält sie eine Lückensperre, um sicherzustellen, dass keine andere Transaktion die eindeutige Schlüsseleinschränkung verletzt. Dies könnte dann einen klassischen Deadlock verursachen.
Weiß jemand, ob Lückensperren in der Protokollierung von innodb-Sperren angezeigt würden oder nicht?
http://thushw.blogspot.co.uk/2010/11/mysql-deadlocks-with-concurrent-inserts.html
Quelle
2017-10-31 18:57:33 ICR
Sperre wird nicht akquiriert, obwohl keine anderen Transaktionen das Schloss halten

Antwort

Verwandte Themen
