如何追溯 PostgreSQL 慢查询当时的状态

背景

数据库出现慢查询的原因很多，例如IO等待，CPU繁忙，执行计划异常，锁等待，等等。

那么在发生慢查询后，如何能追溯慢查询当时的状态呢？

下面给大家提供一种思路，

1. 首先，我们是如何监测慢查询的

2. 监测到慢查询后，需要采集哪些信息

3. 数据库内核层面能做什么

4. 如何分析

如何实现？

1. 如何监测慢查询

select   
  datname, pid, usename, application_name, client_addr, client_port,   
  xact_start, query_start, state_change, waiting, state, backend_xid,   
  backend_xmin, query, xact_start,now()-xact_start   
from pg_stat_activity   
where state<>'idle'   
  and (backend_xid is not null or backend_xmin is not null)   
order by now()-xact_start;    

其中 now()-xact_start 是指事务截至当前已运行时间。

now() - query_start query截至当前已运行时间。

pid 指服务端进程ID。

2. 采集哪些信息

如果发现运行时间超过设定阈值，记录该进程的以下信息：

2.1.

针对pid查看它的pstack, 采集间隔自己定，比如1秒，直到对应的PID运行结束。

2.2.

数据库锁等待记录， 采集间隔自己定，比如1秒，直到对应的PID运行结束。

《PostgreSQL 锁等待监控 珍藏级SQL - 谁堵塞了谁》

2.3.

整机 io 情况, 例如 iostat -x 1 ，采集间隔自己定，比如1秒，直到对应的PID运行结束。

进程IO情况, iotop -p $PID ，采集间隔自己定，比如1秒，直到对应的PID运行结束。

2.4.

网络情况，例如sar -n DEV 1 1 ， 采集间隔自己定，比如1秒，直到对应的PID运行结束。

进程网络情况，例如 iptraf， 根据客户端IP和端口号， 采集间隔自己定，比如1秒，直到对应的PID运行结束。

2.5.

CPU 使用情况

top -p $PID ， 采集间隔自己定，比如1秒，直到对应的PID运行结束。

2.6. 数据库等待事件的监测，pg_stats_activity, wait_event统计。可能会有与pg_stat_statements类似的插件，通过HOOK，将等待事件信息统计并存储起来。用户可以通过快照这些统计结果，查看时间段的等待事件分析。

2.7. 数据库TOP SQL的监测，通过pg_stat_statements插件，快照，可以了解时间段内的TOP SQL，以及TOP SQL的各种开销。

2.8. 数据库表、索引的stats, statsio监测（全表扫描次数，FETCH TUPLE, GET TUPLES统计），（表的物理读的块数）

3. 数据库内核层面能做什么

3.1. 对执行时间超过阈值的SQL，自动记录SQL的explain 输出，以及每个NODE的耗时。

配置auto_explain来实现以上目的，配置例子：

《PostgreSQL 函数调试、诊断、优化 & auto_explain》

《PostgreSQL 加载动态库详解》

3.2. 自动记录SQL的锁等待耗时。

配置例子：

log_lock_waits=on  
deadlock_timeout = 1s  

3.3. 内核还可以记录SQL IO的时间，需要在postgresql.conf或者需要跟踪IO TIME的会话中开启开启io timing trace.

开启时间统计，会带来一定的性能问题，请参考

《Linux 时钟精度 与 PostgreSQL auto_explain (explain timing 时钟开销估算)》

3.4. PG内核目前输出的SQL时间包含了数据传输到客户端的时间，但是网络传输的时间没有单独统计，所以这个可以通过HACK内核来实现。

有了以上信息，就可以追溯慢查询到底慢在什么地方了。

参考

《如何生成和阅读EnterpriseDB (PPAS)诊断报告》

digoal’s 大量PostgreSQL文章入口