Postgresql 中文操作指南

F.4. auto_explain — log execution plans of slow queries #

auto_explain 模块提供了一种方法，用于自动记录慢语句的执行计划，而无需手动运行 EXPLAIN 。这对于追踪大型应用程序中未经优化的查询特别有帮助。

The auto_explain module provides a means for logging execution plans of slow statements automatically, without having to run EXPLAIN by hand. This is especially helpful for tracking down un-optimized queries in large applications.

该模块不提供 SQL 可访问函数。要使用它，只需将其加载到服务器中即可。可以将其加载到单个会话中：

The module provides no SQL-accessible functions. To use it, simply load it into the server. You can load it into an individual session:

LOAD 'auto_explain';

（您必须是超级用户才能这样做）。更典型的用法是，通过在 session_preload_libraries 中包含 auto_explain 或在 postgresql.conf 中包含 shared_preload_libraries，将其预加载到某些或所有会话中。然后，无论何时发生意外的慢查询，您都可以对其进行跟踪。当然，这样会有开销的代价。

(You must be superuser to do that.) More typical usage is to preload it into some or all sessions by including auto_explain in session_preload_libraries or shared_preload_libraries in postgresql.conf. Then you can track unexpectedly slow queries no matter when they happen. Of course there is a price in overhead for that.

F.4.1. Configuration Parameters #

有几个配置参数控制 auto_explain 的行为。请注意，默认行为是不执行任何操作，因此如果需要任何结果，则必须至少设置 auto_explain.log_min_duration。

There are several configuration parameters that control the behavior of auto_explain. Note that the default behavior is to do nothing, so you must set at least auto_explain.log_min_duration if you want any results.

  • auto_explain.log_min_duration (integer) #

    • auto_explain.log_min_duration is the minimum statement execution time, in milliseconds, that will cause the statement’s plan to be logged. Setting this to 0 logs all plans. -1 (the default) disables logging of plans. For example, if you set it to 250ms then all statements that run 250ms or longer will be logged. Only superusers can change this setting.

  • auto_explain.log_parameter_max_length (integer) #

    • auto_explain.log_parameter_max_length controls the logging of query parameter values. A value of -1 (the default) logs the parameter values in full. 0 disables logging of parameter values. A value greater than zero truncates each parameter value to that many bytes. Only superusers can change this setting.

  • auto_explain.log_analyze (boolean) #

    • auto_explain.log_analyze causes EXPLAIN ANALYZE output, rather than just EXPLAIN output, to be printed when an execution plan is logged. This parameter is off by default. Only superusers can change this setting.

  • auto_explain.log_buffers (boolean) #

    • auto_explain.log_buffers controls whether buffer usage statistics are printed when an execution plan is logged; it’s equivalent to the BUFFERS option of EXPLAIN. This parameter has no effect unless auto_explain.log_analyze is enabled. This parameter is off by default. Only superusers can change this setting.

  • auto_explain.log_wal (boolean) #

    • auto_explain.log_wal controls whether WAL usage statistics are printed when an execution plan is logged; it’s equivalent to the WAL option of EXPLAIN. This parameter has no effect unless auto_explain.log_analyze is enabled. This parameter is off by default. Only superusers can change this setting.

  • auto_explain.log_timing (boolean) #

    • auto_explain.log_timing controls whether per-node timing information is printed when an execution plan is logged; it’s equivalent to the TIMING option of EXPLAIN. The overhead of repeatedly reading the system clock can slow down queries significantly on some systems, so it may be useful to set this parameter to off when only actual row counts, and not exact times, are needed. This parameter has no effect unless auto_explain.log_analyze is enabled. This parameter is on by default. Only superusers can change this setting.

  • auto_explain.log_triggers (boolean) #

    • auto_explain.log_triggers causes trigger execution statistics to be included when an execution plan is logged. This parameter has no effect unless auto_explain.log_analyze is enabled. This parameter is off by default. Only superusers can change this setting.

  • auto_explain.log_verbose (boolean) #

    • auto_explain.log_verbose controls whether verbose details are printed when an execution plan is logged; it’s equivalent to the VERBOSE option of EXPLAIN. This parameter is off by default. Only superusers can change this setting.

  • auto_explain.log_settings (boolean) #

    • auto_explain.log_settings controls whether information about modified configuration options is printed when an execution plan is logged. Only options affecting query planning with value different from the built-in default value are included in the output. This parameter is off by default. Only superusers can change this setting.

  • auto_explain.log_format (enum) #

    • auto_explain.log_format selects the EXPLAIN output format to be used. The allowed values are text, xml, json, and yaml. The default is text. Only superusers can change this setting.

  • auto_explain.log_level (enum) #

    • auto_explain.log_level selects the log level at which auto_explain will log the query plan. Valid values are DEBUG5, DEBUG4, DEBUG3, DEBUG2, DEBUG1, INFO, NOTICE, WARNING, and LOG. The default is LOG. Only superusers can change this setting.

  • auto_explain.log_nested_statements (boolean) #

    • auto_explain.log_nested_statements causes nested statements (statements executed inside a function) to be considered for logging. When it is off, only top-level query plans are logged. This parameter is off by default. Only superusers can change this setting.

  • auto_explain.sample_rate (real) #

    • auto_explain.sample_rate causes auto_explain to only explain a fraction of the statements in each session. The default is 1, meaning explain all the queries. In case of nested statements, either all will be explained or none. Only superusers can change this setting.

Note

当此参数打开时，对于所有执行的语句都会发生逐计划节点计时，无论其是否运行得足够长以真正获取日志。这可能会对性能产生极大的负面影响。关闭 auto_explain.log_timing 会减轻性能损失，但代价是获取更少的信息。

When this parameter is on, per-plan-node timing occurs for all statements executed, whether or not they run long enough to actually get logged. This can have an extremely negative impact on performance. Turning off auto_explain.log_timing ameliorates the performance cost, at the price of obtaining less information.

在普通用法中，这些参数是在 postgresql.conf 中设置的，尽管超级用户可以在其自己的会话中即时更改它们。典型用法可能是：

In ordinary usage, these parameters are set in postgresql.conf, although superusers can alter them on-the-fly within their own sessions. Typical usage might be:

# postgresql.conf
session_preload_libraries = 'auto_explain'

auto_explain.log_min_duration = '3s'

F.4.2. Example #

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;

这可能会产生如下日志输出：

This might produce log output such as:

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

F.4.3. Author #

Takahiro Itagaki < link:mailto:itagaki.takahiro@oss.ntt.co.jp[itagaki.takahiro@oss.ntt.co.jp]>

Takahiro Itagaki <link:mailto:itagaki.takahiro@oss.ntt.co.jp[itagaki.takahiro@oss.ntt.co.jp]>