Start background writer during archive recovery. Background writer now performs
[PostgreSQL.git] / contrib / auto_explain / auto_explain.c
blobaa1ae0bdee50a33dac1a0db8f3b30d5af3f077d0
1 /*-------------------------------------------------------------------------
3 * auto_explain.c
6 * Copyright (c) 2008-2009, PostgreSQL Global Development Group
8 * IDENTIFICATION
9 * $PostgreSQL$
11 *-------------------------------------------------------------------------
13 #include "postgres.h"
15 #include "commands/explain.h"
16 #include "executor/instrument.h"
17 #include "utils/guc.h"
19 PG_MODULE_MAGIC;
21 /* GUC variables */
22 static int auto_explain_log_min_duration = -1; /* msec or -1 */
23 static bool auto_explain_log_analyze = false;
24 static bool auto_explain_log_verbose = false;
25 static bool auto_explain_log_nested_statements = false;
27 /* Current nesting depth of ExecutorRun calls */
28 static int nesting_level = 0;
30 /* Saved hook values in case of unload */
31 static ExecutorStart_hook_type prev_ExecutorStart = NULL;
32 static ExecutorRun_hook_type prev_ExecutorRun = NULL;
33 static ExecutorEnd_hook_type prev_ExecutorEnd = NULL;
35 #define auto_explain_enabled() \
36 (auto_explain_log_min_duration >= 0 && \
37 (nesting_level == 0 || auto_explain_log_nested_statements))
39 void _PG_init(void);
40 void _PG_fini(void);
42 static void explain_ExecutorStart(QueryDesc *queryDesc, int eflags);
43 static void explain_ExecutorRun(QueryDesc *queryDesc,
44 ScanDirection direction,
45 long count);
46 static void explain_ExecutorEnd(QueryDesc *queryDesc);
50 * Module load callback
52 void
53 _PG_init(void)
55 /* Define custom GUC variables. */
56 DefineCustomIntVariable("auto_explain.log_min_duration",
57 "Sets the minimum execution time above which plans will be logged.",
58 "Zero prints all plans. -1 turns this feature off.",
59 &auto_explain_log_min_duration,
60 -1,
61 -1, INT_MAX / 1000,
62 PGC_SUSET,
63 GUC_UNIT_MS,
64 NULL,
65 NULL);
67 DefineCustomBoolVariable("auto_explain.log_analyze",
68 "Use EXPLAIN ANALYZE for plan logging.",
69 NULL,
70 &auto_explain_log_analyze,
71 false,
72 PGC_SUSET,
74 NULL,
75 NULL);
77 DefineCustomBoolVariable("auto_explain.log_verbose",
78 "Use EXPLAIN VERBOSE for plan logging.",
79 NULL,
80 &auto_explain_log_verbose,
81 false,
82 PGC_SUSET,
84 NULL,
85 NULL);
87 DefineCustomBoolVariable("auto_explain.log_nested_statements",
88 "Log nested statements.",
89 NULL,
90 &auto_explain_log_nested_statements,
91 false,
92 PGC_SUSET,
94 NULL,
95 NULL);
97 EmitWarningsOnPlaceholders("auto_explain");
99 /* Install hooks. */
100 prev_ExecutorStart = ExecutorStart_hook;
101 ExecutorStart_hook = explain_ExecutorStart;
102 prev_ExecutorRun = ExecutorRun_hook;
103 ExecutorRun_hook = explain_ExecutorRun;
104 prev_ExecutorEnd = ExecutorEnd_hook;
105 ExecutorEnd_hook = explain_ExecutorEnd;
109 * Module unload callback
111 void
112 _PG_fini(void)
114 /* Uninstall hooks. */
115 ExecutorStart_hook = prev_ExecutorStart;
116 ExecutorRun_hook = prev_ExecutorRun;
117 ExecutorEnd_hook = prev_ExecutorEnd;
121 * ExecutorStart hook: start up logging if needed
123 void
124 explain_ExecutorStart(QueryDesc *queryDesc, int eflags)
126 if (auto_explain_enabled())
128 /* Enable per-node instrumentation iff log_analyze is required. */
129 if (auto_explain_log_analyze && (eflags & EXEC_FLAG_EXPLAIN_ONLY) == 0)
130 queryDesc->doInstrument = true;
133 if (prev_ExecutorStart)
134 prev_ExecutorStart(queryDesc, eflags);
135 else
136 standard_ExecutorStart(queryDesc, eflags);
138 if (auto_explain_enabled())
141 * Set up to track total elapsed time in ExecutorRun. Make sure
142 * the space is allocated in the per-query context so it will go
143 * away at ExecutorEnd.
145 if (queryDesc->totaltime == NULL)
147 MemoryContext oldcxt;
149 oldcxt = MemoryContextSwitchTo(queryDesc->estate->es_query_cxt);
150 queryDesc->totaltime = InstrAlloc(1);
151 MemoryContextSwitchTo(oldcxt);
157 * ExecutorRun hook: all we need do is track nesting depth
159 void
160 explain_ExecutorRun(QueryDesc *queryDesc, ScanDirection direction, long count)
162 nesting_level++;
163 PG_TRY();
165 if (prev_ExecutorRun)
166 prev_ExecutorRun(queryDesc, direction, count);
167 else
168 standard_ExecutorRun(queryDesc, direction, count);
169 nesting_level--;
171 PG_CATCH();
173 nesting_level--;
174 PG_RE_THROW();
176 PG_END_TRY();
180 * ExecutorEnd hook: log results if needed
182 void
183 explain_ExecutorEnd(QueryDesc *queryDesc)
185 if (queryDesc->totaltime && auto_explain_enabled())
187 double msec;
190 * Make sure stats accumulation is done. (Note: it's okay if
191 * several levels of hook all do this.)
193 InstrEndLoop(queryDesc->totaltime);
195 /* Log plan if duration is exceeded. */
196 msec = queryDesc->totaltime->total * 1000.0;
197 if (msec >= auto_explain_log_min_duration)
199 StringInfoData buf;
201 initStringInfo(&buf);
202 ExplainPrintPlan(&buf, queryDesc,
203 queryDesc->doInstrument && auto_explain_log_analyze,
204 auto_explain_log_verbose);
206 /* Remove last line break */
207 if (buf.len > 0 && buf.data[buf.len - 1] == '\n')
208 buf.data[--buf.len] = '\0';
211 * Note: we rely on the existing logging of context or
212 * debug_query_string to identify just which statement is being
213 * reported. This isn't ideal but trying to do it here would
214 * often result in duplication.
216 ereport(LOG,
217 (errmsg("duration: %.3f ms plan:\n%s",
218 msec, buf.data)));
220 pfree(buf.data);
224 if (prev_ExecutorEnd)
225 prev_ExecutorEnd(queryDesc);
226 else
227 standard_ExecutorEnd(queryDesc);