Deadlock in JobLogging DB
- Dominant language
- Python
- Stars
- 126
- Forks
- 191
- Avg merge
- 1d 13h
- Merged PRs (30d)
- 33
Description
TLDR: the trigger for the `SeqNum` causes a deadlock
This is not a rare event, it happens several thousand times a day in LHCb
This is how the SeqNum is defined.
https://github.com/DIRACGrid/DIRAC/blob/fddfcf960ed06a12283ba251bf6308da9affc9b7/src/DIRAC/WorkloadManagementSystem/DB/JobLoggingDB.sql#L44-L45
This is what we see in the application log
```
2025-06-12T13:28:55,773492Z WorkloadManagement/JobManager/WorkloadManagement/JobLoggingDB ERROR: _updatemany (INSERT INTO LoggingInfo (JobId, Status, MinorStatus, ApplicationStatus, StatusTime, StatusTimeOrder, StatusSource) VALUES (%s, %s, %s, %s, %s, %s, %s)): Execution failed. 1213: Deadlock found when trying to get lock; try restarting transaction
```
This is what we see in MySQL
```
------------------------
LATEST DETECTED DEADLOCK
------------------------
2025-06-12 16:28:40 140619980732160
*** (1) TRANSACTION:
TRANSACTION 5013963481, ACTIVE 0 sec inserting
mysql tables in use 2, locked 2
LOCK WAIT 4 lock struct(s), heap size 1128, 3 row lock(s)
MySQL thread id 12893884, OS thread handle 140564968916736, query id 32232881775 lbvobox308.cern.ch 188.185.73.26 Dirac
INSERT INTO LoggingInfo (JobId, Status, MinorStatus, ApplicationStatus, StatusTime, StatusTimeOrder, StatusSource) VALUES (1125080145, 'Checking', 'JobSanity', 'idem', '2025-06-12 14:28:40.008487', 479738520.008487e0, 'JobPath')
*** (1) HOLDS THE LOCK(S):
RECORD LOCKS space id 26 page no 3635447 n bits 264 index PRIMARY of table `JobLoggingDB`.`LoggingInfo` trx id 5013963481 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 197 PHYSICAL RECORD: n_fields 10; compact format; info bits 0
0: len 4; hex c30f5c51; asc \Q;;
1: len 4; hex 80000001; asc ;;
2: len 6; hex 00012adb01de; asc * ;;
3: len 7; hex 8200001fbd0110; asc ;;
4: len 8; hex 5265636569766564; asc Received;;
5: len 12; hex 4a6f62206163636570746564; asc Job accepted;;
6: len 4; hex 6964656d; asc idem;;
7: len 5; hex 99b6d8e728; asc (;;
8: len 8; hex b072c8973a98bc41; asc r : A;;
9: len 10; hex 4a6f624d616e61676572; asc JobManager;;
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 26 page no 3635447 n bits 264 index PRIMARY of table `JobLoggingDB`.`LoggingInfo` trx id 5013963481 lock_mode X insert intention waiting
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
0: len 8; hex 73757072656d756d; asc supremum;;
*** (2) TRANSACTION:
TRANSACTION 5013963474, ACTIVE 0 sec inserting
mysql tables in use 2, locked 2
LOCK WAIT 4 lock struct(s), heap size 1128, 3 row lock(s)
MySQL thread id 12891862, OS thread handle 140566792476416, query id 32232881751 lbvobox300.cern.ch 137.138.150.133 Dirac
INSERT INTO LoggingInfo (JobId, Status, MinorStatus, ApplicationStatus, StatusTime, StatusTimeOrder, StatusSource) VALUES (1125080146, 'Received', 'Job accepted', 'idem', '2025-06-12 14:28:40.177626', 479738520.1776259e0, 'JobManager')
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 26 page no 3635447 n bits 264 index PRIMARY of table `JobLoggingDB`.`LoggingInfo` trx id 5013963474 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 197 PHYSICAL RECORD: n_fields 10; compact format; info bits 0
0: len 4; hex c30f5c51; asc \Q;;
1: len 4; hex 80000001; asc ;;
2: len 6; hex 00012adb01de; asc * ;;
3: len 7; hex 8200001fbd0110; asc ;;
4: len 8; hex 5265636569766564; asc Received;;
5: len 12; hex 4a6f62206163636570746564; asc Job accepted;;
6: len 4; hex 6964656d; asc idem;;
7: len 5; hex 99b6d8e728; asc (;;
8: len 8; hex b072c8973a98bc41; asc r : A;;
9: len 10; hex 4a6f624d616e61676572; asc JobManager;;
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 26 page no 3635447 n bits 264 index PRIMARY of table `JobLoggingDB`.`LoggingInfo` trx id 5013963474 lock_mode X insert intention waiting
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
0: len 8; hex 73757072656d756d; asc supremum;;
*** WE ROLL BACK TRANSACTION (2)
```
* Both transactions are holding a shared (S) lock on the PRIMARY index of the LoggingInfo table.
* Both transactions are waiting for an exclusive (X) lock to perform their insert operations.
The details are explained in [here](https://stackoverflow.com/questions/54816599/mysql-deadlocks-with-composite-primary-key-and-trigger-autoincrement) better than I could.
To the best of my knowledge, this `SeqNum` is not even used !
Possible solutions:
* replace `SeqNum` with a random number, but has the possibility to clash
* replace `SeqNum` with a time based UUID
* remove `SeqNum` altogether, meaning having another primary key, which again could be a UUID (possibly 7 in that case)
Contributor guide
Assessment
This issue has not been assessed yet.