【问题标题】:Deadlock in a simple PL/pgsql stored procedure that updates a single row (called by Hibernate)更新单行的简单 PL/pgsql 存储过程中的死锁(由 Hibernate 调用)
【发布时间】:2013-08-15 12:17:18
【问题描述】:

我写了一个简单的存储过程:

CREATE OR REPLACE FUNCTION "public"."update_table01" (
    int4, -- $1 (population)
    int2 -- $2 (id)
) RETURNS "pg_catalog"."void" AS
$body$
BEGIN
    UPDATE "table01"
    SET
            population = $1
    WHERE id = $2;
END;
$body$
LANGUAGE 'plpgsql'
VOLATILE
CALLED ON NULL INPUT
SECURITY INVOKER
COST 100;

我在我的 Java 服务器 (jre7) 中调用它,并且我使用带有 C3P0 的 Hibernate 4 作为我的连接池。这是在 PostgreSQL 9.2.4 上执行的。我有一个对应于 table01 的 Hibernate 实体(由注释映射),我指定这个过程用作 SQL 更新:

@SQLUpdate(sql = "{call update_table01(?, ?)}", callable = true)

当我用多个线程(大约 20 到 30 个)频繁调用这个进行负载测试时,发生了一些死锁,这让我很惊讶。以下是日志的相关部分:

2013-08-14 14:51:19 CEST [23495]: [3-1] LOG:  process 23495 detected deadlock while waiting for ShareLock on transaction 140127434 after 1000.048 ms
2013-08-14 14:51:19 CEST [23495]: [4-1] STATEMENT:  update table01 set population=$1 where id=$2
2013-08-14 14:51:19 CEST [23495]: [5-1] ERROR:  deadlock detected
2013-08-14 14:51:19 CEST [23495]: [6-1] DETAIL:  Process 23495 waits for ShareLock on transaction 140127434; blocked by process 23481.
Process 23481 waits for ShareLock on transaction 140127431; blocked by process 23495.
Process 23495: update table01 set population=$1 where id=$2
Process 23481: update table01 set population=$1 where id=$2
2013-08-14 14:51:19 CEST [23495]: [7-1] HINT:  See server log for query details.
2013-08-14 14:51:19 CEST [23495]: [8-1] STATEMENT:  update table01 set population=$1 where id=$2
2013-08-14 14:51:19 CEST [23481]: [3-1] LOG:  process 23481 still waiting for ShareLock on transaction 140127431 after 1000.086 ms
2013-08-14 14:51:19 CEST [23481]: [4-1] STATEMENT:  update table01 set population=$1 where id=$2
2013-08-14 14:51:19 CEST [23481]: [5-1] LOG:  process 23481 acquired ShareLock on transaction 140127431 after 1000.227 ms
2013-08-14 14:51:19 CEST [23481]: [6-1] STATEMENT:  update table01 set population=$1 where id=$2
2013-08-14 14:51:19 CEST [23938]: [3-1] LOG:  process 23938 still waiting for ExclusiveLock on tuple (8,72) of relation 16890 of database 16751 after 1000.119 ms
2013-08-14 14:51:19 CEST [23938]: [4-1] STATEMENT:  update table01 set population=$1 where id=$2
2013-08-14 14:51:19 CEST [23938]: [5-1] LOG:  process 23938 acquired ExclusiveLock on tuple (8,72) of relation 16890 of database 16751 after 1000.174 ms
2013-08-14 14:51:19 CEST [23938]: [6-1] STATEMENT:  update table01 set population=$1 where id=$2
2013-08-14 14:51:19 CEST [23520]: [3-1] LOG:  duration: 970.319 ms  execute <unnamed>: update table01 set population=$1 where id=$2
2013-08-14 14:51:19 CEST [23520]: [4-1] DETAIL:  parameters: $1 = '5731', $2 = '294'
2013-08-14 14:51:19 CEST [23481]: [7-1] LOG:  duration: 1000.361 ms  execute <unnamed>: update table01 set population=$1 where id=$2
2013-08-14 14:51:19 CEST [23481]: [8-1] DETAIL:  parameters: $1 = '1586', $2 = '253'
2013-08-14 14:51:19 CEST [23524]: [3-1] LOG:  duration: 531.909 ms  execute <unnamed>: update table01 set population=$1 where id=$2
2013-08-14 14:51:19 CEST [23524]: [4-1] DETAIL:  parameters: $1 = '1546', $2 = '248'
2013-08-14 14:51:19 CEST [23938]: [7-1] LOG:  duration: 1004.863 ms  execute <unnamed>: update table01 set population=$1 where id=$2

我不擅长解释 Postgres 日志,如果我错了,请纠正我。我认为这表明两个进程最终陷入僵局。两者都在执行相同的语句。

很多事情都让我感到困惑。最重要的是:我不明白两个进程(甚至更新不同的行)如何最终陷入死锁,当在存储过程中只获得具有该特定 ID 的行的单个行级锁时?这是更改此表的唯一过程。不应该获得排他锁(执行SELECT ... FOR UPDATE时相同)吗? ShareLocks 是从哪里来的?后面几行 (23938) 中显示的过程是什么?我最好的猜测是 23938 也在等待锁,当 23495 被杀死时,它获得了锁。

然后我尝试了以下方法:

CREATE OR REPLACE FUNCTION "public"."update_table01" (
    int4, -- $1 (population)
    int2 -- $2 (id)
) RETURNS "pg_catalog"."void" AS
$body$
BEGIN
    PERFORM 1 FROM "table01" WHERE id = $2 FOR UPDATE;

    UPDATE "table01"
    SET
            population = $1
    WHERE id = $2;
END;
$body$
LANGUAGE 'plpgsql'
VOLATILE
CALLED ON NULL INPUT
SECURITY INVOKER
COST 100;

当我再次运行它时,我无法重现它。没有更多的死锁。

为什么会这样?

编辑:经过一番调查后,Hibernate 似乎在刷新会话时有时会自行调用此方法。在某些情况下,对于不同的实体,几次都在同一个事务中。这可能会导致死锁,因为每次调用 update_table01() 都会使用 FOR UPDATE 锁锁定特定的 table01 列行。对于一些不正确的调用顺序,它会造成循环等待。在我使这个实体不可更新(即用 update=false 标记所有列)之后,一切都正常工作。现在,我对这种 Hibernate 行为感到非常惊讶,因为 RAM 中的 table01 实体没有附加到任何负责后续事务的会话。然而,Hibernate 将这些实体刷新到数据库,我不知道为什么。

至于锁,我已经确定了我的另外两个存储过程,它们插入/更新到引用 table01 的其他表(其中一个更改了 FK 列)。这些将在 table01 中的相应 FK 行上请求 ShareLock,因此将与 update_table01() 冲突。所以这三个存储过程会互相等待完成。仅此一项无法创建循环等待,但如果您在调用这些存储过程之后添加几个 Hibernate 引起的对 update_table01() 的调用,则可能会发生这种情况。

【问题讨论】:

  • 1.只需检查您在此表上没有任何触发器。 2. 如果没有,你有什么外键指向它?
  • 1.根本没有触发器 2. 还有另一个表有一个列引用这个 (ID)。

标签: hibernate postgresql stored-procedures deadlock plpgsql


【解决方案1】:

首先,你看到的排他锁:

ExclusiveLock on tuple (8,72) of relation 16890 of database 16751

这应该是你的“table01” - 试试:

SELECT * FROM pg_class WHERE oid = 16890;

其次,是的,您有进程 23495 和 23481 互相阻塞。 PostgreSQL 在等待 1 秒后检测到这一点并取消 23495。然后,在 1000.361 毫秒后,23481 再往下几行。

要对此进行测试,您需要打开两个终端,每个终端都运行 psql。这样你就可以控制每个的暂停。在每个中发出一个 BEGIN 并尝试在两个终端中运行更新。查看pg_locks 视图以了解发生了什么。

我的实验中没有一个能够重现这一点,我看不出它是如何做到的。

您看到的 ShareLock 可能是在 UPDATE 发生时阻止更改表的那个。您不希望有人删除您尝试更新的列。

当然,有两个共享锁can't conflict,所以肯定有别的东西在起作用。

从您的日志摘录中让我印象深刻的是,您还有许多其他简单的更新,对于这样一个简单的更新来说似乎已经很久了。

死锁检测器可能是错误的 - 您的服务器刚刚处于极端负载下,并且您的两个事务之间没有冲突。如果您的 deadlock_timeout 设置稍长一些,这可能永远不会发生。

【讨论】:

  • 是的,table01 的 OID 为 16890,我刚刚检查过。我要试试你的建议。顺便说一句,我知道在负载测试期间数据库(在其他机器上)没有承受重负载(我监控了它的 CPU 使用率和磁盘 I/O)。这使得微小更新闲置 1 秒的事实更加奇怪。
  • 很奇怪。您可能想订阅一个 postgresql 邮件列表(一般或性能)并在那里询问。一定是有什么东西延迟了更新 - 您是否注意到 CPU 上是否有大量上下文切换或磁盘上的等待时间?
  • 我没有检查 CPU 跳转,但是当我查看 CPU 利用率时,iowait 几乎不存在。试试邮递员,谢谢,伙计。
猜你喜欢
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 2014-11-24
  • 2023-04-01
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 2013-05-29
相关资源
最近更新 更多