PostgreSQL 9.0.3 Documentation
Prev | Fast Backward | Appendix F. Additional Supplied Modules | Fast Forward | Next

# F.2. auto_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.

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';

(You must be superuser to do that.) More typical usage is to preload it into all sessions by including `auto_explain` in 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.2.1. Configuration parameters

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 zero logs all plans. Minus-one (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_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.

  > Note: 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 extremely negative impact on performance.

`auto_explain.log_verbose` (`boolean`)

  `auto_explain.log_verbose` causes `EXPLAIN VERBOSE` 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` causes `EXPLAIN (ANALYZE, BUFFERS)` 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. This parameter has no effect unless `auto_explain.log_analyze` parameter is set.

`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_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.

In order to set these parameters in your `postgresql.conf` file, you will need to add `auto_explain` to custom_variable_classes. Typical usage might be:

    # postgresql.conf
    shared_preload_libraries = 'auto_explain'

    custom_variable_classes = 'auto_explain'
    auto_explain.log_min_duration = '3s'

## F.2.2. Example

    postgres=# LOAD 'auto_explain';
    postgres=# SET auto_explain.log_min_duration = 0;
    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.2.3. Author

Takahiro Itagaki `<itagaki.takahiro@oss.ntt.co.jp>`

Prev | Home | Next
adminpack | Up | btree_gin