跳转到主要内容

19 读计划,不看时钟

逐个节点读取 PostgreSQL 查询计划,找出页和时间到底花在哪里,并用实测的前后对比证明如何修复慢查询。

这个查询在我们的机器上返回 20 行,大约需要一秒半:

select u.email, last.kind, last.created_at
from users u
cross join lateral (
  select e.kind, e.created_at
  from events e
  where e.user_id = u.id
  order by e.created_at desc
  limit 1
) last
where u.account_id = 42
  and u.id in (select owner_id from projects where account_id = 42);

在 explain (analyze, buffers) 下运行它,其中一行就能解释一切:

   ->  Limit  (...) (actual time=70.407..70.408 rows=1.00 loops=20)
         Buffers: shared hit=81803 read=621660

loops=20。内部部分对每个用户运行一次,每次都读取整张 events 表:为了返回 20 行,进行了 703,463 次页访问,访问量超过 5 GB。读懂这一行之后,修复方法就会显现出来:它能让这个查询的页访问次数从 703,714 次降到 331 次。

大多数人读计划时只盯着毫秒数。不要这样做:计时会随着缓存和负载变化。计划还会告诉你每一步预计有多少行、实际得到多少行、运行了多少次,以及触碰了多少页;这些信息才会指向修复方法。读计划不是一门艺术,而是一份按顺序检查的短清单。

这里的所有计划都来自 PostgreSQL 18,在本书的 events 表上真实运行(2,000,000 行、35,173 页,除非特别说明,否则只有一个主键)。你的页数和行数应当相同或接近,但计时不会相同。计划行很长,因此我们把本节不讨论的部分缩写成 ...;估计值和实际值都重要时,则把它们折成两行。

EXPLAIN 负责猜测;EXPLAIN ANALYZE 负责运行

explain 会询问规划器(planner)“它将会怎么做”:不会运行任何东西,你只能看到估计值。查询需要一个小时才能完成时,这正是合适的工具。其他时候使用 explain analyze,它会运行查询,并把现实放在预测旁边输出。下面是 explain analyze select * from events where kind = 'alert';普通的 explain 只会输出第一个括号和 Filter:

 Seq Scan on events  (cost=0.00..60173.43 rows=245404 width=111)
                     (actual time=0.130..100.660 rows=249714.00 loops=1)
   Filter: (kind = 'alert'::text)
   Rows Removed by Filter: 1750286
   Buffers: shared hit=94 read=35079 written=3
   I/O Timings: shared read=1.167 write=0.041
 Planning Time: 0.050 ms
 Execution Time: 106.418 ms

PostgreSQL 18 默认会输出 Buffers:;旧版本需要 explain (analyze, buffers)。本书把这个选项明确写出来,这样各版本都能使用。

EXPLAIN ANALYZE 会执行语句

explain analyze 用在 insert、update、delete 或 merge 上会真正执行写入。务必把它包在 begin …… rollback 中;还要当心那些会调用带副作用函数的 select 语句。

深入阅读:回滚会撤销什么,以及值得了解的选项

explain analyze delete from events where created_at < '2025-10-11' 在 rollback 之前确实删除了 27,397 行(并弄脏了 482 个页)。没有任何东西被复制回来:这些行被一个随后中止的事务盖上了标记,因此它们仍然可见(更新就是插入)。回滚撤销的是删除,不是一切:行确实被锁定了,触发器确实触发了,序列确实前进了,WAL 也确实写入了。

动手验证 · lab 18-explain
begin;
create temp table p_del as
  select lab.plan($$ delete from events where created_at < '2025-10-11' $$) as p;
select lab.prove('explain analyze of a delete really deletes (about 27,000 rows here)',
  (select count(*) from events) < 2000000
  and (select lab.field(p, 'Seq Scan', 'Actual Rows')::numeric between 20000 and 60000 from p_del));
rollback;
select lab.prove('and rollback puts them back',
  (select count(*) from events) = 2000000);

select lab.prove('PostgreSQL 18 includes Buffers without asking',
  lab.plan_text($$ select * from events where id = 1 $$, 'analyze, costs off') like '%Buffers: shared%');

完整实验脚本

其他选项还包括:costs off 隐藏估计值;timing off 跳过那些运行数百万次的节点的逐节点计时;settings、wal 以及 PostgreSQL 17 的 serialize 和 memory 会添加与名称相符的信息;PostgreSQL 16 的 generic_plan 会像预备语句那样,使用 $1 占位符解释查询(预备语句在运行五次后切换计划);format json 供工具使用。

计划是一棵树;从里向外读取

计划是一棵由**节点(nodes)**组成的树。每个节点完成一项工作(扫描、连接、排序、聚合),从下面的节点取行,再把行交给上层。缩进显示树的结构,-> 标记子节点。行从叶子节点开始产生,所以要从最内层节点向外读取,就像一份把第一步写在最后的菜谱。下面是一个两表连接;每个节点的估计值和实际值都折成两行,中间节点的 Buffers: 行则省略了:

explain (analyze, buffers)
select p.name, count(*)
from events e
join projects p on p.id = e.project_id
where e.created_at >= '2026-09-29'
  and p.archived_at is not null
group by p.name;
 GroupAggregate  (cost=61217.60..61314.79 rows=3911 width=21)
     (actual time=94.552..95.476 rows=3307.00 loops=1)
   Group Key: p.name
   Buffers: shared hit=2835 read=32532
   ->  Sort  (cost=61217.60..61236.96 rows=7744 width=13)
           (actual time=94.540..94.726 rows=7358.00 loops=1)
         Sort Key: p.name
         Sort Method: quicksort  Memory: 193kB
         ...
         ->  Hash Join  (cost=439.89..60717.38 rows=7744 width=13)
                 (actual time=81.660..86.492 rows=7358.00 loops=1)
               Hash Cond: (e.project_id = p.id)
               ...
               ->  Seq Scan on events e  (cost=0.00..60173.53 rows=39599 width=8)
                       (actual time=80.537..82.898 rows=38357.00 loops=1)
                     Filter: (created_at >= '2026-09-29 00:00:00+00'::timestamp ...)
                     Rows Removed by Filter: 1961643
                     Buffers: shared hit=2641 read=32532
               ->  Hash  (cost=391.00..391.00 rows=3911 width=21)
                       (actual time=1.048..1.049 rows=3911.00 loops=1)
                     Buckets: 4096  Batches: 1  Memory Usage: 246kB
                     Buffers: shared hit=191
                     ->  Seq Scan on projects p  (cost=0.00..391.00 ...)
                             (actual time=0.023..0.683 rows=3911.00 loops=1)
                           Filter: (archived_at IS NOT NULL)
                           Rows Removed by Filter: 16089

(为了保持简短,捕获时设置了 max_parallel_workers_per_gather = 0。)同一棵树画出来是这样:

   GroupAggregate          3,307 groups
         │
       Sort                7,358 rows, by name
         │
     Hash Join             7,358 rows
      ┌──┴─────────────┐
  Seq Scan events     Hash (3,911 rows, 246 KB)
  38,357 of 2M rows     │
  35,173 pages        Seq Scan projects
                      3,911 of 20,000 rows, 191 pages

从底向上看:扫描 projects,保留已归档的项目,建立哈希表。扫描 events,保留最近一周的数据,再在哈希表中查找每一行。排序,然后按名称计数。

一个节点的数字包含其子节点的数字

每个节点都有相同的组成部分。把那份计划中的 events 扫描拆开来看:

  Seq Scan on events e  (cost=0.00..60173.53 rows=39599 width=8)
  ────────────────────        ────  ──────── ────────── ───────
           1                   2       3         4         5
  (actual time=80.537..82.898 rows=38357.00 loops=1)
               ──────  ────── ───────────── ───────
                 6       7          8          9
    Filter: (created_at >= '2026-09-29 00:00:00+00'::timestamp with time zone)
    Rows Removed by Filter: 1961643
                            ───────
                              10
    Buffers: shared hit=2641 read=32532
             ──────────────────────────
                         11

   1  the node: what this step does
   2  estimated startup cost (before the first row)
   3  estimated total cost (all rows)
   4  estimated rows, per loop
   5  estimated average row width, in bytes
   6  ms until the first row, per loop
   7  ms until the last row, per loop
   8  actual rows, per loop (an average, hence two decimals in 18)
   9  times this node ran: multiply 7 and 8 by it for totals
  10  rows read and thrown away
  11  8 KB pages: this node plus its children, all loops

第一行是猜测;其余部分是实际发生的事情。大多数诊断工作就是比较 4 和 8、用 9 相乘,再读取 11。还有两条规则:

  • 时间和缓冲区是累积的。 一个节点的数字包含其子节点的数字。减去子节点,才能看到节点自己做了什么。
  • actual time=A..B 表示到第一行(A)和到最后一行(B)分别需要多少毫秒。A 很大,说明在输出任何结果之前就做了工作,例如排序或建立哈希表。Hash Join 在 82 ms 时才产生第一行,是因为 events 扫描在找到一行近期数据之前已经读了大部分表。

深入阅读:减去子节点:这份计划的页花在哪里

顶部的 GroupAggregate 报告了 shared hit=2835 read=32532,整棵树一共 35,367 个页。其中 events 扫描占了 35,173 个,Hash 节点处理 projects 占了 191 个。剩下的 3 个页由连接、排序和聚合共同使用:它们都在内存中完成。在慢计划里,用这种减法就能找到大数字从哪个节点开始出现。

动手验证 · lab 18-explain
select lab.prove('buffers are cumulative: the top node reports about 35,367, the events scan 35,173 of them',
  (select pg_temp.bufs(p) between 35364 and 35400 from p_tree)
  and (select (n ->> 'Shared Hit Blocks')::bigint + (n ->> 'Shared Read Blocks')::bigint = 35173
       from (select pg_temp.node(p, '{"Node Type": "Seq Scan", "Relation Name": "events"}') n from p_tree) x));

完整实验脚本

代价是用虚构单位做出的猜测

cost=0.00..60173.43 是估计的启动代价和总代价,单位规定为顺序读取一个页的代价是 1.0。规划器会给它考虑的每份计划定价,然后运行代价最低的那份。代价的用途就这些。它不是毫秒,不能跨查询比较,而且代价高也不一定慢。用代价解释规划器为什么选择了某份计划;用行数、循环次数和缓冲区诊断问题。这些单位价格的解释见规划器是代价计算器。

深入阅读:把顺序扫描的代价算到分

kind = 'alert' 的扫描代价由页数和逐行 CPU 工作组成,每项都按配置的价格计算:

  35,173 pages   × 1.0     =  35,173.00   seq_page_cost
  2,000,034 rows × 0.01    =  20,000.34   cpu_tuple_cost
  2,000,034 rows × 0.0025  =   5,000.09   cpu_operator_cost
                              ---------
                              60,173.43

这与计划中的数字精确到小数点后两位。计数来自 pg_class.relpages 和 reltuples,它们由 vacuum 和 analyze 保持更新。reltuples 是一个估计值(恰好有 2,000,000 行的表被估计为 2,000,034),而每次实验运行都会重新分析自己的副本,所以它会上下浮动几行。这就是上面连接计划中的 created_at 扫描代价为 60173.53 而不是 60173.43 的原因:公式相同,只是 reltuples 略有不同。你的副本可能相差几分钱,但公式仍会精确匹配你的计划。

动手验证 · lab 18-explain
select lab.prove('the plan''s total cost equals relpages x 1.0 + reltuples x 0.01 + reltuples x 0.0025, to the cent',
  (select round((relpages * 1.0 + reltuples * 0.01 + reltuples * 0.0025)::numeric, 2)
   from pg_class where relname = 'events')
  = (select (p -> 'Plan' ->> 'Total Cost')::numeric
     from (select lab.plan($$ select * from events where kind = 'alert' $$) as p) x));

完整实验脚本

乘上循环次数;缓冲区已经是总数

有些节点会运行不止一次。嵌套循环的内侧会对外侧的每一行运行一次,而 loops 就是在统计运行次数。actual time 和 rows 是每次循环的值;缓冲区是总数。

这就是开头那个查询。它的内部 Limit 报告 actual time=70.407..70.408 ... loops=20:70 ms 看起来无害,直到你乘以 20,得到完整的 1.4 秒。它的缓冲区已经是总数:703,463 个页,也就是表的 35,173 页乘以 20。在这棵子树的底部:

               ->  Seq Scan on events e  ... (actual ... rows=104.20 loops=20)
                     Filter: (user_id = u.id)
                     Rows Removed by Filter: 1999896

没有任何东西能按用户查找事件,所以每次循环都会读取整张表,再丢弃将近两百万行。内部查询要问的是“某个用户最新的事件”,这正是索引应该回答的问题:

create index events_user_created_idx on events (user_id, created_at);
   ->  Limit  ... (actual time=0.003..0.003 rows=1.00 loops=20)
         Buffers: shared hit=80
         ->  Index Scan Backward using events_user_created_idx on events e  ...

仍然是 20 次循环,但现在每次只需四个页(三层索引页和一个堆页)。整个查询从 703,714 页降到了 331 页,在我们的机器上还从 1,409 ms 降到了 0.6 ms。只要 loops 大于 1,就先乘起来,再判断节点是否重要。

深入阅读:我们如何知道每次循环都读了整张表

计划的其余部分,也就是找出 20 个用户,占 251 个页;内部子树则包含其余全部开销。修复所用的索引还覆盖了未建索引的外键 events.user_id(一条系统目录查询列出未建索引的外键)。

动手验证 · lab 18-explain
select lab.prove('the inner Limit ran 20 times, each a full Seq Scan with Filter (user_id = u.id)',
  (select lab.field(p, 'Limit', 'Actual Loops')::int = 20
      and pg_temp.node(p, '{"Node Type": "Seq Scan", "Relation Name": "events"}') ->> 'Filter' = '(user_id = u.id)'
      and (lab.field(p, 'Limit', 'Shared Hit Blocks')::bigint
         + lab.field(p, 'Limit', 'Shared Read Blocks')::bigint) = 20 * (pg_relation_size('events') / 8192)
   from p_ex2));

select lab.prove('before: about 703,714 pages for 20 rows',
  (select pg_temp.bufs(p) between 703500 and 704500
      and (p -> 'Plan' ->> 'Actual Rows')::numeric = 20 from p_ex2));

create index events_user_created_idx on events (user_id, created_at);

-- (lab.plan of the same query, after the index)
select lab.prove('each loop now costs 4 pages: 80 for 20 loops',
  (select (lab.field(p, 'Limit', 'Shared Hit Blocks')::int
         + coalesce(lab.field(p, 'Limit', 'Shared Read Blocks')::int, 0)) = 80
      and lab.field(p, 'Limit', 'Actual Loops')::int = 20
   from p_ex2_after));

完整实验脚本

比较估计行数和实际行数

计划中的每个选择都建立在估计值上,因此这个习惯最有回报:从叶子节点开始,逐个节点比较估计行数和实际行数。 相差 2 倍或 3 倍通常无关紧要;相差 10 倍或更多,往往意味着上层做出了错误选择。

在 kind = 'alert' 的计划中,rows=245404 是估计值,rows=249714.00 是实际结果:误差在 2% 以内,因为规划器的统计信息知道 kind 的全部五个取值。统计信息来自表的随机抽样,因此你的估计会略有不同,但应当接近。这就是好的情况。

现在看一个坏的情况。值班仪表板要列出过去一周失败部署最多的十个项目(kind = 'deploy'、payload->>'status' = 'failed'、一个 created_at 范围,并连接 projects)。它读取了 42,397 个页:整张表,再为每个匹配的事件查找一次 projects。在 created_at 上建立索引后降到了 7,990 个页;这看起来像是胜利,直到你继续看这些页究竟花在哪里:

 Nested Loop  (... rows=49 ...) (actual ... rows=2402.00 loops=1)
   ->  Index Scan using events_created_at_idx on events e  (... rows=49 ...)
           (actual ... rows=2402.00 loops=1)
         Buffers: shared hit=784
   ->  Index Scan using projects_pkey on projects p  ...
           (actual ... rows=1.00 loops=2402)
         Buffers: shared hit=7206

events 扫描估计为 rows=49,实际得到 2,402:在最低层节点就是 49 倍的误差。49 次项目查找适合用嵌套循环(Nested loop)连接;但对 2,402 次查找来说,它花了 7,206 个页,而把 projects 的全部 191 个页哈希一次更便宜。49 是一个固定猜测:在你要求之前,Postgres 不会为 payload->>'status' 这样的表达式保存统计信息(函数会隐藏你的统计信息)。有了表达式统计信息(PostgreSQL 14+):

create statistics events_status_stats on (payload->>'status') from events;
analyze events;

估计值变成 2,558,规划器自行切换到哈希连接:从 7,990 个页降到 975 个页。不需要重写查询,只是提供了更好的信息。这就是大多数“规划器怎么这么蠢”的抱怨背后的模式。

动手验证 · lab 18-explain
select lab.prove('the events scan estimated about 49 rows: at least 20x too few',
  (select (n ->> 'Actual Rows')::numeric / (n ->> 'Plan Rows')::numeric > 20
      and (n ->> 'Plan Rows')::int between 30 and 70
   from (select pg_temp.node(p, '{"Index Name": "events_created_at_idx"}') n from p_ex3) x));

select lab.prove('and the planner switches to a Hash Join and a hashed aggregate on its own',
  (select lab.field(p, 'Hash Join', 'Node Type') is not null
      and lab.field(p, 'Nested Loop', 'Node Type') is null
      and lab.field(p, 'Aggregate', 'Strategy') = 'Hashed'
   from p_ex3b));

完整实验脚本

深入阅读:修复后的计划,以及修复留下了什么

执行 create statistics 和 analyze 之后:

 Limit  ... (actual time=7.958..7.961 rows=10.00 loops=1)
   Buffers: shared hit=975
   ...
               ->  Hash Join  (... rows=2558 ...) (actual ... rows=2402.00 loops=1)
                     ->  Index Scan using events_created_at_idx on events e  (...)
                           Rows Removed by Filter: 35955

统计信息来自抽样,所以你的估计会接近 2,558,但不会正好等于它。Rows Removed by Filter: 35955 表示扫描仍然要读取整整一周的数据,才能找出失败部署;如果这个仪表板使用频繁,部分索引也能把这部分去掉。(表达式索引同样会为规划器提供统计信息,但要付出维护索引的代价。)

动手验证 · lab 18-explain
select lab.prove('the default selectivity for an expression without statistics is 0.5%; the real share of failed is 25%',
  (select avg((payload->>'status' = 'failed')::int) between 0.24 and 0.26 from events));

select lab.prove('about 975 pages instead of 7,990',
  lab.warm_buffers($$ select p.id, p.name, count(*) as failures
                  from events e
                  join projects p on p.id = e.project_id
                  where e.kind = 'deploy'
                    and e.payload->>'status' = 'failed'
                    and e.created_at >= '2026-09-29'
                  group by p.id, p.name
                  order by failures desc
                  limit 10 $$) between 900 and 1050);

select lab.prove('the estimate (about 245,000) is within a few percent of the actual rows (5% allows for sampling)',
  (select abs((p -> 'Plan' ->> 'Plan Rows')::numeric - 249714) / 249714 < 0.05 from p_alert));

完整实验脚本

旧版本把实际行数打印成整数,因此“每次循环 0.4 行”会被读成容易误解的 0;PostgreSQL 18 的两位小数(rows=104.20)修复了这个问题。

缓冲区才是证据

Buffers: 统计 8 KB 页数,而这正是整本书讨论的对象;它是计划中最诚实的一行。

shared hit 页已经在shared_buffers中;shared read 页是向操作系统请求的页;写入时会出现 dirtied 和 written;temp 表示排序或哈希已经溢出到磁盘。

hit + read 是页访问次数,而且具有确定性:相同查询、相同数据,每次运行的总数几乎相同。命中数取决于还有什么工作运行过。比较计划时看总数;解释某一次运行时再看两者的拆分。

read 不一定意味着磁盘读取:它表示“页不在 shared_buffers 中,所以 Postgres 向内核请求了它”,而内核可能从自己的页缓存中回答(“Read”不等于“来自磁盘”)。不要用大扫描的 I/O Timings 判断它到底来自哪里。在 kind = 'alert' 的计划中,35,079 次读取只显示约 1 ms 的 I/O 时间,也就是每页约 33 纳秒;这比从任何缓存复制一个页还快。这是因为 PostgreSQL 18 会异步预读:后台 I/O 工作进程(io_method = worker,默认值)会在扫描请求之前取回页,而 I/O Timings 只统计查询自身实际等待的时间。在带有网络存储的冷服务器上,同样的计数可能需要几秒钟,那些等待也会显示出来。

大扫描的第二次运行也不会全都变成命中:大扫描使用一个由少量缓冲区组成的环(大型操作会使用环)。而普通读取中的 written,例如上面的 written=3,表示查询为了腾出空间,不得不刷写别人的脏页(你的查询不该负责写出脏页)。

Filter 表示行已经被读出并丢弃

每份计划的叶子节点都会读取表:Seq Scan、Index Scan、Index Only Scan 以及位图扫描这一对节点,索引能帮多少忙,取决于匹配行有多集中一节都解释过。对它们中的任何一个,都要区分 Index Cond 和 Filter。Index Cond 缩小了读取范围;Filter 表示行已经读出,然后又被丢弃,数量记录在 Rows Removed by Filter 中。索引扫描中这个数量很大,说明某个条件没法使用索引:可能是列顺序、列上的函数,或类型不匹配。

每种连接方法只适合某些行数

Postgres 有三种方式连接两个输入,而错误的行数估计会选出错误的方式:

  • 嵌套循环(Nested loop): 外侧(第一个)子节点每产生一行,就运行内侧(第二个)子节点一次。外侧很小、内侧是索引查找时非常出色;外侧很大时则糟糕。
  • 哈希连接(Hash join): 把内侧子节点装入哈希表(Hash 节点),再让外侧子节点流过它。它适合大型、无序的输入。当表的大小超过work_mem乘以 hash_mem_multiplier 后,就会在磁盘上拆成多个 Batches。
  • 归并连接(Merge join): 按连接键的顺序遍历两个输入,就像合并两个已排序列表。两边都从已经排好序的索引中出来时,代价很低。

规划器按代价做选择,因此它的选择好不好取决于行数估计是否准确,前面 49 行的嵌套循环已经展示了这一点。每种方法为什么会在自己的场景中胜出,以及嵌套循环中可能出现的 Memoize 缓存,见每种连接方法都在代价曲线的某处获胜。

深入阅读:哈希连接溢出时的样子

在并行查询关闭的情况下,把 30 天的事件连接到用户(where e.created_at >= '2026-09-06'):

 Hash Join (actual time=94.638..137.030 rows=164384.00 loops=1)
   Hash Cond: (e.user_id = u.id)
   ->  Seq Scan on events e (...)
   ->  Hash (actual time=17.055..17.057 rows=100000.00 loops=1)
         Buckets: 131072  Batches: 1  Memory Usage: 7274kB

Batches: 1 表示哈希表装得下:7,274 KB 超过了默认的 4 MB work_mem,但 hash_mem_multiplier(默认值为 2)允许哈希表使用两倍,也就是 8 MB。批次数会根据规划器对大小的估计预先选定,因此这里的 Batches: 1 也表示规划器预计它能装下。把 work_mem 降到 1 MB 后,就会得到 Batches: 4 和 temp written=474:结果仍然正确,但更慢,并且能在 temp 缓冲区中看到。

动手验证 · lab 18-explain
select lab.prove('hash join: 100,000 users hashed in 1 batch at the default work_mem (about 7,274 kB)',
  (select lab.field(p, 'Hash', 'Actual Rows')::numeric = 100000
      and lab.field(p, 'Hash', 'Hash Batches')::int = 1
      and lab.field(p, 'Hash', 'Peak Memory Usage')::int between 7000 and 7500
   from p_hash));

begin;
set local work_mem = '1MB';
create temp table p_hash1 on commit drop as
  select lab.plan($$ select e.id, u.email
                     from events e join users u on u.id = e.user_id
                     where e.created_at >= '2026-09-06' $$) as p;
select lab.prove('at work_mem = 1MB it splits into 4 batches and writes temp files',
  (select lab.field(p, 'Hash', 'Hash Batches')::int = 4
      and lab.field(p, 'Hash', 'Temp Written Blocks')::int > 0
   from p_hash1));
commit;

完整实验脚本

先修页数,再提高 work_mem

排序和哈希每个节点最多获得 work_mem(默认 4 MB),超出后就会溢出到临时文件。一个月度报告按用户排序 30 天的事件(where created_at >= '2026-09-06' order by user_id, created_at):

 Sort (actual time=135.067..143.625 rows=164384.00 loops=1)
   Sort Key: user_id, created_at
   Sort Method: external merge  Disk: 5480kB
   Buffers: shared hit=2929 read=32250, temp read=685 written=687
   ->  Seq Scan on events (actual time=90.854..100.979 rows=164384.00 loops=1)
         Rows Removed by Filter: 1835616

external merge 加上 Disk:,再加上 temp 缓冲区,说明发生了溢出。诱人的修复方法是增加内存,而且确实有效:使用 set local work_mem = '32MB' 后,排序变成了 quicksort Memory: 12566kB。总时间没有变化(153 ms 对 148 ms,仍在噪声范围内)。

再读一遍计划,你就能看出原因。扫描在 101 ms 时完成;排序只增加了约 43 ms。真正的代价是为表中 8% 的数据读取全部 35,173 个页,而在 created_at 上建立索引就能解决这个问题(即使是一个很小的 BRIN(块范围索引)也行:BRIN 为每个页范围保留一份汇总)。先修页数,再调内存。 确实需要处理溢出时,为该事务提高 work_mem,使用 set local,不要全局提高:每个连接中的每个排序和哈希节点都可能拿到这么多内存(work_mem 是按节点计算的,而且可以看到)。

深入阅读:测量溢出,以及你会遇到的排序方法

在内存中排序需要 12.5 MB,而磁盘上的数据只占 5.5 MB:内存中的元组带有额外开销。除了 quicksort 和 external merge,你还会遇到 top-N heapsort(在 limit 下只保留 N 行)和 incremental sort(输入已经按键的某个前缀排好序)。哈希聚合也会溢出(PostgreSQL 13+),像哈希连接一样显示 Batches 和 Disk Usage。

动手验证 · lab 18-explain
select lab.prove('sorting 30 days of events (about 164,000 rows) spills: external merge, about 5,480 kB on disk',
  (select lab.field(p, 'Sort', 'Sort Method') = 'external merge'
      and lab.field(p, 'Sort', 'Sort Space Type') = 'Disk'
      and lab.field(p, 'Sort', 'Sort Space Used')::int between 4800 and 6000
      and lab.field(p, 'Sort', 'Actual Rows')::numeric between 150000 and 170000
      and lab.field(p, 'Sort', 'Temp Written Blocks')::int > 0
   from p_sort));

select lab.prove('at work_mem = 32MB it is a quicksort in memory, about 12,566 kB',
  (select lab.field(p, 'Sort', 'Sort Method') = 'quicksort'
      and lab.field(p, 'Sort', 'Sort Space Type') = 'Memory'
      and lab.field(p, 'Sort', 'Sort Space Used')::int between 11000 and 13500
   from p_sort32));

完整实验脚本

Limit 押注于尽早找到行

Limit 一旦取得足够的行,就会停止继续拉取,因此规划器偏爱能便宜地产生前几行的计划,赌它不需要把计划跑完。它要是判断错了行在哪里,代价就会很高。请求 user_id 最小的十个事件,再与 users 连接;events.user_id 上没有索引时,计划会读取 35,176 个页,把 events 的副本溢出到磁盘,并耗时超过半秒。

完整的嵌套循环代价超过 40 亿个单位,但 Limit 的代价只有 20,860,因为规划器假定排在前面的用户会有很多事件。它按 ID 顺序遍历用户,每遇到一个用户,就重新扫描包含全部两百万个事件的副本。用户 1 和 2 没有事件,所以前两次循环白白读完了所有数据,直到第三个用户才找到十行。

在 events (user_id) 上建立索引后,只读取 16 个页。(要跟着做吗?先删除循环一节创建的 (user_id, created_at) 索引,否则它也会服务这个查询。)没有支持索引的 order by ... limit 是经典的“开发环境很快、生产环境很糟”的计划:当 Limit 位于昂贵子树的上方时,要问问有没有索引能按顺序把行交给它。

深入阅读:这份计划,以及修复后的计划为何会因副本而异
 Limit  (cost=0.29..20860.11 rows=10 width=43)
     (actual time=565.905..582.183 rows=10.00 loops=1)
   Buffers: shared hit=4375 read=30801, temp read=9358 written=8301
   ->  Nested Loop  (cost=0.29..4171963906.29 rows=2000000 width=43)
           (actual time=565.904..582.179 rows=10.00 loops=1)
         ...
         ->  Materialize  ... (actual ... rows=1418191.33 loops=3)

loops=3 乘以 1,418,191 行,就是计划中的 Rows Removed by Join Filter: 4254564 所代表的 425 万行;物化的 events 副本也溢出到了磁盘。有了索引,我们的副本选择了两个索引扫描组成的归并连接;另一份套件的副本因为抽样统计信息略有不同,选择了带 Memoize 的嵌套循环(9 次命中、1 次未命中)。两者的代价相差不到几个百分点,读取的都是同样的 16 个页。

动手验证 · lab 18-explain
select lab.prove('the Limit is costed near 20,860; the full nested loop over four billion',
  (select (p -> 'Plan' ->> 'Total Cost')::numeric between 19000 and 23000
      and lab.field(p, 'Nested Loop', 'Total Cost')::numeric > 4e9
   from p_limit));

select lab.prove('users 1 and 2 have no events: the third user found the ten rows (loops=3)',
  (select min(user_id) = 3 from events)
  and (select lab.field(p, 'Materialize', 'Actual Loops')::int = 3 from p_limit));

create index events_user_id_idx on events (user_id);

-- The two plans cost within a few percent of each other, so which one wins
-- depends on the kit's sampled statistics. Both read 16 pages.
select lab.prove('with the index, it reads 16 pages: the events index feeds a merge join, or a nested loop with a Memoize (9 hits, 1 miss)',
  lab.warm_buffers($$ select e.id, e.kind, u.email
                  from events e join users u on u.id = e.user_id
                  order by e.user_id limit 10 $$) = 16
  and (select pg_temp.node(p, '{"Index Name": "events_user_id_idx"}') is not null
          and lab.field(p, 'Materialize', 'Node Type') is null
          and lab.field(p, 'Sort', 'Node Type') is null
          and (lab.field(p, 'Merge Join', 'Node Type') is not null
               or (lab.field(p, 'Memoize', 'Cache Hits')::int = 9
                   and lab.field(p, 'Memoize', 'Cache Misses')::int = 1))
       from p_limit2));

完整实验脚本

并行查询更快,但不更便宜

扫描足够大时,Postgres 会把它分给多个工作进程(workers):Gather 节点位于 Parallel Seq Scan 之上,由领导者(leader)加两个工作进程组成,因此 loops=3。这样统计部署数量仍然会读取全部 35,173 个页。并行通过投入更多核心让大扫描更快完成,所以在繁忙的服务器上,如果一个常用查询需要并行顺序扫描,那它就需要一个索引。

深入阅读:读取并行计划
 Finalize Aggregate (actual time=38.578..40.111 rows=1.00 loops=1)
   Buffers: shared hit=4964 read=30209
   ->  Gather (actual time=38.442..40.105 rows=3.00 loops=1)
         Workers Planned: 2
         Workers Launched: 2
         ->  Partial Aggregate (actual time=36.867..36.868 rows=1.00 loops=3)
               ->  Parallel Seq Scan on events (actual ... rows=166664.00 loops=3)

每个进程扫描自己负责的一部分页,并统计其中的数量;Gather 收集部分计数,再交给 Finalize Aggregate。rows=166664.00 乘以 3 就是 499,992 个部署。Workers Launched 小于 Workers Planned,表示服务器没有空闲的工作进程槽位;Gather Merge 是保持顺序的变体。计划会得到多少工作进程,见并行计划和其他计划一样按代价定价。

动手验证 · lab 18-explain
select lab.prove('count of deploys: Finalize Aggregate over Gather, 2 workers, loops=3',
  (select (p -> 'Plan' ->> 'Node Type') = 'Aggregate'
      and (p -> 'Plan' ->> 'Partial Mode') = 'Finalize'
      and lab.field(p, 'Gather', 'Workers Planned')::int = 2
      and lab.field(p, 'Seq Scan', 'Actual Loops')::int = 3
   from p_par));

select lab.prove('there are 499,992 deploys',
  (select count(*) from events where kind = 'deploy') = 499992);

完整实验脚本

慢查询的方法

上面的内容可以归纳成一份清单。按顺序执行;大多数问题会在第 4 步暴露出来。

  1. 取得真实计划。 在生产规模的数据上,使用真实参数值运行 explain (analyze, buffers)。把写入包在 begin / rollback 中。运行太慢?使用普通的 explain,并让 auto_explain 从生产环境记录真实计划(auto_explain 会记录你之后无法复现的计划)。
  2. 读最上面一行。 问问答案应该花多少代价:20 行应该只需要几十个页,而不是几万个。
  3. 找出缓冲区花在哪里。 向下走,找到大数字开始出现的地方。减去子节点的数字;乘以 loops。
  4. 从底向上比较估计行数和实际行数。 最低层节点相差 10 倍或更多时,通常就是根因;上面的所有节点都是按另一种查询规划的。
  5. 检查常见嫌疑。 Rows Removed by Filter 远大于返回行数(索引缺失或无法使用);loops 达到几千;出现 external merge、大于 1 的 Batches 或 temp 缓冲区(发生溢出);Heap Fetches 接近行数(清理落后);Limit 位于昂贵子树上方。
  6. 只修一件事。 建索引、重写查询,或提供更好的统计信息。
  7. 再次测量并比较缓冲区。 把修改前后的计划保留在拉取请求中,这样下一个人就知道为什么要有这个索引。

本章要点

  • explain (analyze, buffers) 会运行查询,并把现实放在估计值旁边。把写入包在 begin / rollback 中。
  • 从最内层节点向外读取计划。时间和缓冲区是累积的:减去子节点。
  • actual time 和 rows 是每次循环的值:要乘以 loops。70 ms 乘以 20 次循环,就是完整的 1.4 秒。
  • 从底向上比较估计行数和实际行数。行数被低估了 49 倍,因而选用了嵌套循环;哈希连接的页访问次数只有它的八分之一。
  • 用缓冲区作为证据:hit + read 在多次运行间稳定,毫秒数则不稳定。
  • 溢出的实际代价没有看起来那么大。先修扫描,再提高 work_mem,使用 set local。
  • 每增加一个索引,都保留修改前后的计划。

延伸阅读

  • Using EXPLAIN,PostgreSQL 文档。官方演练,至今仍是了解计划输出的最佳一手资料。
  • EXPLAIN,PostgreSQL 文档。介绍所有选项,包括 BUFFERS(18 中默认启用)、WAL、SETTINGS、SERIALIZE 和 MEMORY。
  • auto_explain,PostgreSQL 文档。记录生产环境中无法手工重新运行的慢查询计划。
  • explain.depesz.com 和 explain.dalibo.com,Hubert Lubaczewski 和 Dalibo。粘贴一份计划,就能看到高亮的时间和行数去向。