codekingpro/portable-devtools
115k
1<?xml version="1.0" encoding="UTF-8" standalone="no"?>2<!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Transitional//EN" "http://www.w3.org/TR/xhtml1/DTD/xhtml1-transitional.dtd"><html xmlns="http://www.w3.org/1999/xhtml"><head><meta http-equiv="Content-Type" content="text/html; charset=UTF-8" /><title>F.4. auto_explain — log execution plans of slow queries</title><link rel="stylesheet" type="text/css" href="stylesheet.css" /><link rev="made" href="pgsql-docs@lists.postgresql.org" /><meta name="generator" content="DocBook XSL Stylesheets Vsnapshot" /><link rel="prev" href="auth-delay.html" title="F.3. auth_delay — pause on authentication failure" /><link rel="next" href="basebackup-to-shell.html" title="F.5. basebackup_to_shell — example "shell" pg_basebackup module" /></head><body id="docContent" class="container-fluid col-10"><div class="navheader"><table width="100%" summary="Navigation header"><tr><th colspan="5" align="center">F.4. auto_explain — log execution plans of slow queries</th></tr><tr><td width="10%" align="left"><a accesskey="p" href="auth-delay.html" title="F.3. auth_delay — pause on authentication failure">Prev</a> </td><td width="10%" align="left"><a accesskey="u" href="contrib.html" title="Appendix F. Additional Supplied Modules and Extensions">Up</a></td><th width="60%" align="center">Appendix F. Additional Supplied Modules and Extensions</th><td width="10%" align="right"><a accesskey="h" href="index.html" title="PostgreSQL 16.3 Documentation">Home</a></td><td width="10%" align="right"> <a accesskey="n" href="basebackup-to-shell.html" title="F.5. basebackup_to_shell — example "shell" pg_basebackup module">Next</a></td></tr></table><hr /></div><div class="sect1" id="AUTO-EXPLAIN"><div class="titlepage"><div><div><h2 class="title" style="clear: both">F.4. auto_explain — log execution plans of slow queries <a href="#AUTO-EXPLAIN" class="id_link">#</a></h2></div></div></div><div class="toc"><dl class="toc"><dt><span class="sect2"><a href="auto-explain.html#AUTO-EXPLAIN-CONFIGURATION-PARAMETERS">F.4.1. Configuration Parameters</a></span></dt><dt><span class="sect2"><a href="auto-explain.html#AUTO-EXPLAIN-EXAMPLE">F.4.2. Example</a></span></dt><dt><span class="sect2"><a href="auto-explain.html#AUTO-EXPLAIN-AUTHOR">F.4.3. Author</a></span></dt></dl></div><a id="id-1.11.7.14.2" class="indexterm"></a><p>3 The <code class="filename">auto_explain</code> module provides a means for4 logging execution plans of slow statements automatically, without5 having to run <a class="xref" href="sql-explain.html" title="EXPLAIN"><span class="refentrytitle">EXPLAIN</span></a>6 by hand. This is especially helpful for tracking down un-optimized queries7 in large applications.8 </p><p>9 The module provides no SQL-accessible functions. To use it, simply10 load it into the server. You can load it into an individual session:11 12</p><pre class="programlisting">13LOAD 'auto_explain';14</pre><p>15 16 (You must be superuser to do that.) More typical usage is to preload17 it into some or all sessions by including <code class="literal">auto_explain</code> in18 <a class="xref" href="runtime-config-client.html#GUC-SESSION-PRELOAD-LIBRARIES">session_preload_libraries</a> or19 <a class="xref" href="runtime-config-client.html#GUC-SHARED-PRELOAD-LIBRARIES">shared_preload_libraries</a> in20 <code class="filename">postgresql.conf</code>. Then you can track unexpectedly slow queries21 no matter when they happen. Of course there is a price in overhead for22 that.23 </p><div class="sect2" id="AUTO-EXPLAIN-CONFIGURATION-PARAMETERS"><div class="titlepage"><div><div><h3 class="title">F.4.1. Configuration Parameters <a href="#AUTO-EXPLAIN-CONFIGURATION-PARAMETERS" class="id_link">#</a></h3></div></div></div><p>24 There are several configuration parameters that control the behavior of25 <code class="filename">auto_explain</code>. Note that the default behavior is26 to do nothing, so you must set at least27 <code class="varname">auto_explain.log_min_duration</code> if you want any results.28 </p><div class="variablelist"><dl class="variablelist"><dt id="AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-MIN-DURATION"><span class="term">29 <code class="varname">auto_explain.log_min_duration</code> (<code class="type">integer</code>)30 <a id="id-1.11.7.14.5.3.1.1.3" class="indexterm"></a>31 </span> <a href="#AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-MIN-DURATION" class="id_link">#</a></dt><dd><p>32 <code class="varname">auto_explain.log_min_duration</code> is the minimum statement33 execution time, in milliseconds, that will cause the statement's plan to34 be logged. Setting this to <code class="literal">0</code> logs all plans.35 <code class="literal">-1</code> (the default) disables logging of plans. For36 example, if you set it to <code class="literal">250ms</code> then all statements37 that run 250ms or longer will be logged. Only superusers can change this38 setting.39 </p></dd><dt id="AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-PARAMETER-MAX-LENGTH"><span class="term">40 <code class="varname">auto_explain.log_parameter_max_length</code> (<code class="type">integer</code>)41 <a id="id-1.11.7.14.5.3.2.1.3" class="indexterm"></a>42 </span> <a href="#AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-PARAMETER-MAX-LENGTH" class="id_link">#</a></dt><dd><p>43 <code class="varname">auto_explain.log_parameter_max_length</code> controls the44 logging of query parameter values. A value of <code class="literal">-1</code> (the45 default) logs the parameter values in full. <code class="literal">0</code> disables46 logging of parameter values. A value greater than zero truncates each47 parameter value to that many bytes. Only superusers can change this48 setting.49 </p></dd><dt id="AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-ANALYZE"><span class="term">50 <code class="varname">auto_explain.log_analyze</code> (<code class="type">boolean</code>)51 <a id="id-1.11.7.14.5.3.3.1.3" class="indexterm"></a>52 </span> <a href="#AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-ANALYZE" class="id_link">#</a></dt><dd><p>53 <code class="varname">auto_explain.log_analyze</code> causes <code class="command">EXPLAIN ANALYZE</code>54 output, rather than just <code class="command">EXPLAIN</code> output, to be printed55 when an execution plan is logged. This parameter is off by default.56 Only superusers can change this setting.57 </p><div class="note"><h3 class="title">Note</h3><p>58 When this parameter is on, per-plan-node timing occurs for all59 statements executed, whether or not they run long enough to actually60 get logged. This can have an extremely negative impact on performance.61 Turning off <code class="varname">auto_explain.log_timing</code> ameliorates the62 performance cost, at the price of obtaining less information.63 </p></div></dd><dt id="AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-BUFFERS"><span class="term">64 <code class="varname">auto_explain.log_buffers</code> (<code class="type">boolean</code>)65 <a id="id-1.11.7.14.5.3.4.1.3" class="indexterm"></a>66 </span> <a href="#AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-BUFFERS" class="id_link">#</a></dt><dd><p>67 <code class="varname">auto_explain.log_buffers</code> controls whether buffer68 usage statistics are printed when an execution plan is logged; it's69 equivalent to the <code class="literal">BUFFERS</code> option of <code class="command">EXPLAIN</code>.70 This parameter has no effect71 unless <code class="varname">auto_explain.log_analyze</code> is enabled.72 This parameter is off by default.73 Only superusers can change this setting.74 </p></dd><dt id="AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-WAL"><span class="term">75 <code class="varname">auto_explain.log_wal</code> (<code class="type">boolean</code>)76 <a id="id-1.11.7.14.5.3.5.1.3" class="indexterm"></a>77 </span> <a href="#AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-WAL" class="id_link">#</a></dt><dd><p>78 <code class="varname">auto_explain.log_wal</code> controls whether WAL79 usage statistics are printed when an execution plan is logged; it's80 equivalent to the <code class="literal">WAL</code> option of <code class="command">EXPLAIN</code>.81 This parameter has no effect82 unless <code class="varname">auto_explain.log_analyze</code> is enabled.83 This parameter is off by default.84 Only superusers can change this setting.85 </p></dd><dt id="AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-TIMING"><span class="term">86 <code class="varname">auto_explain.log_timing</code> (<code class="type">boolean</code>)87 <a id="id-1.11.7.14.5.3.6.1.3" class="indexterm"></a>88 </span> <a href="#AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-TIMING" class="id_link">#</a></dt><dd><p>89 <code class="varname">auto_explain.log_timing</code> controls whether per-node90 timing information is printed when an execution plan is logged; it's91 equivalent to the <code class="literal">TIMING</code> option of <code class="command">EXPLAIN</code>.92 The overhead of repeatedly reading the system clock can slow down93 queries significantly on some systems, so it may be useful to set this94 parameter to off when only actual row counts, and not exact times, are95 needed.96 This parameter has no effect97 unless <code class="varname">auto_explain.log_analyze</code> is enabled.98 This parameter is on by default.99 Only superusers can change this setting.100 </p></dd><dt id="AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-TRIGGERS"><span class="term">101 <code class="varname">auto_explain.log_triggers</code> (<code class="type">boolean</code>)102 <a id="id-1.11.7.14.5.3.7.1.3" class="indexterm"></a>103 </span> <a href="#AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-TRIGGERS" class="id_link">#</a></dt><dd><p>104 <code class="varname">auto_explain.log_triggers</code> causes trigger105 execution statistics to be included when an execution plan is logged.106 This parameter has no effect107 unless <code class="varname">auto_explain.log_analyze</code> is enabled.108 This parameter is off by default.109 Only superusers can change this setting.110 </p></dd><dt id="AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-VERBOSE"><span class="term">111 <code class="varname">auto_explain.log_verbose</code> (<code class="type">boolean</code>)112 <a id="id-1.11.7.14.5.3.8.1.3" class="indexterm"></a>113 </span> <a href="#AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-VERBOSE" class="id_link">#</a></dt><dd><p>114 <code class="varname">auto_explain.log_verbose</code> controls whether verbose115 details are printed when an execution plan is logged; it's116 equivalent to the <code class="literal">VERBOSE</code> option of <code class="command">EXPLAIN</code>.117 This parameter is off by default.118 Only superusers can change this setting.119 </p></dd><dt id="AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-SETTINGS"><span class="term">120 <code class="varname">auto_explain.log_settings</code> (<code class="type">boolean</code>)121 <a id="id-1.11.7.14.5.3.9.1.3" class="indexterm"></a>122 </span> <a href="#AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-SETTINGS" class="id_link">#</a></dt><dd><p>123 <code class="varname">auto_explain.log_settings</code> controls whether information124 about modified configuration options is printed when an execution plan is logged.125 Only options affecting query planning with value different from the built-in126 default value are included in the output. This parameter is off by default.127 Only superusers can change this setting.128 </p></dd><dt id="AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-FORMAT"><span class="term">129 <code class="varname">auto_explain.log_format</code> (<code class="type">enum</code>)130 <a id="id-1.11.7.14.5.3.10.1.3" class="indexterm"></a>131 </span> <a href="#AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-FORMAT" class="id_link">#</a></dt><dd><p>132 <code class="varname">auto_explain.log_format</code> selects the133 <code class="command">EXPLAIN</code> output format to be used.134 The allowed values are <code class="literal">text</code>, <code class="literal">xml</code>,135 <code class="literal">json</code>, and <code class="literal">yaml</code>. The default is text.136 Only superusers can change this setting.137 </p></dd><dt id="AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-LEVEL"><span class="term">138 <code class="varname">auto_explain.log_level</code> (<code class="type">enum</code>)139 <a id="id-1.11.7.14.5.3.11.1.3" class="indexterm"></a>140 </span> <a href="#AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-LEVEL" class="id_link">#</a></dt><dd><p>141 <code class="varname">auto_explain.log_level</code> selects the log level at which142 auto_explain will log the query plan.143 Valid values are <code class="literal">DEBUG5</code>, <code class="literal">DEBUG4</code>,144 <code class="literal">DEBUG3</code>, <code class="literal">DEBUG2</code>,145 <code class="literal">DEBUG1</code>, <code class="literal">INFO</code>,146 <code class="literal">NOTICE</code>, <code class="literal">WARNING</code>,147 and <code class="literal">LOG</code>. The default is <code class="literal">LOG</code>.148 Only superusers can change this setting.149 </p></dd><dt id="AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-NESTED-STATEMENTS"><span class="term">150 <code class="varname">auto_explain.log_nested_statements</code> (<code class="type">boolean</code>)151 <a id="id-1.11.7.14.5.3.12.1.3" class="indexterm"></a>152 </span> <a href="#AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-LOG-NESTED-STATEMENTS" class="id_link">#</a></dt><dd><p>153 <code class="varname">auto_explain.log_nested_statements</code> causes nested154 statements (statements executed inside a function) to be considered155 for logging. When it is off, only top-level query plans are logged. This156 parameter is off by default. Only superusers can change this setting.157 </p></dd><dt id="AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-SAMPLE-RATE"><span class="term">158 <code class="varname">auto_explain.sample_rate</code> (<code class="type">real</code>)159 <a id="id-1.11.7.14.5.3.13.1.3" class="indexterm"></a>160 </span> <a href="#AUTO-EXPLAIN-CONFIGURATION-PARAMETERS-SAMPLE-RATE" class="id_link">#</a></dt><dd><p>161 <code class="varname">auto_explain.sample_rate</code> causes auto_explain to only162 explain a fraction of the statements in each session. The default is 1,163 meaning explain all the queries. In case of nested statements, either all164 will be explained or none. Only superusers can change this setting.165 </p></dd></dl></div><p>166 In ordinary usage, these parameters are set167 in <code class="filename">postgresql.conf</code>, although superusers can alter them168 on-the-fly within their own sessions.169 Typical usage might be:170 </p><pre class="programlisting">171# postgresql.conf172session_preload_libraries = 'auto_explain'173 174auto_explain.log_min_duration = '3s'175</pre></div><div class="sect2" id="AUTO-EXPLAIN-EXAMPLE"><div class="titlepage"><div><div><h3 class="title">F.4.2. Example <a href="#AUTO-EXPLAIN-EXAMPLE" class="id_link">#</a></h3></div></div></div><pre class="programlisting">176postgres=# LOAD 'auto_explain';177postgres=# SET auto_explain.log_min_duration = 0;178postgres=# SET auto_explain.log_analyze = true;179postgres=# SELECT count(*)180 FROM pg_class, pg_index181 WHERE oid = indrelid AND indisunique;182</pre><p>183 This might produce log output such as:184 </p><pre class="screen">185LOG: duration: 3.651 ms plan:186 Query Text: SELECT count(*)187 FROM pg_class, pg_index188 WHERE oid = indrelid AND indisunique;189 Aggregate (cost=16.79..16.80 rows=1 width=0) (actual time=3.626..3.627 rows=1 loops=1)190 -> Hash Join (cost=4.17..16.55 rows=92 width=0) (actual time=3.349..3.594 rows=92 loops=1)191 Hash Cond: (pg_class.oid = pg_index.indrelid)192 -> Seq Scan on pg_class (cost=0.00..9.55 rows=255 width=4) (actual time=0.016..0.140 rows=255 loops=1)193 -> Hash (cost=3.02..3.02 rows=92 width=4) (actual time=3.238..3.238 rows=92 loops=1)194 Buckets: 1024 Batches: 1 Memory Usage: 4kB195 -> Seq Scan on pg_index (cost=0.00..3.02 rows=92 width=4) (actual time=0.008..3.187 rows=92 loops=1)196 Filter: indisunique197</pre></div><div class="sect2" id="AUTO-EXPLAIN-AUTHOR"><div class="titlepage"><div><div><h3 class="title">F.4.3. Author <a href="#AUTO-EXPLAIN-AUTHOR" class="id_link">#</a></h3></div></div></div><p>198 Takahiro Itagaki <code class="email"><<a class="email" href="mailto:itagaki.takahiro@oss.ntt.co.jp">itagaki.takahiro@oss.ntt.co.jp</a>></code>199 </p></div></div><div class="navfooter"><hr /><table width="100%" summary="Navigation footer"><tr><td width="40%" align="left"><a accesskey="p" href="auth-delay.html" title="F.3. auth_delay — pause on authentication failure">Prev</a> </td><td width="20%" align="center"><a accesskey="u" href="contrib.html" title="Appendix F. Additional Supplied Modules and Extensions">Up</a></td><td width="40%" align="right"> <a accesskey="n" href="basebackup-to-shell.html" title="F.5. basebackup_to_shell — example "shell" pg_basebackup module">Next</a></td></tr><tr><td width="40%" align="left" valign="top">F.3. auth_delay — pause on authentication failure </td><td width="20%" align="center"><a accesskey="h" href="index.html" title="PostgreSQL 16.3 Documentation">Home</a></td><td width="40%" align="right" valign="top"> F.5. basebackup_to_shell — example "shell" pg_basebackup module</td></tr></table></div></body></html>