Details
-
Bug
-
Status: Open (View Workflow)
-
Minor
-
Resolution: Unresolved
-
10.11.14
-
None
Description
In MDEV-37974 it's clear that InnoDB deadlock report incorrectly states the rolled back transaction.
Specifically for the following audit log:
20251027 18:57:53,f6a52a894ee3,root,172.20.0.1,4,5,QUERY,,'SET GLOBAL server_audit_logging=\'ON\'',0
|
20251027 18:57:53,f6a52a894ee3,root,172.20.0.1,4,6,QUERY,,'CREATE DATABASE test',0
|
20251027 18:57:53,f6a52a894ee3,root,172.20.0.1,4,7,QUERY,,'SELECT DATABASE()',0
|
20251027 18:57:53,f6a52a894ee3,root,172.20.0.1,4,9,QUERY,test,'show databases',0
|
20251027 18:57:53,f6a52a894ee3,root,172.20.0.1,4,10,QUERY,test,'show tables',0
|
20251027 18:57:53,f6a52a894ee3,root,172.20.0.1,4,11,QUERY,test,'CREATE TABLE parent (id bigint(20) NOT NULL AUTO_INCREMENT PRIMARY KEY) ENGINE InnoDB',0
|
20251027 18:57:53,f6a52a894ee3,root,172.20.0.1,4,12,QUERY,test,'CREATE TABLE child (id bigint(20) NOT NULL AUTO_INCREMENT PRIMARY KEY,\n parent_id bigint(20) NOT NULL,\n CONSTRAINT `fk_parent`\n FOREIGN KEY (parent_id) REFERENCES parent (id)\n ON DELETE CASCADE\n ON UPDATE RESTRICT\n ) ENGINE InnoDB',0
|
20251027 18:57:53,f6a52a894ee3,root,172.20.0.1,4,13,QUERY,test,'INSERT INTO parent (id) VALUES(1), (2), (3)',0
|
20251027 18:57:53,f6a52a894ee3,root,172.20.0.1,4,14,QUERY,test,'INSERT INTO child (parent_id) VALUES(1), (2), (3)',0
|
20251027 18:58:09,f6a52a894ee3,root,172.20.0.1,3,2,QUERY,,'SELECT DATABASE()',0
|
20251027 18:58:09,f6a52a894ee3,root,172.20.0.1,3,17,QUERY,test,'show databases',0
|
20251027 18:58:09,f6a52a894ee3,root,172.20.0.1,3,18,QUERY,test,'show tables',0
|
20251027 18:58:09,f6a52a894ee3,root,172.20.0.1,3,21,QUERY,test,'START TRANSACTION',0
|
20251027 18:58:11,f6a52a894ee3,root,172.20.0.1,3,22,QUERY,test,'DELETE FROM child WHERE parent_id IN (1, 2, 3)',0
|
20251027 18:58:20,f6a52a894ee3,root,172.20.0.1,4,23,QUERY,test,'SELECT DATABASE()',0
|
20251027 18:58:20,f6a52a894ee3,root,172.20.0.1,4,25,QUERY,test,'START TRANSACTION',0
|
20251027 18:58:30,f6a52a894ee3,root,172.20.0.1,3,27,QUERY,test,'INSERT INTO child (parent_id) VALUES (1)',0
|
20251027 18:58:30,f6a52a894ee3,root,172.20.0.1,4,26,QUERY,test,'DELETE FROM child WHERE parent_id IN (2, 3)',1213
|
20251027 18:58:58,f6a52a894ee3,root,172.20.0.1,4,28,QUERY,test,'SHOW ENGINE INNODB STATUS',0
|
20251027 19:00:51,f6a52a894ee3,root,172.20.0.1,3,0,DISCONNECT,test,,0
|
20251027 19:00:54,f6a52a894ee3,root,172.20.0.1,4,0,DISCONNECT,test,,0
|
it is clear that Connection #4, Query #26 encounters the deadlock (result 1213) and is rolled back.
However the same InnoDB status (Connection #4, Query #28)
*************************** 1. row ***************************
|
Type: InnoDB
|
Name:
|
Status:
|
=====================================
|
2025-10-27 18:58:58 0x7f0b6c0c1640 INNODB MONITOR OUTPUT
|
=====================================
|
Per second averages calculated from the last 53 seconds
|
-----------------
|
BACKGROUND THREAD
|
-----------------
|
srv_master_thread loops: 0 srv_active, 0 srv_shutdown, 113 srv_idle
|
srv_master_thread log flush and writes: 113
|
----------
|
SEMAPHORES
|
----------
|
------------------------
|
LATEST DETECTED DEADLOCK
|
------------------------
|
2025-10-27 18:58:30 0x7f0b6c10c640
|
*** (1) TRANSACTION:
|
TRANSACTION 31, ACTIVE 19 sec inserting
|
mysql tables in use 1, locked 1
|
LOCK WAIT 7 lock struct(s), heap size 1128, 8 row lock(s), undo log entries 4
|
MariaDB thread id 3, OS thread handle 139687034406464, query id 27 172.20.0.1 root Update
|
INSERT INTO child (parent_id) VALUES (1)
|
*** WAITING FOR THIS LOCK TO BE GRANTED:
|
RECORD LOCKS space id 6 page no 4 n bits 320 index fk_parent of table `test`.`child` trx id 31 lock_mode X locks gap before rec insert intention waiting
|
Record lock, heap no 3 PHYSICAL RECORD: n_fields 2; compact format; info bits 32
|
0: len 8; hex 8000000000000002; asc ;;
|
1: len 8; hex 8000000000000002; asc ;;
|
|
|
*** CONFLICTING WITH:
|
RECORD LOCKS space id 6 page no 4 n bits 320 index fk_parent of table `test`.`child` trx id 31 lock_mode X locks rec but not gap
|
Record lock, heap no 3 PHYSICAL RECORD: n_fields 2; compact format; info bits 32
|
0: len 8; hex 8000000000000002; asc ;;
|
1: len 8; hex 8000000000000002; asc ;;
|
|
|
|
|
*** (2) TRANSACTION:
|
TRANSACTION 34, ACTIVE 10 sec starting index read
|
mysql tables in use 1, locked 1
|
LOCK WAIT 2 lock struct(s), heap size 1128, 1 row lock(s)
|
MariaDB thread id 4, OS thread handle 139687034099264, query id 26 172.20.0.1 root Updating
|
DELETE FROM child WHERE parent_id IN (2, 3)
|
*** WAITING FOR THIS LOCK TO BE GRANTED:
|
RECORD LOCKS space id 6 page no 4 n bits 320 index fk_parent of table `test`.`child` trx id 34 lock_mode X waiting
|
Record lock, heap no 3 PHYSICAL RECORD: n_fields 2; compact format; info bits 32
|
0: len 8; hex 8000000000000002; asc ;;
|
1: len 8; hex 8000000000000002; asc ;;
|
|
|
*** CONFLICTING WITH:
|
RECORD LOCKS space id 6 page no 4 n bits 320 index fk_parent of table `test`.`child` trx id 31 lock_mode X locks rec but not gap
|
Record lock, heap no 3 PHYSICAL RECORD: n_fields 2; compact format; info bits 32
|
0: len 8; hex 8000000000000002; asc ;;
|
1: len 8; hex 8000000000000002; asc ;;
|
|
|
*** WE ROLL BACK TRANSACTION (1)
|
------------
|
TRANSACTIONS
|
------------
|
Trx id counter 35
|
Purge done for trx's n:o < 34 undo n:o < 0 state: running but idle
|
History list length 1
|
LIST OF TRANSACTIONS FOR EACH SESSION:
|
---TRANSACTION 31, ACTIVE 47 sec
|
7 lock struct(s), heap size 1128, 8 row lock(s), undo log entries 4
|
MariaDB thread id 3, OS thread handle 139687034406464, query id 27 172.20.0.1 root
|
---TRANSACTION (0x7f0b573feb80), not started
|
0 lock struct(s), heap size 1128, 0 row lock(s)
|
--------
|
FILE I/O
|
--------
|
Pending flushes (fsync): 0
|
157 OS file reads, 0 OS file writes, 15 OS fsyncs
|
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.06 fsyncs/s
|
---
|
LOG
|
---
|
Log sequence number 59282
|
Log flushed up to 59282
|
Pages flushed up to 46846
|
Last checkpoint at 46830
|
----------------------
|
BUFFER POOL AND MEMORY
|
----------------------
|
Total large memory allocated 167772160
|
Dictionary memory allocated 859368
|
Buffer pool size 8112
|
Free buffers 7815
|
Database pages 297
|
Old database pages 0
|
Modified db pages 41
|
Percent of dirty pages(LRU & free pages): 0.505
|
Max dirty pages percent: 90.000
|
Pending reads 0
|
Pending writes: LRU 0, flush list 0
|
Pages made young 0, not young 0
|
0.00 youngs/s, 0.00 non-youngs/s
|
Pages read 149, created 148, written 0
|
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: 297, unzip_LRU len: 0
|
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
|
--------------
|
ROW OPERATIONS
|
--------------
|
0 read views open inside InnoDB
|
state: sleeping
|
----------------------------
|
END OF INNODB MONITOR OUTPUT
|
============================
|
reports "WE ROLLBACK TRANSACTION (1)", where as "transaction 1" is the one with the `INSERT` (Connection #3, Query #27).
InnoDB transaction rollback report is wrong.
Attachments
Issue Links
- relates to
-
MDEV-37974 Improper deadlock with DELETE/DELETE/INSERT
-
- Confirmed
-