Bug #7975 deadlock without any locking, simple select and update
Submitted: 17 Jan 2005 22:56 Modified: 18 Apr 2005 10:22
Reporter: Corin Langosch Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S3 (Non-critical)
Version:4.1.9, official 686 binary OS:Linux (debian amd64 pure64)
Assigned to: Bugs System CPU Architecture:Any

[17 Jan 2005 22:56] Corin Langosch
Description:
we have the table

CREATE TABLE `user_views` (
  `id` int(10) unsigned NOT NULL default '0',
  `views` int(10) unsigned NOT NULL default '0',
  PRIMARY KEY  (`id`)
) ENGINE=InnoDB DEFAULT CHARSET=latin1 COLLATE=latin1_german1_ci;
        

with about 140.000 rows. the table gets heavily used (80 w/s, 1000 r/s) by only the following two statements:

INSERT INTO user_views (id,views) VALUES ({$id},1) ON DUPLICATE KEY UPDATE views=views+1

and

SELECT views FROM user_views WHERE id={$id}

with autocommit=1

as we had a lot of waiting locking issues using myisam, we converted it into innodb. since that, we get about 50 errors with the following a day:

------------------------
LATEST DETECTED DEADLOCK
------------------------
050117 23:25:39
*** (1) TRANSACTION:
TRANSACTION 0 10296573, ACTIVE 0 sec, process no 27353, OS thread id 50130979 starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 320
MySQL thread id 5861, query id 4719941 213.131.244.141 findmich update
INSERT  INTO user_views (id,views) VALUES (228011,1) ON DUPLICATE KEY UPDATE views=views+1
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 1025 n bits 512 index `PRIMARY` of table `derhut/user_views` trx id 0 10296573 lock_mode X locks rec but not gap waiting
Record lock, heap no 98 PHYSICAL RECORD: n_fields 4; 1-byte offs TRUE; info bits 0
 0: len 4; hex 00037aab; asc   z ;; 1: len 6; hex 0000009d0f55; asc      U;; 2: len 7; hex 0000000bb20084; asc        ;; 3: len 4; hex 00000090; asc     ;;

*** (2) TRANSACTION:
TRANSACTION 0 10295984, ACTIVE 5 sec, process no 1054, OS thread id 74875214 starting index read, thread declared inside InnoDB 500
mysql tables in use 1, locked 1
3 lock struct(s), heap size 320
MySQL thread id 6371, query id 4718404 213.131.244.133 findmich update
INSERT  INTO user_views (id,views) VALUES (228011,1) ON DUPLICATE KEY UPDATE views=views+1
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 0 page no 1025 n bits 512 index `PRIMARY` of table `derhut/user_views` trx id 0 10295984 lock mode S locks rec but not gap
Record lock, heap no 98 PHYSICAL RECORD: n_fields 4; 1-byte offs TRUE; info bits 0
 0: len 4; hex 00037aab; asc   z ;; 1: len 6; hex 0000009d0f55; asc      U;; 2: len 7; hex 0000000bb20084; asc        ;; 3: len 4; hex 00000090; asc     ;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 1025 n bits 512 index `PRIMARY` of table `derhut/user_views` trx id 0 10295984 lock_mode X locks rec but not gap waiting
Record lock, heap no 98 PHYSICAL RECORD: n_fields 4; 1-byte offs TRUE; info bits 0
 0: len 4; hex 00037aab; asc   z ;; 1: len 6; hex 0000009d0f55; asc      U;; 2: len 7; hex 0000000bb20084; asc        ;; 3: len 4; hex 00000090; asc     ;;

*** WE ROLL BACK TRANSACTION (2)

configuration:
--
innodb_additional_mem_pool_size =       16M
innodb_buffer_pool_size         =       1G
innodb_data_file_path           =       ibdata1:10M:autoextend
innodb_thread_concurrency       =       16
innodb_flush_log_at_trx_commit  =       0
innodb_log_buffer_size          =       16M
innodb_log_file_size            =       256M
innodb_log_files_in_group       =       3
innodb_max_dirty_pages_pct      =       90
innodb_lock_wait_timeout        =       30
innodb_locks_unsafe_for_binlog
transaction_isolation   =       READ-COMMITTED
low-priority-updates
--

How to repeat:
create table and generate a lot of traffic
[18 Jan 2005 7:03] Jan Lindström
Thank you for your bug report but this is not a bug. 
This is what happens in your case:

1. Transaction 1 is doing INSERT with ON UPDATE and in constraint check
it set shared (S-lock) to duplicate key.

2. Transaction 2 is also doing INSERT with ON UPDATE and it also in constraint
check sets firts shared (S-lock) to duplicate key and then request an X-lock to
update that row but cannot have it because transaction 1 has conflicting lock.

3. Transaction 2 now tryes to get X-lock on duplicate key to update that row
but cannot have it because we already have conflicting lock for same row.

We could change this behaviour so that only a X-lock is taken when duplicate
key is found when ON UPDATE or ON DELETE constraint is checked. Would you
like to set a feature request to change this behaviour ?

Regards
    JanL
[18 Jan 2005 10:12] Corin Langosch
thanks for your quick response.

yes il'' do so, as i dont see any other real solution to prevent this deadlock. the only possible way would be, to use old fashin select and if a row is found insert new and if not found issue an update. but this is not the "good" way i guess.
[18 Jan 2005 10:13] Corin Langosch
please see above
[18 Jan 2005 12:46] Heikki Tuuri
Jan,

a good idea. If the INSERT operation has a clause 'ON DUPLICATE KEY UPDATE', then do like in REPLACE, and acquire an X-lock on the duplicate key record.

Thank you,

Heikki

http://dev.mysql.com/doc/mysql/en/INSERT.html

INSERT [LOW_PRIORITY | DELAYED | HIGH_PRIORITY] [IGNORE]
    [INTO] tbl_name [(col_name,...)]
    VALUES ({expr | DEFAULT},...),(...),...
    [ ON DUPLICATE KEY UPDATE col_name=expr, ... ]

Or: 

INSERT [LOW_PRIORITY | DELAYED | HIGH_PRIORITY] [IGNORE]
    [INTO] tbl_name
    SET col_name={expr | DEFAULT}, ...
    [ ON DUPLICATE KEY UPDATE col_name=expr, ... ]

Or: 

INSERT [LOW_PRIORITY | DELAYED | HIGH_PRIORITY] [IGNORE]
    [INTO] tbl_name [(col_name
[15 Feb 2005 21:38] Heikki Tuuri
Fixed in 5.0.3.
http://lists.mysql.com/internals/20859
[18 Apr 2005 10:06] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/internals/24102
[18 Apr 2005 10:22] Jan Lindström
Fixed on 4.1.12.
[20 Feb 2007 20:20] Benjamin Morin
We're on 4.1.21-standard-log (OS X) and have what appears to be this exact problem using this table:

CREATE TABLE `visit` (
  `org` int(11) NOT NULL default '0',
  `uuid` varchar(32) NOT NULL default '',
  `vuid` varchar(32) NOT NULL default '',
  `ip` int(11) unsigned default NULL,
  `referrer_host` varchar(100) default NULL,
  `referrer_path` varchar(255) default NULL,
  `search_engine` varchar(25) default NULL,
  `keyword` varchar(100) default NULL,
  `first_page` varchar(100) NOT NULL default '',
  `first_hit` datetime NOT NULL default '0000-00-00 00:00:00',
  `last_page` varchar(100) NOT NULL default '',
  `last_hit` timestamp NOT NULL default '0000-00-00 00:00:00',
  `hit_count` int(10) NOT NULL default '1',
  `sale_gift` int(11) NOT NULL default '0',
  `sale_request` int(11) NOT NULL default '0',
  `email_signup` int(11) NOT NULL default '0',
  `atom_type` tinyint(4) default NULL,
  `atom` int(11) default NULL,
  PRIMARY KEY  (`org`,`uuid`,`vuid`),
  KEY `atom_type` (`atom_type`,`atom`)
) ENGINE=InnoDB DEFAULT CHARSET=latin1;

...and an INSERT ON DUPLICATE UPDATE similar to:

INSERT INTO visit (org, uuid, vuid, ip, referrer_host, referrer_path, search_engine, keyword, first_hit, last_hit, first_page, last_page, atom_type, atom) SELECT org, 'b9331d577210d7a4fde01a880e427e51', 'cd117055f1847d74ed3e894d97d28657', inet_aton('70.242.194.240'), '', '', '', '', '2007-02-13 17:24:23', '2007-02-13 17:24:23', 'buy-spa-gift-certificates', 'buy-spa-gift-certificates', 0, 0 FROM org JOIN client_address ON org.client = client_address.client AND address_type = 0 WHERE id = 'spaemergency' ON DUPLICATE KEY UPDATE hit_count = hit_count+1, last_page = 'buy-spa-gift-certificates', last_hit = '2007-02-13 17:24:23'

...creates a LATEST DETECTED DEADLOCK like this one (a different occurrence):

070213 10:24:27
*** (1) TRANSACTION:
TRANSACTION 0 28063215, ACTIVE 62 sec, OS thread id 30779904 starting index read, thread declared inside InnoDB 499
mysql tables in use 3, locked 3
LOCK WAIT 9 lock struct(s), heap size 1024
MySQL thread id 353546, query id 68051079 kutzeddi 192.168.0.191 root Sending data
INSERT INTO visit (org, uuid, vuid, ip, referrer_host, referrer_path, search_engine, keyword, first_hit, last_hit, first_page, last_page, atom_type, atom) SELECT org, '331f1a5a2c6b04147d79f992264ab4e5', 'ac7df2a58866f464a151bb2cffbb21bc', inet_aton('70.251.70.29'), '', '', '', '', '2007-02-13 17:23:
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 102425 n bits 112 index `PRIMARY` of table `sevence/visit` trx id 0 28063215 lock_mode X locks rec but not gap waiting
Record lock, heap no 44 PHYSICAL RECORD: n_fields 20; 1-byte offs FALSE; info bits 0
 0: len 4; hex 80000088; asc     ;; 1: len 30; hex 333331663161356132633662303431343764373966393932323634616234; asc 331f1a5a2c6b04147d79f992264ab4;...(truncated); 2: len 30; hex 616337646632613538383636663436346131353162623263666662623231; asc ac7df2a58866f464a151bb2cffbb21;...(truncated); 3: len 6; hex 000001ac351a; asc     5 ;; 4: len 7; hex 000001c02d0084; asc     -  ;; 5: len 4; hex 46fb461d; asc F F ;; 6: len 18; hex 636f6f7065726165726f626963732e636f6d; asc cooperaerobics.com;; 7: len 5; hex 2f7370612f; asc /spa/;; 8: len 0; hex ; asc ;; 9: len 0; hex ; asc ;; 10: len 5; hex 6c67696674; asc lgift;; 11: len 8; hex 80001240f5ed35b8; asc    @  5 ;; 12: len 5; hex 6c67696674; asc lgift;; 13: len 4; hex 45d25664; asc E Vd;; 14: len 4; hex 80000003; asc     ;; 15: len 4; hex 80000000; asc     ;; 16: len 4; hex 80000000; asc     ;; 17: len 4; hex 80000000; asc     ;; 18: len 1; hex 80; asc  ;; 19: len 4; hex 80000000; asc     ;;

*** (2) TRANSACTION:
TRANSACTION 0 28063504, ACTIVE 30 sec, OS thread id 32451584 starting index read, thread declared inside InnoDB 500
mysql tables in use 3, locked 3
9 lock struct(s), heap size 1024
MySQL thread id 353577, query id 68051637 kutzeddi 192.168.0.191 root Sending data
INSERT INTO visit (org, uuid, vuid, ip, referrer_host, referrer_path, search_engine, keyword, first_hit, last_hit, first_page, last_page, atom_type, atom) SELECT org, '331f1a5a2c6b04147d79f992264ab4e5', 'ac7df2a58866f464a151bb2cffbb21bc', inet_aton('70.251.70.29'), '', '', '', '', '2007-02-13 17:23:
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 0 page no 102425 n bits 112 index `PRIMARY` of table `sevence/visit` trx id 0 28063504 lock mode S locks rec but not gap
Record lock, heap no 44 PHYSICAL RECORD: n_fields 20; 1-byte offs FALSE; info bits 0
 0: len 4; hex 80000088; asc     ;; 1: len 30; hex 333331663161356132633662303431343764373966393932323634616234; asc 331f1a5a2c6b04147d79f992264ab4;...(truncated); 2: len 30; hex 616337646632613538383636663436346131353162623263666662623231; asc ac7df2a58866f464a151bb2cffbb21;...(truncated); 3: len 6; hex 000001ac351a; asc     5 ;; 4: len 7; hex 000001c02d0084; asc     -  ;; 5: len 4; hex 46fb461d; asc F F ;; 6: len 18; hex 636f6f7065726165726f626963732e636f6d; asc cooperaerobics.com;; 7: len 5; hex 2f7370612f; asc /spa/;; 8: len 0; hex ; asc ;; 9: len 0; hex ; asc ;; 10: len 5; hex 6c67696674; asc lgift;; 11: len 8; hex 80001240f5ed35b8; asc    @  5 ;; 12: len 5; hex 6c67696674; asc lgift;; 13: len 4; hex 45d25664; asc E Vd;; 14: len 4; hex 80000003; asc     ;; 15: len 4; hex 80000000; asc     ;; 16: len 4; hex 80000000; asc     ;; 17: len 4; hex 80000000; asc     ;; 18: len 1; hex 80; asc  ;; 19: len 4; hex 80000000; asc     ;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 102425 n bits 112 index `PRIMARY` of table `sevence/visit` trx id 0 28063504 lock_mode X locks rec but not gap waiting
Record lock, heap no 44 PHYSICAL RECORD: n_fields 20; 1-byte offs FALSE; info bits 0
 0: len 4; hex 80000088; asc     ;; 1: len 30; hex 333331663161356132633662303431343764373966393932323634616234; asc 331f1a5a2c6b04147d79f992264ab4;...(truncated); 2: len 30; hex 616337646632613538383636663436346131353162623263666662623231; asc ac7df2a58866f464a151bb2cffbb21;...(truncated); 3: len 6; hex 000001ac351a; asc     5 ;; 4: len 7; hex 000001c02d0084; asc     -  ;; 5: len 4; hex 46fb461d; asc F F ;; 6: len 18; hex 636f6f7065726165726f626963732e636f6d; asc cooperaerobics.com;; 7: len 5; hex 2f7370612f; asc /spa/;; 8: len 0; hex ; asc ;; 9: len 0; hex ; asc ;; 10: len 5; hex 6c67696674; asc lgift;; 11: len 8; hex 80001240f5ed35b8; asc    @  5 ;; 12: len 5; hex 6c67696674; asc lgift;; 13: len 4; hex 45d25664; asc E Vd;; 14: len 4; hex 80000003; asc     ;; 15: len 4; hex 80000000; asc     ;; 16: len 4; hex 80000000; asc     ;; 17: len 4; hex 80000000; asc     ;; 18: len 1; hex 80; asc  ;; 19: len 4; hex 80000000; asc     ;;

*** WE ROLL BACK TRANSACTION (2)

Does it appear that this is the same problem?  It certainly appears to be.
[9 Nov 2011 10:21] Marko Mäkelä
Some of this was apparently broken in MySQL 5.1 when implementing the pluggable storage engine interface. REPLACE and INSERT...ON DUPLICATE KEY UPDATE would not X-lock the existing record, but only S-lock it.
[20 Jan 2014 11:41] Marko Mäkelä
The regression in MySQL 5.1 was filed and fixed as
Bug#52020 InnoDB can still deadlock on just INSERT...ON DUPLICATE KEY