Bug #48029 Deadlock between INSERT...ON DUPLICATE KEY... and DELETE on InnoDB
Submitted: 13 Oct 2009 19:30 Modified: 13 Nov 2009 19:55
Reporter: Wei Shao Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S3 (Non-critical)
Version:5.1.34 OS:Linux
Assigned to: CPU Architecture:Any
Tags: innodb, locking

[13 Oct 2009 19:30] Wei Shao
Description:
We had a frequent deadlocks between DELETE and INSERT...ON DUPLICATE KEY... statements (see InnoDB status output below). The DELETE and INSERT statements conflict on the same record when the deadlock happened.

As explained in http://dev.mysql.com/doc/refman/5.1/en/innodb-locks-set.html, INSERT statement should first get a insertion intention gap lock then the index-record lock on the inserted row. But from the deadlock report, it seems the documented locking sequence is not correct. Instead, the INSERT statement seems to acquire the index-record record first and then the insertion intention gap lock. The following is the sequence that I am guessing:

1: INSERT transaction acquired index-record lock
2: DELETE transaction was in the middle of setting next-key lock and had locked the gap but blocked on the index-record lock
3: INSERT transaction tried to set the insertion intention lock and was blocked by the DELETE transaction

Is this the case? If so, can you suggest a solution to this problem?

Thank you,
Wei Shao

*************************** 1. row ***************************
  Type: InnoDB
  Name: 
Status: 
=====================================
091013 10:13:52 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 46 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 1310323, signal count 1203927
Mutex spin waits 0, rounds 100391859, OS waits 616558
RW-shared spins 614517, OS waits 270301; RW-excl spins 777136, OS waits 306031
------------------------
LATEST DETECTED DEADLOCK
------------------------
091012 18:09:31
*** (1) TRANSACTION:
TRANSACTION 0 663867080, ACTIVE 0 sec, process no 19444, OS thread id 1319291216 starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 368, 1 row lock(s)
MySQL thread id 20803, query id 313854913 asterbot1.asterpix.com 10.6.4.20 asterpix updating
DELETE FROM cloud_servicequeue
      WHERE pub_id= NAME_CONST('pid',2128701) AND referer_hash1= NAME_CONST('hash1',_binary'??5???\0' COLLATE 'binary') AND referer_hash2= NAME_CONST('hash2',_binary'????z?-' COLLATE 'binary') AND qsource= NAME_CONST('qsrc',_latin1'txtdoms1' COLLATE 'latin1_swedish_ci') COLLATE latin1_general_ci AND inst_id= NAME_CONST('tid',2416931)
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 98 page no 4 n bits 280 index `cloud_servicequeue_pk` of table `asterpix`.`cloud_servicequeue` trx id 0 663867080 lock_mode X waiting
Record lock, heap no 201 PHYSICAL RECORD: n_fields 5; compact format; info bits 32
 0: len 8; hex d70c8a35dcc4e500; asc    5    ;; 1: len 8; hex 7ffa868bda7a3f2d; asc      z?-;; 2: len 4; hex 80207b3d; asc   {=;; 3: len 8; hex 747874646f6d7331; asc txtdoms1;; 4: len 6; hex 000001faddfd; asc       ;;

*** (2) TRANSACTION:
TRANSACTION 0 663867079, ACTIVE 0 sec, process no 19444, OS thread id 1172060496 inserting, thread declared inside InnoDB 500
mysql tables in use 1, locked 1
3 lock struct(s), heap size 1216, 3 row lock(s), undo log entries 1
MySQL thread id 20479, query id 313854904 app7.asterpix.com 10.6.3.207 asterpix update
INSERT INTO cloud_servicequeue (referer, referer_hash1, referer_hash2, pub_id, qsource, inst_id, enqueue_time) VALUES ('http://www.consumeraffairs.com/news04/2008/04/fl_cruise_charges.html', 15296269159764312983, 15810000434707798294, 2128701, 'txtdoms1', '2416931', NOW()) ON DUPLICATE KEY UPDATE count = count + 1
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 98 page no 4 n bits 280 index `cloud_servicequeue_pk` of table `asterpix`.`cloud_servicequeue` trx id 0 663867079 lock_mode X
Record lock, heap no 178 PHYSICAL RECORD: n_fields 5; compact format; info bits 32
 0: len 8; hex d44743c1f883c397; asc  GC     ;; 1: len 8; hex db6867a161879916; asc  hg a   ;; 2: len 4; hex 80207b3d; asc   {=;; 3: len 8; hex 747874646f6d7331; asc txtdoms1;; 4: len 6; hex 000001fadde5; asc       ;;

Record lock, heap no 201 PHYSICAL RECORD: n_fields 5; compact format; info bits 32
 0: len 8; hex d70c8a35dcc4e500; asc    5    ;; 1: len 8; hex 7ffa868bda7a3f2d; asc      z?-;; 2: len 4; hex 80207b3d; asc   {=;; 3: len 8; hex 747874646f6d7331; asc txtdoms1;; 4: len 6; hex 000001faddfd; asc       ;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 98 page no 4 n bits 280 index `cloud_servicequeue_pk` of table `asterpix`.`cloud_servicequeue` trx id 0 663867079 lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 201 PHYSICAL RECORD: n_fields 5; compact format; info bits 32
 0: len 8; hex d70c8a35dcc4e500; asc    5    ;; 1: len 8; hex 7ffa868bda7a3f2d; asc      z?-;; 2: len 4; hex 80207b3d; asc   {=;; 3: len 8; hex 747874646f6d7331; asc txtdoms1;; 4: len 6; hex 000001faddfd; asc       ;;

*** WE ROLL BACK TRANSACTION (1)
------------

How to repeat:
Timing dependent and hard to reproduce
[13 Oct 2009 19:55] MySQL Verification Team
Thank you for the bug report. Could you please try the latest released version and comment the result here. Thanks in advance.
[14 Nov 2009 0:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".