数据库出现慢查询的原因很多，例如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运行结束。
with t_wait as
(select a.mode,a.locktype,a.database,a.relation,a.page,a.tuple,a.classid,
a.objid,a.objsubid,a.pid,a.virtualtransaction,a.virtualxid,a,
transactionid,b.query,b.xact_start,b.query_start,b.usename,b.datname
from pg_locks a,pg_stat_activity b where a.pid=b.pid and not a.granted),
t_run as
(select a.mode,a.locktype,a.database,a.relation,a.page,a.tuple,
a.classid,a.objid,a.objsubid,a.pid,a.virtualtransaction,a.virtualxid,
a,transactionid,b.query,b.xact_start,b.query_start,
b.usename,b.datname from pg_locks a,pg_stat_activity b where
a.pid=b.pid and a.granted)
select r.locktype,r.mode r_mode,r.usename r_user,r.datname r_db,
r.relation::regclass,r.pid r_pid,
r.page r_page,r.tuple r_tuple,r.xact_start r_xact_start,
r.query_start r_query_start,
now()-r.query_start r_locktime,r.query r_query,w.mode w_mode,
w.pid w_pid,w.page w_page,
w.tuple w_tuple,w.xact_start w_xact_start,w.query_start w_query_start,
now()-w.query_start w_locktime,w.query w_query
from t_wait w,t_run r where
r.locktype is not distinct from w.locktype and
r.database is not distinct from w.database and
r.relation is not distinct from w.relation and
r.page is not distinct from w.page and
r.tuple is not distinct from w.tuple and
r.classid is not distinct from w.classid and
r.objid is not distinct from w.objid and
r.objsubid is not distinct from w.objsubid and
r.transactionid is not distinct from w.transactionid and
r.pid <> w.pid
order by
(( case w.mode
when 'INVALID' then 0
when 'AccessShareLock' then 1
when 'RowShareLock' then 2
when 'RowExclusiveLock' then 3
when 'ShareUpdateExclusiveLock' then 4
when 'ShareLock' then 5
when 'ShareRowExclusiveLock' then 6
when 'ExclusiveLock' then 7
when 'AccessExclusiveLock' then 8
else 0
end ) +
( case r.mode
when 'INVALID' then 0
when 'AccessShareLock' then 1
when 'RowShareLock' then 2
when 'RowExclusiveLock' then 3
when 'ShareUpdateExclusiveLock' then 4
when 'ShareLock' then 5
when 'ShareRowExclusiveLock' then 6
when 'ExclusiveLock' then 7
when 'AccessExclusiveLock' then 8
else 0
end )) desc,r.xact_start;.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运行结束。
.3. 数据库内核层面能做什么
.3.1. 对执行时间超过阈值的SQL，自动记录SQL的explain 输出，以及每个NODE的耗时。
配置auto_explain来实现以上目的，配置例子：
http://blog.163.com/digoal@126/blog/static/16387704020115825612145/
.3.2. 自动记录SQL的锁等待耗时。
配置例子：
log_lock_waits=on
deadlock_timeout = 1s.3.3. 内核还可以记录SQL IO的时间，需要开启io timing trace.
.3.4. PG内核目前输出的SQL时间包含了数据传输到客户端的时间，但是网络传输的时间没有单独统计，所以这个可以通过HACK内核来实现。
有了以上信息，就可以追溯慢查询到底慢在什么地方了。
