Bug #84607 Print more information about deadlocks

• Submitted: 23 Jan 2017 11:41
• Reporter: Sveta Smirnova (OCA)
• Status: Open
• Category: MySQL Server: InnoDB storage engine
• Severity: S4 (Feature request)
• Version: 5.5, 5.6, 5.7, 8.0
• OS: Any
• CPU Architecture: Any

[23 Jan 2017 11:41] Sveta Smirnova

Description:
With option innodb_print_all_deadlocks we can have all deadlocks logged. But only last statements which participate in deadlock are logged while they mostly happen in multiple statement transactions

How to repeat:
Try to uncover what exactly caused this deadlock:

------------------------
LATEST DETECTED DEADLOCK
------------------------
2017-01-23 14:40:21 0x7f7924f99700
*** (1) TRANSACTION:
TRANSACTION 2828, ACTIVE 2 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 1160, 1 row lock(s)
MySQL thread id 5, OS thread handle 140158287841024, query id 14 localhost 127.0.0.1 root updating
DELETE FROM t WHERE i = 1
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 326 n bits 72 index GEN_CLUST_INDEX of table `test`.`t` trx id 2828 lock_mode X waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 6; hex 000000000200; asc       ;;
 1: len 6; hex 000000000b0b; asc       ;;
 2: len 7; hex aa0000014a0110; asc     J  ;;
 3: len 4; hex 80000001; asc     ;;

*** (2) TRANSACTION:
TRANSACTION 2829, ACTIVE 12 sec starting index read
mysql tables in use 1, locked 1
4 lock struct(s), heap size 1160, 3 row lock(s)
MySQL thread id 4, OS thread handle 140158288107264, query id 15 localhost 127.0.0.1 root updating
DELETE FROM t WHERE i = 1
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 0 page no 326 n bits 72 index GEN_CLUST_INDEX of table `test`.`t` trx id 2829 lock mode S
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;

Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 6; hex 000000000200; asc       ;;
 1: len 6; hex 000000000b0b; asc       ;;
 2: len 7; hex aa0000014a0110; asc     J  ;;
 3: len 4; hex 80000001; asc     ;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 326 n bits 72 index GEN_CLUST_INDEX of table `test`.`t` trx id 2829 lock_mode X waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 6; hex 000000000200; asc       ;;
 1: len 6; hex 000000000b0b; asc       ;;
 2: len 7; hex aa0000014a0110; asc     J  ;;
 3: len 4; hex 80000001; asc     ;;

*** WE ROLL BACK TRANSACTION (1)

(For answer see https://dev.mysql.com/doc/refman/5.7/en/innodb-deadlock-example.html)

Suggested fix:
Print previous statements. At least, when P_S statements instrumentation is enabled.