From e125e28e781116ceb2860be29e6508906c81d2da Mon Sep 17 00:00:00 2001 From: Tom Lane Date: Wed, 19 Nov 2008 02:59:28 +0000 Subject: Add auto-explain contrib module for automatic logging of the plans of slow-running queries. Takahiro Itagaki --- doc/src/sgml/auto-explain.sgml | 176 +++++++++++++++++++++++++++++++++++++++++ doc/src/sgml/contrib.sgml | 3 +- doc/src/sgml/filelist.sgml | 3 +- 3 files changed, 180 insertions(+), 2 deletions(-) create mode 100644 doc/src/sgml/auto-explain.sgml (limited to 'doc/src') diff --git a/doc/src/sgml/auto-explain.sgml b/doc/src/sgml/auto-explain.sgml new file mode 100644 index 00000000000..c8215e0cc81 --- /dev/null +++ b/doc/src/sgml/auto-explain.sgml @@ -0,0 +1,176 @@ + + + + auto_explain + + + auto_explain + + + + The auto_explain module provides a means for + logging execution plans of slow statements automatically, without + having to run + 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 + 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. + + + + 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 + explain.log_min_duration if you want any results. + + + + + + explain.log_min_duration (integer) + + + explain.log_min_duration configuration parameter + + + + 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. + + + + + + + explain.log_analyze (boolean) + + + explain.log_analyze configuration parameter + + + + 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. + + + + 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. + + + + + + + + explain.log_verbose (boolean) + + + explain.log_verbose configuration parameter + + + + 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. + + + + + + + explain.log_nested_statements (boolean) + + + explain.log_nested_statements configuration parameter + + + + 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 explain in + custom_variable_classes. Typical usage might be: + + + +# postgresql.conf +shared_preload_libraries = 'auto_explain' + +custom_variable_classes = 'explain' +explain.log_min_duration = '3s' + + + + + Example + + + postgres=# LOAD 'auto_explain'; + postgres=# SET 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: 0.986 ms plan: + Aggregate (cost=14.90..14.91 rows=1 width=0) + -> Hash Join (cost=3.91..14.70 rows=81 width=0) + Hash Cond: (pg_class.oid = pg_index.indrelid) + -> Seq Scan on pg_class (cost=0.00..8.27 rows=227 width=4) + -> Hash (cost=2.90..2.90 rows=81 width=4) + -> Seq Scan on pg_index (cost=0.00..2.90 rows=81 width=4) + Filter: indisunique + STATEMENT: SELECT count(*) + FROM pg_class, pg_index + WHERE oid = indrelid AND indisunique; + + + + + Author + + + Takahiro Itagaki itagaki.takahiro@oss.ntt.co.jp + + + + diff --git a/doc/src/sgml/contrib.sgml b/doc/src/sgml/contrib.sgml index bac5044205b..ecc5a0b23e3 100644 --- a/doc/src/sgml/contrib.sgml +++ b/doc/src/sgml/contrib.sgml @@ -1,4 +1,4 @@ - + Additional Supplied Modules @@ -79,6 +79,7 @@ psql -d dbname -f SHAREDIR/contrib/module.sql &adminpack; + &auto-explain; &btree-gist; &chkpass; &citext; diff --git a/doc/src/sgml/filelist.sgml b/doc/src/sgml/filelist.sgml index 32aa90400bb..ea1c7c274fa 100644 --- a/doc/src/sgml/filelist.sgml +++ b/doc/src/sgml/filelist.sgml @@ -1,4 +1,4 @@ - + @@ -92,6 +92,7 @@ + -- cgit v1.2.3