Hi,

I'd really appreciate help with reading this db deadlock notice.
Essentially, I'd like to understand:
-what holds the lock that TX2 is waiting on index `token` of table
`eviltwin/user_sessions`? I thought it'd be TX1 (hence deadlock ?), yet
it appears that TX1 holds no locks....
-if the answer to the above cannot be found in attached report, is there
a setting I should turn on the server to get the necessary info next
time this deadlock occurs?

Our setup: MySQL 5, InnoDB, Repeatable Read

relevant columns in table user_sessions:
-id (PK)
-token (unique, nullable)
-serverSessionId (FK, nullable)

TX1 does:
-select for update on a given 'token'
-set serverSessionId to null

TX2 does:
-select for update on the same 'token'
-delete selected record

TX2 seems to start a little earlier, and succeed on 'select for update'.
TX1 then tries to do the same and is forced to wait on a lock. This I
understand.
But why does TX2 need to wait on a lock to deleted already 'selected for
update' user_session? Who's holding that lock?

thanks,
-nikita

*************************** 1. row ***************************
Status:
=====================================
070402 12:24:38 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 29 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 6313003, signal count 5099409
Mutex spin waits 819355967, rounds 1424470313, OS waits 4424501
RW-shared spins 1000685, OS waits 629116; RW-excl spins 760423, OS waits 175362
------------------------
LATEST DETECTED DEADLOCK
------------------------
070402 12:22:41
*** (1) TRANSACTION:
TRANSACTION 0 12012950, ACTIVE 0 sec, process no 7328, OS thread id 1161120096 starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1216
MySQL thread id 93849, query id 1913636508 lf20.eviltwinstudios.net 192.168.100.163 eviltwin Sending data
select usersessio0_.id as id37_, usersessio0_.hibernateVersion as hibernat2_37_, usersessio0_.serverSessionId as serverSe3_37_, usersessio0_.userId as userId37_, usersessio0_.loginTime as loginTime37_, usersessio0_.logoutTime as logoutTime37_, usersessio0_.boot as boot37_, usersessio0_.tokenas token37_, usersessio0_.macAddressMD5 as macAddre9_37_, usersessio0_.expirationTime as expirat10_37_, usersessio0_.creationDate as creatio11_37_ from user_sessions usersessio0_ where usersessio0_.token='82ff6193-1216-449a-9e33-5426fb8e10ef' for update
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 130062 n bits 144 index `PRIMARY` of table `eviltwin/user_sessions` trx id 0 12012950 lock_mode X locks rec but not gap waiting
Record lock, heap no 9 PHYSICAL RECORD: n_fields 13; compact format; infobits 32
0: len 30; hex 37653530373061382d393537362d343363352d623138342d65 6266633763; asc 7e5070a8-9576-43c5-b184-ebfc7c;...(truncated); 1: len 6; hex 000000b74d95; asc M ;; 2: len 7; hex 000000803c29ee; asc <) ;; 3: len 4; hex 80000001; asc ;; 4: len 30; hex 39373939383430622d323938372d346630382d613539342d66 3736303831; asc 9799840b-2987-4f08-a594-f76081;...(truncated); 5: len 30; hex 34343431316237362d386663312d343332652d386332342d65 3837646433; asc 44411b76-8fc1-432e-8c24-e87dd3;...(truncated); 6: len8; hex 80001241013060af; asc A 0` ;; 7: SQL NULL; 8: len 1; hex 00; asc ;; 9: len 30; hex 38326666363139332d313231362d343439612d396533332d35 3432366662; asc 82ff6193-1216-449a-9e33-5426fb;...(truncated); 10: len 30;hex 62653637616563323661316363613261646566666161613537 3430646130; asc be67aec26a1cca2adeffaaa5740da0;...(truncated); 11: len 8; hex 80001241014ee557; asc A N W;; 12: len 8; hex 80001241013060af; asc A 0` ;;

*** (2) TRANSACTION:
TRANSACTION 0 12012949, ACTIVE 0 sec, process no 7328, OS thread id 1182153056 updating or deleting, thread declared inside InnoDB 499
mysql tables in use 1, locked 1
8 lock struct(s), heap size 1216, undo log entries 3
MySQL thread id 93773, query id 1913636516 lf20.eviltwinstudios.net 192.168.100.163 eviltwin updating
delete from user_sessions where id='7e5070a8-9576-43c5-b184-ebfc7c288d69' and hibernateVersion=1
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 0 page no 130062 n bits 144 index `PRIMARY` of table `eviltwin/user_sessions` trx id 0 12012949 lock_mode X locks rec but not gap
Record lock, heap no 9 PHYSICAL RECORD: n_fields 13; compact format; infobits 32
0: len 30; hex 37653530373061382d393537362d343363352d623138342d65 6266633763; asc 7e5070a8-9576-43c5-b184-ebfc7c;...(truncated); 1: len 6; hex 000000b74d95; asc M ;; 2: len 7; hex 000000803c29ee; asc <) ;; 3: len 4; hex 80000001; asc ;; 4: len 30; hex 39373939383430622d323938372d346630382d613539342d66 3736303831; asc 9799840b-2987-4f08-a594-f76081;...(truncated); 5: len 30; hex 34343431316237362d386663312d343332652d386332342d65 3837646433; asc 44411b76-8fc1-432e-8c24-e87dd3;...(truncated); 6: len8; hex 80001241013060af; asc A 0` ;; 7: SQL NULL; 8: len 1; hex 00; asc ;; 9: len 30; hex 38326666363139332d313231362d343439612d396533332d35 3432366662; asc 82ff6193-1216-449a-9e33-5426fb;...(truncated); 10: len 30;hex 62653637616563323661316363613261646566666161613537 3430646130; asc be67aec26a1cca2adeffaaa5740da0;...(truncated); 11: len 8; hex 80001241014ee557; asc A N W;; 12: len 8; hex 80001241013060af; asc A 0` ;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 130063 n bits 240 index `token` of table `eviltwin/user_sessions` trx id 0 12012949 lock_mode X locks rec but not gap waiting
Record lock, heap no 159 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 38326666363139332d313231362d343439612d396533332d35 3432366662; asc 82ff6193-1216-449a-9e33-5426fb;...(truncated); 1: len 30; hex 37653530373061382d393537362d343363352d623138342d65 6266633763; asc 7e5070a8-9576-43c5-b184-ebfc7c;...(truncated);

*** WE ROLL BACK TRANSACTION (1)
------------
TRANSACTIONS
------------
Trx id counter 0 12013755
Purge done for trx's n < 0 12013741 undo n < 0 0
History list length 12
Total number of lock structs in row lock hash table 0

"Nikita Tovstoles" <nikita@doppelganger.com> wrote in message
news:4611F8A4.2030403@doppelganger.com...

Do both of your SELECT statements use the same index (`token`) when setting
locks on the rows? My guess is that the situation is as follows.

TX2: SELECT ... WHERE id = ... FOR UPDATE
TX2 sets an exclusive lock for a row on PRIMARY index.

TX1: SELECT ... WHERE token = ... FOR UPDATE
TX1 tries to acquire X-lock for a row in `token` index, which succedes. This
however requires also a lock on PRIMARY, but the corresponding row on that
index is already locked by TX2. TX1 waits.

TX2: DELETE ... WHERE id = ...
TX2 tries to delete the row. This of course requires the removal of its
presence in the indxexes, including `token`, but because of the earlier
exclusive lock set by TX1 this cannot be accomplished without waiting for
the lock to be freed. TX2 waits.

Hence, the deadlock.


I'm wondering if granting X-locks for the secondary indexes could not be
delayed until such lock on the primary key is acquired...?

Maciek