本章目录
第 7 章：性能剖析
7.1 什么是性能剖析
前面几章介绍了查询如何工作、执行计划由哪些基本操作组成，以及哪些因素会影响规划器对不同计划的选择。这是最难、也最重要的部分。理解这些机制之后，结合逻辑与常识，我们往往就能判断一个查询的执行是否高效，以及怎样才能改进它。
但怎样才能找到真正值得优化的那个查询呢？
任何优化工作都应从性能剖析 (profiling) 开始，数据库优化也不例外，尽管我们并不总是使用这个名称。我们将出现问题的任务拆成较小的部分，测量各部分占总工作量的多少。了解各部分的执行频率也很有帮助。
某一部分占总开销的比例越大，优化它可能带来的收益就越大。实际工作中，还要考虑优化本身的投入：理论上很大的收益，可能需要付出很高的代价，或承担较大的风险。
有时，某个操作单次执行很快，却被执行了太多次。ORM 生成的查询中就经常出现这种情况。此时，更值得问的是：这个操作真的需要执行这么多次吗？调整应用架构通常并不容易，但它带来的收益可能远大于优化某一次查询执行。
对于管理员而言，即使不是在排查某一个具体的性能问题，数据库整体活动的性能剖析结果也很有价值。它能够帮助管理员找出消耗系统资源最多的部分。监控系统应当提供这样的视角。
Andrey Zubkov 开发的 pg_profile 扩展就是完成这项工作的工具之一。1 它基于 PostgreSQL 的统计视图，定期保存数据库活动快照。对比这些快照，既有助于发现性能问题，也有助于了解问题出现时的运行状况。监控架构、工具和指标选择是一个很大的话题，这里不再展开。
Postgres Professional 还出版了 Alexey Lesovsky 的俄文著作《Monitoring PostgreSQL》，对这一主题有更深入的介绍。2
不过，如果要排查某个具体问题，就应当限定性能剖析的范围，让测量仅覆盖复现该问题所需的操作。
7.2 测量什么
应该用什么单位衡量各部分的开销？对最终用户而言，最有意义的指标是响应时间：从发起操作到获得结果，经过了多少秒。
从衡量工作量的角度看，观察 I/O 量可能更方便，也就是读取和写入的页面数。这个指标更稳定：在数据和配置参数相同的情况下，它不依赖硬件特性或服务器当前的负载。
使用接近实际情况的数据量进行分析也很重要。Postgres.ai 的 Database Lab Engine 等工具能够快速创建 thin clone，无需完整复制底层存储，就能帮助我们复现生产规模下的数据库行为。3
执行查询的大量时间都花在读取和处理数据页上，因此，I/O 量通常能够较好地反映查询所需的工作量。不过，对最终用户而言，这个指标并没有多少直观意义。
7.3 应用的性能剖析
性能问题经常出在数据库中：一个不合适的执行计划，就可能让运行时间相差几个数量级。但情况并非总是如此。缓慢的客户端连接、序列化、应用服务器上的处理、客户端渲染、排队等待、远程服务调用，以及网络传输，都可能占据用户响应时间的大部分。因此，完整的性能剖析应当覆盖客户端、应用服务器、网络和数据库。
要获得这样的端到端性能剖析结果，并不容易，除非系统各部分都能提供有用的监测数据。至少应该测量总响应时间，并将其与数据库处理所耗费的时间进行比较。在认定数据库就是瓶颈之前，先检查是否存在明显的网络延迟，以及时间是否花在了 PostgreSQL 之外。
下文假定我们已经将问题定位到数据库。
7.4 PL/pgSQL 的性能剖析
用户的一次操作通常会执行不止一条 SQL 语句。要找出值得优化的语句，就需要将性能剖析细化到语句级别。
数据库端的应用也可能包含过程式代码，而不只是 SQL。
对于 PL/pgSQL 代码，可以使用 Jan Wieck 开发的 PLProfiler 对脚本和正在运行的会话进行性能剖析。它能够生成 HTML 报告，并以火焰图展示调用关系。4
Pavel Stěhule 开发的 plpgsql_check 也是一个实用的扩展。它能够对 PL/pgSQL 代码进行额外检查，发现某些性能问题，同时也提供性能剖析功能。5
7.5 查询的性能剖析
PostgreSQL 主要提供两种方式来剖析已执行的 SQL：服务器日志，以及语句执行的累积统计。后一种方式最常用的工具是 pg_stat_statements。
7.5.1 服务器日志
通过配置参数，可以让服务器记录语句及其执行时长。通常可以从 log_min_duration_statement 入手。
怎样从日志中准确找出属于某次用户操作的查询呢？在一个会话中修改 log_min_duration_statement，只会影响这个会话；性能分析人员无法通过标准机制，从另一个会话修改任意后端进程的这一设置。我们可以从汇总的日志消息中筛选出所需的记录。为此，最好在 log_line_prefix 中加入更多标识信息，例如进程 ID、会话 ID、用户、数据库或应用名称。连接池会使事情变得更加复杂。
函数内部执行的嵌套 SQL 则是另一个需要处理的问题。auto_explain 模块能够记录执行计划；配置 auto_explain.log_nested_statements 后，还可以记录嵌套语句的计划。6
繁忙服务器的日志可能非常庞大。pgBadger 等外部工具能够汇总和分析 PostgreSQL 日志。7
应用代码也可以输出自己的关联标识和诊断消息，帮助我们将用户操作与数据库活动对应起来。
7.5.2 语句执行统计
第二种方式是使用 pg_stat_statements 扩展收集的语句执行统计。8 这里的“统计”与第 6 章《统计信息》中的含义不同。规划器统计信息描述的是数据分布，用于预测后续查询的执行情况；pg_stat_statements 汇总的则是已经发生的执行活动。收集到的查询执行统计中，也包括以页面数表示的 I/O 信息。
不同查询的数量可能非常多，因此可保存的统计条目数受到 pg_stat_statements.max 的限制。条目达到上限时，执行频率较低的语句条目会被淘汰。
如果两个查询除常量外具有相同的语法树，就会被视为同一种查询。需要注意，这些查询可能使用不同的执行计划，执行时间也可能不同。
当 compute_query_id 设置为 auto 或 on 时，PostgreSQL 内核会计算查询标识符。这样就可以使用统一的标识符，关联不同扩展提供的信息。9
启用 pg_stat_statements 扩展，后面将用它进行性能剖析：
CREATE EXTENSION pg_stat_statements;
CREATE EXTENSION
ALTER SYSTEM SET shared_preload_libraries =
'pg_stat_statements';
ALTER SYSTEM随后需要重启服务器。
postgres$ pg_ctl restart -l /home/postgres/logfile
postgres$ /usr/local/pgsql/bin/psql demo下面的示例还需要收集嵌套语句的统计信息：
SET pg_stat_statements.track = 'all';
SET创建一个简洁的视图，只保留我们要查看的字段：
CREATE VIEW statements_v AS
SELECT
queryid,
toplevel,
substring(regexp_replace(query,' +',' ','g') FOR 55)
AS query,
calls,
round(total_exec_time)/1000 AS time_sec,
shared_blks_hit + shared_blks_read +
shared_blks_written AS shared_blks
FROM pg_stat_statements
ORDER BY total_exec_time DESC;
CREATE VIEW现在来看一份按机型和舱位等级统计旅客人数的报表。先定义一个函数，统计指定机型、指定舱位等级的旅客人数：
CREATE FUNCTION qty(
airplane_code text, fare_conditions text
) RETURNS bigint
AS $$
SELECT count(*)
FROM timetable tt
JOIN boarding_passes bp ON bp.flight_id = tt.flight_id
JOIN seats s ON s.airplane_code = tt.airplane_code
AND s.seat_no = bp.seat_no
WHERE tt.airplane_code = qty.airplane_code
AND s.fare_conditions = qty.fare_conditions;
$$ STABLE LANGUAGE sql;
CREATE FUNCTION再基于它构建一个返回表的函数：
CREATE FUNCTION report()
RETURNS TABLE(
model text,
economy bigint, comfort bigint, business bigint
)
AS $$
DECLARE
r record;
BEGIN
FOR r IN
SELECT a.airplane_code, a.model
FROM airplanes a
ORDER BY a.model
LOOP
report.model := r.model;
report.economy := qty(r.airplane_code, 'Economy');
report.comfort := qty(r.airplane_code, 'Comfort');
report.business := qty(r.airplane_code, 'Business');
RETURN NEXT;
END LOOP;
END;
$$ STABLE LANGUAGE plpgsql;重置语句执行统计，然后执行报表：
SELECT pg_stat_statements_reset();
SELECT * FROM report();
model | economy | comfort | business
--------------------------+---------+---------+----------
Aerobus A320neo | 120803 | 0 | 24494
Aerobus A330-900neo | 337923 | 42242 | 43775
Aerobus A350-1000 | 736214 | 0 | 115244
Aerobus A350F | 0 | 0 | 0
Boeing 737 MAX 7 | 556344 | 0 | 61743
Boeing 767-300F | 0 | 0 | 0
Boeing 777-300ER | 2238243 | 329509 | 205873
Boeing 787-9 Dreamliner | 613540 | 68505 | 156712
Bombardier CRJ700 | 91626 | 21181 | 10604
Embraer E170 | 191837 | 0 | 16006
(10 rows)现在查看性能剖析结果：
SELECT * FROM statements_v \gx
-[ RECORD 1 ]----------------------------------
queryid | -3009688052632882778
toplevel | t
query | SELECT * FROM report()
calls | 1
time_sec | 28.311
shared_blks | 9417875
-[ RECORD 2 ]----------------------------------
queryid | -3792749405278051211
toplevel | f
query | SELECT count(*) +
| FROM timetable tt +
| JOIN boarding_passe
calls | 30
time_sec | 28.292
shared_blks | 9416655
-[ RECORD 3 ]----------------------------------
queryid | 704897965492952962
toplevel | f
query | SELECT a.airplane_code, a.model +
| FROM airplanes a +
| ORDE
calls | 1
time_sec | 0
shared_blks | 4
-[ RECORD 4 ]----------------------------------
queryid | -3948231919979109674
toplevel | t
query | SELECT pg_stat_statements_reset()
calls | 1
time_sec | 0
shared_blks | 0其中有三个值得关注的条目：
- 顶层的 report() 调用。
- qty 内部的查询，执行了 30 次。
- 驱动 PL/pgSQL 循环的查询。
几乎所有执行时间和缓冲区访问都来自 qty 内部的查询。这些重复工作显然是优化的重点：应当将报表改写成一条面向集合的查询。
7.6 单条查询的性能剖析
找到值得优化的语句之后，还需要剖析这条查询内部的执行情况。EXPLAIN ANALYZE 就能提供这样的信息，此时剖析的对象是各个计划节点。不过，计划是一棵树，而不是一个平铺的列表；理解各节点的耗时时，必须考虑这一点。
对于每个节点，actual time、rows 和 loops 反映了它的实际执行情况。
EXPLAIN 的 buffers 选项显示 I/O 量；如果启用了 track_io_timing，还会显示 I/O 操作所花费的时间。
诊断执行计划时，基数估算至少与运行时间同样重要。应当比较估算行数和实际行数，并结合 loops 理解这些数据。计划树底层的较大估算误差可能逐层向上传播，影响连接方法、访问路径、聚合方式和内存使用等方面的选择。
应从计划树深处最早出现严重估算偏差的节点查起，而不是将问题归咎于每一个继承了该误差的父节点。
准确的基数估算并不能保证得到好的计划，成本参数或成本模型仍可能有偏差。但严重的基数估算错误，是首先应当排查的问题之一。
有时，查询执行时间太长，使用 EXPLAIN ANALYZE 并不现实。此时只能先使用普通的 EXPLAIN，在信息不完整的情况下尝试找出低效的原因。
现在将旅客报表改写为一条 SQL 查询，并查看它的执行情况：
EXPLAIN (analyze, costs off, timing off)
WITH rf AS MATERIALIZED (
SELECT f.flight_id, r.airplane_code
FROM flights f
JOIN routes r ON r.route_no = f.route_no
AND r.validity @> f.scheduled_departure
), t AS (
SELECT rf.airplane_code,
count(*) FILTER
(WHERE s.fare_conditions = 'Economy') AS economy,
count(*) FILTER
(WHERE s.fare_conditions = 'Comfort') AS comfort,
count(*) FILTER
(WHERE s.fare_conditions = 'Business') AS business
FROM rf
JOIN boarding_passes bp ON bp.flight_id = rf.flight_id
JOIN seats s ON s.airplane_code = rf.airplane_code
AND s.seat_no = bp.seat_no
GROUP BY rf.airplane_code
)
SELECT a.model,
coalesce(t.economy, 0) AS economy,
coalesce(t.comfort, 0) AS comfort,
coalesce(t.business, 0) AS business
FROM airplanes a
LEFT JOIN t ON a.airplane_code = t.airplane_code
ORDER BY a.model;从下面的输出可以看出，较大的计划并不总是适合直接以文本形式阅读。借助第三方工具，可以更直观地查看计划，例如 explain.tensor.ru。10
注意，消除重复读取之后，查询执行时间缩短了多少，页面读取量又减少了多少：
QUERY PLAN
-------------------------------------------------------------
Sort (actual rows=10.00 loops=1)
Sort Key: ((ml.model ->> current_setting('bookings.la...
Sort Method: quicksort Memory: 25kB
Buffers: shared hit=13059 read=37154
CTE rf
-> Hash Join (actual rows=37671.00 loops=1)
Hash Cond: (f.route_no = r.route_no)
Join Filter: (r.validity @> f.scheduled_departure)
Rows Removed by Join Filter: 115016
Buffers: shared hit=397 read=5
-> Seq Scan on flights f (actual rows=37671.00 ...
Buffers: shared hit=368
-> Hash (actual rows=2030.00 loops=1)
Buckets: 2048 Batches: 1 Memory Usage: 145kB
Buffers: shared hit=29 read=5
-> Seq Scan on routes r (actual rows=2030.0...
Buffers: shared hit=29 read=5
...
Buffers: shared hit=13059 read=37153
-> Hash Join (actual rows=5982418.00 ...
Hash Cond: ((rf.airplane_code = s...
Buffers: shared hit=13059 read=37153
-> Hash Join (actual rows=5982418...
Hash Cond: (bp.flight_id = rf...
Buffers: shared hit=13057 rea...
-> Seq Scan on boarding_passe...
Buffers: shared hit=12660...
-> Hash (actual rows=37671.00...
Buckets: 65536 (originall...
Buffers: shared hit=397 r...
-> CTE Scan on rf (actual...
Storage: Memory Maxi...
Buffers: shared hit=3...
-> Hash (actual rows=1741.00 loop...
Buckets: 2048 Batches: 1 Me...
Buffers: shared hit=2 read=8
-> Seq Scan on seats s (actua...
Buffers: shared hit=2 read=8
Planning:
Buffers: shared hit=5 read=1
Planning Time: 0.287 ms
Execution Time: 1388.015 ms
(54 rows)作为参照，我们统计一下所涉及的主要表的堆页面数：
SELECT sum(relpages)
FROM pg_class
WHERE relname IN ('flights', 'routes', 'boarding_passes',
'seats', 'airplanes');
sum
-------
50212
(1 row)对于需要读取全部行的查询，这个数可以作为页面处理量的粗略上限估计：如果实际处理的页面数远高于它，就可能意味着同一批数据被扫描了多次。
在这个例子中，计划已经接近最优。虽然仍有改进空间，但很难再获得刚才那样大幅度的提升。