| Bug #20134 | deadlock with DELETE/INSERT | ||
|---|---|---|---|
| Submitted: | 30 May 2006 4:10 | Modified: | 14 Jun 2006 15:26 |
| Reporter: | Bradley Baetz | Email Updates: | |
| Status: | Not a Bug | Impact on me: | |
| Category: | MySQL Server: InnoDB storage engine | Severity: | S3 (Non-critical) |
| Version: | 4.1.19 | OS: | Linux (RHEL4) |
| Assigned to: | CPU Architecture: | Any | |
[30 May 2006 4:57]
Valeriy Kravchuk
Thank you for a detailed problem report. Sorry, but it looks like a result of documented "next key locking" algorithm (http://dev.mysql.com/doc/refman/4.1/en/innodb-next-key-locking.html): "When InnoDB scans an index, it can also lock the gap after the last record in the index. Just that happens in the previous example: The locks set by InnoDB prevent any insert to the table where id would be bigger than 100."
[30 May 2006 5:29]
Bradley Baetz
Sure, but I don't have a problem with the lock. The problem is that this is being detected as a deadlock. I'd be happy with one of the queries blocking (well, not happy, but... ;) If I use SELECT * FROM foo WHERE user_id > 1 FOR UPDATE instead of the delete, there isn't any deadlock, so theres something different then that page. This happens under any transaction isolation mode, so its not a side effect of the transaction being serializable.
[30 May 2006 5:59]
Bradley Baetz
innodb_locks_unsafe_for_binlog makes this go away, but since I'm also using replication that doesn't help... However, if the highest isolation mode used is READ COMMITTED (which it is for me), would replication still be unsafe?
[14 Jun 2006 15:26]
Valeriy Kravchuk
I think, manual explains it all in enough details. Read http://dev.mysql.com/doc/refman/4.1/en/innodb-parameters.html, for example: "- innodb_locks_unsafe_for_binlog This variable controls next-key locking in InnoDB searches and index scans. By default, this variable is 0 (disabled), which means that next-key locking is enabled. Normally, InnoDB uses an algorithm called next-key locking. InnoDB performs row-level locking in such a way that when it searches or scans a table index, it sets shared or exclusive locks on any index records it encounters. Thus, the row-level locks are actually index record locks. The locks that InnoDB sets on index records also affect the “gap” preceding that index record. If a user has a shared or exclusive lock on record R in an index, another user cannot insert a new index record immediately before R in the order of the index. Enabling this variable causes InnoDB not to use next-key locking in searches or index scans. Next-key locking is still used to ensure foreign key constraints and duplicate key checking. Note that enabling this variable may cause phantom problems: Suppose that you want to read and lock all children from the child table with an identifier value larger than 100, with the intention of updating some column in the selected rows later: SELECT * FROM child WHERE id > 100 FOR UPDATE; Suppose that there is an index on the id column. The query scans that index starting from the first record where id is larger than 100. If the locks set on the index records do not lock out inserts made in the gaps, another client can insert a new row into the table. If you execute the same SELECT within the same transaction, you see a new row in the result set returned by the query. This also means that if new items are added to the database, InnoDB does not guarantee serializability Therefore, if this variable is enabled InnoDB guarantees at most isolation level READ COMMITTED. (Conflict serializability is still guaranteed.) This variable is available as of MySQL 4.1.4." You need to serialize actions to replicate them properly with the same results. I am closing this report as not a bug. All these is intended and documented behaviour.
Description: Running DELETE/INSERT in multiple processes causes deadlocks, even when there is no overlap in the rows used. How to repeat: Given: CREATE TABLE `foo` ( `user_id` int(11) NOT NULL default '0', UNIQUE KEY `user_id` (`user_id`) ) ENGINE=InnoDB doing in parallel: while (1) { my $user = int(rand(10000))*2 + $flag; $dbh->begin_work; $dbh->do("DELETE FROM foo WHERE user_id = ?", undef, $user); $dbh->do("INSERT INTO foo (user_id) VALUES (?)", undef, $user); $dbh->commit; # Below is not neccessary, but makes it happen much more reliably. # If commented out, truncate the table between tests $dbh->do("DELETE FROM foo WHERE user_id = ?", undef, $user); } will deadlock in 2-60 seconds. (This is a stripped down test case; the original used REPLACE rather than INSERT, FWIW) Uncommenting the commented out line seems to make it happen a bit quicker and more reliably; if you don't do this then you'll need to clear out the table between tests. Note that $flag is set to 0 for one process, and 1 for the other, so there is not any overlap in user_ids between the two processes. This gives: DBD::mysql::db do failed: Deadlock found when trying to get lock; try restarting transaction at foo.pl line 17. and: ===================================== 060530 14:06:09 INNODB MONITOR OUTPUT ===================================== Per second averages calculated from the last 30 seconds ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 124, signal count 107 Mutex spin waits 9281, rounds 169290, OS waits 71 RW-shared spins 1341, OS waits 40; RW-excl spins 986, OS waits 13 ------------------------ LATEST DETECTED DEADLOCK ------------------------ 060530 14:02:41 *** (1) TRANSACTION: TRANSACTION 0 14289879, ACTIVE 0 sec, process no 29753, OS thread id 9227184 inserting mysql tables in use 1, locked 1 LOCK WAIT 3 lock struct(s), heap size 1024 MySQL thread id 25, query id 227391 localhost root update INSERT INTO foo (user_id) VALUES ('2540') *** (1) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 188 page no 4 n bits 680 index `user_id` of table `provisioning/foo` trx id 0 14289879 lock_mode X locks gap before rec insert intention waiting Record lock, heap no 161 PHYSICAL RECORD: n_fields 3; 1-byte offs TRUE; info bits 0 0: len 4; hex 800009fb; asc ;; 1: len 6; hex 000000da0a0e; asc ;; 2: len 7; hex 80000000330084; asc 3 ;; *** (2) TRANSACTION: TRANSACTION 0 14289880, ACTIVE 0 sec, process no 29753, OS thread id 7482288 inserting, thread declared inside InnoDB 500 mysql tables in use 1, locked 1 3 lock struct(s), heap size 1024 MySQL thread id 26, query id 227392 localhost root update INSERT INTO foo (user_id) VALUES ('2539') *** (2) HOLDS THE LOCK(S): RECORD LOCKS space id 188 page no 4 n bits 680 index `user_id` of table `provisioning/foo` trx id 0 14289880 lock_mode X locks gap before rec Record lock, heap no 161 PHYSICAL RECORD: n_fields 3; 1-byte offs TRUE; info bits 0 0: len 4; hex 800009fb; asc ;; 1: len 6; hex 000000da0a0e; asc ;; 2: len 7; hex 80000000330084; asc 3 ;; *** (2) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 188 page no 4 n bits 680 index `user_id` of table `provisioning/foo` trx id 0 14289880 lock_mode X locks gap before rec insert intention waiting Record lock, heap no 161 PHYSICAL RECORD: n_fields 3; 1-byte offs TRUE; info bits 0 0: len 4; hex 800009fb; asc ;; 1: len 6; hex 000000da0a0e; asc ;; 2: len 7; hex 80000000330084; asc 3 ;; *** WE ROLL BACK TRANSACTION (2) ------------ TRANSACTIONS ------------ Trx id counter 0 14295849 Purge done for trx's n:o < 0 14295839 undo n:o < 0 0 History list length 17 Total number of lock structs in row lock hash table 0 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 0 14295784, not started, process no 29753, OS thread id 7482288 MySQL thread id 27, query id 253384 localhost root ---TRANSACTION 0 14295846, not started, process no 29753, OS thread id 6880176 MySQL thread id 14, query id 253436 localhost root ---TRANSACTION 0 14295845, not started, process no 29753, OS thread id 8285104 MySQL thread id 13, query id 253435 localhost root ---TRANSACTION 0 14295844, not started, process no 29753, OS thread id 8084400 MySQL thread id 12, query id 253434 localhost root ---TRANSACTION 0 14251222, not started, process no 29753, OS thread id 7883696 MySQL thread id 11, query id 253439 localhost root show innodb status ---TRANSACTION 0 14295843, not started, process no 29753, OS thread id 7682992 MySQL thread id 10, query id 253433 localhost root ---TRANSACTION 0 14295805, not started, process no 29753, OS thread id 7281584 MySQL thread id 7, query id 253403 localhost root ---TRANSACTION 0 14295804, not started, process no 29753, OS thread id 7080880 MySQL thread id 6, query id 253402 localhost root ---TRANSACTION 0 14295803, not started, process no 29753, OS thread id 6679472 MySQL thread id 4, query id 253401 localhost root ---TRANSACTION 0 14295802, not started, process no 29753, OS thread id 8584112 MySQL thread id 3, query id 253400 localhost root ---TRANSACTION 0 14295848, not started, process no 29753, OS thread id 8977328 MySQL thread id 2, query id 253438 localhost root ---TRANSACTION 0 14295847, not started, process no 29753, OS thread id 6478768 MySQL thread id 1, query id 253437 localhost root -------- FILE I/O -------- I/O thread 0 state: waiting for i/o request (insert buffer thread) I/O thread 1 state: waiting for i/o request (log thread) I/O thread 2 state: waiting for i/o request (read thread) I/O thread 3 state: waiting for i/o request (write thread) Pending normal aio reads: 0, aio writes: 0, ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0 Pending flushes (fsync) log: 0; buffer pool: 0 444 OS file reads, 57724 OS file writes, 57641 OS fsyncs 0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s ------------------------------------- INSERT BUFFER AND ADAPTIVE HASH INDEX ------------------------------------- Ibuf for space 0: size 1, free list len 101, seg size 103, is empty Ibuf for space 0: size 1, free list len 101, seg size 103, 0 inserts, 0 merged recs, 0 merges Hash table size 830173, used cells 18674, node heap has 20 buffer(s) 8.97 hash searches/s, 0.50 non-hash searches/s --- LOG --- Log sequence number 0 1478248928 Log flushed up to 0 1478248928 Last checkpoint at 0 1478248928 0 pending log writes, 0 pending chkp writes 57551 log i/o's done, 0.00 log i/o's/second ---------------------- BUFFER POOL AND MEMORY ---------------------- Total memory allocated 235231786; in additional pool allocated 1048448 Buffer pool size 12800 Free buffers 12280 Database pages 500 Modified db pages 0 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages read 468, created 44, written 374 0.00 reads/s, 0.00 creates/s, 0.00 writes/s Buffer pool hit rate 1000 / 1000 -------------- ROW OPERATIONS -------------- 0 queries inside InnoDB, 0 queries in queue Main thread process no. 29753, id 2856291248, state: waiting for server activity Number of rows inserted 37162, updated 44, deleted 31730, read 367872 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 8.60 reads/s ---------------------------- END OF INNODB MONITOR OUTPUT ============================