PG插件之auto_explain记录慢查询执行计划
Tags： auto_explainPG慢查询
简介
auto_explain模块提供了一种自动记录慢语句执行计划的方法，而不必手动运行EXPLAIN。这对于在大型应用程序中跟踪未优化的查询特别有帮助。
该模块不提供sql可访问的函数。要使用它，只需将它加载到服务器。你可以将它加载到一个单独的会话中:
1 | load 'auto_explain' |
如果想在全局开启该功能，可以在配置文件postgres.conf文件中通过session_preload_libraries或shared_preload_libraries进行配置。不过会有一定开销产生。
比如：
1 2 3 | # postgresql.conf session_preload_libraries = 'auto_explain' auto_explain.log_min_duration = '2s' |
安装
1 | make && make install |
auto_explain相关参数
有几个配置参数用来控制auto_explain的行为。注意默认行为是什么也不做，因此如果你想要任何结果就必须至少设置auto_explain.log_min_duration。
auto_explain.log_min_duration
log_min_duration是导致记录语句执行计划的最小的执行时间(以毫秒为单位)。如果设置为0，会记录所有的执行计划。默认值是-1，即不记录。比如，如果设置为250ms，即记录运行时间超过250ms的语句的执行计划(包含250ms)
auto_explain.log_analyze
布尔类型的值。如果设置为true，在记录的执行计划的时候，输出的内容是explain analyze的结果，而不是explain的结果。默认值是off。开启后对性会有影响，
auto_explain.log_buffers
布尔类型的值。控制是否统计在执行计划中，对buffer的使用统计信息。等价于explain buffers。默认是off的。该选项只有在开启了auto_explain.log_analyze后才有效。
auto_explain.log_timing
布尔类型的值。控制执行计划中是否统计每个节点的时间信息。等价于explain timing。在有些系统中，重复地读取系统锁信息会降低查询性能。一般不建议开启。要想生效，必须先开启auto_explain.log_analyze。默认设置是on。
auto_explain.log_triggers
布尔类型的值。在记录执行计划时包含触发器执行统计信息。这个参数没有作用，除非auto_explain.log_analyze被启用。该参数默认关闭。只有超级用户才能更改此设置。
auto_explain.log_verbose
布尔类型的值。控制在记录执行计划时是否打印详细信息;它相当于冗长的EXPLAIN VERBOSE选项。该参数默认关闭。只有超级用户才能更改此设置。
auto_explain.log_format
枚举类型。定义explain的输出格式。支持的格式有：text、xml、json、yaml。默认是text。
auto_explain.log_nested_statements
布尔类型的值。考虑对嵌套语句(在函数中执行的语句)进行日志记录。当它关闭时，只记录顶级查询计划。该参数默认关闭。只有超级用户才能更改此设置。
auto_explain.sample_rate
real类型的值。只解释每个会话中的一小部分语句。默认值是1，表示解释所有查询。在嵌套语句的情况下，要么全部解释，要么全部不解释。只有超级用户才能更改此设置。
使用示例
1 2 3 4 5 6 | postgres=# LOAD 'auto_explain'; postgres=# SET auto_explain.log_min_duration = 0; postgres=# SET auto_explain.log_analyze = true; postgres=# SELECT count(*) FROM pg_class, pg_index WHERE oid = indrelid AND indisunique; |
在日志中就可以看到以下执行计划内容：
1 2 3 4 5 6 7 8 9 10 11 12 | LOG: duration: 3.651 ms plan: Query Text: SELECT count(*) FROM pg_class, pg_index WHERE oid = indrelid AND indisunique; Aggregate (cost=16.79..16.80 rows=1 width=0) (actual time=3.626..3.627 rows=1 loops=1) -> Hash Join (cost=4.17..16.55 rows=92 width=0) (actual time=3.349..3.594 rows=92 loops=1) Hash Cond: (pg_class.oid = pg_index.indrelid) -> Seq Scan on pg_class (cost=0.00..9.55 rows=255 width=4) (actual time=0.016..0.140 rows=255 loops=1) -> Hash (cost=3.02..3.02 rows=92 width=4) (actual time=3.238..3.238 rows=92 loops=1) Buckets: 1024 Batches: 1 Memory Usage: 4kB -> Seq Scan on pg_index (cost=0.00..3.02 rows=92 width=4) (actual time=0.008..3.187 rows=92 loops=1) Filter: indisunique |
如果你不想看日志这么麻烦，想在client直接显示，也很方便，设置client_min_messages='log'就可以看到auto explain的输出了。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 | set client_min_messages='log'; set auto_explain.log_min_duration = 0; set auto_explain.log_analyze = true; set auto_explain.log_verbose = true; set auto_explain.log_buffers = true; set auto_explain.log_nested_statements = true; postgres=# do language plpgsql $$ declare begin perform 1 from pg_class where oid=1; end; $$; LOG: duration: 0.008 ms plan: Query Text: SELECT 1 from pg_class where oid=1 Index Only Scan using pg_class_oid_index on pg_catalog.pg_class (cost=0.27..1.29 rows=1 width=4) (actual time=0.006..0.006 rows=0 loops=1) Output: 1 Index Cond: (pg_class.oid = '1'::oid) Heap Fetches: 0 Buffers: shared hit=2 DO |
