慢查询不再靠猜：auto_explain 阈值与采样落地实录

问题背景：慢查询为什么总是事后才出现

很多团队排查 PostgreSQL 慢查询时，第一反应是打开应用日志，找到一条超过 1 秒的 SQL，然后手工复制到 psql 中执行 EXPLAIN (ANALYZE, BUFFERS)。问题在于：慢查询往往与当时的参数、缓存命中率、锁等待、并发压力有关，事后复现时数据缓存已经变热，执行计划也可能完全不同。

PostgreSQL 自带的 auto_explain 模块可以在语句执行超过阈值时，自动把执行计划写入数据库日志；从 PostgreSQL 16 开始，还支持基于采样率只记录一部分慢语句。它解决的不是“统计 SQL 平均耗时”，而是“在慢发生的那一刻保留现场”。

本文给出一套生产可落地的配置方法：先用阈值捕获确定的慢查询，再用采样控制日志量，最后结合 pg_stat_statements 判断该 SQL 是偶发抖动还是系统性问题。

方案对比：日志、触发器钩子与 auto_explain

常见慢查询捕获方案有三类。

第一类是应用侧埋点或中间件日志。它接入简单，能记录 trace id，但通常只有 SQL 文本和耗时，没有执行计划；遇到预编译参数、ORM 改写或分批查询时，信息不够完整。

第二类是定期查询 pg_stat_activity，抓取长时间运行的语句。这种方式适合发现当前正在执行的慢 SQL，但采样间隔内结束的语句会漏掉，也无法稳定拿到执行计划。

第三类是使用 auto_explain。它通过执行器钩子在数据库内核侧工作，可以自动输出嵌套语句、触发器、存储过程内 SQL 的计划，并可选择真实执行指标。它的代价是：开启 ANALYZE 后会额外记录计时、行数与缓冲区信息，阈值过低或采样过高时会明显增加日志量。

因此，推荐把 auto_explain 当作“现场快照”，把 pg_stat_statements 当作“长期统计”。前者回答某一次为什么慢，后者回答这类 SQL 出现了多少次、平均耗时和 P99 趋势如何。

参数落地：先加载模块，再设置阈值

auto_explain 属于 contrib 扩展模块，通常随 PostgreSQL 软件包一起安装，但需要显式加入 shared_preload_libraries。修改以下配置后需要重启数据库实例：

-- postgresql.auto.conf 或 postgresql.conf
-- 也可在系统命令中使用 ALTER SYSTEM 修改
-- shared_preload_libraries = 'auto_explain,pg_stat_statements';

-- 推荐先在当前会话验证模块是否可用
LOAD 'auto_explain';

-- 超过 200ms 的语句自动记录执行计划，单位为毫秒
SET auto_explain.log_min_duration = '200ms';

-- 记录实际执行时间与真实行数
SET auto_explain.log_analyze = on;

-- 记录共享缓冲区命中与读写情况，便于判断缓存问题
SET auto_explain.log_buffers = on;

-- 输出更易读的文本计划；如集中采集到日志平台，也可考虑 JSON、YAML
SET auto_explain.log_format = 'text';

-- 记录时间线信息，可辅助排查触发器耗时
SET auto_explain.log_timing = on;

-- 生产环境谨慎开启：会把绑定参数值写入日志
SET auto_explain.log_parameter_max_length = -1;

如果希望全局生效，可使用超级用户执行：

-- 全局配置；新连接自动生效，已存在连接需要重连
ALTER SYSTEM SET shared_preload_libraries = 'auto_explain,pg_stat_statements';
ALTER SYSTEM SET auto_explain.log_min_duration = '200ms';
ALTER SYSTEM SET auto_explain.log_analyze = on;
ALTER SYSTEM SET auto_explain.log_buffers = on;
ALTER SYSTEM SET auto_explain.log_timing = on;
ALTER SYSTEM SET auto_explain.log_verbose = off;

-- 不建议一开始全局记录所有语句，0 表示没有阈值，会产生大量日志
-- ALTER SYSTEM SET auto_explain.log_min_duration = 0;

-- PostgreSQL 16+ 支持采样；90 表示约 90% 的符合阈值语句被记录
-- ALTER SYSTEM SET auto_explain.sample_rate = 0.9;

-- 修改配置文件类参数后 reload；shared_preload_libraries 仍需重启
SELECT pg_reload_conf();

阈值应该怎么设

阈值不要直接照抄“1 秒”。更合理的方法是按业务 SLO 倒推：接口 P99 目标为 300ms，而一个接口可能执行 3 到 5 条 SQL，那么单条 SQL 的初始阈值可设在 50ms 到 100ms；批处理任务则可放宽到 1s 或 5s。上线初期建议保守一些，例如 200ms，观察日志增长后再逐步下调。

采样率应该怎么设

PostgreSQL 16 之前没有内建 auto_explain.sample_rate，常见替代方式是只在特定业务用户、特定数据库或排障窗口启用，或者提高阈值。PostgreSQL 16 及以上版本，可以在高并发且同类 SQL 很多的系统中设置采样率：

-- 排障窗口：阈值较低，采样较高，快速收集样本
ALTER SYSTEM SET auto_explain.log_min_duration = '100ms';
ALTER SYSTEM SET auto_explain.sample_rate = 0.5;
SELECT pg_reload_conf();

-- 稳定期：阈值恢复，采样降低，控制日志成本
ALTER SYSTEM SET auto_explain.log_min_duration = '300ms';
ALTER SYSTEM SET auto_explain.sample_rate = 0.1;
SELECT pg_reload_conf();

注意采样是概率性的，不保证每 10 条恰好记录 1 条。低频但严重的慢查询不应依赖采样，应通过阈值、锁监控和语句超时共同覆盖。

可运行实验：构造一次可被自动记录的慢查询

下面用一张测试表演示顺序扫描如何触发 auto_explain。示例使用会话级参数，不需要重启，适合在测试库直接验证。

-- 1. 准备测试数据
DROP TABLE IF EXISTS ae_order_demo;

CREATE TABLE ae_order_demo (
    id bigint GENERATED ALWAYS AS IDENTITY PRIMARY KEY,
    user_id bigint NOT NULL,
    status text NOT NULL,
    amount numeric(12,2) NOT NULL,
    created_at timestamptz NOT NULL DEFAULT now()
);

INSERT INTO ae_order_demo(user_id, status, amount)
SELECT
    (random() * 100000)::bigint + 1,
    CASE (random() * 3)::int
        WHEN 0 THEN 'paid'
        WHEN 1 THEN 'pending'
        ELSE 'canceled'
    END,
    round((random() * 1000)::numeric, 2)
FROM generate_series(1, 500000) AS s(n);

-- 2. 在当前会话加载并配置 auto_explain
LOAD 'auto_explain';
SET auto_explain.log_min_duration = '10ms';
SET auto_explain.log_analyze = on;
SET auto_explain.log_buffers = on;
SET auto_explain.log_timing = on;

-- 3. 故意制造无索引条件，观察 Seq Scan
EXPLAIN (ANALYZE, BUFFERS)
SELECT count(*)
FROM ae_order_demo
WHERE status = 'pending' AND amount > 900;

-- auto_explain 关注的是实际执行语句；下面的查询也会进入当前会话日志
SELECT count(*)
FROM ae_order_demo
WHERE status = 'pending' AND amount > 900;

-- 4. 增加匹配数据分布的复合索引
CREATE INDEX CONCURRENTLY IF NOT EXISTS
    idx_ae_order_status_amount
ON ae_order_demo(status, amount);

ANALYZE ae_order_demo;

-- 5. 再次执行，对比计划中的 Index Scan / Bitmap Heap Scan 与 buffers
SELECT count(*)
FROM ae_order_demo
WHERE status = 'pending' AND amount > 900;

日志中通常会出现 duration: ... ms、plan:、Seq Scan、actual time、Rows Removed by Filter、Buffers: shared hit/read 等字段。如果看到大量 shared read，说明磁盘 IO 或缓存预热是重要因素；如果估算行数与 actual rows 偏差很大，应优先执行 ANALYZE 或检查统计信息、数据倾斜与谓词相关性。

与 pg_stat_statements 配合：从单次慢到模式化慢

auto_explain 的日志适合看单次现场，但不擅长回答“哪类 SQL 最消耗总时间”。这时应查询 pg_stat_statements。

-- 如未启用，需要加入 shared_preload_libraries 并创建扩展
CREATE EXTENSION IF NOT EXISTS pg_stat_statements;

-- 查看总耗时最高、调用次数较多的 SQL
SELECT
    substring(query, 1, 120) AS query_sample,
    calls,
    round(total_exec_time::numeric, 2) AS total_exec_ms,
    round(mean_exec_time::numeric, 2) AS mean_exec_ms,
    rows,
    shared_blks_hit,
    shared_blks_read
FROM pg_stat_statements
WHERE query ILIKE '%ae_order_demo%'
ORDER BY total_exec_time DESC
LIMIT 10;

一个实用判断方法是：如果 auto_explain 只记录到一两次慢计划，而 pg_stat_statements 中该 SQL 的调用次数很少、均值正常，可能是冷缓存、锁等待或备份窗口导致；如果调用频繁、总耗时很高，即使均值没有超过阈值，也值得通过索引、改写或分区治理。

避坑总结：生产环境最容易踩的 5 个坑

1. 把阈值设成 0，导致日志暴涨。 常见现象是磁盘 IO 升高、日志采集延迟，甚至磁盘被写满。修正方法是先按 SLO 设置 100ms 到 300ms 的阈值，排障结束立即恢复；不要在全局长期记录全部语句。

2. 只开 auto_explain.log_analyze，却忘记 log_buffers。 现象是能看到执行时间和行数，却无法判断慢在缓存命中还是磁盘读取。修正方法是在线事务系统同时开启 log_analyze 与 log_buffers，重点查看 shared hit/read 比例。

3. 误把采样当成确定性捕获。 常见错误是设置很低采样率后，抱怨某条关键慢 SQL 没有计划。采样只能降低高频重复样本的数量，不能保证严重事件必现。低频核心 SQL 应保留阈值捕获，并配合锁等待、语句超时和应用 trace。

4. 参数值泄露敏感信息。 log_parameter_max_length = -1 会把完整绑定参数写入日志，可能包含手机号、身份证号或订单金额。生产环境应限制长度，例如设置为 128，并确认日志平台的访问权限、脱敏和保留周期。

5. 看到慢计划就盲目加索引。 日志中的计划只是一次执行现场。若 estimated rows 与 actual rows 差异很大，应先 ANALYZE；若过滤性很差，单列索引可能不如复合索引或部分索引；若表很小，顺序扫描反而可能是优化器的正确选择。建议结合 pg_stat_statements 的调用频次、总耗时和缓存统计再做索引决策。

最终建议是：测试库用会话级 LOAD 快速验证，生产库通过 shared_preload_libraries 常驻启用；稳定期使用较稳健的阈值和低采样，排障窗口再临时降低阈值、提高采样。这样既能在慢查询发生时保留真实执行计划，又不会让日志系统成为新的性能瓶颈。

免责声明

本工具与文章内容仅用于学习测试场景，优化建议仅供参考，请勿直接用于生产环境，由此产生的风险自行承担。