Here is what I am seeing
I see three queries, all almost identical.
UPDATE people SET company_id = 1610, name = '<name>', password = '<hash>',
temp_password = NULL, reset_password_hash = NULL, email = '<redacted>@yahoo.com',
phone = NULL, mobile = '<phone>', iphone_device_id = 'android:<id>-<id>',
iphone_device_time = '2011-06-06 05:35:09', last_checkin = '2011-06-06 05:24:42',
location_lat = <lat>, location_long = -<lng>, gps_strength = 3296,
picture_blob_id = 1190,authority = 1, active = 1,
date_created = '2011-04-13 20:21:20',
last_login = '2011-06-06 05:35:09', panic_mode = 0, battery_level = NULL,
battery_state = NULL WHERE people_id = 3125;
The differences
TRANSACTION 1
iphone_device_time = '2011-06-06 05:24:42', last_checkin = '2011-06-06 05:35:07'
TRANSACTION 2
iphone_device_time = '2011-06-06 05:35:09', last_checkin = '2011-06-06 05:24:42'
Please notice that the column values are flipped. Normally, a deadlock occurs when two different transactions are accessing two locks from two tables with TX1 (Transaction 1) getting row A and then row B while TX2 is getting row B and then row A. In this case, it is TX1 and TX2 are accessing the same row but changing two different columns (iphone_device_time,last_checkin).
The values do not make any sense. At 5:24:42, your last checkin was 5:35:07. Ten minutes and 27 seconds later (5:35:07 - 05:24:42), the column values are reversed.
The big question is: Why is TX1 held up for almost 11 min ???
This is not really an answer. This is just bandwidth and throughout from me. I hope these observations help.
UPDATE 2011-06-06 09:57
Please check out this link concerning innodb_locks_unsafe_for_binlog : The reason I suggest reading this is something else I saw in your INNODB STATUS display. The phrase lock_mode X (exclusive lock) and lock_mode S (shared lock) indicates both locks being imposed (or attempting to impose) on the same row . There may be some internal serialization going on doing next row locking. The default is OFF. After reading this, you may need to consider enabling it.
UPDATE 2011-06-06 10:03
Another reason to examine this line of thought is the fact that all the transactions are traversing the PRIMARY key. Since the PRIMARY is a clustered index in InnoDB, the PRIMARY key and the row itself are together. Thus, traversing a row and and the PRIMARY KEY are one and the same. Therefore, any index lock on the PRIMARY KEY is a row level lock as well.
UPDATE 2011-06-06 19:21
Check what auocommit value you have. If autocommit is off, I can see two(2) possible problems
- updating the same row twice in the same transaction
- updating the same row in two different transactions
In fact, the SHOW ENGINE INNODB STATUS you show in the question has exactly both scenarios.
I think that the problem must be searched is into the insert ignore statements.
It is multiinsert, and I presume it has the same effect of executing the rolling out statements in sequence. It is a single statements but it is the same of executing multiple statements. So the locks will be acquired step by step. Furthermore the clause on duplicate key update has the effect
to acquire more locks when it is fired.
Let me try to explain it. I guess what happened from the show engine innodb status. We have two transactions T1 and T2, I have extracted the last statements of each transactions from the log. For clarity, I have truncated the queries and added the missing part from the comments.
T1:
UPDATE indicators.filesi fi
JOIN(
SELECT fo.sha256
FROM indicators.filesoi foi
JOIN indicators.fileso fo ON foi.uniqueness = fo.uniqueness
WHERE fo.lastSeen > '2016-03-16 11:10:22' ...
) x ON x.sha256=fi.sha256
T2:
INSERT IGNORE INTO indicators.fileso (hostId, ...)
VALUES
('8662', ...),
('9143', ...),
on duplicate key update ....
From the log, I supposed the lock are acquired in the following sequence.
Time 1
T2 starts to execute and acquire a lock on single index record in exclusive mode, but it don't acquire the gap between indexes record. Maybe the on duplicate key was fired.
RECORD LOCKS space id 859892 page no 1508578 n bits 888
index `lastSeen` of table `indicators`.`fileso` trx id 2264758569
lock_mode X locks rec but not gap
Time 2
T1 starts and it stops trying to acquire a shared lock on the same records of T2. Maybe at the end of the index because the condition contains lastSeen > ...
RECORD LOCKS space id 859892 page no 1508578 n bits 888
index `lastSeen` of table `indicators`.`fileso` trx id 2264758566
lock mode S waiting
Time 3
T2 tries to acquire another lock, but it finds T1 waiting for a shared lock on the same page.
RECORD LOCKS space id 859892 page no 1508578 n bits 904
index `lastSeen` of table `indicators`.`fileso` trx id 2264758569
lock_mode X locks gap before rec insert intention waiting
Deadlock is detects.
I have tried to replicate the behavior. I don't know if I have got it right.
CREATE TABLE t (
`i1` int(11) NOT NULL,
`i2` int(11) DEFAULT NULL,
PRIMARY KEY (`i1`)
) ENGINE=InnoDB;
insert into t values(10,10), (20,20), (30,30), (40, 40), (50,50),(60,60);
let starts session 2. We try to simulate T2 (insert ignore)
session2> begin;
Query OK, 0 rows affected (0.00 sec)
session2> update t set i2=60 where i1=60;
Query OK, 0 rows affected (0.00 sec)
Rows matched: 1 Changed: 0 Warnings: 0
switch to the session 1, try to simulate T1
session1> begin;
Query OK, 0 rows affected (0.00 sec)
session1> select * from t where i1 >= 50 lock in share mode;
<session1 blocked>
in the session2 we try to acquire a gap lock:
session2> insert t values(55,55);
ERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transaction
There is the output of show engine innodb status:
------------------------
LATEST DETECTED DEADLOCK
------------------------
2016-03-17 18:38:51 0x700000e61000
*** (1) TRANSACTION:
TRANSACTION 281479505194560, ACTIVE 178 sec fetching rows
mysql tables in use 1, locked 1
LOCK WAIT 4 lock struct(s), heap size 1136, 3 row lock(s)
MySQL thread id 2, OS thread handle 123145316274176, query id 1644 localhost msandbox Sending data
select * from t where i1 >= 50 lock in share mode
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 38 page no 3 n bits 80 index PRIMARY of table `test_dbaexchange`.`t` trx id 281479505194560 lock mode S waiting
Record lock, heap no 7 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
0: len 4; hex 8000003c; asc <;;
1: len 6; hex 000000001008; asc ;;
2: len 7; hex 2f00000147048c; asc / G ;;
3: len 4; hex 8000003c; asc <;;
*** (2) TRANSACTION:
TRANSACTION 4104, ACTIVE 303 sec inserting
mysql tables in use 1, locked 1
3 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
MySQL thread id 7, OS thread handle 123145317388288, query id 1645 localhost msandbox update
insert t values(55,55)
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 38 page no 3 n bits 80 index PRIMARY of table `test_dbaexchange`.`t` trx id 4104 lock_mode X locks rec but not gap
Record lock, heap no 7 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
0: len 4; hex 8000003c; asc <;;
1: len 6; hex 000000001008; asc ;;
2: len 7; hex 2f00000147048c; asc / G ;;
3: len 4; hex 8000003c; asc <;;
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 38 page no 3 n bits 80 index PRIMARY of table `test_dbaexchange`.`t` trx id 4104 lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 7 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
0: len 4; hex 8000003c; asc <;;
1: len 6; hex 000000001008; asc ;;
2: len 7; hex 2f00000147048c; asc / G ;;
3: len 4; hex 8000003c; asc <;;
*** WE ROLL BACK TRANSACTION (2)
You can note that:
T1 is waiting for a shared lock on table tT2 has an exclusive lock on table t without gapT2 has tried to acquire a lock with gap on table t
Hope this help!
Best Answer
There are situations where InnoDB deadlock would come up when you least expect it. For example, SELECT queries can perform locks on the gen_clust_index, aka the Clustered Index.
Here are three past questions I agressively looked over with @RedBlueThing, the person who asked these questions. @RedBlueThing found work arounds for his questions.
Just to keep your question in perspective, when you look over these answers (don't look too deeply, even I get dizzy looking at my own convoluted answers) it should be quickly apparent that even SELECT queries can lock InnoDB data. Although autocommit could be enabled (rendering each query its own transaction), a single SQL statement can still be victimized by deadlocks.
You also have special cases of SELECT where you can lock specific rows on demand.
Based on InnoDB Deadlocking link, the sequences of event to cause this situation could theoretically be as follows:
Personally, that last statement scares me. It would have been nice for MySQL to inform everyone of this quirk instead of just documenting and hopong you google for it. Yet, that statement is from the MySQL Documentation. (Oh yeah, Oracle owns InnoDB)