# 活动统计 LLMS 索引： [llms.txt](/llms.txt) --- > [!NOTE] > **本章将介绍：** > > - 客户端活动； > > - 事务活动； > > - `pg_stat_activity`、`pg_locks` 和 `pg_stat_database` 视图； > > - 客户端会话的主要状态； > > - 等待与锁； > > - 处于空闲状态的事务； > > - 如何确定查询和事务的持续时间； > > - 如何确定等待锁的时间； > > - 锁树。 活动统计信息是理解数据库管理系统中正在发生什么的关键要素。从操作系统的角度看，数据库管理系统像一个黑盒。操作系统不了解数据库管理系统内部的用户、数据库、会话、事务等实体。活动统计信息可以让我们看到这个黑盒内部，从而更好地理解其中发生的事情。活动包括数据库管理系统中的各种进程，这些进程既可能由子系统之间的内部交互引起，也可能由服务外部客户端引起。本章将详细讨论客户端会话以及与之相关的所有内容：客户端与服务器的交互、会话建立、查询和事务执行、会话的主要状态，以及会话期间可能出现的异常场景，例如空闲事务和锁。跟踪数据库管理系统中各项活动的过程，是成功运维应用和数据库管理系统所需的一项重要技能。为此，我们将介绍主要的统计信息来源及其使用示例。 ## 2.1. 理解数据库管理系统中正在发生什么的关键 {#mon-section-2-1} 我喜欢说，数据库管理系统是一项*服务*。人们常常把数据库管理系统看成内部规模庞大、结构复杂的东西，但也可以把它想象成一种小型且易于部署的微服务（这对 Web 开发人员来说十分熟悉）。从这个角度看，数据库管理系统的主要任务就是接收并处理客户端的查询。内部复杂组件之间的交互可以视为次要部分，因为它不需要客户端直接采取行动。在这个简化的模型中，只有客户端和服务器。客户端是一种程序：可以是 Go、Python 或 Ruby 应用，也可以是 Airflow 或 Celery 任务，还可以是开发人员喜欢的 IDE。总之，任何能够连接数据库管理系统并通过其协议与之通信的东西都可以充当客户端。服务器则是执行客户端命令的数据库管理系统。客户端产生的活动构成工作负载。数据库管理系统能够处理的工作负载量决定了它的吞吐量，进而决定整体性能。数据库管理系统中的活动可以被测量和分析；找出并消除异常后，就能提高数据库管理系统和应用的性能。 从管理角度分析活动时，重要的是获得有关已连接客户端的定量和定性信息，例如： - 已建立多少个会话，以及这些会话从哪里建立； - 会话以哪些用户身份、连接到哪些数据库建立； - 会话处于哪些状态； - 会话处于这些状态的时间有多长； - 正在执行多少个查询，分别来自哪些用户和数据库； - 查询执行了多长时间； - 会话中具体执行的是什么查询。 关于数据库管理系统中发生了什么，管理员可能会提出各种各样的问题，具体取决于管理员的任务、掌握的信息，以及在排查和解决问题过程中提出的假设。这些问题不仅可能涉及客户端查询的处理，也可能涉及后台服务的工作。借助活动统计信息得到的答案，可以消除问题，或优化应用的工作方式，从而实现更可靠的运行和更高的性能。 ## 2.2. 客户端与服务器的交互 {#mon-section-2-2} 为了更完整地理解活动是什么，让我们看看客户端与数据库管理系统如何相互交互。这种交互遵循经典的“客户端—服务器”模式。服务器持续在后台运行，等待客户端连接。客户端无论是应用还是用户，都会连接到服务器；连接成功后，客户端按照自身的内部逻辑或用户的意愿生成并向服务器发送命令，等待命令执行，接收响应并处理响应。 在 PostgreSQL 中，服务器由一个专用进程承担，这个进程按照历史习惯称为 postmaster。该进程负责监听各个接口上的客户端连接，创建会话，并启动用于维护数据库的后台进程。客户端连接时，postmaster 会创建一个新的子进程，在其中完成会话所需的配置和准备。会话准备好后，客户端就可以开始发送查询。 > [!NOTE] > **运行模式** > > 根据客户端的实现方式，会话可以采用同步或异步运行模式。大多数实现使用同步模式：客户端发送命令，等待命令执行结果，在此期间不能发送其他命令。异步运行模式也是可能的，但其实现取决于驱动程序。例如，标准驱动程序 libpq 就提供了这种功能[^mon-30-1]。 下面从操作系统的角度，展示使用 ps 工具输出的数据库管理系统服务器进程。 ```text {label="psql" .source-commands hl_lines="1"} $ ps f -u postgres -o pid,cmd PID CMD 4150200 /usr/lib/postgresql/15/bin/postgres -c config_file=/etc/postgresql/15/main/postgresql.conf 4150206 \_ postgres: 15/main: logger 3979107 \_ postgres: 15/main: checkpointer 3979108 \_ postgres: 15/main: background writer 3979109 \_ postgres: 15/main: walwriter 3979110 \_ postgres: 15/main: autovacuum launcher 3979111 \_ postgres: 15/main: archiver last was 000000010000000400000096 3979112 \_ postgres: 15/main: logical replication launcher 1389347 \_ postgres: 15/main: walsender postgres 127.0.0.1(39540) streaming 4/97BB49B0 1865559 \_ postgres: 15/main: postgres pgbench [local] idle 1865560 \_ postgres: 15/main: postgres pgbench [local] SELECT 1865561 \_ postgres: 15/main: postgres pgbench [local] idle 1865562 \_ postgres: 15/main: postgres pgbench [local] SELECT 1865563 \_ postgres: 15/main: postgres pgbench [local] idle 1865564 \_ postgres: 15/main: postgres pgbench [local] SELECT 1865565 \_ postgres: 15/main: postgres pgbench [local] SELECT 1865566 \_ postgres: 15/main: postgres pgbench [local] SELECT 1865567 \_ postgres: 15/main: postgres pgbench [local] SELECT 1865568 \_ postgres: 15/main: postgres pgbench [local] idle 1865571 \_ postgres: 15/main: postgres pgbench [local] UPDATE 1865572 \_ postgres: 15/main: postgres pgbench [local] COMMIT ``` 这些进程以“父进程—子进程”树的形式输出。其中最主要的是 postmaster，它是其他所有进程的父进程。子进程中既有后台服务进程，也有客户端连接进程，这些进程通常称为*后端进程*（backend）。从操作系统角度观察数据库管理系统的运行，可以使用 top、htop 和 atop 等工具。借助这些工具，可以观察操作系统进程如何使用 CPU、内存、磁盘和网络输入/输出、磁盘空间等系统资源。还应注意 vmstat、dstat、nicstat、pidstat，以及属于 sysstat 软件包的 iostat；这些工具也有助于评估系统资源的使用情况。 在会话期间，客户端通过命令与服务器通信。SQL 查询是这类命令的一个特例，并且通常可以组织成*事务*。事务由多个查询组成，整体上应被视为*一个*逻辑操作。事务由 `BEGIN` 命令声明，结束时可以使用命令 `COMMIT`（`END`）或 `ROLLBACK`。事务是数据库管理系统的重要机制，使多个客户端能够并发工作。事务具有*原子性*、*隔离性*和*一致性*。原子性意味着，事务中的所有操作要么一起执行，要么全部不执行。如果事务出错或回滚，所有操作的结果都会被撤销，恢复到事务开始之前的状态。一致性也体现在这里：它规定，原子执行（或回滚）的事务会使数据库保持无矛盾且一致的状态。不使用 `BEGIN` 和 `END` 声明事务块而执行的单个查询，实际上也属于事务，只不过事务中只有一条命令。隔离性意味着，在事务提交之前，一个事务的结果对其他相邻事务不可见；具体情况还取决于所使用的隔离级别。要更完整地理解这一问题，可以阅读 Bruce Momjian 的演讲《MVCC Unmasked》[^mon-31-1]。 尽管事务具有隔离性，也不能认为事务彼此完全独立。并发工作意味着多个事务可能同时访问同一份数据（表中的行）。对于读操作，情况比较简单，因为并发读取几乎不会产生冲突[^mon-31-2]。写入则复杂一些：并发写入可能引起冲突，而这类操作必须被*串行化*，也就是排成严格的顺序。数据库对象的访问通过*锁*来串行化。锁机制可以限制或禁止对资源的并发访问。锁的工作方式对用户是透明的，在大多数情况下不需要用户显式操作。不过，有时多个客户端会同时尝试在同一资源上建立不兼容的锁。此时只有一个客户端能够建立锁，其他客户端会排成队列，必须等待锁被释放。 作为阶段性小结，可以得出这样的结论：并发访问的性质、事务属性、锁机制以及某些偶然因素共同作用，可能给数据库管理系统和应用带来不良后果。根据所运行数据库的重要程度，这些情况可能被视为事故，因为它们可能导致性能下降，甚至使查询停止执行。 数据库管理员的任务之一，就是跟踪这些情况、查明原因并加以预防。本章接下来将更详细地讨论这些情况。 ## 2.3. 活动信息的来源 {#mon-section-2-3} 我们将从 `pg_stat_activity`、`pg_locks` 和 `pg_stat_database` 视图开始。从历史角度看，活动展示能力是逐步发展起来的，最终形成了今天的样子。在早期版本中，这三个视图包含的信息在主题上并不相关。`pg_stat_activity` 和 `pg_locks` 视图可以相互补充，而 `pg_stat_database` 并不包含后文将要讨论的那些统计信息。如今，这三个视图包含不同的信息，但共同围绕一个主题：确定活动。三个视图共同帮助我们了解数据库管理系统中正在发生什么： - `pg_stat_activity` —— 关于进程、已连接客户端和后台服务的统计信息； - `pg_locks` —— 关于活动进程持有或等待的锁的统计信息； - `pg_stat_database` —— 以单个数据库为上下文的客户端会话累计统计信息。 > [!NOTE] > **命名约定** > > 下文在指出视图及其字段时，将使用*`视图`*`.`*`字段`*这种记法。例如，`pg_stat_activity.pid` 表示视图 `pg_stat_activity` 中的 `pid` 字段。 ### `pg_stat_activity` 视图 {#mon-section-star-26} 我在排查和解决问题方面的全部实践经验都表明，当对数据库管理系统的运行产生各种怀疑时，`pg_stat_activity` 是最主要的初始信息来源。从操作系统角度看，管理员只能看到进程；而 `pg_stat_activity` 可以帮助管理员从 PostgreSQL 自身的角度进入数据库管理系统内部，查看这些进程的工作情况。该视图包含数据库管理系统所有进程的信息，无论是后端进程还是后台服务；其中每一行描述一个独立的服务器进程。在 PostgreSQL 的早期版本中，`pg_stat_activity` 主要包含后端进程的信息。后续版本加入了后台服务的信息。不过，后端进程和后台服务与数据库管理系统交互的方式不同，因此后端进程所具有的一部分信息对后台服务来说根本不存在。 后台进程的信息不足可以由其他视图补充，`pg_stat_activity` 仍然是了解数据库管理系统内部活动最有价值的信息来源。 可以使用元命令 `\d+ pg_stat_activity` 查看此视图的完整说明。 > [!NOTE] > **元命令** > > psql 客户端包含一组元命令，可用于获取用户对象和系统对象的帮助信息。所有元命令都以反斜杠 `\` 开头，例如 `\d`。如需获取帮助并列出全部元命令，请使用元命令 `\?`。 下面给出该视图的简要说明。 ```text {label="text" .source-commands hl_lines="1"} # \d pg_stat_activity View "pg_catalog.pg_stat_activity" Column | Type | Collation | Nullable | Default ------------------+--------------------------+-----------+----------+--------- datid | oid | | | datname | name | | | pid | integer | | | leader_pid | integer | | | usesysid | oid | | | usename | name | | | application_name | text | | | client_addr | inet | | | client_hostname | text | | | client_port | integer | | | backend_start | timestamp with time zone | | | xact_start | timestamp with time zone | | | query_start | timestamp with time zone | | | state_change | timestamp with time zone | | | wait_event_type | text | | | wait_event | text | | | state | text | | | backend_xid | xid | | | backend_xmin | xid | | | query_id | bigint | | | query | text | | | backend_type | text | | | ``` `pg_stat_activity` 中的统计信息输出，是一个基于 `pg_stat_get_activity` 函数的表，其中每一行描述一个具体的服务器进程。 让我们看看可以从该视图中获得哪些有用信息。 **客户端信息。** 连接的主要属性如下： - `client_addr` —— 建立连接的网络地址。如果连接通过 UNIX 套接字建立，该值将不存在（`NULL`）； - `client_port` —— 远程系统上建立连接所使用的端口号； - `usename` —— 连接所使用的用户名； - `datname` —— 连接到的数据库名称。 为了更好地识别客户端，客户端连接时可以通过单独的标识符 *application\_name* 标明自身。当多个应用使用相同的连接属性并且来自同一地址时，这是区分应用的便捷方法。`backend_type` 字段可以区分后端进程和后台服务。在数据库管理系统的早期版本中没有这个字段，确定客户端连接只能采用各种变通办法，例如在 SQL 查询中增加条件 `datname IS NOT NULL`。 ```text {label="psql" .source-commands hl_lines="1 2 3 4 5"} # SELECT row_number() OVER (ORDER BY pid) AS n, pid, backend_type, client_addr, application_name, usename, datname FROM pg_stat_activity LIMIT 15; n | pid | backend_type | client_addr | application_name | usename | datname ----+--------+------------------------------+--------------+------------------+----------+---------- 1 | 65 | checkpointer | | | | 2 | 66 | background writer | | | | 3 | 67 | walwriter | | | | 4 | 68 | autovacuum launcher | | | | 5 | 69 | archiver | | | | 6 | 71 | logical replication launcher | | | postgres | 7 | 117 | walsender | 192.168.64.5 | walreceiver | replica | 8 | 209017 | client backend | | psql | postgres | postgres 9 | 224802 | client backend | | psql | postgres | postgres 10 | 230568 | client backend | 192.168.64.9 | pgbench | pgbench | pgbench 11 | 231751 | client backend | 192.168.64.4 | pgbench | maru | pgbench 12 | 231752 | client backend | 192.168.64.4 | pgbench | maru | pgbench 13 | 231753 | client backend | 192.168.64.4 | pgbench | maru | pgbench 14 | 231754 | client backend | 192.168.64.4 | pgbench | maru | pgbench 15 | 231755 | client backend | 192.168.64.4 | pgbench | maru | pgbench ``` 这个例子清楚展示了后台服务（第 1 至 7 行）与后端进程（第 8 至 15 行）的区别。首先，可以根据 `backend_type` 字段的值区分它们。其次，后台服务的其他字段可能没有值，例如 `client_addr`、`application_name`、`usename` 和 `datname`，因为后台进程可能在本地启动，也可能不建立数据库连接。 **会话、事务和查询的持续时间。** 该视图包含与会话开始时间以及会话中正在发生的活动相关的时间信息： - `backend_start` —— 会话开始时间，也就是客户端连接到数据库管理系统的时刻； - `xact_start` —— 当前事务的开始时间； - `query_start` —— 当前查询的开始时间；如果事务中不止一个查询，这个字段尤其有用。 借助这些字段，可以发现与特定工作负载不相称的长时间运行查询和事务。 **会话状态。** 会话在生命周期内可能处于不同的*状态*。根据状态，可以判断会话是否一切正常，并在出现问题时采取措施。`state` 字段指示会话状态。`state_change` 字段还提供了切换到当前状态的时间，据此可以确定会话处于该状态的持续时间。接下来，我们将利用这些字段跟踪数据库中潜在危险的活动及其持续时间。 **等待与锁。** 数据库管理系统的内部机制需要使用各种同步机制；用于串行化对象访问的锁就是一个很好的例子。使用这些机制的结果之一，是在代码执行的不同位置产生等待的风险。为跟踪等待，数据库管理系统提供了 `wait_event` 和 `wait_event_type` 字段，它们可以详细标识产生等待的位置。借助 `state`、`wait_event_type` 和 `wait_event` 字段，可以确定数据库管理系统工作中的瓶颈，即进程在这些位置等待，而不是执行有用的工作。 **查询标识符和文本。** `query` 字段包含数据库管理系统中正在执行的查询文本。该字段受缓冲区大小限制，而缓冲区大小由参数 *track\_activity\_query\_size* 控制（默认值为 1 KB）。发现慢查询的文本后，管理员就有了优化性能的起点。可以重放查询、获取执行计划、分析性能，并据此制定优化措施。此外，每个查询还会生成唯一标识符 `queryid`；将它与 `usesysid` 和 `datid` 字段结合起来，可以和 `pg_stat_statements` 视图连接，从而获得关于该查询及其同类查询使用了多少资源的更多信息。 **进程标识符。** `pg_stat_activity` 中的所有进程都是操作系统进程，都有操作系统分配的唯一标识符 `pid`。统计信息中提供了这个标识符，它也是将 `pg_stat_activity` 与其他视图连接起来的键。例如，获取有关锁或某项操作执行进度的详细信息时，就可能需要用到它。 数据库管理系统可以把查询的一部分分配给多个进程执行，从而加快查询执行，并提高多核系统的使用效率。观察时，重要的是把执行并行查询的进程组与其他进程或进程组区分开来。`leader_pid` 字段就是为此服务的：所有子进程中的该字段都指向父进程的 `pid`。 **事务标识符和事务可见性界限。** 两个标识符分别表示已分配的事务号 `backend_xid` 和事务可见性界限 `backend_xmin`。在调查自动清理工作效率低下导致的表和索引大小异常增长时，这两个标识符可能很有用。关于这些统计信息的具体使用场景，我们将在介绍清理的第 [8](/08-vacuum/#mon-chapter-8) 章中详细讨论。 ### `pg_locks` 视图 {#mon-section-star-34} `pg_locks` 视图包含有关已持有锁的信息。它可以单独使用，但实践中经常与 `pg_stat_activity` 一起使用，两个视图相互补充，形成更完整的结果。 `pg_locks` 的每一行都包含有关被加锁或等待加锁的对象，以及发起锁请求者的信息。当多个进程试图获取同一对象的锁时，该对象会在视图中出现多次。对象上的锁被释放后，相关信息就会从视图中删除。锁对象可以是表、单独的行，甚至是表中的页面、事务标识符和数据库管理系统的共享对象。某些需要锁的操作也以单独对象的形式出现，例如扩展表文件，或更新 `pg_database.datfrozenxid` 等元数据。该视图还显示建议锁（advisory lock）；其含义和用途由应用自行决定，但不包含轻量级锁（lightweight lock，LWLock）的信息。轻量级锁在更低层次工作，用于控制对内存中内部结构的访问。 ```text {label="text" .source-commands hl_lines="1"} # \d pg_locks View "pg_catalog.pg_locks" Column | Type | Collation | Nullable | Default --------------------+--------------------------+-----------+----------+--------- locktype | text | | | database | oid | | | relation | oid | | | page | integer | | | tuple | smallint | | | virtualxid | text | | | transactionid | xid | | | classid | oid | | | objid | oid | | | objsubid | smallint | | | virtualtransaction | text | | | pid | integer | | | mode | text | | | granted | boolean | | | fastpath | boolean | | | waitstart | timestamp with time zone | | | ``` 可以使用元命令 `\d+ pg_locks` 查看 `pg_locks` 的完整说明；上面给出的是简要说明。该视图基于 `pg_lock_status` 函数，以表格形式展示信息。 **锁对象。** 可以使用下面这组字段识别与锁相关的对象： - `relation`、`page`、`tuple` —— 关系、页面编号和页面内的行编号； - `virtualxid`、`transactionid` —— 虚拟事务号和实际事务号； - `classid`、`objid`、`objsubid` —— 当锁对象不是关系对象时，它在系统目录中的锁对象标识符。 根据锁对象的不同，某些字段可能没有值（`NULL`）。 **锁的详细信息。** 带有附加信息的字段，对于确定正在等待获取锁的进程十分重要： - `locktype` —— 锁类型，用于区分不同的锁[^mon-37-1]； - `database` —— 发生锁的数据库标识符（OID）； - `virtualtransaction` —— 持有锁或等待锁的虚拟事务标识符； - `pid` —— 操作系统进程标识符。这个字段最常用于与 `pg_stat_activity` 连接，以获取用户名、查询或事务的开始时间、查询文本、等待标记等附加信息； - `mode` —— 锁模式，用于判断它与其他锁是否兼容。模式的完整列表见文档[^mon-37-2]； - `granted` —— 标志，表示锁已被持有（值为 `true`），还是正在等待获取（值为 `false`）； - `waitstart` —— 进入等待锁状态的时间。这是能够可靠说明进程等待锁的时间长度的唯一来源。不过要注意，即使已经开始等待锁（`granted = false`），这个字段在很短的一段时间内仍可能没有值（`NULL`）； - `fastpath` —— 标志，表示是否通过 fast-path 接口获取锁。这个接口早已被宣布为过时，只有运行使用该接口的应用时，这个字段才有意义。 利用锁的详细信息，可以筛除无关的锁，只关注那些与正在调查的问题直接相关的锁，例如与特定会话有关、具有某种类型，或等待时间超过允许时长的锁。与 `pg_stat_activity` 连接后，还可以获得有助于分析和修复应用侧问题的附加信息，例如用户名、应用名称和查询文本。 ### `pg_stat_activity` 和 `pg_locks` 的特点 {#mon-section-star-37} `pg_stat_activity` 和 `pg_locks` 两个视图有一个重要特点，我习惯把它看成一种缺点。基于这些视图实现监控时，始终应记住这一点。它们输出的统计信息反映当前时刻，并不是累计值。从这些视图取得的数据，是访问视图的那一刻所发生情况的*快照*。两个快照之间发生了什么，是未知的。实践中可能会遇到每秒处理数万甚至数十万个查询的系统。在两次快照之间，可能出现大量短暂的等待；这些等待不会进入快照，也不会在监控中显示出来，但可能对查询执行时间产生负面影响。这样一来，缺失的信息就造成了对实际情况的不完整认识。在基于这类快照构建监控系统并积累统计信息时，对情况的客观描述会严重依赖统计信息的采集频率。实践中通常每隔几秒采集一次，最常见的间隔在 15 到 60 秒之间。但即使以 1–10 毫秒的频率进行分析，也不能保证图景完整，而且还会增加分析本身的开销。总结一下：查看基于 `pg_stat_activity` 或 `pg_locks` 视图绘制的图表时，必须记住这个特点。其他一些视图也以类似方式工作；后文讨论它们时，我会单独指出这一点。 ### `pg_stat_database` 视图 {#mon-section-star-38} `pg_stat_database` 视图的每一行都包含有关特定数据库使用情况的统计信息。该视图还有一行专门用于记录可共享、供所有数据库使用的对象的统计信息（其中一部分属于所谓的系统目录）。该视图建立在一组函数之上，这些函数的前缀是 `pg_stat_get_db_`，它们接收数据库标识符作为参数并返回一个指标。可以使用元命令 `\d+ pg_stat_database` 查看该视图的完整说明。该视图的部分字段可以归入客户端连接统计信息，这有助于监控数据库管理系统的活动。 虽然这个视图包含数据库信息，但其中一些信息也可以放在客户端及其会话的上下文中理解。借助这些信息，可以跟踪已连接客户端的数量，以及应用是否正常地使用数据库管理系统。可以使用以下字段： - `numbackends` —— 连接到数据库的后端进程数量。在可共享对象统计行中，该值不存在（`NULL`）。这是视图中唯一表示当前值的字段，其他字段都包含某个时间段内的累计统计信息； - `xact_commit` —— 以提交（`COMMIT`）结束的事务数量。该计数器也会统计隐式事务中单个查询成功执行的次数； - `xact_rollback` —— 以回滚（`ROLLBACK`）结束的事务数量，包括因错误而回滚的事务； - `sessions_abandoned` —— 因客户端留下连接而被强制结束的会话数量。这可能说明客户端应用忘记了连接，没有按应有方式关闭连接（graceful close）。另一个原因可能是网络问题，例如传输错误和丢包，导致 TCP 会话无法正常工作； - `sessions_fatal` —— 因发生致命错误且无法继续工作而被强制结束的会话数量。这类错误可能发生在查询执行期间，也可能由客户端与服务器交互时服务器侧的异常情况引起。此时服务器无法继续会话，只能结束会话。一个例子是，由参数 *idle\_in\_transaction\_session\_timeout* 设置的超时期限超过后，会话被结束； - `sessions_killed` —— 以管理方式强制结束的会话数量。这种会话终止可能由 `pg_terminate_backend` 函数发起，也可能由数据库管理系统自身发起，例如服务器关闭或重启时； - `sessions` —— 与数据库建立的会话总数。该字段的值表示已建立的会话总数，不论会话以何种状态结束，也就是说，它包含其他所有可能状态的数值。 会话通常由客户端发起并结束。上面列出的一些字段，正好表示由数据库管理系统服务器发起结束的会话数量。因此，在某些情况下，会话结束可以被视为异常。会话期间，客户端会发送单独的命令，也可以把命令组合成事务。这些命令构成工作负载，通过 `xact_commit` 和 `xact_rollback` 字段，可以定量计算数据库管理系统中的工作负载大小。 关于会话工作的另一项有用信息，是会话在不同状态下持续的时间。这些状态在介绍 `pg_stat_activity` 时曾简要提到，稍后还会更详细地讨论。不过，字段集合并不完整，有些信息需要通过简单的算术运算计算出来。我们关心以下字段： - `session_time` —— 所有会话累计花费的总时间。时间统计有一个特点：只有在状态切换时，时间才会增加。因此，如果某些会话长时间保持同一状态，就可能出现很大的跳变。开发人员在 IDE 中长时间留下的会话就是一个很好的例子； - `active_time` —— 会话处于 `active` 和 `fastpath function call` 状态的时间，这两个状态都对应查询执行； - `idle_in_transaction_time` —— 会话处于 `idle in transaction` 和 `idle in transaction (aborted)` 状态的时间。 注意，上述字段中没有统计处于 `idle` 状态的时间。这个值必须自行计算：从总时间中减去处于空闲事务状态的时间和查询执行时间。 这些字段的所有值都以毫秒表示。 `pg_stat_database` 提供的数据库统计信息具有累计性质，会随时间积累，从而可以连续记录，不会像 `pg_stat_activity` 或 `pg_locks` 那样存在丢失风险。管理员可以使用单独的函数重置统计信息，从头开始累计。该视图有一个 `stats_reset` 字段，表示统计信息重置的时间。借助它，可以计算统计信息累计覆盖的时间区间。 ## 2.4. 已连接的客户端 {#mon-section-2-4} 遇到新情况或陌生环境时，首先要评估当前情况的全貌，了解即将排查和解决问题的环境。刚开始接触一个数据库管理系统时，我首先想知道系统的使用活跃程度以及它的用户是谁。通常需要了解系统连接了多少客户端、连接的是什么客户端，由此大致判断它们可能需要多少资源、会产生多大负载。 获取这类信息有两种方法。第一种方法是使用 `pg_stat_database` 视图： ```text {label="psql" .source-commands hl_lines="1 2"} # SELECT datname, numbackends FROM pg_stat_database ORDER BY numbackends DESC; datname | numbackends -----------+------------- pgbench | 32 postgres | 1 | 0 template1 | 0 template0 | 0 ``` 在查询输出中，可以看到每个数据库当前连接的后端进程数量。不过，`pg_stat_database` 只在数据库上下文中展示已连接客户端的信息，这可能不足以进行更详细的分析。还要注意查询结果中名称为空的行：这是一个服务行，汇总了*共享*对象的统计信息。这些对象可供所有数据库使用，但不属于任何一个数据库；它们全部属于系统目录。 > [!NOTE] > **系统目录** > > 系统目录是一组包含服务信息的表，由数据库管理系统自身使用。服务数据包括表、字段、索引、数据类型等信息。实际上，`CREATE`、`ALTER`、`DROP` 等几乎所有 DDL 命令，操作的正是系统目录中的数据[^mon-41-1]。 第二种方法是使用 `pg_stat_activity` 视图，得到的信息也详细得多： ```text {label="psql" .source-commands hl_lines="1 2 3 4"} # SELECT client_addr, usename, datname, count(*) FROM pg_stat_activity GROUP BY 1,2,3 ORDER BY 4 DESC; client_addr | usename | datname | count --------------+----------+----------+------- 192.168.64.8 | classic | pgbench | 19 192.168.64.4 | maru | pgbench | 15 | | | 5 192.168.64.7 | serral | pgbench | 4 192.168.64.5 | replica | | 1 192.168.64.9 | pgbench | pgbench | 1 | postgres | | 1 | postgres | postgres | 1 ``` 在这个例子中，客户端按连接地址、用户名和数据库名称分组。可以得出以下结论： - 有两个地址提供了绝大多数连接； - 大部分连接都指向 `pgbench` 数据库； - 有多个用户在使用该数据库。 `client_addr` 为 `NULL` 表示连接通过 UNIX 套接字从数据库管理系统服务器所在的同一节点建立，很可能就是我们通过 psql 建立的连接。在 `usename` 和 `datname` 字段中也可以看到 `NULL`，这类行通常对应后台服务。在 `pg_stat_activity` 的完整输出中，还能看到更多类似的行。 通常使用条件 `backend_type = 'client backend'` 来筛除后台服务，只显示客户端会话。 > [!NOTE] > **早期 PostgreSQL 版本的做法** > > `backend_type` 字段在 PostgreSQL 10 中出现；在更早的版本中，可以使用类似 `datname IS NULL` 的条件。通常，后台进程不会连接数据库，自动清理进程除外。 使用附加条件，可以从查询结果中排除后台进程，只获取后端进程的信息： ```text {label="psql" .source-commands hl_lines="1 2 3 4 5"} # SELECT client_addr, usename, datname, count(*) FROM pg_stat_activity WHERE backend_type = 'client backend' GROUP BY 1,2,3 ORDER BY 4 DESC; client_addr | usename | datname | count --------------+----------+----------+------- 192.168.64.8 | classic | pgbench | 19 192.168.64.4 | maru | pgbench | 11 192.168.64.7 | serral | pgbench | 5 192.168.64.9 | pgbench | pgbench | 1 | postgres | postgres | 1 ``` 实践中分析问题时，还需要按其他字段进行分组，并根据所提出的问题和待验证的假设使用不同的条件。 ### 跟踪客户端会话 {#mon-section-star-39} 使用 SQL 获取信息很方便，但实践中经常要在问题已经消失后再进行分析，这时需要历史视角下的信息以及随时间变化的趋势。这些任务由监控系统完成：监控系统采集、保存并可视化统计信息。借助监控，管理员可以通过图表观察统计信息随时间的变化。 监控系统必须始终掌握已连接客户端的信息，而且信息要足够详细。下面看一些客户端统计信息的实际例子，以及它们能够回答哪些问题。 要获取已连接客户端的总数，可以使用下面的 PromQL 查询： ```text {label="PromQL" .source-commands hl_lines="1"} # sum(postgres_connected_clients_total{service_id="primary"}) ``` 根据这个查询可以绘制图表，如图 [2.1](/02-activity-statistics/#mon-figure-caption-40) 所示。 ![客户端总数](/images/monitoring/figure-2.1.png) {#fig-2.1 num="2.1" caption="客户端总数" width=1829 height=598} 图中显示了最近一小时内连接数的变化。除了主要指标外，图中还给出了并发连接数上限，可以直观看出达到上限前还可以建立多少连接。连接数上限由参数 *max\_connections* 设置，默认值为 100。从图中可以看出，当前连接数略少于允许上限的一半，仍有余量。 > [!NOTE] > **配置参数指标** > > 数据库管理系统的参数也可以作为指标使用。例如，可以通过指标 `postgres_service_settings_info{name=`"`max_connections`"`}` 获取参数 *max\_connections* 的值。 指标 `postgres_connected_clients_total` 包含 `address`、`user` 和 `database` 标签，可以按这些标签分组，从不同视角获得统计信息。先按地址分组： ```text {label="PromQL" .source-commands hl_lines="1"} # sum by (address) (postgres_connected_clients_total{service_id="primary"}) ``` 图表将如图 [2.2](/02-activity-statistics/#mon-figure-caption-41) 所示。其中可以看到，大部分会话来自地址 192.168.64.8 和 192.168.64.4。在应用实例较多的环境中，这类图表可以帮助找出使用异常多会话的地址。 ![按连接地址统计的客户端数量](/images/monitoring/figure-2.2.png) {#fig-2.2 num="2.2" caption="按连接地址统计的客户端数量" width=1829 height=598} 现在把分组条件改为用户名，就可以了解哪些用户正在连接数据库管理系统（图 [2.3](/02-activity-statistics/#mon-figure-caption-42)）： ![按用户名统计的客户端数量](/images/monitoring/figure-2.3.png) {#fig-2.3 num="2.3" caption="按用户名统计的客户端数量" width=1828 height=598} 从图中可以看出，大部分会话来自两个应用用户。再仔细看，还可以发现 `stats` 用户比较突出。在测试环境中，指标导出器使用该用户建立连接以采集统计信息。对于导出器以及任何其他监控代理来说，这样多的连接都过多了，值得以此为起点优化代码。 现在看看连接指向哪些数据库（图 [2.4](/02-activity-statistics/#mon-figure-caption-43)）。 ![连接到各数据库的数量](/images/monitoring/figure-2.4.png) {#fig-2.4 num="2.4" caption="连接到各数据库的数量" width=1827 height=598} 从图中可以清楚看到，几乎所有连接都指向 `pgbench` 数据库，它是工作负载集中的主要数据库。只有很少一部分连接指向 postgres 数据库；这些连接很可能同样由指标导出器建立。 根据指标的信息量和所使用的标签，还可以绘制其他视角的图表。例如，如果应用广泛使用 *application\_name*，也可以把这项信息作为指标标签导出，并绘制相应的图表。 ### 事务活动 {#mon-section-star-44} 查询是工作负载的基本单位。可以把查询组合成事务，而事务作为一个整体执行：即使只有一个查询出错，也会被视为整个事务出错。事务机制的设计方式决定了，即使没有显式包在事务控制命令（`BEGIN` 和 `END`）中的单个查询，也属于事务（只包含一条命令）。 通过所执行的事务数量，可以判断数据库的使用活跃程度。所需信息可以在 `pg_stat_database` 中找到。该视图包含 `xact_commit` 和 `xact_rollback` 字段，分别表示已提交和已回滚的事务数量。这两个字段的总和表示数据库中的事务活动： ```text {label="psql" .source-commands hl_lines="1 2 3"} # SELECT datname, xact_commit + xact_rollback AS xacts FROM pg_stat_database ORDER BY xact_commit + xact_rollback DESC; datname | xacts -----------+--------- pgbench | 5786340 postgres | 357301 template1 | 6116 | 13 template0 | 0 ``` 测试环境中只有两个数据库在积极使用：`pgbench` 和 `postgres`。此外还有一个数据库名称为空的特殊行，其中包含系统目录共享对象的统计信息。下面的查询可以从监控系统中获得数据： ```text {label="PromQL" .source-commands hl_lines="1 2"} # rate(postgres_database_xact_commits_total{service_id="primary"} + postgres_database_xact_rollbacks_total{service_id="primary"}[1m]) ``` 这个查询计算每秒执行的事务数，根据它可以绘制图表（图 [2.5](/02-activity-statistics/#mon-figure-caption-45)），以动态展示当前情况。图中可以直观看出，`pgbench` 数据库中的事务量是 `postgres` 数据库的数倍。 ![事务活动：每秒事务数](/images/monitoring/figure-2.5.png) {#fig-2.5 num="2.5" caption="事务活动：每秒事务数" width=1822 height=628} 事务活动图表适合做粗略分析和了解数据库管理系统当前的活动，也很适合作为值班工程师查看的汇总图表。剧烈波动通常表示应用实例数量发生变化，或工作负载规模发生变化，进而可能导致数据库管理系统的资源使用发生变化。 > [!NOTE] > > > **使用 pg\_stat\_statements 统计事务** > > 可以通过 `pg_stat_statements.query` 获取事务信息，跟踪事务开始和结束命令（`BEGIN`、`COMMIT` 等）。不过，这种方法有几个缺点。第一，必须启用实用命令跟踪（*track\_utility* `= on`）。第二，该扩展只记录直接调用的 `ROLLBACK` 命令，因此无法跟踪因错误而发生的事务回滚。第三，事务开始并不总是能够被跟踪。例如，如果客户端使用 `\set AUTOCOMMIT off`，事务会在执行第一条命令后立即隐式打开。因此，虽然可以使用 `pg_stat_statements` 进行统计，但不太方便。 ### 会话结束状态 {#mon-section-star-46} 会话正常工作时，客户端会连接数据库管理系统、发送查询；不再需要连接时，则关闭连接并断开连接。不过，会话也可能出现异常行为而被中断： - 客户端、数据库管理系统或中间网络设备重置连接； - 会话发生错误，之后无法继续会话； - 管理员或数据库管理系统主动强制结束会话。 当然还可能有其他更为特殊的情况，但上面列出的原因最常见。会话异常结束有时很少发生，也不容易察觉：会话中断后，数据库管理系统把消息写入日志，应用重新建立连接，工作继续进行。网络错误、超时或丢包都可能造成这种情况，它们会破坏 TCP 连接的运行。但也可能出现另一个极端：错误成批出现，无法忽略。通常这是应用层错误的结果，会话因为应用中的错误而结束。例如，会话中断后，应用可能重新建立连接并执行有错误的代码，结果会话再次被重置，整个过程不停重复。这种行为很好地体现了 *crash loop* 这个术语，Kubernetes 管理员对此并不陌生。如果错误之间的间隔很短（只有几毫秒），应用可能造成连接建立尝试风暴。最好的情况下，这会增加数据库管理系统侧的 CPU 负载（创建后端进程的开销并不低）。最坏的情况下，如果多个应用实例表现相同，就可能耗尽连接上限 *max\_connections*，使其他应用无法连接数据库管理系统。 会话状态统计位于 `pg_stat_database` 中，可以这样获取： ```text {label="psql" .source-commands hl_lines="1 2 3"} # SELECT datname, sessions, sessions_abandoned, sessions_fatal, sessions_killed FROM pg_stat_database WHERE sessions > 0; datname | sessions | sessions_abandoned | sessions_fatal | sessions_killed ----------+----------+--------------------+----------------+----------------- postgres | 1154107 | 0 | 0 | 0 pgbench | 383947 | 0 | 0 | 0 ``` 提醒一下，`pg_stat_database` 包含累计统计信息，因此其中可能出现很大的数值。需要关注的是是否存在异常状态：`abandoned`、`fatal` 和 `killed`。在这个例子中没有记录这类会话，说明应用在会话层面运行正常，没有错误。还可以注意到，与应用数据库 `pgbench` 相比，连接到服务数据库 `postgres` 的数量多得多。可以使用下面的 PromQL 查询绘制图表，查看随时间变化的情况： ```text {label="PromQL" .source-commands hl_lines="1 2 3 4"} # sum by (database) ( increase(postgres_database_sessions_total{ service_id="primary", database=~"(postgres|pgbench)" }[1m])) ``` 在这个查询中，会话在所有状态下的数量按我们关心的两个数据库汇总。统计信息是累计值；为了直观看到随时间的变化，可以使用 `increase` 函数，它显示指定时间间隔内的指标变化（本例中为一分钟）。 图 [2.6](/02-activity-statistics/#mon-figure-caption-47) 显示，每分钟大约有 90 个会话连接到 `postgres` 数据库。原因是指标导出器特有的工作负载。导出器在采集统计信息期间建立多个会话， ![按数据库统计的每分钟会话建立频率](/images/monitoring/figure-2.6.png) {#fig-2.6 num="2.6" caption="按数据库统计的每分钟会话建立频率" width=1830 height=598} 随后结束这些会话。就资源使用而言，这种做法效率不高，因为数据库管理系统要为每个会话创建独立进程，并执行成本高昂的初始化。从这个角度看，长期建立并使用几个会话更有利，这也是优化导出器代码的一个好起点。除了导出器，测试环境中还有一些应用，它们每隔几分钟就会带着新的负载参数重启，这一点从 `pgbench` 数据库建立会话时出现的尖峰就能看出来。在实际环境中，应用可能很少重启，而它们建立的连接可能持续运行几十分钟甚至数小时。 **实践案例。** 异常状态通常表示存在问题，或说明应用或环境的工作方式效率不高。下面的案例发生在准备本章材料时。 获取会话状态的查询显示，`sessions_abandoned` 的值占 `sessions` 总数的 13%，并且还在缓慢增加。这个数值相当大，因此我尝试查明遗留会话数量如此之多的原因。关闭测试负载后，计数器仍然继续增长，于是我怀疑问题出在监控代理上。这个问题我很熟悉：如果应用侧没有正确关闭连接，就会出现这种现象。我可以访问代理的源代码，于是检查了所有打开连接的位置。需要确认连接在使用后都被关闭；检查后，我发现有一个位置没有关闭连接，可能造成连接泄漏。 为了确认问题是否持续存在，我根据下面的查询绘制了图表（图 [2.7](/02-activity-statistics/#mon-figure-caption-49)）： ```text {label="PromQL" .source-commands hl_lines="1 2 3"} # sum by (reason) (increase(postgres_database_sessions_total{ service_id="primary",database="pgbench" }[1m])) ``` ![按状态分组的每分钟会话建立频率](/images/monitoring/figure-2.7.png) {#fig-2.7 num="2.7" caption="按状态分组的每分钟会话建立频率" width=1829 height=597} 调查结果是修复了 d098923[^mon-50-1]。大约在 20:00，应用版本完成更新，问题消失，图表也证实了这一点。监控就这样帮助发现并解决了代理应用中的错误。 ## 2.5. 会话状态 {#mon-section-2-5} 后端进程在其生命周期中可能处于不同状态，这些状态反映会话中正在发生的事情。可以把进程状态看作一个条件标记，用来区分行为正常和不符合预期的会话。状态显示在 `pg_stat_activity.state` 中，但只有客户端连接才会有这个状态；后台进程的该字段始终为空。这可能是因为“状态”描述的正是会话，而后台进程不会建立会话，因而也没有可供显示的内容。未来 PostgreSQL 版本的情况可能会改变，届时或许会提供某种关于后台进程状态的信息。下面看一看会话可能处于的所有状态： - `idle` 表示空闲状态。如果客户端没有发送命令，服务器也没有忙于执行查询，那么会话就处于空闲模式，服务器正在等待客户端的命令。会话大部分时间都可能处于这种状态。 - `active` 表示活动状态。进程接收到客户端命令后开始执行，并进入活动状态。需要注意，这个状态也包括等待状态：进程可能暂停工作，等待某个事件。 - `idle in transaction` 表示事务已经打开，但其中没有任何活动，进程正在等待客户端发送要执行的命令。应用打开事务后，应该在其中执行一组命令并将其关闭，但由于某些内部原因，命令之间可能出现停顿。根据所执行命令的性质，这种状态可能导致锁，以及由于延迟自动清理而导致的表和索引*膨胀*。应当跟踪这类事务，并消除导致其进入这种状态的原因。关于空闲事务的更多信息，请参见第 [56](/02-activity-statistics/#mon-section-star-55) 页。 - `idle in transaction (aborted)` 表示一个未完成的事务，事务内部发生过错误。良好的实践是让应用完全控制事务的执行过程。如果事务中的任何命令执行出错，应用都应回滚事务。如果缺乏事务管理，就会出现*资源泄漏*风险，例如应用中数据库驱动程序一侧的事务池槽位被占用。对于数据库系统本身，会话处于这种状态的危害较小，因为错误发生后所有资源和锁都会释放；但对应用来说，这种情况可能很敏感，可能耗尽内部池中的连接或引发错误。关于空闲事务的更多信息，请参见第 [56](/02-activity-statistics/#mon-section-star-55) 页。 - `fastpath function call` 表示通过 fast-path 接口执行函数[^mon-51-1]。这种执行方式已经过时，不建议使用。实践中我没有遇到过这种状态，但可以设想，早期开发且已经无人维护的应用可能仍在使用这项功能。 - `disabled` 不表示进程的某个具体状态，而只表示数据库系统配置中关闭了会话状态跟踪。跟踪通常默认开启，不建议关闭，因为这会降低可观测性，也会削弱监控和调试能力。 还有一种重要状态不会反映在 `state` 字段中，那就是*等待*。这个状态被隐含在 `active` 状态中，但在我看来，两者应该分开，并作为彼此独立的状态来考察。活动状态意味着正在执行操作并使用资源，而等待意味着进程不执行操作，却占用着本可供使用的资源。由此可见，活动状态是系统正常工作的状态，等待则是不正常的状态，管理员应采取措施减少等待。 ### 状态跟踪 {#mon-section-star-50} 按状态监控客户端会话，可以跟踪工作负载的执行情况以及其中出现的各种异常。可以使用下面的 SQL 查询查看所有后端进程及其状态： ```text {label="psql" .source-commands hl_lines="1 2 3"} # SELECT state, count(*) FROM pg_stat_activity WHERE backend_type = 'client backend' GROUP BY 1 ORDER BY 2 DESC; state | count ---------------------+------- idle | 39 active | 3 idle in transaction | 1 ``` 这个合成负载示例表明，大部分连接处于空闲状态。在查询 `pg_stat_activity` 的时刻，只有三个进程正在执行查询，另有一个客户端打开了事务并在等待客户端命令。不过要记住，`active` 状态隐含地包括可能的等待，因此从结果中无法判断会话的确切状态。下面我们考察等待和锁的本质，以及更准确地确定会话状态的方法。 ### 等待与锁 {#mon-section-star-51} 锁的作用是限制或禁止对资源的并发访问。在并发环境中，使用锁会导致对被锁资源的访问排队。处于这种队列中会直接影响查询或事务的执行时间：在获得访问权之前，执行会一直被阻塞，而只有整个队列处理完、锁被释放后，访问才可能发生。执行查询时等待锁会损害性能：数据库系统和应用不得不等待，无法进行有用的工作。管理员必须跟踪系统何时把时间花在等待上，而不是有用工作上。 对于后端进程来说，等待意味着在资源（对象）释放或预期事件出现之前无法继续工作。对象可以是表或单独的行；轻量级锁则施加在更低层级的资源上。磁盘或网络 I/O，例如文件同步、网络传输等，都可能成为等待的事件。 可以使用 `pg_stat_activity` 视图跟踪等待。数据库系统中可能有很多位置会让进程停下来等待。相比一个笼统的状态，了解等待的具体原因更为重要，因此 `state` 字段并不十分适合这项任务。数据库系统提供了所谓的*等待事件*（wait event）：它们指出进程正在等待的具体事件或资源。在 `pg_stat_activity` 中，这些等待事件由两个字段表示： - `wait_event_type` — 等待的总体类型，换句话说，是该等待所属组的标识； - `wait_event` — 进程正在等待的具体事件或资源。 等待事件表示进程确实在等待某个事件或资源，而这项信息是在 9.6 版本中引入的。在更早版本中，可以通过 `pg_stat_activity.waiting` 标志判断等待；它只表示一种特定的等待情况，即等待锁。等待事件扩大了可记录事件的范围，覆盖可能造成等待的各种原因，并取代了这个更简单的标志。所有可记录等待的完整列表，请参见文档中关于 `pg_stat_activity` 的章节[^mon-52-1]。下面用测试环境中的一个查询结果做简单示例。 ```text {label="psql" .source-commands hl_lines="1 2 3 4"} # SELECT wait_event_type ||'.'|| wait_event AS waiting, count(*) FROM pg_stat_activity WHERE wait_event_type IS NOT NULL AND backend_type = 'client backend' GROUP BY 1 ORDER BY 2 DESC; waiting | count --------------------+------- Client.ClientRead | 30 LWLock.WALWrite | 7 Lock.transactionid | 3 IO.WALSync | 1 ``` 查询条件排除了后台服务；它们被等待事件覆盖的程度并不高，在这个例子中也不是我们关注的对象。为了便于处理等待事件，可以用分隔符（例如点号）把这两个字段合并为一个值，使其同时显示等待类型和具体事件。这样的合并值可以称为*等待标记*。测试环境中有多个应用生成合成负载，查询结果展示了该负载执行期间的等待快照： - `Client.ClientRead` — 进程正在等待接收客户端命令。这是空闲进程的常见状态，进程大部分生命周期都可能处于这种等待中。 - `LWLock.WALWrite` — 等待轻量级锁，以便把预写式日志页面从内存中的缓冲区写入磁盘。WAL 按顺序写入，在写入负载高度并发时，这经常会成为数据库系统性能的瓶颈。 - `Lock.transactionid` — 等待相邻事务完成。如果多个事务尝试修改相同数据，就经常会出现这种等待。 - `IO.WALSync` — 等待把 WAL 段的写入同步到磁盘。 从这个小例子可以看出，等待的形式可能非常多，而且它们对合成负载的影响也可能不同。例如，磁盘类型和性能（HDD、SSD、NVMe）不同，WAL 的写入和同步速度也不同，等待时间会随之变化。等待相邻事务取决于工作负载的性质、并发事务的数量，以及事务本身和其中各条命令的持续时间。至于等待客户端命令，它对负载没有影响：会话处于空闲模式，只要应用需要，就可以立即使用，不会产生延迟。因此，等待标记可以提示管理员时间花在了哪里，并为系统可能的优化提供起点。 不过，等待标记的数量很多，并非每一种都应被视为需要立即处理的关键状态。正如前面提到的，`Client.ClientRead` 是一种完全无害的等待，不会影响系统工作。 经过多年的实践，我和几位同事认为，在所有等待事件类型中有一组特殊事件，可以把它从其他事件中区分出来，并把它看作与 `pg_stat_activity.state` 中各值同等的一种独立状态。这就是类型为 `Lock` 的事件组：这一组等待表示命令执行已经停止，正在等待获取重量级锁。该组包含多个等待事件，可以更准确地指出等待原因。例如，`transactionid` 等待表示正在等待相邻并发事务完成。`Lock` 组中的事件明确说明，进程和客户端应用都没有在做有用工作，而是在等待，这本身就会损害应用和数据库系统的性能。 ### 考虑等待的状态跟踪 {#mon-section-star-52} 跟踪锁等待状态有两种方法。第一种也是首选的方法是使用等待事件。通过条件 `wait_event_type = 'Lock'`，可以把进程识别为正在等待锁： ```text {label="psql" .source-commands hl_lines="1 2 3 4 5 6 7"} # SELECT CASE WHEN wait_event_type = 'Lock' THEN 'waiting' ELSE state END AS state, count(*) FROM pg_stat_activity WHERE backend_type = 'client backend' GROUP BY 1 ORDER BY 2 DESC; state | count ---------------------+------- idle | 31 waiting | 3 active | 3 idle in transaction | 1 ``` 第二种方法稍微复杂一些，更多是出于学术上的兴趣。它需要连接 `pg_locks` 并使用 `granted` 标志。不过要注意，对于一个进程，`pg_locks` 中会有多个锁（多行），因此只应统计尚未获取的锁： ```text {label="psql" .source-commands hl_lines="1 2 3 4 5 6 7 8 9"} # SELECT CASE WHEN NOT l.granted THEN 'waiting' ELSE a.state END AS state, count(*) FROM pg_stat_activity a LEFT JOIN pg_locks l ON a.pid = l.pid AND NOT l.granted WHERE a.backend_type = 'client backend' GROUP BY 1 ORDER BY 2 DESC; ``` ```text {label="text"} state | count ---------------------+------- idle | 24 active | 8 waiting | 3 idle in transaction | 1 ``` 两种方法的结果并不完全相同，因为它们是在不同时间执行的。不过第一种方法更简单，因为不需要连接。 至少有两种方法可以实现用于监控客户端状态的指标： 1. 根据 `state` 字段分别显示各状态，并显示 `wait_event_state` 字段值为 `Lock` 的进程数。在这种情况下，`active` 状态会包含正在等待锁的进程。 2. 把等待类型为 `Lock` 的进程从 `active` 状态的进程数中排除。 指标 `postgres_activity_connections_in_flight` 的内部实现采用第二种方法，并包含 `state` 标签。除了标准状态外，该标签还可能包含额外的 `waiting` 状态，它正是用来表示正在等待锁的进程： ```text {label="PromQL" .source-commands hl_lines="1 2"} # sum by (state) (postgres_activity_connections_in_flight{service_id="primary"}) ``` 图 [2.8](/02-activity-statistics/#mon-figure-caption-53) 展示了根据这个查询生成的图表示例。 ![按状态划分的客户端数量](/images/monitoring/figure-2.8.png) {#fig-2.8 num="2.8" caption="按状态划分的客户端数量" width=1838 height=598} 图中几乎包含所有可能状态的进程，其中也包括等待锁的进程。结合 `state` 和 `wait_event_type` 字段，就可以汇总出客户端会话的状态信息。 ### 死锁 {#mon-section-star-54} 死锁（deadlock）是由多个锁形成的一种无法自行解决的情况：参与者陷入互相阻塞的僵局，进入等待状态，无法继续工作。要解决这种情况，必须强制结束死锁中的一个参与者，以释放部分锁。 普通锁的等待可能持续不可预测的长时间。死锁则简单得多：系统会自动检测并解决死锁，无需管理员干预。如果在 *deadlock\_timeout* 时间内无法获取锁（默认是一秒），会话就会检查自己是否参与了死锁。检查过程中会确定冲突参与者。如果参与者中有清理进程，系统会向它发送终止信号，但为了防止事务计数器回绕（to prevent wraparound）而运行的清理进程除外。如果没有清理进程，会话会强制取消自己的查询；正是这个查询需要获取锁，因而触发了检查。如果查询在事务中执行，整个事务会进入错误状态，应当将其回滚结束。死锁中的其他参与者可以继续工作，但不能保证死锁不会再次出现。 实践中，最简单的死锁通常发生在不同会话交叉尝试获取相同资源的锁时。例如，第一个事务试图获取第二个事务已经持有的资源上的锁，而第二个事务又试图获取第一个事务已经持有的资源上的锁。死锁的主要危害在于：如果它们不断发生，系统性能会显著下降（并发性降低），而且由于操作被强制取消，还必须重试该操作（查询或事务）。不过，考虑到死锁会自动解决，它造成的危害仍然远小于普通锁；普通锁可能让相邻会话的工作不可预测地长时间停顿。 遗憾的是，数据库系统不存在通用的解决方案，因为问题在于应用与数据库系统并发工作时命令执行顺序不合理。要彻底解决问题，必须由应用本身改变处理数据的方式。 可以使用每个数据库各自的计数器 `pg_stat_database.deadlocks` 跟踪死锁。发生死锁时，相关信息会写入活动日志： ```text {label="text"} [UPDATE] ERROR: deadlock detected [UPDATE] DETAIL: Process 3498160 waits for ShareLock on transaction 809; blocked by process 3498137. Process 3498137 waits for ShareLock on transaction 808; blocked by process 3498160. Process 3498160: update t1 set a = 1 where a = 2; Process 3498137: update t1 set a = 2 where a = 1; [UPDATE] HINT: See server log for query details. [UPDATE] CONTEXT: while updating tuple (0,3) in relation "t1" [UPDATE] STATEMENT: update t1 set a = 1 where a = 2; ``` 根据 *log\_line\_prefix* 的值，日志内容还可能补充其他有用信息（时间、用户、数据库、事务标识符等）。输出中最关键的信息是已经记录到死锁出现，即 `deadlock detected`。随后是关于哪个进程处于等待、哪个进程造成阻塞，以及检测到死锁时两个会话正在执行的查询文本。这里要注意，这些是当时的当前查询；实际上，冲突锁可能是由同一事务中更早执行的另一个查询获取的。要进行完整分析，必须启用所有查询的日志记录（*log\_statement* `= all` 或 *log\_min\_duration\_statement* `= 0`），完整记录事务中查询的执行过程，并检查它们的执行顺序。 ### 空闲事务 {#mon-section-star-55} 理想情况下，组成事务的一系列命令应该连续执行，中间没有停顿或延迟：客户端收到结果后应立即发送下一条命令。但实际情况是，应用在发送命令之间执行某些工作，而数据库系统正在等待它继续（等待标记为 `Client.ClientRead`）。处于等待客户端命令状态的事务称为空闲（idle）事务。`idle in transaction` 空闲状态绝大多数情况下由客户端造成，只有少数情况下是运行应用的环境（操作系统或网络环境）造成的。从应用的角度看，命令之间的停顿可能由以下原因引起： - 根据前面命令的结果进行计算； - 访问远程服务（缓存、队列、数据库、API 等）； - 系统资源不足，以及操作系统分配资源（内存）； - 应用耗尽已设置的资源使用限制后被暂停（Kubernetes requests/limits）； - 发生错误并处理异常。 这不是完整列表，事务出现空闲的原因可能多种多样，而且并不总是显而易见。大多数情况下，造成空闲事务的责任在应用。错误处理就是一个很好的例子。发生错误时，应用正确的做法是回滚并结束事务。最糟糕的情况是出现事务泄漏：应用失去对事务的控制，而事务在不确定的长时间内保持未完成状态。还可能有其他场景。例如，用户连接到数据库并执行某些命令。用户可能需要开启事务，在其中执行一条命令，然后回滚。或者，用户使用的 IDE 在执行命令时可能隐式开启事务。用户转而处理其他任务，之前打开的事务就保持未完成状态。 客户端会话处于 `idle in transaction` 状态会产生负面影响，其中一些影响在特定数据库系统运行条件下可能导致故障： - 占用数据库连接。应用打开事务时，通常意味着它将执行一系列命令。如果应用一侧使用了连接池，带有打开事务的连接就不能被其他执行线程使用。当连接池达到同时打开连接数上限时，应用会被阻塞，直到至少释放一个连接。 - 过时的行版本、*膨胀效应*和性能下降。在写入强度较高时，由于同一行出现多个版本，表和索引的大小会增长。过时的行版本不仅占用磁盘空间，还会损害性能。读取和查找数据时，进程必须处理更多页面来寻找所需的行版本，从而使查询变慢，并额外消耗 CPU、内存和 I/O 资源。数据库使用自动清理定期删除过时的行版本并释放空间。自动清理工作进程会扫描表和索引，找出任何事务都不再需要的行版本并删除它们。但长事务（包括空闲事务）可能仍需要旧的行版本，因此自动清理会跳过这些版本。即使删除成功，释放出的空间仍然属于表（或索引）。因此，表和索引的大小会增长，却不会在清理后缩小，这就称为膨胀效应。在极端情况下，表和索引内部的已释放空间可能超过有效数据的总量。 - 锁和数据库系统可用连接耗尽。在写入强度较高时，事务中的命令可能持有行锁。相邻事务可能希望访问同一行，并在尝试获取锁时等待空闲事务释放锁。等待中的进程无法供应用使用。在高负载下，应用会尝试打开新的连接，这可能导致等待队列增长，并达到同时允许的连接数上限。一旦达到这个上限，应用就无法连接数据库，从而使应用、数据库系统以及其他也想建立数据库连接的应用都无法工作。 因此，`idle in transaction` 是一种潜在危险的状态，进程长时间处于其中可能导致负面后果。应当跟踪并消除这类事务。作为临时措施，可以在数据库系统设置中启用 *idle\_in\_transaction\_session\_timeout* 超时，自动结束这类事务。该设置既可以在数据库系统的全局配置层面统一设置，也可以针对特定用户或数据库单独设置。另一种方案是使用 cron 工具定期运行基于 `pg_terminate_backend` 函数的脚本。当 *idle\_in\_transaction\_session\_timeout* 的能力不足、需要更精细的超时设置时，这种方案可能更合适。下面是 `pg_terminate_backend` 与 `pg_stat_activity` 配合使用的示例： ```text {label="psql" .source-commands hl_lines="1 2 3 4"} # SELECT pg_terminate_backend(pid) FROM pg_stat_activity WHERE usename = 'pgbench' AND application_name = 'pgbench' AND clock_timestamp() - coalesce(xact_start, query_start) > '00:01:00'::interval AND state ~ 'idle in transaction'; ``` 在 psql 中执行一次这个查询即可。如有需要，可以重新定义 `SELECT` 中的字段列表或条件，也可以保存结果输出，例如用于分析。 > [!NOTE] > **clock\_timestamp vs now** > > 通常，可以用当前时间减去时间戳来确定持续时间。任何数据库系统都有一个输出当前时间的函数。在 PostgreSQL 中，这个函数就是众所周知的 `now`，但它的特点是显示事务开始时间。可以在一个事务中多次调用 `now` 试试看。而对于监控，建议使用总是显示当前时间戳的 `clock_timestamp`。 ## 2.6. 查询与事务的执行时间 {#mon-section-2-6} 工作负载由持续不断的查询和事务流组成，执行得越快，系统的吞吐量就越高。观察工作负载时，可以聚焦于单独的执行单位——事务和查询，并跟踪工作负载中出现的不常见长查询和长事务。无论工作负载属于哪种类型，优化执行时间都会改善性能。无论是 OLTP、OLAP 还是 HTAP，优化的目标始终是缩短查询执行时间，并减少执行查询所需的资源量。查询执行时间取决于所需资源数量、数据库系统可用资源、查询复杂度、查询参数和执行计划等因素。命令执行时间过长可能表明存在各种问题。例如，规划器选择了低效的计划，就可能表现为执行时间长且资源消耗过多。长事务可能源于应用设计不佳，以及应用一侧的事务管理存在问题。从应用角度看，数据库系统中的操作执行时间过长，可能导致应用自身处理查询超时，或者在没有配置超时时表现为卡死；还可能耗尽数据库连接并导致应用异常停止。管理员的日常工作包括跟踪命令执行时间、调查并消除运行缓慢的原因。DBA 往往需要与应用开发团队共同解决这些原因。 `pg_stat_activity` 中有几个字段可用于跟踪命令和事务的执行时长： - `xact_start` — 事务开始时间。如果当前没有活动事务，或者事务中发生了错误但事务没有关闭，即处于 `idle in transaction (aborted)` 状态，则该值可能为空（`NULL`）； - `query_start` — 当前查询开始的时间（`active` 状态），或者会话中最近一次执行的查询开始时间（其他所有状态）。 可以使用下面这种查询获取查询和事务的执行时长： ```text {label="psql" .source-commands hl_lines="1 2 3 4 5 6 7 8 9"} # SELECT pid, CASE WHEN wait_event_type = 'Lock' THEN 'waiting' ELSE state END AS state, (clock_timestamp() - xact_start) AS xact_age, (clock_timestamp() - query_start) AS query_age FROM pg_stat_activity WHERE (clock_timestamp() - xact_start > '00:00:00'::interval) OR (clock_timestamp() - query_start > '00:00:00'::interval AND state = 'idle in transaction (aborted)') ORDER BY coalesce(xact_start, query_start); pid | state | xact_age | query_age --------+-------------------------------+-----------------+----------------- 3878 | idle in transaction (aborted) | | 00:00:04.264773 242533 | active | 00:00:00.176216 | 00:00:00.174478 241520 | active | 00:00:00.150633 | 00:00:00.149281 242541 | waiting | 00:00:00.141747 | 00:00:00.139989 241506 | waiting | 00:00:00.123768 | 00:00:00.122107 241523 | active | 00:00:00.102864 | 00:00:00.101012 ``` 这个查询有几点需要注意： - 确定状态时使用了包含等待事件的扩展逻辑。事件类型为 `wait_event_type = 'Lock'` 的进程会被视为正在等待并发事务完成的进程。 - 查询条件筛选的是事务，而不是单独的查询：`OR` 左侧查找活动事务，右侧查找已取消（`aborted`）但尚未关闭的事务。原因如下：即使查询在事务之外单独执行，它实际上也使用事务机制，本质上是只包含一条命令的事务。在这种情况下，即使是普通查询也会填充 `xact_start` 字段（此时它等于 `query_start`）。因此没有必要专门查找查询；它们无论如何都会出现在结果中。 - `OR` 右侧用于查找已取消事务的条件使用了 `state` 字段。这样做是因为事务内部发生错误时，`xact_start` 会被设置为 `NULL`，但事务本身仍然保持打开。为了不漏掉这类事务，应依据 `query_start`——即发生错误并结束的那个查询的开始时间。 - 修改区间值可以把非常短的事务从结果中排除。 借助指标 `postgres_activity_max_seconds` 可以获取事务的最长持续时间。该指标包含多个标签： - `user` — 发起活动的用户； - `database` — 客户端连接到的数据库； - `type` — 活动类型：用户查询或后台维护（自动清理或收集规划器统计信息时）； - `state` — 会话状态，对应 `state` 字段，并考虑了 `waiting` 状态。 利用这些标签，可以按所需的维度聚合多个指标。例如，下面的查询可以按具体用户显示长时间活动，而不考虑活动类型、数据库和状态： ```text {label="PromQL" .source-commands hl_lines="1"} # max by (user) (postgres_activity_max_seconds{service_id="primary"}) ``` 图 [2.9](/02-activity-statistics/#mon-figure-caption-56) 展示了根据这个查询生成的图表示例。从图中可以看出，大部分查询的执行时间不超过 500 毫秒。有一个自动清理进程比较突出，在当时已经运行了大约 4 秒。需要注意，这个指标及其图表并不显示数据库系统中发生的全部活动，而只显示查询 `pg_stat_activity` 时刻正在发生的活动。 ![事务执行时长](/images/monitoring/figure-2.9.png) {#fig-2.9 num="2.9" caption="事务执行时长" width=1830 height=598} ## 2.7. 锁等待时间跟踪 {#mon-section-2-7} 进程在等待期间无法进行有用工作，直到等待原因消失。长时间等待本身就意味着资源和时间使用效率低下。找出并消除发生等待的环节，可以加快工作负载执行，提高系统整体性能。下面讨论锁上的耗时，因为目前没有一种能够保证准确确定特定事件等待时间的方法。 ### 使用 pg\_locks.waitstart {#mon-section-star-57} 要评估等待时间，需要使用 `pg_locks.waitstart` 字段。如果进程没有处于等待状态，该字段的值就为空。如果进程无法获取锁，就会进入等待，该字段显示进程进入等待的时间。这里还存在与同一视图另一个字段的隐含联系：不仅 `waitstart` 表示正在等待锁，`granted` 标志也表示这一点。不过两者并不完全同步；当 `granted` 已经设置为 `false` 时，`waitstart` 仍可能在很短时间内保持为 `NULL`。 评估等待时间时，至少可以采用两种计算方法（实践中还可能遇到更多方法）。可以用下面的查询获取当前所有进程的等待时间： ```text {label="psql" .source-commands hl_lines="1 2 3 4 5 6 7"} # SELECT a.pid, a.state, l.granted, a.wait_event ||'.'|| a.wait_event_type AS wait, clock_timestamp() - l.waitstart AS wait_age FROM pg_stat_activity a, pg_locks l WHERE a.pid = l.pid AND NOT l.granted; pid | state | granted | wait | wait_age ---------+--------+---------+--------------------+----------------- 2405179 | active | f | transactionid.Lock | 00:00:00.284314 2406471 | active | f | transactionid.Lock | 00:00:00.277662 2405394 | active | f | transactionid.Lock | 00:00:00.018215 2406467 | active | f | transactionid.Lock | 00:00:00.060994 2406472 | active | f | tuple.Lock | 00:00:00.240659 2406466 | active | f | transactionid.Lock | 00:00:00.125218 ``` 第一种计算方法是把所有进程的所有等待相加。这样得到的是总等待时间；这个值越大，情况越糟，尤其是在并发性很高的系统中。这种方法适合总体评估数据库系统花费了多少时间等待。 第二种方法只统计所有进程中的最大等待时间。这样得到的情况只对应等待时间最长的一个进程。这种方法适合实时监控，用来了解某一时刻是否存在（或曾经存在）一个进程，它等待了特定的一段时间。 从原始查询中删去多余字段，并把它放入 CTE，就可以同时得到这两个值，还能计算等待进程的数量： ```text {label="psql" .source-commands hl_lines="1 2 3 4 5 6 7 8"} # WITH q AS ( SELECT clock_timestamp() - l.waitstart AS wait_age FROM pg_stat_activity a, pg_locks l WHERE a.pid = l.pid AND NOT l.granted ) SELECT count(*), coalesce(max(wait_age), '0'::interval) AS max, coalesce(sum(wait_age), '0'::interval) AS sum FROM q; count | max | sum -------+-----------------+---------------- 6 | 00:00:00.284314 | 00:00:01.007062 ``` 从输出可以看出，查询时刻有 6 个进程在等待，等待时间最长的约为 284 毫秒，所有数据库客户端合计等待了大约 1 秒。在测试环境的合成负载下，这些数字可能显得微不足道，但在真实环境中，数值可能会大得多。及时发现并缩短等待时间，可以提高应用和数据库系统的性能。 当前使用的代理的默认实现会收集所有进程中的最大等待时间。可以使用下面的查询获取等待统计信息和图表（图 [2.10](/02-activity-statistics/#mon-figure-caption-58)）： ```text {label="PromQL" .source-commands hl_lines="1"} # postgres_activity_max_seconds{service_id="primary",state="waiting"} ``` ![锁等待时长](/images/monitoring/figure-2.10.png) {#fig-2.10 num="2.10" caption="锁等待时长" width=1838 height=598} 锁等待没有超过 1 秒，对测试环境来说可以接受。但实际情况很可能比图表显示的稍差，因为 `pg_locks` 不会累积统计信息，因此无法提供锁情况的完整视图。 ### 使用 pg\_stat\_activity.state\_change {#mon-section-star-59} 在 PostgreSQL 14 以前，`pg_locks.waitstart` 字段不存在，但跟踪等待时间的需求一直存在。在这些数据库系统版本中，可以使用 `pg_stat_activity.state_change` 字段提供一种精度较低的方法。该字段保存状态从前一个状态切换到当前状态的时间戳。如果等待被包含在活动状态中，那么当进程具有等待标记时，可以把处于活动状态的时间视为等待时间。这种方法的缺点是，进程切换到活动状态后，等待可能不会立即开始，而是在一段时间后才开始，但整个期间都会被计入等待时间。在包含正确来源 `pg_locks.waitstart` 的 PostgreSQL 14 中，可以很容易演示这一点。 为了演示，需要一张小表，例如由标准 pgbench 脚本创建的表。在实验中，这张表包含 50,000 行。需要打开到数据库系统的三个会话：第一个和第二个会话用于重现查询被阻塞的测试场景，第三个会话用于跟踪统计信息。在第一个会话中，需要打开事务并更新测试表的最后一行，同时保持事务打开： ```text {label="text" .source-commands hl_lines="1 2"} # BEGIN; # UPDATE pgbench_accounts SET abalance = abalance + 1 WHERE aid = 50000; ``` 在第二个会话中，需要先获取进程的 `pid`，然后启动对整张表的更新。 ```text {label="psql" .source-commands hl_lines="1 3"} # SELECT pg_backend_pid(); 2291758 # UPDATE pgbench_accounts SET abalance = abalance + 1; ``` 在第三个会话中，应从 `pg_stat_activity` 和 `pg_locks` 获取统计信息。条件指定只输出进程标识符为 2291758 的第二个会话。为了便于跟踪，第一次执行查询后可以运行元命令 `\watch 1`，让查询每秒重复一次。 ```text {label="psql" .source-commands hl_lines="1 2 3 4 5 6"} # SELECT a.pid, a.state, l.granted, a.wait_event ||'.'|| a.wait_event_type AS wait, (clock_timestamp() - a.state_change)::interval(0) AS state_age, (clock_timestamp() - l.waitstart)::interval(0) AS wait_age FROM pg_stat_activity a, pg_locks l WHERE a.pid = l.pid AND a.pid = 2291758; ``` 我们关注查询输出中的 `state_age` 和 `wait_age` 字段，它们将展示两种进程等待时间计算方法的差异。整张表的更新会持续执行，直到到达此前在仍未关闭的事务中已经更新过的最后一行。 ```text {label="text"} pid | state | granted | wait | state_age | wait_age ---------+--------+---------+-----------------+-----------+---------- 2291758 | active | t | WALWrite.LWLock | 00:00:08 | 2291758 | active | t | WALWrite.LWLock | 00:00:08 | 2291758 | active | t | WALWrite.LWLock | 00:00:08 | 2291758 | active | t | WALWrite.LWLock | 00:00:08 | ``` 这里可以看到，进程处于 `active` 状态，状态切换时间 `state_age` 在增加。`granted = true` 表示没有锁等待，查询正在工作。过一段时间后，查询执行会停下来，此时可能看到类似下面的结果： ```text {label="text"} pid | state | granted | wait | state_age | wait_age ---------+--------+---------+--------------------+-----------+---------- 2291758 | active | t | transactionid.Lock | 00:00:14 | 2291758 | active | t | transactionid.Lock | 00:00:14 | 2291758 | active | t | transactionid.Lock | 00:00:14 | 2291758 | active | f | transactionid.Lock | 00:00:14 | 00:00:05 2291758 | active | t | transactionid.Lock | 00:00:14 | 2291758 | active | t | transactionid.Lock | 00:00:14 | ``` 输出中出现了一行未能获取的锁，其状态为 `granted = false`，并且 `wait_age` 开始计时。与此同时，`state` 的值保持不变，`state_age` 没有重置，仍在继续计时。这个例子表明，查询在开始等待锁之前进行了大约 9 秒的有用工作。实际上，等待是在查询运行 9 秒后才开始的。这种行为正体现了使用 `waitstart` 和 `state_change` 进行统计时的差异。如果决定重现实验，请不要忘记最后取消或关闭事务，这样第二个会话中的查询才能结束。 使用基于 `state_change` 的时间统计时，应记住这种行为。例如，在主要由短而快的查询组成的 OLTP 负载中，它不会严重扭曲统计信息，这种计算方法可能看起来可以接受。但对于更长的 OLAP 查询（如上面的实验），统计信息可能不准确，等待时间会不恰当地包含有用工作的执行时间，这种计算方法就可能值得怀疑。 ## 2.8. 锁树 {#mon-section-2-8} 实践中经常会出现这样的情况：某些时刻有很多进程在等待锁，其中一部分进程又被其他进程阻塞。如果此时找到并消除锁的来源，其他进程很可能就能正常继续工作。然而，如果没有准备好的工具，很难准确识别出导致所有这些锁的进程。可以直接分析 `pg_stat_activity` 和 `pg_locks` 的输出，但这样做不方便，也可能耗费很长时间。要确定锁的来源，需要找出进程之间的依赖关系，并在被阻塞进程与阻塞进程之间建立依赖树。这样的可视化可以快速确定锁的来源并消除它。解决这类问题的方法并不新颖，在互联网上可以找到多种用于输出锁树的实现。这些查询都基于 `pg_stat_activity` 和 `pg_locks`，通常会占据数页篇幅，因此这里不再列出。为了便于使用，最好把这类查询封装成视图。 我以这个查询[^mon-67-1]为起点，并对它做了少量修改。最终查询位于本书代码仓库的 `playground/scripts/locktree.sql` 文件中[^mon-67-2]。该查询的关键特点是使用 `pg_blocking_pids` 函数。这个函数接收进程标识符，并返回阻塞该进程的进程列表。这样很方便，也可以避免使用 `pg_locks`；不过根据文档，频繁调用该函数可能损害数据库系统性能，因为函数会短暂地独占锁管理器的共享状态。无论如何，这个函数很实用，偶尔用于搜索问题通常不会有问题。但不应为了监控而定期使用它，例如用它采集指标。在某些运行条件下（负载很高、对延迟有要求），即使只为调试，这一特性也无法接受；此时可以使用 `pg_locks`[^mon-67-3] 代替 `pg_blocking_pids`。 下面看一看如何在测试环境中获取锁树的两个示例。 ```text {label="text"} pid | blocked_by | state | wait | wait_age | tx_age | usename | datname | blkd | query ---------+-------------------+----------+---------------------+----------+-----------+---------+---------+------+--------------------------------------------------------------------------------------- 2072376 | {} | active | LWLock.WALWrite | | 00:00:00 | classic | pgbench | 1 | [2072376] END; 2072427 | {2072376} | waiting | Lock.transactionid | 00:00:00 | 00:00:00 | maru | pgbench | 0 | [2072427] . UPDATE pgbench_branches SET bbalance = bbalance + 3135 WHERE bid = 17; 2072386 | {} | active | LWLock.WALWrite | | 00:00:01 | classic | pgbench | 1 | [2072386] END; 2072382 | {2072386} | waiting | Lock.transactionid | 00:00:01 | 00:00:01 | classic | pgbench | 0 | [2072382] . UPDATE pgbench_branches SET bbalance = bbalance + 232 WHERE bid = 15; 2072387 | {} | active | LWLock.WALWrite | | 00:00:01 | classic | pgbench | 1 | [2072387] END; 2072388 | {2072387} | waiting | Lock.transactionid | 00:00:00 | 00:00:00 | classic | pgbench | 0 | [2072388] . UPDATE pgbench_branches SET bbalance = bbalance + 3169 WHERE bid = 13; 2072394 | {} | active | LWLock.WALWrite | | 00:00:01 | classic | pgbench | 1 | [2072394] END; 2072391 | {2072394} | waiting | Lock.transactionid | 00:00:00 | 00:00:00 | classic | pgbench | 0 | [2072391] . UPDATE pgbench_branches SET bbalance = bbalance + -2825 WHERE bid = 6; 2072399 | {} | active | LWLock.WALWrite | | 00:00:01 | classic | pgbench | 1 | [2072399] END; 2072390 | {2072399} | waiting | Lock.transactionid | 00:00:01 | 00:00:01 | classic | pgbench | 0 | [2072390] . UPDATE pgbench_branches SET bbalance = bbalance + -122 WHERE bid = 7; 2072415 | {} | active | LWLock.WALWrite | | 00:00:01 | maru | pgbench | 1 | [2072415] END; 2072418 | {2072415} | waiting | Lock.transactionid | 00:00:00 | 00:00:00 | maru | pgbench | 0 | [2072418] . UPDATE pgbench_branches SET bbalance = bbalance + -3319 WHERE bid = 12; 2072423 | {} | active | IO.WALSync | | 00:00:01 | maru | pgbench | 2 | [2072423] END; 2072410 | {2072423} | waiting | Lock.transactionid | 00:00:01 | 00:00:01 | serral | pgbench | 0 | [2072410] . UPDATE pgbench_tellers SET tbalance = tbalance + 1404 WHERE tid = 18; 2072416 | {2072423} | waiting | Lock.transactionid | 00:00:00 | 00:00:00 | maru | pgbench | 0 | [2072416] . UPDATE pgbench_branches SET bbalance = bbalance + 1468 WHERE bid = 11; 2072424 | {} | active | LWLock.WALWrite | | 00:00:01 | maru | pgbench | 4 | [2072424] END; 2072408 | {2072424} | waiting | Lock.transactionid | 00:00:01 | 00:00:01 | serral | pgbench | 3 | [2072408] . UPDATE pgbench_branches SET bbalance = bbalance + -1605 WHERE bid = 8; 2072392 | {2072408} | waiting | Lock.tuple | 00:00:00 | 00:00:00 | classic | pgbench | 2 | [2072392] .. UPDATE pgbench_branches SET bbalance = bbalance + -3889 WHERE bid = 8; 2072409 | {2072408,2072392} | waiting | Lock.tuple | 00:00:00 | 00:00:00 | serral | pgbench | 1 | [2072409] ... UPDATE pgbench_branches SET bbalance = bbalance + 4620 WHERE bid = 8; 2072419 | {2072409} | waiting | Lock.transactionid | 00:00:00 | 00:00:00 | maru | pgbench | 0 | [2072419] .... UPDATE pgbench_tellers SET tbalance = tbalance + 2315 WHERE tid = 180; ``` 第一个示例中的锁经常出现在并发更新数据时。输出中的每一行描述一个进程，并根据 `pg_stat_activity` 展示该会话的详细信息。下面看一看这个查询中的字段： - `pid` — 进程标识符； - `blocked_by` — 阻塞当前进程的进程列表。根据 `pg_blocking_pids` 函数计算； - `state` — 进程状态；根据条件 `wait_event_type = 'Lock'`，其中补充了伪状态 `waiting`； - `wait` — 由 `wait_event_type` 和 `wait_event` 组成的等待标记； - `wait_age` — 根据 `pg_locks.waitstart` 计算的进程等待时长； - `tx_age` — 事务时长； - `usename` — 用户名； - `datname` — 数据库名； - `blkd` — 被该进程阻塞的其他进程数量； - `query` — 查询文本。包含进程标识符，以及该进程在所属锁树分支中的层级。 可以把所有进程大致分成几组：每组都有一个没有被任何进程阻塞的主要锁来源，也有被阻塞的进程，而这些进程还可能阻塞组内的其他参与者。我们仔细看看最后一组，其中阻塞其他参与者的主要进程的标识符是 2072424。从查询文本可以看出，这是提交事务（`END` 或 `COMMIT`）；该进程处于活动状态，等待标记为 `LWLock.WALWrite`。这表明系统正在写入 WAL，在写入完成之前，客户端无法发送其他命令或打开事务。这种行为符合默认使用的同步提交模式（参见 *synchronous\_commit*）。从 `blkd` 字段可以看到，该事务提交还阻塞了下面几行所描述的另外 4 个进程。通过 `pid` 和 `blocked_by` 字段，可以跟踪进程之间的关系以及谁阻塞了谁。`query` 字段中的点号还可以方便地表示*锁深度*。同一字段中的查询文本显示，有 3 个进程试图根据条件 `WHERE bid = 8` 更新同一行。这一行很可能是在当前正在提交的事务中更新的，因此形成了等待队列。`state` 和 `wait` 字段表明，这 4 个进程都在等待锁。根据 `wait_age` 字段，等待时间不到 1 秒，这对测试工作负载来说完全可以接受；但在生产负载中，即使这么短的等待也可能导致应用延迟。`usename` 和 `datname` 字段指出了锁是以哪些用户的身份、在什么数据库中产生的。 再看一个可能出现在测试环境中的锁树示例。 ```text {label="text"} pid | blocked_by | state | wait | wait_age | tx_age | usename | datname | blkd | query ------+------------+---------+--------------------+----------+----------+----------+---------+------+-----------------------------------------------------------------------------------------------... 161 | {} | active | IO.WALSync | | 00:00:00 | postgres | pgbench | 20 | [161] TRUNCATE pgbench_history ; 1923 | {161} | waiting | Lock. relation | 00:00:00 | 00:00:00 | serral | pgbench | 0 | [1923] . INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (15, 13, 1518573,... 1924 | {161} | waiting | Lock. relation | 00:00:00 | 00:00:00 | serral | pgbench | 2 | [1924] . INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (46, 6, 589135, -... 1925 | {161} | waiting | Lock. relation | 00:00:00 | 00:00:01 | serral | pgbench | 1 | [1925] . INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (106, 12, 100334,... 1929 | {161} | waiting | Lock. relation | 00:00:00 | 00:00:00 | serral | pgbench | 0 | [1929] . INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (93, 18, 1330287,... 1936 | {161} | waiting | Lock. relation | 00:00:00 | 00:00:00 | maru | pgbench | 0 | [1936] . INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (99, 7, 914556, 1... 1942 | {161} | waiting | Lock. relation | 00:00:00 | 00:00:00 | maru | pgbench | 3 | [1942] . INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (61, 20, 669763, ... 1957 | {161} | waiting | Lock. relation | 00:00:00 | 00:00:00 | classic | pgbench | 0 | [1957] . INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (104, 4, 880250, ... 1963 | {161} | waiting | Lock. relation | 00:00:00 | 00:00:00 | classic | pgbench | 0 | [1963] . INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (162, 8, 1371725,... 1964 | {161} | waiting | Lock. relation | 00:00:00 | 00:00:00 | classic | pgbench | 0 | [1964] . INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (69, 9, 71583, 18... 1971 | {161} | waiting | Lock. relation | 00:00:00 | 00:00:01 | classic | pgbench | 1 | [1971] . INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (44, 14, 1331579,... 1976 | {161} | waiting | Lock. relation | 00:00:00 | 00:00:00 | classic | pgbench | 2 | [1976] . INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (60, 17, 1238351,... 955 | {1942} | waiting | Lock.transactionid | 00:00:00 | 00:00:00 | pgbench | pgbench | 1 | [955] .. UPDATE pgbench_branches SET bbalance = bbalance + -2769 WHERE bid = 20; 1926 | {1976} | waiting | Lock.transactionid | 00:00:00 | 00:00:00 | serral | pgbench | 0 | [1926] .. UPDATE pgbench_branches SET bbalance = bbalance + -410 WHERE bid = 17; 1927 | {1971} | waiting | Lock.transactionid | 00:00:00 | 00:00:00 | serral | pgbench | 0 | [1927] .. UPDATE pgbench_branches SET bbalance = bbalance + -4047 WHERE bid = 14; 1930 | {1924} | waiting | Lock.transactionid | 00:00:00 | 00:00:00 | serral | pgbench | 1 | [1930] .. UPDATE pgbench_branches SET bbalance = bbalance + -3100 WHERE bid = 6; 1938 | {1925} | waiting | Lock.transactionid | 00:00:00 | 00:00:00 | maru | pgbench | 0 | [1938] .. UPDATE pgbench_branches SET bbalance = bbalance + 608 WHERE bid = 12; 1955 | {1976} | waiting | Lock.transactionid | 00:00:00 | 00:00:00 | classic | pgbench | 0 | [1955] .. UPDATE pgbench_branches SET bbalance = bbalance + 1745 WHERE bid = 17; 1966 | {1942} | waiting | Lock.transactionid | 00:00:00 | 00:00:00 | classic | pgbench | 0 | [1966] .. UPDATE pgbench_branches SET bbalance = bbalance + -4835 WHERE bid = 20; 1931 | {955} | waiting | Lock.transactionid | 00:00:00 | 00:00:00 | serral | pgbench | 0 | [1931] ... UPDATE pgbench_tellers SET tbalance = tbalance + -4006 WHERE tid = 182; 1972 | {1930} | waiting | Lock.tuple | 00:00:00 | 00:00:00 | classic | pgbench | 0 | [1972] ... UPDATE pgbench_branches SET bbalance = bbalance + -3771 WHERE bid = 6; ``` 这个示例中的锁来源是执行清空表命令（`TRUNCATE`）的进程。这是一个相当快的操作，实质是把数据文件替换为空文件；不过它首先必须等待此前针对目标表启动的查询完成。清空表时表会被锁定，因此所有访问该表的进程都必须等待命令完成。`blkd` 字段显示，`TRUNCATE` 进程（`pid = 161`）还阻塞了 20 个进程的执行。其中大约一半试图向被清空的表插入行，这些进程的 `blocked_by` 字段都包含 `TRUNCATE` 进程的标识符。另一部分进程是更新操作，它们又在等待插入完成。可以通过把 `blocked_by` 中的标识符与执行插入的进程的 `pid` 字段进行匹配来确认这一点。还可以匹配查询中的 `bid` 字段：它会在各条等待查询链中保持一致。例如，进程 955 更新 `bid = 20` 的行，并等待进程 1942 中的插入完成；而进程 1942 自己又在等待 `TRUNCATE` 命令完成。执行 `TRUNCATE` 的进程的状态和等待标记表明，该进程处于活动状态，正在把 WAL 段与磁盘上的文件同步（通过调用 `fsync`，或使用参数 *wal\_sync\_method* 指定的其他方法）。确定等待原因的另一种方法，是检查数据库系统服务器日志中的锁记录，前提是启用了 *log\_lock\_waits* 参数，且等待时间超过 *deadlock\_timeout* 参数的值（默认是一秒）。 上面两个案例都属于测试环境中的工作负载，其特点是事务和锁都很短。实践中情况可能复杂得多，尤其是锁的来源为空闲事务时，它们可能不可预测地长时间持有锁，并可能导致故障。在这类情况下，通常的处理方式是强制结束进程。遇到关键情况时，重要的是快速判断并找到根进程，结束它就能解决问题。如果信息不足，往往只能不加区分地结束大量进程。而使用类似上面查询的工具，就可以更准确地确定并消除锁来源，让其他进程继续工作。 ## 总结 {#mon-p69-h561} - 客户端活动统计信息有助于了解数据库系统中正在发生什么。 - 数据库系统提供了三个关于客户端活动的重要数据源：`pg_stat_activity`、`pg_locks` 和 `pg_stat_database` 视图。 - 数据库管理员和监控工具都通过 SQL 查询从这些视图中获取数据。 - 客户端会话在其生命周期中可能处于不同状态。 - 事务活动有助于快速评估数据库集簇中的负载。 - 必须及时跟踪并消除危险的等待和锁。 - 应消除事务处于空闲状态的情况，或将其保持时间降至最低。 - 客户端活动的持续时间会直接影响性能。 - 锁等待会降低数据库系统和应用的性能。 - 锁树可以快速找出锁的来源。 [^mon-30-1]: [postgrespro.ru/docs/postgresql/current/libpq-async]() [^mon-31-1]: [momjian.us/main/writings/pgsql/mvcc.pdf]() [^mon-31-2]: [postgrespro.ru/docs/postgresql/current/sql-select#SQL-FOR-UPDATE-SHARE]() [^mon-37-1]: [postgrespro.ru/docs/postgresql/current/monitoring-stats#WAIT-EVENT-LOCK-TABLE]() [^mon-37-2]: [postgrespro.ru/docs/postgresql/current/explicit-locking#LOCKING-TABLES]() [^mon-41-1]: [postgrespro.ru/docs/postgresql/current/catalogs]() [^mon-50-1]: [github.com/lesovsky/pgscv/commit/d098923caef2d1a839df76ad9f441893640faed5]() [^mon-51-1]: [postgrespro.ru/docs/postgresql/current/libpq-fastpath]() [^mon-52-1]: [postgrespro.ru/docs/postgresql/current/monitoring-stats#MONITORING-PG-STAT-ACTIVITY-VIEW]() [^mon-67-1]: [postgres.ai/blog/20211018-postgresql-lock-trees]() [^mon-67-2]: [github.com/lesovsky/postgresql-monitoring-book/blob/main/playground/scripts/locktree.sql]() [^mon-67-3]: [dev.to/bolajiwahab/2022-01-13-postgresql-lock-trees-56e0]()