我在Postgres中遇到了三方死锁,并且我不太明白是什么原因导致了这种情况。日志消息如下:
Process 5671 waits for ExclusiveLock on tuple (33,12) of relation 31709 of database 16393; blocked by process 5652.
Process 5652 waits for ShareLock on transaction 3382643; blocked by process 5670.
Process 5670 waits for ExclusiveLock on tuple (33,12) of relation 31709 of database 16393; blocked by process 5671.
Process 5671: UPDATE "user" SET
seqno = seqno + 1,
push_pending = true
WHERE user_id = $1
RETURNING seqno
Process 5652: UPDATE "user" SET
seqno = seqno + 1,
push_pending = true
WHERE user_id = $1
RETURNING seqno
Process 5670: UPDATE "user" SET
seqno = seqno + 1,
push_pending = true
WHERE user_id = $1
RETURNING seqno
关系31709是"user"
表。在三个事务中,user_id
是相同的。
这似乎不是你在文档中看到的普通死锁情况。我没有以错误顺序更新此表的多行。我怀疑RETURNING
子句与此有关,但我无法确定原因。有什么想法可以解决这个问题或进一步调试吗?
更新Erwin在评论中的问题:这是Postgres 9.3版本。此事务中还有其他命令,尽管我不认为它们会触及“用户”表。表上有一个触发器,用current_timestamp()
更新updated_at
列:
CREATE OR REPLACE FUNCTION update_timestamp() RETURNS TRIGGER AS $$
BEGIN
NEW.updated_at = now();
RETURN NEW;
END;
$$ LANGUAGE plpgsql;
我会在能够重现此问题时查看交易细节;事后我正在分析日志。
更新#2:我使用LOCK_DEBUG
重新构建了Postgres,并尝试使用trace_locks=on
来理解锁定顺序。
更新的死锁消息如下:
Process 54131 waits for ShareLock on transaction 4774; blocked by process 54157.
Process 54157 waits for ExclusiveLock on tuple (1,16) of relation 18150 of database 18136; blocked by process 54131.
我可以清楚地看到ExclusiveLock
的阻塞:
2014-08-05 10:35:15 EDT apiary [54131] 2/316 4773 LOG: 00000: LockAcquire: new: lock(0x10f039f88) id(18136,18150,1,16,3,1) grantMask(0) req(0,0,0,0,0,0,0)=0 grant(0,0,0,0,0,0,0)=0 wait(0) type(ExclusiveLock)
2014-08-05 10:35:15 EDT apiary [54131] 2/316 4773 LOG: 00000: GrantLock: lock(0x10f039f88) id(18136,18150,1,16,3,1) grantMask(80) req(0,0,0,0,0,0,1)=1 grant(0,0,0,0,0,0,1)=1 wait(0) type(ExclusiveLock)
2014-08-05 10:35:15 EDT apiary [54157] 3/188 4774 LOG: 00000: LockAcquire: found: lock(0x10f039f88) id(18136,18150,1,16,3,1) grantMask(80) req(0,0,0,0,0,0,1)=1 grant(0,0,0,0,0,0,1)=1 wait(0) type(ExclusiveLock)
2014-08-05 10:35:15 EDT apiary [54157] 3/188 4774 LOG: 00000: WaitOnLock: sleeping on lock: lock(0x10f039f88) id(18136,18150,1,16,3,1) grantMask(80) req(0,0,0,0,0,0,2)=2 grant(0,0,0,0,0,0,1)=1 wait(0) type(ExclusiveLock)
(格式为
日期 程序 [pid] 虚拟txid txid 消息
)但我不知道
ShareLock
在哪里创建,或者事务4773为什么会阻塞事务4774。当查询pg_locks
表时,我看到类似的结果:始终有一个事务正在等待另一个事务的ShareLock
,而该事务正阻塞于第一个事务的元组。有没有建议可以挖掘ShareLock
源代码?更新3:我需要更新
LOCK_DEBUG_ENABLED
行内函数以无条件返回true才能看到ShareLock
的创建。一旦我这样做了,我开始看到它们的创建:2014-08-05 12:53:22 EDT apiary [76705] 2/471 6294 LOG: 00000: LockAcquire: lock [6294,0] ExclusiveLock
2014-08-05 12:53:22 EDT apiary [76705] 2/471 6294 LOG: 00000: LockAcquire: new: lock(0x115818378) id(6294,0,0,0,4,1) grantMask(0) req(0,0,0,0,0,0,0)=0 grant(0,0,0,0,0,0,0)=0 wait(0) type(ExclusiveLock)
2014-08-05 12:53:22 EDT apiary [76705] 2/471 6294 LOG: 00000: GrantLock: lock(0x115818378) id(6294,0,0,0,4,1) grantMask(80) req(0,0,0,0,0,0,1)=1 grant(0,0,0,0,0,0,1)=1 wait(0) type(ExclusiveLock)
2014-08-05 12:53:22 EDT apiary [76706] 4/153 6295 LOG: 00000: LockAcquire: lock [6294,0] ShareLock
2014-08-05 12:53:22 EDT apiary [76706] 4/153 6295 LOG: 00000: LockAcquire: found: lock(0x115818378) id(6294,0,0,0,4,1) grantMask(80) req(0,0,0,0,0,0,1)=1 grant(0,0,0,0,0,0,1)=1 wait(0) type(ShareLock)
2014-08-05 12:53:22 EDT apiary [76706] 4/153 6295 LOG: 00000: WaitOnLock: sleeping on lock: lock(0x115818378) id(6294,0,0,0,4,1) grantMask(80) req(0,0,0,0,1,0,1)=2 grant(0,0,0,0,0,0,1)=1 wait(0) type(ShareLock)
但我仍然不确定为什么会创建那个ShareLock
,以及为什么6295(在这种情况下)必须等待6294。