CODEWITHSUNDEEP
mysqldeadlockdatabase-deadlocksdatabase-locking
Kevin
Kevin

Reputation: 1697

Mysql Deadlock - Is a transaction waiting on a lock it holds?

I'm having trouble interpreting this deadlock output from MySql (5.7, InnoDB). I understand that the deadlock will eventually be solved by changing application level code, and you can't find the root cause from this snippet. However, hopefully someone will be able to tell me why my interpretation of this MySql diagnostic is incorrect.

------------------------
LATEST DETECTED DEADLOCK
------------------------
2018-04-09 19:41:39 0x2b7323ef1700
*** (1) TRANSACTION:
TRANSACTION 33312589, ACTIVE 16 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 1136, 1 row lock(s)
MySQL thread id 150744, OS thread handle 47781157312256, query id 53141856 ec2-34-250-106-67.eu-west-1.compute.amazonaws.com 34.250.106.67 sc_appuser3 statistics
/* requestId: 11e8-3c2d-fb145a10-b404-0242ac110003 */ SELECT locator FROM policy WHERE locator = 'df0d7ef5-2e14-4664-90b2-2bfb3f35cce2' AND tenant_locator = '8df5d824-6de9-4e21-8135-b19303aec800' FOR UPDATE
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 464385 page no 21 n bits 232 index policy_locator_idx of table `main_1523299445`.`policy` trx id 33312589 lock_mode X locks rec but not gap waiting
Record lock, heap no 41 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
 0: len 30; hex 64663064376566352d326531342d343636342d393062322d326266623366; asc df0d7ef5-2e14-4664-90b2-2bfb3f; (total 36 bytes);
 1: len 30; hex 38646635643832342d366465392d346532312d383133352d623139333033; asc 8df5d824-6de9-4e21-8135-b19303; (total 36 bytes);
 2: len 8; hex 000000000000004e; asc N;;

*** (2) TRANSACTION:
TRANSACTION 33312511, ACTIVE 31 sec starting index read
mysql tables in use 2, locked 2
37 lock struct(s), heap size 3520, 21 row lock(s), undo log entries 10
MySQL thread id 150683, OS thread handle 47773524104960, query id 53142921 ec2-34-250-106-67.eu-west-1.compute.amazonaws.com 34.250.106.67 sc_appuser3 Sending data
/* requestId: 11e8-3c2d-cc07ac92-93f6-0242ac110002 */ UPDATE invoice_schedule iss JOIN policy p on iss.policy_id = p.id SET iss.deleted = TRUE WHERE iss.deleted = FALSE AND iss.scheduled_invoice_locator IS NULL AND (null IS NULL OR iss.start_timestamp >= null) AND p.locator = 'df0d7ef5-2e14-4664-90b2-2bfb3f35cce2' AND iss.tenant_locator = '8df5d824-6de9-4e21-8135-b19303aec800'
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 464385 page no 21 n bits 232 index policy_locator_idx of table `main_1523299445`.`policy` trx id 33312511 lock_mode X locks rec but not gap
Record lock, heap no 41 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
 0: len 30; hex 64663064376566352d326531342d343636342d393062322d326266623366; asc df0d7ef5-2e14-4664-90b2-2bfb3f; (total 36 bytes);
 1: len 30; hex 38646635643832342d366465392d346532312d383133352d623139333033; asc 8df5d824-6de9-4e21-8135-b19303; (total 36 bytes);
 2: len 8; hex 000000000000004e; asc N;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 464385 page no 21 n bits 232 index policy_locator_idx of table `main_1523299445`.`policy` trx id 33312511 lock mode S waiting
Record lock, heap no 41 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
 0: len 30; hex 64663064376566352d326531342d343636342d393062322d326266623366; asc df0d7ef5-2e14-4664-90b2-2bfb3f; (total 36 bytes);
 1: len 30; hex 38646635643832342d366465392d346532312d383133352d623139333033; asc 8df5d824-6de9-4e21-8135-b19303; (total 36 bytes);
 2: len 8; hex 000000000000004e; asc N;;

*** WE ROLL BACK TRANSACTION (1)

To me, it looks like we have two transactions involved in this deadlock. Transaction 2 holds this lock while transaction 1 waits for it:

RECORD LOCKS space id 464385 page no 21 n bits 232 index policy_locator_idx of table `main_1523299445`.`policy` trx id 33312589 lock_mode X locks rec but not gap waiting
Record lock, heap no 41 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
 0: len 30; hex 64663064376566352d326531342d343636342d393062322d326266623366; asc df0d7ef5-2e14-4664-90b2-2bfb3f; (total 36 bytes);
 1: len 30; hex 38646635643832342d366465392d346532312d383133352d623139333033; asc 8df5d824-6de9-4e21-8135-b19303; (total 36 bytes);
 2: len 8; hex 000000000000004e; asc N;;

Now, this is the part I don't understand. Transaction 2 also appears to be waiting on that same lock in S (shared) mode. But, transaction 2 already acquired that lock in X mode, so I don't see why it would need to wait in order to acquire the lock.

  1. Something must be wrong with my interpretation of this diagnostic output. Can anyone point out what is actually going on here?
  2. Is there any other diagnostic information available from MySql that would help me understand what is going on here?

Upvotes: 5

Views: 1396

Answers (1)

Kevin
Kevin

Reputation: 1697

I think the issue is that MySql can not grant a shared record lock if another transaction is waiting for an exclusive grant to that lock, even if the same transaction already has an exclusive grant for that lock.

I haven't found any documentation that directly supports that from MySql, but I can't think of anything else that could be causing this.

Upvotes: 1

Related Questions