即使您了解什么是死锁,调试死锁也可能很棘手。本文展示了一些有关如何找出死锁原因的技术。
一、一个简单的死锁示例
1.设置阶段
我们将通过以下示例测试我们的死锁调试技术:
CREATE TABLE parent ( pid bigint PRIMARY KEY, pdata text NOT NULL ); CREATE TABLE child ( cid bigint PRIMARY KEY, pid bigint REFERENCES parent NOT NULL, cdata text NOT NULL ); INSERT INTO parent VALUES (1, 'no children yet');
复制
2.死锁
为了引发死锁,我们并行运行以下事务。每个事务向child表中添加一行,然后尝试修改parent.
-- session 1 |
BEGIN; INSERT INTO child VALUES (100, 1, 'new child');
复制
-- session 2 |
BEGIN; INSERT INTO child VALUES (101, 1, 'another child'); SELECT pdata FROM parent WHERE pid = 1 FOR UPDATE;
复制
(session 2 阻塞)
-- session 1 |
SELECT pdata FROM parent WHERE pid = 1 FOR UPDATE;
复制
(session 1 阻塞, 但一秒钟后,它接收到一个错误)
ERROR: deadlock detected DETAIL: Process 19674 waits for ShareLock on transaction 1109; blocked by process 19718. Process 19718 waits for ShareLock on transaction 1108; blocked by process 19674. HINT: See server log for query details. CONTEXT: while locking tuple (0,1) in relation "parent"
复制
-- session 2 |
(session 2 解除阻塞并接收结果)
pdata ═════════════ no children (1 row)
复制
3.死锁如何出现在日志中
PostgreSQL的日志揭示了更多细节:
ERROR: deadlock detected DETAIL: Process 19674 waits for ShareLock on transaction 1109; blocked by process 19718. Process 19718 waits for ShareLock on transaction 1108; blocked by process 19674. Process 19674: SELECT pdata FROM parent WHERE pid = 1 FOR UPDATE; Process 19718: SELECT pdata FROM parent WHERE pid = 1 FOR UPDATE; HINT: See server log for query details. CONTEXT: while locking tuple (0,1) in relation "parent" STATEMENT: SELECT pdata FROM parent WHERE pid = 1 FOR UPDATE;
复制
4.为什么调试死锁很困难?
发送给客户端的错误消息不包含任何有意义的细节。这是因为来自其他参与死锁的会话的 SQL 语句可能有您无权查看的数据。PostgreSQL 日志包含更多有用的数据,但也不足以让我们搞清死锁产生的原因。要了解死锁的原因,您必须了解相关事务中的所有语句,因为锁始终保持到事务结束。仅来自错误消息的两个语句永远不会导致死锁。因此,这些事务中的一些较早的语句一定已经获取了问题的一部分的锁。但是,PostgreSQL 并没有保留这些先前语句的任何内存,因此我们必须找到其他方法来了解全局。
通常您需要应用程序开发人员的帮助。可能你很幸运,错误消息中的 SQL 语句足以识别所涉及的数据库事务,并且很容易重构从每个事务发出的 SQL 语句。通过检查这些语句占用的锁,您应该能够重建死锁的原因。
二、我们例子中死锁的原因
如果我们知道上面示例中交易的语句,我们可以推断出以下内容:
- 这个INSERT语句对parent上了 FOR KEY SHARE 锁. 这是必要的,这样没有并发事务可以删除我们尚未提交的引用的行INSERT。正如您在兼容性矩阵中看到的那样,这些锁不会相互冲突。
- 语句SELECT … FOR UPDATE中的 FOR UPDATE 行锁与其他事务中的FOR KEY SHARE锁冲突,从而导致死锁。
知道了原因,解决办法就很简单了:把“ SELECT … FOR UPDATE”改成“ SELECT … FOR NO KEY UPDATE”,这样就不会再有锁冲突,也就不会死锁了。请注意,FOR UPDATE 仅当您想要 DELETE 一行,或者如果您打算更新具有唯一或主键约束(键)的列时,才需要行锁。 锁的名称FOR UPDATE是与正常预期相反的,因为它表明这是一个正确的UPDATE的锁,并且它是 PostgreSQL 初学者的常见陷阱。
凭借我们完整的知识,我们可以解决问题。但是我们如何从交易中获取SQL语句呢?
三、调试死锁的技术
有几种方法:
1.通过在应用程序端登录来调试死锁
如果应用程序记录有关每个错误和每个数据库事务启动的信息,则很容易确定导致问题的事务。但是,这要求您要么控制应用程序代码,要么要求应用程序具有设计良好的跟踪工具。你并不总是比较幸运的能根据报错找到问题。
2.通过在应用程序端注释查询来调试死锁
这也是一种要求您可以修改应用程序的方法。这里的技巧是在查询中添加注释,例如
SELECT /* function "add_data", source file "app.c", line 1234 */ pdata FROM parent WHERE pid = 1 FOR UPDATE;
复制
3.通过在数据库端登录来调试死锁
为了使我们能够跟踪语句,我们必须确保每个语句都记录了进程 ID 和事务号。对于 CSV 日志记录,情况总是如此,但对于stderr日志记录,您必须更改log_line_prefix:
log_line_prefix = '%m [pid=%p] %q[txid=%x] %u@%d '
复制
此外,您必须记录所有语句:
log_statement = 'all'
复制
现在,记录所有语句的数量和性能影响对于繁忙的应用程序可能是禁止的。PostgreSQL v12 引入log_transaction_sample_rate,它允许您只记录所有事务的一定百分比。但是,在许多情况下,这还不够好,因为您通常只会看到所涉及交易之一的SQL语句。
我们示例的日志文件如下所示:
2022-06-20 17:17:52.988 CEST [pid=19718] [txid=0] laurenz@test LOG: statement: INSERT INTO child VALUES (100, 1, 'new child'); 2022-06-20 17:17:58.215 CEST [pid=19674] [txid=0] laurenz@test LOG: statement: BEGIN; 2022-06-20 17:18:03.626 CEST [pid=19674] [txid=0] laurenz@test LOG: statement: INSERT INTO child VALUES (101, 1, 'another child'); 2022-06-20 17:18:18.979 CEST [pid=19674] [txid=1108] laurenz@test LOG: statement: SELECT pdata FROM parent WHERE pid = 1 FOR UPDATE; 2022-06-20 17:18:31.550 CEST [pid=19718] [txid=1109] laurenz@test LOG: statement: SELECT pdata FROM parent WHERE pid = 1 FOR UPDATE; 2022-06-20 17:18:32.551 CEST [pid=19718] [txid=1109] laurenz@test ERROR: deadlock detected 2022-06-20 17:18:32.551 CEST [pid=19718] [txid=1109] laurenz@test DETAIL: Process 19718 waits for ShareLock on transaction 1108; blocked by process 19674. Process 19674 waits for ShareLock on transaction 1109; blocked by process 19718. Process 19718: SELECT pdata FROM parent WHERE pid = 1 FOR UPDATE; Process 19674: SELECT pdata FROM parent WHERE pid = 1 FOR UPDATE; 2022-06-20 17:18:32.551 CEST [pid=19718] [txid=1109] laurenz@test HINT: See server log for query details. 2022-06-20 17:18:32.551 CEST [pid=19718] [txid=1109] laurenz@test CONTEXT: while locking tuple (0,1) in relation "parent" 2022-06-20 17:18:32.551 CEST [pid=19718] [txid=1109] laurenz@test STATEMENT: SELECT pdata FROM parent WHERE pid = 1 FOR UPDATE;
复制
请注意,在事务中的第一个数据修改语句之后,事务 ID 记录为 0。这是因为 PostgreSQL 会延迟分配事务 ID,仅在需要时才分配。
4.通过增加deadlock_timeout调试死锁
PostgreSQL 死锁检测器不会立即启动,而是等到 afterdeadlock_timeout过去。这是因为死锁检测器是一个计算量很大的组件,所以我们只想在很可能出现问题时才激活它。默认情况下,该参数设置为一秒。不幸的是,一秒钟太短了,无法调试问题。现在,如果您可以让死锁会话“挂起”直到可以调试它们,您可以增加该参数。最大允许值几乎是 600 天,这比您需要的要长。通过适当的监控,您可以设置deadlock_timeout为 15 分钟来捕捉行为中的死锁。
一旦你有一个活跃的死锁,你可以从pg_stat_activity里挂起的会话找到client_addr和client_port:
SELECT client_addr, client_port, query FROM pg_stat_activity WHERE state = 'active' AND wait_event_type = 'Lock' ORDER BY state_change; client_addr │ client_port │ query ═══════════════╪═════════════╪════════════════════════════════════════════════════ 192.168.2.120 │ 49578 │ SELECT pdata FROM parent WHERE pid = 1 FOR UPDATE; 192.168.2.122 │ 47432 │ SELECT pdata FROM parent WHERE pid = 1 FOR UPDATE; (2 rows)
复制
我们按state_change 排序,因为其他会话稍后可能会卡在最初导致死锁的会话后面。因此,您希望专注于最旧的条目。
接下来,登录客户端机器,找出哪个进程在端口 49578 上有 TCP 连接:
# lsof -P | grep 49578 myapp 3974 laurenz [...] TCP localhost:49578->dbserver:5432 (ESTABLISHED)
复制
现在你知道客户端进程是3974,运行程序myapp。您现在可以使用调试器 attach 到程序并查看当前执行堆栈。这应该为您提供有关正在执行的内容的线索,以便您可以找出在该事务中运行的 SQL 语句。
不用说,这是另一种需要控制应用程序代码的方法。
结论
我们已经看到了几种调试死锁的方法。它们中的大多数都要求您控制应用程序代码。但并非所有技术在每种情况下都有用:例如,您可能无法保留记录下的所有语句或者让死锁挂起更长的时间。
原文链接:https://www.cybertec-postgresql.com/en/debugging-deadlocks-in-postgresql/
作者:Laurenz Albe
译者:阎书利