Age Owner Branch data TLA Line data Source code
1 : : /*-------------------------------------------------------------------------
2 : : *
3 : : * explain.c
4 : : * Explain query execution plans
5 : : *
6 : : * Portions Copyright (c) 1996-2025, PostgreSQL Global Development Group
7 : : * Portions Copyright (c) 1994-5, Regents of the University of California
8 : : *
9 : : * IDENTIFICATION
10 : : * src/backend/commands/explain.c
11 : : *
12 : : *-------------------------------------------------------------------------
13 : : */
14 : : #include "postgres.h"
15 : :
16 : : #include "access/xact.h"
17 : : #include "catalog/pg_type.h"
18 : : #include "commands/createas.h"
19 : : #include "commands/defrem.h"
20 : : #include "commands/explain.h"
21 : : #include "commands/explain_dr.h"
22 : : #include "commands/explain_format.h"
23 : : #include "commands/explain_state.h"
24 : : #include "commands/prepare.h"
25 : : #include "foreign/fdwapi.h"
26 : : #include "jit/jit.h"
27 : : #include "libpq/pqformat.h"
28 : : #include "libpq/protocol.h"
29 : : #include "nodes/extensible.h"
30 : : #include "nodes/makefuncs.h"
31 : : #include "nodes/nodeFuncs.h"
32 : : #include "parser/analyze.h"
33 : : #include "parser/parsetree.h"
34 : : #include "rewrite/rewriteHandler.h"
35 : : #include "storage/bufmgr.h"
36 : : #include "tcop/tcopprot.h"
37 : : #include "utils/builtins.h"
38 : : #include "utils/guc_tables.h"
39 : : #include "utils/json.h"
40 : : #include "utils/lsyscache.h"
41 : : #include "utils/rel.h"
42 : : #include "utils/ruleutils.h"
43 : : #include "utils/snapmgr.h"
44 : : #include "utils/tuplesort.h"
45 : : #include "utils/typcache.h"
46 : : #include "utils/xml.h"
47 : :
48 : :
49 : : /* Hook for plugins to get control in ExplainOneQuery() */
50 : : ExplainOneQuery_hook_type ExplainOneQuery_hook = NULL;
51 : :
52 : : /* Hook for plugins to get control in explain_get_index_name() */
53 : : explain_get_index_name_hook_type explain_get_index_name_hook = NULL;
54 : :
55 : : /* per-plan and per-node hooks for plugins to print additional info */
56 : : explain_per_plan_hook_type explain_per_plan_hook = NULL;
57 : : explain_per_node_hook_type explain_per_node_hook = NULL;
58 : :
59 : : /*
60 : : * Various places within need to convert bytes to kilobytes. Round these up
61 : : * to the next whole kilobyte.
62 : : */
63 : : #define BYTES_TO_KILOBYTES(b) (((b) + 1023) / 1024)
64 : :
65 : : static void ExplainOneQuery(Query *query, int cursorOptions,
66 : : IntoClause *into, ExplainState *es,
67 : : ParseState *pstate, ParamListInfo params);
68 : : static void ExplainPrintJIT(ExplainState *es, int jit_flags,
69 : : JitInstrumentation *ji);
70 : : static void ExplainPrintSerialize(ExplainState *es,
71 : : SerializeMetrics *metrics);
72 : : static void report_triggers(ResultRelInfo *rInfo, bool show_relname,
73 : : ExplainState *es);
74 : : static double elapsed_time(instr_time *starttime);
75 : : static bool ExplainPreScanNode(PlanState *planstate, Bitmapset **rels_used);
76 : : static void ExplainNode(PlanState *planstate, List *ancestors,
77 : : const char *relationship, const char *plan_name,
78 : : ExplainState *es);
79 : : static void show_plan_tlist(PlanState *planstate, List *ancestors,
80 : : ExplainState *es);
81 : : static void show_expression(Node *node, const char *qlabel,
82 : : PlanState *planstate, List *ancestors,
83 : : bool useprefix, ExplainState *es);
84 : : static void show_qual(List *qual, const char *qlabel,
85 : : PlanState *planstate, List *ancestors,
86 : : bool useprefix, ExplainState *es);
87 : : static void show_scan_qual(List *qual, const char *qlabel,
88 : : PlanState *planstate, List *ancestors,
89 : : ExplainState *es);
90 : : static void show_upper_qual(List *qual, const char *qlabel,
91 : : PlanState *planstate, List *ancestors,
92 : : ExplainState *es);
93 : : static void show_sort_keys(SortState *sortstate, List *ancestors,
94 : : ExplainState *es);
95 : : static void show_incremental_sort_keys(IncrementalSortState *incrsortstate,
96 : : List *ancestors, ExplainState *es);
97 : : static void show_merge_append_keys(MergeAppendState *mstate, List *ancestors,
98 : : ExplainState *es);
99 : : static void show_agg_keys(AggState *astate, List *ancestors,
100 : : ExplainState *es);
101 : : static void show_grouping_sets(PlanState *planstate, Agg *agg,
102 : : List *ancestors, ExplainState *es);
103 : : static void show_grouping_set_keys(PlanState *planstate,
104 : : Agg *aggnode, Sort *sortnode,
105 : : List *context, bool useprefix,
106 : : List *ancestors, ExplainState *es);
107 : : static void show_group_keys(GroupState *gstate, List *ancestors,
108 : : ExplainState *es);
109 : : static void show_sort_group_keys(PlanState *planstate, const char *qlabel,
110 : : int nkeys, int nPresortedKeys, AttrNumber *keycols,
111 : : Oid *sortOperators, Oid *collations, bool *nullsFirst,
112 : : List *ancestors, ExplainState *es);
113 : : static void show_sortorder_options(StringInfo buf, Node *sortexpr,
114 : : Oid sortOperator, Oid collation, bool nullsFirst);
115 : : static void show_window_def(WindowAggState *planstate,
116 : : List *ancestors, ExplainState *es);
117 : : static void show_window_keys(StringInfo buf, PlanState *planstate,
118 : : int nkeys, AttrNumber *keycols,
119 : : List *ancestors, ExplainState *es);
120 : : static void show_storage_info(char *maxStorageType, int64 maxSpaceUsed,
121 : : ExplainState *es);
122 : : static void show_tablesample(TableSampleClause *tsc, PlanState *planstate,
123 : : List *ancestors, ExplainState *es);
124 : : static void show_sort_info(SortState *sortstate, ExplainState *es);
125 : : static void show_incremental_sort_info(IncrementalSortState *incrsortstate,
126 : : ExplainState *es);
127 : : static void show_hash_info(HashState *hashstate, ExplainState *es);
128 : : static void show_material_info(MaterialState *mstate, ExplainState *es);
129 : : static void show_windowagg_info(WindowAggState *winstate, ExplainState *es);
130 : : static void show_ctescan_info(CteScanState *ctescanstate, ExplainState *es);
131 : : static void show_table_func_scan_info(TableFuncScanState *tscanstate,
132 : : ExplainState *es);
133 : : static void show_recursive_union_info(RecursiveUnionState *rstate,
134 : : ExplainState *es);
135 : : static void show_memoize_info(MemoizeState *mstate, List *ancestors,
136 : : ExplainState *es);
137 : : static void show_hashagg_info(AggState *aggstate, ExplainState *es);
138 : : static void show_indexsearches_info(PlanState *planstate, ExplainState *es);
139 : : static void show_tidbitmap_info(BitmapHeapScanState *planstate,
140 : : ExplainState *es);
141 : : static void show_instrumentation_count(const char *qlabel, int which,
142 : : PlanState *planstate, ExplainState *es);
143 : : static void show_foreignscan_info(ForeignScanState *fsstate, ExplainState *es);
144 : : static const char *explain_get_index_name(Oid indexId);
145 : : static bool peek_buffer_usage(ExplainState *es, const BufferUsage *usage);
146 : : static void show_buffer_usage(ExplainState *es, const BufferUsage *usage);
147 : : static void show_wal_usage(ExplainState *es, const WalUsage *usage);
148 : : static void show_memory_counters(ExplainState *es,
149 : : const MemoryContextCounters *mem_counters);
150 : : static void ExplainIndexScanDetails(Oid indexid, ScanDirection indexorderdir,
151 : : ExplainState *es);
152 : : static void ExplainScanTarget(Scan *plan, ExplainState *es);
153 : : static void ExplainModifyTarget(ModifyTable *plan, ExplainState *es);
154 : : static void ExplainTargetRel(Plan *plan, Index rti, ExplainState *es);
155 : : static void show_modifytable_info(ModifyTableState *mtstate, List *ancestors,
156 : : ExplainState *es);
157 : : static void ExplainMemberNodes(PlanState **planstates, int nplans,
158 : : List *ancestors, ExplainState *es);
159 : : static void ExplainMissingMembers(int nplans, int nchildren, ExplainState *es);
160 : : static void ExplainSubPlans(List *plans, List *ancestors,
161 : : const char *relationship, ExplainState *es);
162 : : static void ExplainCustomChildren(CustomScanState *css,
163 : : List *ancestors, ExplainState *es);
164 : : static ExplainWorkersState *ExplainCreateWorkersState(int num_workers);
165 : : static void ExplainOpenWorker(int n, ExplainState *es);
166 : : static void ExplainCloseWorker(int n, ExplainState *es);
167 : : static void ExplainFlushWorkersState(ExplainState *es);
168 : :
169 : :
170 : :
171 : : /*
172 : : * ExplainQuery -
173 : : * execute an EXPLAIN command
174 : : */
175 : : void
2072 peter@eisentraut.org 176 :CBC 12031 : ExplainQuery(ParseState *pstate, ExplainStmt *stmt,
177 : : ParamListInfo params, DestReceiver *dest)
178 : : {
3887 tgl@sss.pgh.pa.us 179 : 12031 : ExplainState *es = NewExplainState();
180 : : TupOutputState *tstate;
1613 bruce@momjian.us 181 : 12031 : JumbleState *jstate = NULL;
182 : : Query *query;
183 : : List *rewritten;
184 : :
185 : : /* Configure the ExplainState based on the provided options */
172 rhaas@postgresql.org 186 : 12031 : ParseExplainOptionList(es, stmt->options, pstate);
187 : :
188 : : /* Extract the query and, if enabled, jumble it */
1613 bruce@momjian.us 189 : 12024 : query = castNode(Query, stmt->query);
1575 alvherre@alvh.no-ip. 190 [ + + ]: 12024 : if (IsQueryIdEnabled())
801 michael@paquier.xyz 191 : 3491 : jstate = JumbleQuery(query);
192 : :
1613 bruce@momjian.us 193 [ + + ]: 12024 : if (post_parse_analyze_hook)
194 : 3471 : (*post_parse_analyze_hook) (pstate, query, jstate);
195 : :
196 : : /*
197 : : * Parse analysis was done already, but we still have to run the rule
198 : : * rewriter. We do not do AcquireRewriteLocks: we assume the query either
199 : : * came straight from the parser, or suitable locks were acquired by
200 : : * plancache.c.
201 : : */
1541 tgl@sss.pgh.pa.us 202 : 12024 : rewritten = QueryRewrite(castNode(Query, stmt->query));
203 : :
204 : : /* emit opening boilerplate */
3887 205 : 12024 : ExplainBeginOutput(es);
206 : :
6752 207 [ - + ]: 12024 : if (rewritten == NIL)
208 : : {
209 : : /*
210 : : * In the case of an INSTEAD NOTHING, tell at least that. But in
211 : : * non-text format, the output is delimited, so this isn't necessary.
212 : : */
3887 tgl@sss.pgh.pa.us 213 [ # # ]:UBC 0 : if (es->format == EXPLAIN_FORMAT_TEXT)
214 : 0 : appendStringInfoString(es->str, "Query rewrites to nothing\n");
215 : : }
216 : : else
217 : : {
218 : : ListCell *l;
219 : :
220 : : /* Explain every plan */
6752 tgl@sss.pgh.pa.us 221 [ + - + + :CBC 23995 : foreach(l, rewritten)
+ + ]
222 : : {
3071 223 : 12030 : ExplainOneQuery(lfirst_node(Query, l),
224 : : CURSOR_OPT_PARALLEL_OK, NULL, es,
225 : : pstate, params);
226 : :
227 : : /* Separate plans with an appropriate separator */
2245 228 [ + + ]: 11971 : if (lnext(rewritten, l) != NULL)
3887 229 : 6 : ExplainSeparatePlans(es);
230 : : }
231 : : }
232 : :
233 : : /* emit closing boilerplate */
234 : 11965 : ExplainEndOutput(es);
235 [ - + ]: 11965 : Assert(es->indent == 0);
236 : :
237 : : /* output tuples */
2487 andres@anarazel.de 238 : 11965 : tstate = begin_tup_output_tupdesc(dest, ExplainResultDesc(stmt),
239 : : &TTSOpsVirtual);
3887 tgl@sss.pgh.pa.us 240 [ + + ]: 11965 : if (es->format == EXPLAIN_FORMAT_TEXT)
241 : 11815 : do_text_output_multiline(tstate, es->str->data);
242 : : else
243 : 150 : do_text_output_oneline(tstate, es->str->data);
8449 bruce@momjian.us 244 : 11965 : end_tup_output(tstate);
245 : :
3887 tgl@sss.pgh.pa.us 246 : 11965 : pfree(es->str->data);
5886 247 : 11965 : }
248 : :
249 : : /*
250 : : * ExplainResultDesc -
251 : : * construct the result tupledesc for an EXPLAIN
252 : : */
253 : : TupleDesc
8159 254 : 28040 : ExplainResultDesc(ExplainStmt *stmt)
255 : : {
256 : : TupleDesc tupdesc;
257 : : ListCell *lc;
4967 rhaas@postgresql.org 258 : 28040 : Oid result_type = TEXTOID;
259 : :
260 : : /* Check for XML format option */
5871 tgl@sss.pgh.pa.us 261 [ + + + + : 53078 : foreach(lc, stmt->options)
+ + ]
262 : : {
5671 bruce@momjian.us 263 : 25038 : DefElem *opt = (DefElem *) lfirst(lc);
264 : :
5871 tgl@sss.pgh.pa.us 265 [ + + ]: 25038 : if (strcmp(opt->defname, "format") == 0)
266 : : {
5671 bruce@momjian.us 267 : 397 : char *p = defGetString(opt);
268 : :
4967 rhaas@postgresql.org 269 [ + + ]: 397 : if (strcmp(p, "xml") == 0)
270 : 12 : result_type = XMLOID;
271 [ + + ]: 385 : else if (strcmp(p, "json") == 0)
272 : 349 : result_type = JSONOID;
273 : : else
274 : 36 : result_type = TEXTOID;
275 : : /* don't "break", as ExplainQuery will use the last value */
276 : : }
277 : : }
278 : :
279 : : /* Need a tuple descriptor representing a single TEXT or XML column */
2482 andres@anarazel.de 280 : 28040 : tupdesc = CreateTemplateTupleDesc(1);
8159 tgl@sss.pgh.pa.us 281 : 28040 : TupleDescInitEntry(tupdesc, (AttrNumber) 1, "QUERY PLAN",
282 : : result_type, -1, 0);
283 : 28040 : return tupdesc;
284 : : }
285 : :
286 : : /*
287 : : * ExplainOneQuery -
288 : : * print out the execution plan for one Query
289 : : *
290 : : * "into" is NULL unless we are explaining the contents of a CreateTableAsStmt.
291 : : */
292 : : static void
3157 293 : 12113 : ExplainOneQuery(Query *query, int cursorOptions,
294 : : IntoClause *into, ExplainState *es,
295 : : ParseState *pstate, ParamListInfo params)
296 : : {
297 : : /* planner will not cope with utility statements */
8988 298 [ + + ]: 12113 : if (query->commandType == CMD_UTILITY)
299 : : {
313 michael@paquier.xyz 300 : 326 : ExplainOneUtility(query->utilityStmt, into, es, pstate, params);
6752 tgl@sss.pgh.pa.us 301 : 311 : return;
302 : : }
303 : :
304 : : /* if an advisor plugin is present, let it manage things */
6679 305 [ - + ]: 11787 : if (ExplainOneQuery_hook)
3157 tgl@sss.pgh.pa.us 306 :UBC 0 : (*ExplainOneQuery_hook) (query, cursorOptions, into, es,
307 : : pstate->p_sourcetext, params, pstate->p_queryEnv);
308 : : else
544 michael@paquier.xyz 309 :CBC 11787 : standard_ExplainOneQuery(query, cursorOptions, into, es,
310 : : pstate->p_sourcetext, params, pstate->p_queryEnv);
311 : : }
312 : :
313 : : /*
314 : : * standard_ExplainOneQuery -
315 : : * print out the execution plan for one Query, without calling a hook.
316 : : */
317 : : void
318 : 11787 : standard_ExplainOneQuery(Query *query, int cursorOptions,
319 : : IntoClause *into, ExplainState *es,
320 : : const char *queryString, ParamListInfo params,
321 : : QueryEnvironment *queryEnv)
322 : : {
323 : : PlannedStmt *plan;
324 : : instr_time planstart,
325 : : planduration;
326 : : BufferUsage bufusage_start,
327 : : bufusage;
328 : : MemoryContextCounters mem_counters;
329 : 11787 : MemoryContext planner_ctx = NULL;
330 : 11787 : MemoryContext saved_ctx = NULL;
331 : :
332 [ + + ]: 11787 : if (es->memory)
333 : : {
334 : : /*
335 : : * Create a new memory context to measure planner's memory consumption
336 : : * accurately. Note that if the planner were to be modified to use a
337 : : * different memory context type, here we would be changing that to
338 : : * AllocSet, which might be undesirable. However, we don't have a way
339 : : * to create a context of the same type as another, so we pray and
340 : : * hope that this is OK.
341 : : */
342 : 12 : planner_ctx = AllocSetContextCreate(CurrentMemoryContext,
343 : : "explain analyze planner context",
344 : : ALLOCSET_DEFAULT_SIZES);
345 : 12 : saved_ctx = MemoryContextSwitchTo(planner_ctx);
346 : : }
347 : :
348 [ + + ]: 11787 : if (es->buffers)
349 : 1286 : bufusage_start = pgBufferUsage;
350 : 11787 : INSTR_TIME_SET_CURRENT(planstart);
351 : :
352 : : /* plan the query */
353 : 11787 : plan = pg_plan_query(query, queryString, cursorOptions, params);
354 : :
355 : 11764 : INSTR_TIME_SET_CURRENT(planduration);
356 : 11764 : INSTR_TIME_SUBTRACT(planduration, planstart);
357 : :
358 [ + + ]: 11764 : if (es->memory)
359 : : {
360 : 12 : MemoryContextSwitchTo(saved_ctx);
361 : 12 : MemoryContextMemConsumed(planner_ctx, &mem_counters);
362 : : }
363 : :
364 : : /* calc differences of buffer counters. */
365 [ + + ]: 11764 : if (es->buffers)
366 : : {
367 : 1286 : memset(&bufusage, 0, sizeof(BufferUsage));
368 : 1286 : BufferUsageAccumDiff(&bufusage, &pgBufferUsage, &bufusage_start);
369 : : }
370 : :
371 : : /* run it (if needed) and produce output */
107 amitlan@postgresql.o 372 : 23528 : ExplainOnePlan(plan, into, es, queryString, params, queryEnv,
544 michael@paquier.xyz 373 [ + + ]: 11764 : &planduration, (es->buffers ? &bufusage : NULL),
374 [ + + ]: 11764 : es->memory ? &mem_counters : NULL);
8252 tgl@sss.pgh.pa.us 375 : 11743 : }
376 : :
377 : : /*
378 : : * ExplainOneUtility -
379 : : * print out the execution plan for one utility statement
380 : : * (In general, utility statements don't have plans, but there are some
381 : : * we treat as special cases)
382 : : *
383 : : * "into" is NULL unless we are explaining the contents of a CreateTableAsStmt.
384 : : *
385 : : * This is exported because it's called back from prepare.c in the
386 : : * EXPLAIN EXECUTE case. In that case, we'll be dealing with a statement
387 : : * that's in the plan cache, so we have to ensure we don't modify it.
388 : : */
389 : : void
4919 390 : 326 : ExplainOneUtility(Node *utilityStmt, IntoClause *into, ExplainState *es,
391 : : ParseState *pstate, ParamListInfo params)
392 : : {
6752 393 [ - + ]: 326 : if (utilityStmt == NULL)
6752 tgl@sss.pgh.pa.us 394 :UBC 0 : return;
395 : :
4919 tgl@sss.pgh.pa.us 396 [ + + ]:CBC 326 : if (IsA(utilityStmt, CreateTableAsStmt))
397 : : {
398 : : /*
399 : : * We have to rewrite the contained SELECT and then pass it back to
400 : : * ExplainOneQuery. Copy to be safe in the EXPLAIN EXECUTE case.
401 : : */
402 : 83 : CreateTableAsStmt *ctas = (CreateTableAsStmt *) utilityStmt;
403 : : Query *ctas_query;
404 : : List *rewritten;
313 michael@paquier.xyz 405 : 83 : JumbleState *jstate = NULL;
406 : :
407 : : /*
408 : : * Check if the relation exists or not. This is done at this stage to
409 : : * avoid query planning or execution.
410 : : */
1711 411 [ + + ]: 83 : if (CreateTableAsRelExists(ctas))
412 : : {
413 [ + + ]: 15 : if (ctas->objtype == OBJECT_TABLE)
414 : 9 : ExplainDummyGroup("CREATE TABLE AS", NULL, es);
415 [ + - ]: 6 : else if (ctas->objtype == OBJECT_MATVIEW)
416 : 6 : ExplainDummyGroup("CREATE MATERIALIZED VIEW", NULL, es);
417 : : else
1578 tgl@sss.pgh.pa.us 418 [ # # ]:UBC 0 : elog(ERROR, "unexpected object type: %d",
419 : : (int) ctas->objtype);
1711 michael@paquier.xyz 420 :CBC 15 : return;
421 : : }
422 : :
313 423 : 53 : ctas_query = castNode(Query, copyObject(ctas->query));
424 [ + + ]: 53 : if (IsQueryIdEnabled())
425 : 23 : jstate = JumbleQuery(ctas_query);
426 [ + + ]: 53 : if (post_parse_analyze_hook)
427 : 19 : (*post_parse_analyze_hook) (pstate, ctas_query, jstate);
428 : 53 : rewritten = QueryRewrite(ctas_query);
4530 tgl@sss.pgh.pa.us 429 [ - + ]: 53 : Assert(list_length(rewritten) == 1);
3071 430 : 53 : ExplainOneQuery(linitial_node(Query, rewritten),
431 : : CURSOR_OPT_PARALLEL_OK, ctas->into, es,
432 : : pstate, params);
433 : : }
3157 434 [ + + ]: 243 : else if (IsA(utilityStmt, DeclareCursorStmt))
435 : : {
436 : : /*
437 : : * Likewise for DECLARE CURSOR.
438 : : *
439 : : * Notice that if you say EXPLAIN ANALYZE DECLARE CURSOR then we'll
440 : : * actually run the query. This is different from pre-8.3 behavior
441 : : * but seems more useful than not running the query. No cursor will
442 : : * be created, however.
443 : : */
444 : 30 : DeclareCursorStmt *dcs = (DeclareCursorStmt *) utilityStmt;
445 : : Query *dcs_query;
446 : : List *rewritten;
313 michael@paquier.xyz 447 : 30 : JumbleState *jstate = NULL;
448 : :
449 : 30 : dcs_query = castNode(Query, copyObject(dcs->query));
450 [ + + ]: 30 : if (IsQueryIdEnabled())
451 : 13 : jstate = JumbleQuery(dcs_query);
452 [ + + ]: 30 : if (post_parse_analyze_hook)
453 : 11 : (*post_parse_analyze_hook) (pstate, dcs_query, jstate);
454 : :
455 : 30 : rewritten = QueryRewrite(dcs_query);
3157 tgl@sss.pgh.pa.us 456 [ - + ]: 30 : Assert(list_length(rewritten) == 1);
3071 457 : 30 : ExplainOneQuery(linitial_node(Query, rewritten),
458 : : dcs->options, NULL, es,
459 : : pstate, params);
460 : : }
4919 461 [ + - ]: 213 : else if (IsA(utilityStmt, ExecuteStmt))
462 : 213 : ExplainExecuteQuery((ExecuteStmt *) utilityStmt, into, es,
463 : : pstate, params);
6752 tgl@sss.pgh.pa.us 464 [ # # ]:UBC 0 : else if (IsA(utilityStmt, NotifyStmt))
465 : : {
5871 466 [ # # ]: 0 : if (es->format == EXPLAIN_FORMAT_TEXT)
467 : 0 : appendStringInfoString(es->str, "NOTIFY\n");
468 : : else
469 : 0 : ExplainDummyGroup("Notify", NULL, es);
470 : : }
471 : : else
472 : : {
473 [ # # ]: 0 : if (es->format == EXPLAIN_FORMAT_TEXT)
474 : 0 : appendStringInfoString(es->str,
475 : : "Utility statements have no plan structure\n");
476 : : else
477 : 0 : ExplainDummyGroup("Utility Statement", NULL, es);
478 : : }
479 : : }
480 : :
481 : : /*
482 : : * ExplainOnePlan -
483 : : * given a planned query, execute it if needed, and then print
484 : : * EXPLAIN output
485 : : *
486 : : * "into" is NULL unless we are explaining the contents of a CreateTableAsStmt,
487 : : * in which case executing the query should result in creating that table.
488 : : *
489 : : * This is exported because it's called back from prepare.c in the
490 : : * EXPLAIN EXECUTE case, and because an index advisor plugin would need
491 : : * to call it.
492 : : */
493 : : void
107 amitlan@postgresql.o 494 :CBC 11977 : ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
495 : : const char *queryString, ParamListInfo params,
496 : : QueryEnvironment *queryEnv, const instr_time *planduration,
497 : : const BufferUsage *bufusage,
498 : : const MemoryContextCounters *mem_counters)
499 : : {
500 : : DestReceiver *dest;
501 : : QueryDesc *queryDesc;
502 : : instr_time starttime;
8252 tgl@sss.pgh.pa.us 503 : 11977 : double totaltime = 0;
504 : : int eflags;
5744 rhaas@postgresql.org 505 : 11977 : int instrument_option = 0;
521 tgl@sss.pgh.pa.us 506 : 11977 : SerializeMetrics serializeMetrics = {0};
507 : :
3157 508 [ - + ]: 11977 : Assert(plannedstmt->commandType != CMD_UTILITY);
509 : :
4960 rhaas@postgresql.org 510 [ + + + + ]: 11977 : if (es->analyze && es->timing)
5744 511 : 1301 : instrument_option |= INSTRUMENT_TIMER;
4960 512 [ + + ]: 10676 : else if (es->analyze)
513 : 397 : instrument_option |= INSTRUMENT_ROWS;
514 : :
5744 515 [ + + ]: 11977 : if (es->buffers)
516 : 1286 : instrument_option |= INSTRUMENT_BUFFERS;
1979 akapila@postgresql.o 517 [ - + ]: 11977 : if (es->wal)
1979 akapila@postgresql.o 518 :UBC 0 : instrument_option |= INSTRUMENT_WAL;
519 : :
520 : : /*
521 : : * We always collect timing for the entire statement, even when node-level
522 : : * timing is off, so we don't look at es->timing here. (We could skip
523 : : * this if !es->summary, but it's hardly worth the complication.)
524 : : */
5305 tgl@sss.pgh.pa.us 525 :CBC 11977 : INSTR_TIME_SET_CURRENT(starttime);
526 : :
527 : : /*
528 : : * Use a snapshot with an updated command ID to ensure this query sees
529 : : * results of any previously executed queries.
530 : : */
5304 531 : 11977 : PushCopiedSnapshot(GetActiveSnapshot());
532 : 11977 : UpdateActiveSnapshotCommandId();
533 : :
534 : : /*
535 : : * We discard the output if we have no use for it. If we're explaining
536 : : * CREATE TABLE AS, we'd better use the appropriate tuple receiver, while
537 : : * the SERIALIZE option requires its own tuple receiver. (If you specify
538 : : * SERIALIZE while explaining CREATE TABLE AS, you'll see zeroes for the
539 : : * results, which is appropriate since no data would have gone to the
540 : : * client.)
541 : : */
4530 542 [ + + ]: 11977 : if (into)
543 : 53 : dest = CreateIntoRelDestReceiver(into);
521 544 [ + + ]: 11924 : else if (es->serialize != EXPLAIN_SERIALIZE_NONE)
545 : 12 : dest = CreateExplainSerializeDestReceiver(es);
546 : : else
4530 547 : 11912 : dest = None_Receiver;
548 : :
549 : : /* Create a QueryDesc for the query */
107 amitlan@postgresql.o 550 : 11977 : queryDesc = CreateQueryDesc(plannedstmt, queryString,
551 : : GetActiveSnapshot(), InvalidSnapshot,
552 : : dest, params, queryEnv, instrument_option);
553 : :
554 : : /* Select execution options */
5886 tgl@sss.pgh.pa.us 555 [ + + ]: 11977 : if (es->analyze)
7130 556 : 1698 : eflags = 0; /* default run-to-completion flags */
557 : : else
558 : 10279 : eflags = EXEC_FLAG_EXPLAIN_ONLY;
897 559 [ + + ]: 11977 : if (es->generic)
560 : 6 : eflags |= EXEC_FLAG_EXPLAIN_GENERIC;
4919 561 [ + + ]: 11977 : if (into)
562 : 53 : eflags |= GetIntoRelEFlags(into);
563 : :
564 : : /* call ExecutorStart to prepare the plan for execution */
107 amitlan@postgresql.o 565 : 11977 : ExecutorStart(queryDesc, eflags);
566 : :
567 : : /* Execute the plan for statistics if asked for */
5886 tgl@sss.pgh.pa.us 568 [ + + ]: 11959 : if (es->analyze)
569 : : {
570 : : ScanDirection dir;
571 : :
572 : : /* EXPLAIN ANALYZE CREATE TABLE AS WITH NO DATA is weird */
4919 573 [ + + + + ]: 1698 : if (into && into->skipData)
574 : 12 : dir = NoMovementScanDirection;
575 : : else
576 : 1686 : dir = ForwardScanDirection;
577 : :
578 : : /* run the plan */
271 579 : 1698 : ExecutorRun(queryDesc, dir, 0);
580 : :
581 : : /* run cleanup too */
5305 582 : 1695 : ExecutorFinish(queryDesc);
583 : :
584 : : /* We can't run ExecutorEnd 'till we're done printing the stats... */
8311 585 : 1695 : totaltime += elapsed_time(&starttime);
586 : : }
587 : :
588 : : /* grab serialization metrics before we destroy the DestReceiver */
521 589 [ + + ]: 11956 : if (es->serialize != EXPLAIN_SERIALIZE_NONE)
590 : 15 : serializeMetrics = GetSerializationMetrics(dest);
591 : :
592 : : /* call the DestReceiver's destroy method even during explain */
593 : 11956 : dest->rDestroy(dest);
594 : :
5871 595 : 11956 : ExplainOpenGroup("Query", NULL, true, es);
596 : :
597 : : /* Create textual dump of plan tree */
5886 598 : 11956 : ExplainPrintPlan(es, queryDesc);
599 : :
600 : : /* Show buffer and/or memory usage in planning */
586 alvherre@alvh.no-ip. 601 [ + + + + ]: 11956 : if (peek_buffer_usage(es, bufusage) || mem_counters)
602 : : {
1981 fujii@postgresql.org 603 : 407 : ExplainOpenGroup("Planning", "Planning", true, es);
604 : :
586 alvherre@alvh.no-ip. 605 [ + + ]: 407 : if (es->format == EXPLAIN_FORMAT_TEXT)
606 : : {
607 : 282 : ExplainIndentText(es);
608 : 282 : appendStringInfoString(es->str, "Planning:\n");
609 : 282 : es->indent++;
610 : : }
611 : :
612 [ + + ]: 407 : if (bufusage)
613 : 395 : show_buffer_usage(es, bufusage);
614 : :
615 [ + + ]: 407 : if (mem_counters)
616 : 15 : show_memory_counters(es, mem_counters);
617 : :
618 [ + + ]: 407 : if (es->format == EXPLAIN_FORMAT_TEXT)
619 : 282 : es->indent--;
620 : :
1842 fujii@postgresql.org 621 : 407 : ExplainCloseGroup("Planning", "Planning", true, es);
622 : : }
623 : :
3979 tgl@sss.pgh.pa.us 624 [ + + + - ]: 11956 : if (es->summary && planduration)
625 : : {
4141 bruce@momjian.us 626 : 1307 : double plantime = INSTR_TIME_GET_DOUBLE(*planduration);
627 : :
2731 andres@anarazel.de 628 : 1307 : ExplainPropertyFloat("Planning Time", "ms", 1000.0 * plantime, 3, es);
629 : : }
630 : :
631 : : /* Print info about runtime of triggers */
5886 tgl@sss.pgh.pa.us 632 [ + + ]: 11956 : if (es->analyze)
4247 alvherre@alvh.no-ip. 633 : 1695 : ExplainPrintTriggers(es, queryDesc);
634 : :
635 : : /*
636 : : * Print info about JITing. Tied to es->costs because we don't want to
637 : : * display this in regression tests, as it'd cause output differences
638 : : * depending on build options. Might want to separate that out from COSTS
639 : : * at a later stage.
640 : : */
2538 andres@anarazel.de 641 [ + + ]: 11956 : if (es->costs)
2530 642 : 5237 : ExplainPrintJITSummary(es, queryDesc);
643 : :
644 : : /* Print info about serialization of output */
521 tgl@sss.pgh.pa.us 645 [ + + ]: 11956 : if (es->serialize != EXPLAIN_SERIALIZE_NONE)
646 : 15 : ExplainPrintSerialize(es, &serializeMetrics);
647 : :
648 : : /* Allow plugins to print additional information */
172 rhaas@postgresql.org 649 [ + + ]: 11956 : if (explain_per_plan_hook)
650 : 9 : (*explain_per_plan_hook) (plannedstmt, into, es, queryString,
651 : : params, queryEnv);
652 : :
653 : : /*
654 : : * Close down the query and free resources. Include time for this in the
655 : : * total execution time (although it should be pretty minimal).
656 : : */
7475 tgl@sss.pgh.pa.us 657 : 11956 : INSTR_TIME_SET_CURRENT(starttime);
658 : :
8311 659 : 11956 : ExecutorEnd(queryDesc);
660 : :
8301 661 : 11956 : FreeQueryDesc(queryDesc);
662 : :
6326 alvherre@alvh.no-ip. 663 : 11956 : PopActiveSnapshot();
664 : :
665 : : /* We need a CCI just in case query expanded to multiple plans */
5886 tgl@sss.pgh.pa.us 666 [ + + ]: 11956 : if (es->analyze)
7663 667 : 1695 : CommandCounterIncrement();
668 : :
8311 669 : 11956 : totaltime += elapsed_time(&starttime);
670 : :
671 : : /*
672 : : * We only report execution time if we actually ran the query (that is,
673 : : * the user specified ANALYZE), and if summary reporting is enabled (the
674 : : * user can set SUMMARY OFF to not have the timing information included in
675 : : * the output). By default, ANALYZE sets SUMMARY to true.
676 : : */
3104 sfrost@snowman.net 677 [ + + + + ]: 11956 : if (es->summary && es->analyze)
2731 andres@anarazel.de 678 : 1304 : ExplainPropertyFloat("Execution Time", "ms", 1000.0 * totaltime, 3,
679 : : es);
680 : :
5871 tgl@sss.pgh.pa.us 681 : 11956 : ExplainCloseGroup("Query", NULL, true, es);
6135 682 : 11956 : }
683 : :
684 : : /*
685 : : * ExplainPrintSettings -
686 : : * Print summary of modified settings affecting query planning.
687 : : */
688 : : static void
2347 tomas.vondra@postgre 689 : 11966 : ExplainPrintSettings(ExplainState *es)
690 : : {
691 : : int num;
692 : : struct config_generic **gucs;
693 : :
694 : : /* bail out if information about settings not requested */
695 [ + + ]: 11966 : if (!es->settings)
696 : 11960 : return;
697 : :
698 : : /* request an array of relevant settings */
699 : 6 : gucs = get_explain_guc_options(&num);
700 : :
701 [ + + ]: 6 : if (es->format != EXPLAIN_FORMAT_TEXT)
702 : : {
703 : 3 : ExplainOpenGroup("Settings", "Settings", true, es);
704 : :
2050 tgl@sss.pgh.pa.us 705 [ + + ]: 9 : for (int i = 0; i < num; i++)
706 : : {
707 : : char *setting;
2347 tomas.vondra@postgre 708 : 6 : struct config_generic *conf = gucs[i];
709 : :
710 : 6 : setting = GetConfigOptionByName(conf->name, NULL, true);
711 : :
712 : 6 : ExplainPropertyText(conf->name, setting, es);
713 : : }
714 : :
715 : 3 : ExplainCloseGroup("Settings", "Settings", true, es);
716 : : }
717 : : else
718 : : {
719 : : StringInfoData str;
720 : :
721 : : /* In TEXT mode, print nothing if there are no options */
2050 tgl@sss.pgh.pa.us 722 [ - + ]: 3 : if (num <= 0)
2050 tgl@sss.pgh.pa.us 723 :UBC 0 : return;
724 : :
2347 tomas.vondra@postgre 725 :CBC 3 : initStringInfo(&str);
726 : :
2050 tgl@sss.pgh.pa.us 727 [ + + ]: 9 : for (int i = 0; i < num; i++)
728 : : {
729 : : char *setting;
2347 tomas.vondra@postgre 730 : 6 : struct config_generic *conf = gucs[i];
731 : :
732 [ + + ]: 6 : if (i > 0)
733 : 3 : appendStringInfoString(&str, ", ");
734 : :
735 : 6 : setting = GetConfigOptionByName(conf->name, NULL, true);
736 : :
737 [ + - ]: 6 : if (setting)
738 : 6 : appendStringInfo(&str, "%s = '%s'", conf->name, setting);
739 : : else
2347 tomas.vondra@postgre 740 :UBC 0 : appendStringInfo(&str, "%s = NULL", conf->name);
741 : : }
742 : :
2050 tgl@sss.pgh.pa.us 743 :CBC 3 : ExplainPropertyText("Settings", str.data, es);
744 : : }
745 : : }
746 : :
747 : : /*
748 : : * ExplainPrintPlan -
749 : : * convert a QueryDesc's plan tree to text and append it to es->str
750 : : *
751 : : * The caller should have set up the options fields of *es, as well as
752 : : * initializing the output buffer es->str. Also, output formatting state
753 : : * such as the indent level is assumed valid. Plan-tree-specific fields
754 : : * in *es are initialized here.
755 : : *
756 : : * NB: will not work on utility statements
757 : : */
758 : : void
5886 759 : 11966 : ExplainPrintPlan(ExplainState *es, QueryDesc *queryDesc)
760 : : {
4733 761 : 11966 : Bitmapset *rels_used = NULL;
762 : : PlanState *ps;
763 : : ListCell *lc;
764 : :
765 : : /* Set up ExplainState fields associated with this plan tree */
6135 766 [ - + ]: 11966 : Assert(queryDesc->plannedstmt != NULL);
5886 767 : 11966 : es->pstmt = queryDesc->plannedstmt;
768 : 11966 : es->rtable = queryDesc->plannedstmt->rtable;
4733 769 : 11966 : ExplainPreScanNode(queryDesc->planstate, &rels_used);
770 : 11966 : es->rtable_names = select_rtable_names_for_explain(es->rtable, rels_used);
2096 771 : 11966 : es->deparse_cxt = deparse_context_for_plan_tree(queryDesc->plannedstmt,
772 : : es->rtable_names);
3344 773 : 11966 : es->printed_subplans = NULL;
361 rguo@postgresql.org 774 : 11966 : es->rtable_size = list_length(es->rtable);
775 [ + - + + : 42834 : foreach(lc, es->rtable)
+ + ]
776 : : {
777 : 31700 : RangeTblEntry *rte = lfirst_node(RangeTblEntry, lc);
778 : :
779 [ + + ]: 31700 : if (rte->rtekind == RTE_GROUP)
780 : : {
781 : 832 : es->rtable_size--;
782 : 832 : break;
783 : : }
784 : : }
785 : :
786 : : /*
787 : : * Sometimes we mark a Gather node as "invisible", which means that it's
788 : : * not to be displayed in EXPLAIN output. The purpose of this is to allow
789 : : * running regression tests with debug_parallel_query=regress to get the
790 : : * same results as running the same tests with debug_parallel_query=off.
791 : : * Such marking is currently only supported on a Gather at the top of the
792 : : * plan. We skip that node, and we must also hide per-worker detail data
793 : : * further down in the plan tree.
794 : : */
3499 rhaas@postgresql.org 795 : 11966 : ps = queryDesc->planstate;
1939 tgl@sss.pgh.pa.us 796 [ + + - + ]: 11966 : if (IsA(ps, GatherState) && ((Gather *) ps->plan)->invisible)
797 : : {
3499 rhaas@postgresql.org 798 :UBC 0 : ps = outerPlanState(ps);
2091 tgl@sss.pgh.pa.us 799 : 0 : es->hide_workers = true;
800 : : }
3499 rhaas@postgresql.org 801 :CBC 11966 : ExplainNode(ps, NIL, NULL, NULL, es);
802 : :
803 : : /*
804 : : * If requested, include information about GUC parameters with values that
805 : : * don't match the built-in defaults.
806 : : */
2347 tomas.vondra@postgre 807 : 11966 : ExplainPrintSettings(es);
808 : :
809 : : /*
810 : : * COMPUTE_QUERY_ID_REGRESS means COMPUTE_QUERY_ID_AUTO, but we don't show
811 : : * the queryid in any of the EXPLAIN plans to keep stable the results
812 : : * generated by regression test suites.
813 : : */
99 drowley@postgresql.o 814 [ + + + + ]: 11966 : if (es->verbose && queryDesc->plannedstmt->queryId != INT64CONST(0) &&
954 michael@paquier.xyz 815 [ + + ]: 316 : compute_query_id != COMPUTE_QUERY_ID_REGRESS)
816 : : {
99 drowley@postgresql.o 817 : 10 : ExplainPropertyInteger("Query Identifier", NULL,
954 michael@paquier.xyz 818 : 10 : queryDesc->plannedstmt->queryId, es);
819 : : }
10651 scrappy@hub.org 820 : 11966 : }
821 : :
822 : : /*
823 : : * ExplainPrintTriggers -
824 : : * convert a QueryDesc's trigger statistics to text and append it to
825 : : * es->str
826 : : *
827 : : * The caller should have set up the options fields of *es, as well as
828 : : * initializing the output buffer es->str. Other fields in *es are
829 : : * initialized here.
830 : : */
831 : : void
4247 alvherre@alvh.no-ip. 832 : 1695 : ExplainPrintTriggers(ExplainState *es, QueryDesc *queryDesc)
833 : : {
834 : : ResultRelInfo *rInfo;
835 : : bool show_relname;
836 : : List *resultrels;
837 : : List *routerels;
838 : : List *targrels;
839 : : ListCell *l;
840 : :
1789 heikki.linnakangas@i 841 : 1695 : resultrels = queryDesc->estate->es_opened_result_relations;
2767 rhaas@postgresql.org 842 : 1695 : routerels = queryDesc->estate->es_tuple_routing_result_relations;
843 : 1695 : targrels = queryDesc->estate->es_trig_target_relations;
844 : :
4247 alvherre@alvh.no-ip. 845 : 1695 : ExplainOpenGroup("Triggers", "Triggers", false, es);
846 : :
1789 heikki.linnakangas@i 847 [ + - ]: 3384 : show_relname = (list_length(resultrels) > 1 ||
2767 rhaas@postgresql.org 848 [ + + - + ]: 3384 : routerels != NIL || targrels != NIL);
1789 heikki.linnakangas@i 849 [ + + + + : 1749 : foreach(l, resultrels)
+ + ]
850 : : {
851 : 54 : rInfo = (ResultRelInfo *) lfirst(l);
2941 rhaas@postgresql.org 852 : 54 : report_triggers(rInfo, show_relname, es);
853 : : }
854 : :
2767 855 [ - + - - : 1695 : foreach(l, routerels)
- + ]
856 : : {
2941 rhaas@postgresql.org 857 :UBC 0 : rInfo = (ResultRelInfo *) lfirst(l);
858 : 0 : report_triggers(rInfo, show_relname, es);
859 : : }
860 : :
4247 alvherre@alvh.no-ip. 861 [ - + - - :CBC 1695 : foreach(l, targrels)
- + ]
862 : : {
4247 alvherre@alvh.no-ip. 863 :UBC 0 : rInfo = (ResultRelInfo *) lfirst(l);
864 : 0 : report_triggers(rInfo, show_relname, es);
865 : : }
866 : :
4247 alvherre@alvh.no-ip. 867 :CBC 1695 : ExplainCloseGroup("Triggers", "Triggers", false, es);
868 : 1695 : }
869 : :
870 : : /*
871 : : * ExplainPrintJITSummary -
872 : : * Print summarized JIT instrumentation from leader and workers
873 : : */
874 : : void
2530 andres@anarazel.de 875 : 5247 : ExplainPrintJITSummary(ExplainState *es, QueryDesc *queryDesc)
876 : : {
877 : 5247 : JitInstrumentation ji = {0};
878 : :
879 [ + + ]: 5247 : if (!(queryDesc->estate->es_jit_flags & PGJIT_PERFORM))
880 : 5235 : return;
881 : :
882 : : /*
883 : : * Work with a copy instead of modifying the leader state, since this
884 : : * function may be called twice
885 : : */
886 [ - + ]: 12 : if (queryDesc->estate->es_jit)
2530 andres@anarazel.de 887 :UBC 0 : InstrJitAgg(&ji, &queryDesc->estate->es_jit->instr);
888 : :
889 : : /* If this process has done JIT in parallel workers, merge stats */
2530 andres@anarazel.de 890 [ + - ]:CBC 12 : if (queryDesc->estate->es_jit_worker_instr)
891 : 12 : InstrJitAgg(&ji, queryDesc->estate->es_jit_worker_instr);
892 : :
2051 tgl@sss.pgh.pa.us 893 : 12 : ExplainPrintJIT(es, queryDesc->estate->es_jit_flags, &ji);
894 : : }
895 : :
896 : : /*
897 : : * ExplainPrintJIT -
898 : : * Append information about JITing to es->str.
899 : : */
900 : : static void
901 : 12 : ExplainPrintJIT(ExplainState *es, int jit_flags, JitInstrumentation *ji)
902 : : {
903 : : instr_time total_time;
904 : :
905 : : /* don't print information if no JITing happened */
2538 andres@anarazel.de 906 [ + - + - ]: 12 : if (!ji || ji->created_functions == 0)
907 : 12 : return;
908 : :
909 : : /* calculate total time */
2539 andres@anarazel.de 910 :UBC 0 : INSTR_TIME_SET_ZERO(total_time);
911 : : /* don't add deform_counter, it's included in generation_counter */
2538 912 : 0 : INSTR_TIME_ADD(total_time, ji->generation_counter);
913 : 0 : INSTR_TIME_ADD(total_time, ji->inlining_counter);
914 : 0 : INSTR_TIME_ADD(total_time, ji->optimization_counter);
915 : 0 : INSTR_TIME_ADD(total_time, ji->emission_counter);
916 : :
2719 917 : 0 : ExplainOpenGroup("JIT", "JIT", true, es);
918 : :
919 : : /* for higher density, open code the text output format */
920 [ # # ]: 0 : if (es->format == EXPLAIN_FORMAT_TEXT)
921 : : {
2051 tgl@sss.pgh.pa.us 922 : 0 : ExplainIndentText(es);
923 : 0 : appendStringInfoString(es->str, "JIT:\n");
924 : 0 : es->indent++;
925 : :
2538 andres@anarazel.de 926 : 0 : ExplainPropertyInteger("Functions", NULL, ji->created_functions, es);
927 : :
2051 tgl@sss.pgh.pa.us 928 : 0 : ExplainIndentText(es);
2539 andres@anarazel.de 929 : 0 : appendStringInfo(es->str, "Options: %s %s, %s %s, %s %s, %s %s\n",
2538 930 [ # # ]: 0 : "Inlining", jit_flags & PGJIT_INLINE ? "true" : "false",
931 [ # # ]: 0 : "Optimization", jit_flags & PGJIT_OPT3 ? "true" : "false",
932 [ # # ]: 0 : "Expressions", jit_flags & PGJIT_EXPR ? "true" : "false",
933 [ # # ]: 0 : "Deforming", jit_flags & PGJIT_DEFORM ? "true" : "false");
934 : :
2539 935 [ # # # # ]: 0 : if (es->analyze && es->timing)
936 : : {
2051 tgl@sss.pgh.pa.us 937 : 0 : ExplainIndentText(es);
2539 andres@anarazel.de 938 : 0 : appendStringInfo(es->str,
939 : : "Timing: %s %.3f ms (%s %.3f ms), %s %.3f ms, %s %.3f ms, %s %.3f ms, %s %.3f ms\n",
2538 940 : 0 : "Generation", 1000.0 * INSTR_TIME_GET_DOUBLE(ji->generation_counter),
729 dgustafsson@postgres 941 : 0 : "Deform", 1000.0 * INSTR_TIME_GET_DOUBLE(ji->deform_counter),
2538 andres@anarazel.de 942 : 0 : "Inlining", 1000.0 * INSTR_TIME_GET_DOUBLE(ji->inlining_counter),
943 : 0 : "Optimization", 1000.0 * INSTR_TIME_GET_DOUBLE(ji->optimization_counter),
944 : 0 : "Emission", 1000.0 * INSTR_TIME_GET_DOUBLE(ji->emission_counter),
2539 945 : 0 : "Total", 1000.0 * INSTR_TIME_GET_DOUBLE(total_time));
946 : : }
947 : :
2051 tgl@sss.pgh.pa.us 948 : 0 : es->indent--;
949 : : }
950 : : else
951 : : {
2538 andres@anarazel.de 952 : 0 : ExplainPropertyInteger("Functions", NULL, ji->created_functions, es);
953 : :
2539 954 : 0 : ExplainOpenGroup("Options", "Options", true, es);
2538 955 : 0 : ExplainPropertyBool("Inlining", jit_flags & PGJIT_INLINE, es);
956 : 0 : ExplainPropertyBool("Optimization", jit_flags & PGJIT_OPT3, es);
957 : 0 : ExplainPropertyBool("Expressions", jit_flags & PGJIT_EXPR, es);
958 : 0 : ExplainPropertyBool("Deforming", jit_flags & PGJIT_DEFORM, es);
2539 959 : 0 : ExplainCloseGroup("Options", "Options", true, es);
960 : :
961 [ # # # # ]: 0 : if (es->analyze && es->timing)
962 : : {
963 : 0 : ExplainOpenGroup("Timing", "Timing", true, es);
964 : :
729 dgustafsson@postgres 965 : 0 : ExplainOpenGroup("Generation", "Generation", true, es);
966 : 0 : ExplainPropertyFloat("Deform", "ms",
967 : 0 : 1000.0 * INSTR_TIME_GET_DOUBLE(ji->deform_counter),
968 : : 3, es);
969 : 0 : ExplainPropertyFloat("Total", "ms",
2538 andres@anarazel.de 970 : 0 : 1000.0 * INSTR_TIME_GET_DOUBLE(ji->generation_counter),
971 : : 3, es);
729 dgustafsson@postgres 972 : 0 : ExplainCloseGroup("Generation", "Generation", true, es);
973 : :
2539 andres@anarazel.de 974 : 0 : ExplainPropertyFloat("Inlining", "ms",
2538 975 : 0 : 1000.0 * INSTR_TIME_GET_DOUBLE(ji->inlining_counter),
976 : : 3, es);
2539 977 : 0 : ExplainPropertyFloat("Optimization", "ms",
2538 978 : 0 : 1000.0 * INSTR_TIME_GET_DOUBLE(ji->optimization_counter),
979 : : 3, es);
2539 980 : 0 : ExplainPropertyFloat("Emission", "ms",
2538 981 : 0 : 1000.0 * INSTR_TIME_GET_DOUBLE(ji->emission_counter),
982 : : 3, es);
2539 983 : 0 : ExplainPropertyFloat("Total", "ms",
984 : 0 : 1000.0 * INSTR_TIME_GET_DOUBLE(total_time),
985 : : 3, es);
986 : :
987 : 0 : ExplainCloseGroup("Timing", "Timing", true, es);
988 : : }
989 : : }
990 : :
991 : 0 : ExplainCloseGroup("JIT", "JIT", true, es);
992 : : }
993 : :
994 : : /*
995 : : * ExplainPrintSerialize -
996 : : * Append information about query output volume to es->str.
997 : : */
998 : : static void
521 tgl@sss.pgh.pa.us 999 :CBC 15 : ExplainPrintSerialize(ExplainState *es, SerializeMetrics *metrics)
1000 : : {
1001 : : const char *format;
1002 : :
1003 : : /* We shouldn't get called for EXPLAIN_SERIALIZE_NONE */
1004 [ + + ]: 15 : if (es->serialize == EXPLAIN_SERIALIZE_TEXT)
1005 : 12 : format = "text";
1006 : : else
1007 : : {
1008 [ - + ]: 3 : Assert(es->serialize == EXPLAIN_SERIALIZE_BINARY);
1009 : 3 : format = "binary";
1010 : : }
1011 : :
1012 : 15 : ExplainOpenGroup("Serialization", "Serialization", true, es);
1013 : :
1014 [ + + ]: 15 : if (es->format == EXPLAIN_FORMAT_TEXT)
1015 : : {
1016 : 12 : ExplainIndentText(es);
1017 [ + + ]: 12 : if (es->timing)
515 peter@eisentraut.org 1018 : 9 : appendStringInfo(es->str, "Serialization: time=%.3f ms output=" UINT64_FORMAT "kB format=%s\n",
521 tgl@sss.pgh.pa.us 1019 : 9 : 1000.0 * INSTR_TIME_GET_DOUBLE(metrics->timeSpent),
478 drowley@postgresql.o 1020 : 9 : BYTES_TO_KILOBYTES(metrics->bytesSent),
1021 : : format);
1022 : : else
515 peter@eisentraut.org 1023 : 3 : appendStringInfo(es->str, "Serialization: output=" UINT64_FORMAT "kB format=%s\n",
478 drowley@postgresql.o 1024 : 3 : BYTES_TO_KILOBYTES(metrics->bytesSent),
1025 : : format);
1026 : :
521 tgl@sss.pgh.pa.us 1027 [ + + - + ]: 12 : if (es->buffers && peek_buffer_usage(es, &metrics->bufferUsage))
1028 : : {
521 tgl@sss.pgh.pa.us 1029 :UBC 0 : es->indent++;
1030 : 0 : show_buffer_usage(es, &metrics->bufferUsage);
1031 : 0 : es->indent--;
1032 : : }
1033 : : }
1034 : : else
1035 : : {
521 tgl@sss.pgh.pa.us 1036 [ + - ]:CBC 3 : if (es->timing)
1037 : 3 : ExplainPropertyFloat("Time", "ms",
1038 : 3 : 1000.0 * INSTR_TIME_GET_DOUBLE(metrics->timeSpent),
1039 : : 3, es);
1040 : 3 : ExplainPropertyUInteger("Output Volume", "kB",
478 drowley@postgresql.o 1041 : 3 : BYTES_TO_KILOBYTES(metrics->bytesSent), es);
521 tgl@sss.pgh.pa.us 1042 : 3 : ExplainPropertyText("Format", format, es);
1043 [ + - ]: 3 : if (es->buffers)
1044 : 3 : show_buffer_usage(es, &metrics->bufferUsage);
1045 : : }
1046 : :
1047 : 15 : ExplainCloseGroup("Serialization", "Serialization", true, es);
1048 : 15 : }
1049 : :
1050 : : /*
1051 : : * ExplainQueryText -
1052 : : * add a "Query Text" node that contains the actual text of the query
1053 : : *
1054 : : * The caller should have set up the options fields of *es, as well as
1055 : : * initializing the output buffer es->str.
1056 : : *
1057 : : */
1058 : : void
5681 andrew@dunslane.net 1059 : 10 : ExplainQueryText(ExplainState *es, QueryDesc *queryDesc)
1060 : : {
1061 [ + - ]: 10 : if (queryDesc->sourceText)
1062 : 10 : ExplainPropertyText("Query Text", queryDesc->sourceText, es);
1063 : 10 : }
1064 : :
1065 : : /*
1066 : : * ExplainQueryParameters -
1067 : : * add a "Query Parameters" node that describes the parameters of the query
1068 : : *
1069 : : * The caller should have set up the options fields of *es, as well as
1070 : : * initializing the output buffer es->str.
1071 : : *
1072 : : */
1073 : : void
1158 michael@paquier.xyz 1074 : 10 : ExplainQueryParameters(ExplainState *es, ParamListInfo params, int maxlen)
1075 : : {
1076 : : char *str;
1077 : :
1078 : : /* This check is consistent with errdetail_params() */
1079 [ + + + - : 10 : if (params == NULL || params->numParams <= 0 || maxlen == 0)
+ + ]
1080 : 7 : return;
1081 : :
1082 : 3 : str = BuildParamLogString(params, NULL, maxlen);
1083 [ + - + - ]: 3 : if (str && str[0] != '\0')
1084 : 3 : ExplainPropertyText("Query Parameters", str, es);
1085 : : }
1086 : :
1087 : : /*
1088 : : * report_triggers -
1089 : : * report execution stats for a single relation's triggers
1090 : : */
1091 : : static void
5871 tgl@sss.pgh.pa.us 1092 : 54 : report_triggers(ResultRelInfo *rInfo, bool show_relname, ExplainState *es)
1093 : : {
1094 : : int nt;
1095 : :
6597 1096 [ - + - - ]: 54 : if (!rInfo->ri_TrigDesc || !rInfo->ri_TrigInstrument)
1097 : 54 : return;
6597 tgl@sss.pgh.pa.us 1098 [ # # ]:UBC 0 : for (nt = 0; nt < rInfo->ri_TrigDesc->numtriggers; nt++)
1099 : : {
1100 : 0 : Trigger *trig = rInfo->ri_TrigDesc->triggers + nt;
1101 : 0 : Instrumentation *instr = rInfo->ri_TrigInstrument + nt;
1102 : : char *relname;
5871 1103 : 0 : char *conname = NULL;
1104 : :
1105 : : /* Must clean up instrumentation state */
6597 1106 : 0 : InstrEndLoop(instr);
1107 : :
1108 : : /*
1109 : : * We ignore triggers that were never invoked; they likely aren't
1110 : : * relevant to the current query type.
1111 : : */
1112 [ # # ]: 0 : if (instr->ntuples == 0)
1113 : 0 : continue;
1114 : :
5871 1115 : 0 : ExplainOpenGroup("Trigger", NULL, true, es);
1116 : :
1117 : 0 : relname = RelationGetRelationName(rInfo->ri_RelationDesc);
1118 [ # # ]: 0 : if (OidIsValid(trig->tgconstraint))
1119 : 0 : conname = get_constraint_name(trig->tgconstraint);
1120 : :
1121 : : /*
1122 : : * In text format, we avoid printing both the trigger name and the
1123 : : * constraint name unless VERBOSE is specified. In non-text formats
1124 : : * we just print everything.
1125 : : */
1126 [ # # ]: 0 : if (es->format == EXPLAIN_FORMAT_TEXT)
1127 : : {
1128 [ # # # # ]: 0 : if (es->verbose || conname == NULL)
1129 : 0 : appendStringInfo(es->str, "Trigger %s", trig->tgname);
1130 : : else
1131 : 0 : appendStringInfoString(es->str, "Trigger");
1132 [ # # ]: 0 : if (conname)
1133 : 0 : appendStringInfo(es->str, " for constraint %s", conname);
1134 [ # # ]: 0 : if (show_relname)
1135 : 0 : appendStringInfo(es->str, " on %s", relname);
3312 1136 [ # # ]: 0 : if (es->timing)
1137 : 0 : appendStringInfo(es->str, ": time=%.3f calls=%.0f\n",
1138 : 0 : 1000.0 * instr->total, instr->ntuples);
1139 : : else
1140 : 0 : appendStringInfo(es->str, ": calls=%.0f\n", instr->ntuples);
1141 : : }
1142 : : else
1143 : : {
5871 1144 : 0 : ExplainPropertyText("Trigger Name", trig->tgname, es);
1145 [ # # ]: 0 : if (conname)
1146 : 0 : ExplainPropertyText("Constraint Name", conname, es);
1147 : 0 : ExplainPropertyText("Relation", relname, es);
3312 1148 [ # # ]: 0 : if (es->timing)
2731 andres@anarazel.de 1149 : 0 : ExplainPropertyFloat("Time", "ms", 1000.0 * instr->total, 3,
1150 : : es);
1151 : 0 : ExplainPropertyFloat("Calls", NULL, instr->ntuples, 0, es);
1152 : : }
1153 : :
5871 tgl@sss.pgh.pa.us 1154 [ # # ]: 0 : if (conname)
1155 : 0 : pfree(conname);
1156 : :
1157 : 0 : ExplainCloseGroup("Trigger", NULL, true, es);
1158 : : }
1159 : : }
1160 : :
1161 : : /* Compute elapsed time in seconds since given timestamp */
1162 : : static double
7448 tgl@sss.pgh.pa.us 1163 :CBC 13651 : elapsed_time(instr_time *starttime)
1164 : : {
1165 : : instr_time endtime;
1166 : :
7475 1167 : 13651 : INSTR_TIME_SET_CURRENT(endtime);
6324 1168 : 13651 : INSTR_TIME_SUBTRACT(endtime, *starttime);
7475 1169 : 13651 : return INSTR_TIME_GET_DOUBLE(endtime);
1170 : : }
1171 : :
1172 : : /*
1173 : : * ExplainPreScanNode -
1174 : : * Prescan the planstate tree to identify which RTEs are referenced
1175 : : *
1176 : : * Adds the relid of each referenced RTE to *rels_used. The result controls
1177 : : * which RTEs are assigned aliases by select_rtable_names_for_explain.
1178 : : * This ensures that we don't confusingly assign un-suffixed aliases to RTEs
1179 : : * that never appear in the EXPLAIN output (such as inheritance parents).
1180 : : */
1181 : : static bool
4733 1182 : 42176 : ExplainPreScanNode(PlanState *planstate, Bitmapset **rels_used)
1183 : : {
1184 : 42176 : Plan *plan = planstate->plan;
1185 : :
1186 [ + + - + : 42176 : switch (nodeTag(plan))
+ + + ]
1187 : : {
1188 : 19585 : case T_SeqScan:
1189 : : case T_SampleScan:
1190 : : case T_IndexScan:
1191 : : case T_IndexOnlyScan:
1192 : : case T_BitmapHeapScan:
1193 : : case T_TidScan:
1194 : : case T_TidRangeScan:
1195 : : case T_SubqueryScan:
1196 : : case T_FunctionScan:
1197 : : case T_TableFuncScan:
1198 : : case T_ValuesScan:
1199 : : case T_CteScan:
1200 : : case T_NamedTuplestoreScan:
1201 : : case T_WorkTableScan:
1202 : 39170 : *rels_used = bms_add_member(*rels_used,
1203 : 19585 : ((Scan *) plan)->scanrelid);
1204 : 19585 : break;
3781 rhaas@postgresql.org 1205 : 425 : case T_ForeignScan:
1206 : 850 : *rels_used = bms_add_members(*rels_used,
950 tgl@sss.pgh.pa.us 1207 : 425 : ((ForeignScan *) plan)->fs_base_relids);
3781 rhaas@postgresql.org 1208 : 425 : break;
3781 rhaas@postgresql.org 1209 :UBC 0 : case T_CustomScan:
1210 : 0 : *rels_used = bms_add_members(*rels_used,
2999 tgl@sss.pgh.pa.us 1211 : 0 : ((CustomScan *) plan)->custom_relids);
3781 rhaas@postgresql.org 1212 : 0 : break;
4733 tgl@sss.pgh.pa.us 1213 :CBC 553 : case T_ModifyTable:
1214 : 1106 : *rels_used = bms_add_member(*rels_used,
2999 1215 : 553 : ((ModifyTable *) plan)->nominalRelation);
3774 andres@anarazel.de 1216 [ + + ]: 553 : if (((ModifyTable *) plan)->exclRelRTI)
1217 : 49 : *rels_used = bms_add_member(*rels_used,
2999 tgl@sss.pgh.pa.us 1218 : 49 : ((ModifyTable *) plan)->exclRelRTI);
1219 : : /* Ensure Vars used in RETURNING will have refnames */
107 1220 [ + + ]: 553 : if (plan->targetlist)
1221 : 124 : *rels_used = bms_add_member(*rels_used,
1222 : 124 : linitial_int(((ModifyTable *) plan)->resultRelations));
4733 1223 : 553 : break;
2096 1224 : 1746 : case T_Append:
1225 : 3492 : *rels_used = bms_add_members(*rels_used,
1226 : 1746 : ((Append *) plan)->apprelids);
1227 : 1746 : break;
1228 : 171 : case T_MergeAppend:
1229 : 342 : *rels_used = bms_add_members(*rels_used,
1230 : 171 : ((MergeAppend *) plan)->apprelids);
1231 : 171 : break;
4733 1232 : 19696 : default:
1233 : 19696 : break;
1234 : : }
1235 : :
3642 rhaas@postgresql.org 1236 : 42176 : return planstate_tree_walker(planstate, ExplainPreScanNode, rels_used);
1237 : : }
1238 : :
1239 : : /*
1240 : : * plan_is_disabled
1241 : : * Checks if the given plan node type was disabled during query planning.
1242 : : * This is evident by the disabled_nodes field being higher than the sum of
1243 : : * the disabled_nodes field from the plan's children.
1244 : : */
1245 : : static bool
330 drowley@postgresql.o 1246 : 42086 : plan_is_disabled(Plan *plan)
1247 : : {
1248 : : int child_disabled_nodes;
1249 : :
1250 : : /* The node is certainly not disabled if this is zero */
1251 [ + + ]: 42086 : if (plan->disabled_nodes == 0)
1252 : 41955 : return false;
1253 : :
1254 : 131 : child_disabled_nodes = 0;
1255 : :
1256 : : /*
1257 : : * Handle special nodes first. Children of BitmapOrs and BitmapAnds can't
1258 : : * be disabled, so no need to handle those specifically.
1259 : : */
1260 [ + + ]: 131 : if (IsA(plan, Append))
1261 : : {
1262 : : ListCell *lc;
1263 : 1 : Append *aplan = (Append *) plan;
1264 : :
1265 : : /*
1266 : : * Sum the Append childrens' disabled_nodes. This purposefully
1267 : : * includes any run-time pruned children. Ignoring those could give
1268 : : * us the incorrect number of disabled nodes.
1269 : : */
1270 [ + - + + : 3 : foreach(lc, aplan->appendplans)
+ + ]
1271 : : {
1272 : 2 : Plan *subplan = lfirst(lc);
1273 : :
1274 : 2 : child_disabled_nodes += subplan->disabled_nodes;
1275 : : }
1276 : : }
1277 [ + + ]: 130 : else if (IsA(plan, MergeAppend))
1278 : : {
1279 : : ListCell *lc;
1280 : 3 : MergeAppend *maplan = (MergeAppend *) plan;
1281 : :
1282 : : /*
1283 : : * Sum the MergeAppend childrens' disabled_nodes. This purposefully
1284 : : * includes any run-time pruned children. Ignoring those could give
1285 : : * us the incorrect number of disabled nodes.
1286 : : */
1287 [ + - + + : 15 : foreach(lc, maplan->mergeplans)
+ + ]
1288 : : {
1289 : 12 : Plan *subplan = lfirst(lc);
1290 : :
1291 : 12 : child_disabled_nodes += subplan->disabled_nodes;
1292 : : }
1293 : : }
1294 [ - + ]: 127 : else if (IsA(plan, SubqueryScan))
330 drowley@postgresql.o 1295 :UBC 0 : child_disabled_nodes += ((SubqueryScan *) plan)->subplan->disabled_nodes;
330 drowley@postgresql.o 1296 [ - + ]:CBC 127 : else if (IsA(plan, CustomScan))
1297 : : {
1298 : : ListCell *lc;
330 drowley@postgresql.o 1299 :UBC 0 : CustomScan *cplan = (CustomScan *) plan;
1300 : :
1301 [ # # # # : 0 : foreach(lc, cplan->custom_plans)
# # ]
1302 : : {
1303 : 0 : Plan *subplan = lfirst(lc);
1304 : :
1305 : 0 : child_disabled_nodes += subplan->disabled_nodes;
1306 : : }
1307 : : }
1308 : : else
1309 : : {
1310 : : /*
1311 : : * Else, sum up disabled_nodes from the plan's inner and outer side.
1312 : : */
330 drowley@postgresql.o 1313 [ + + ]:CBC 127 : if (outerPlan(plan))
1314 : 83 : child_disabled_nodes += outerPlan(plan)->disabled_nodes;
1315 [ + + ]: 127 : if (innerPlan(plan))
1316 : 24 : child_disabled_nodes += innerPlan(plan)->disabled_nodes;
1317 : : }
1318 : :
1319 : : /*
1320 : : * It's disabled if the plan's disabled_nodes is higher than the sum of
1321 : : * its child's plan disabled_nodes.
1322 : : */
1323 [ + + ]: 131 : if (plan->disabled_nodes > child_disabled_nodes)
1324 : 50 : return true;
1325 : :
1326 : 81 : return false;
1327 : : }
1328 : :
1329 : : /*
1330 : : * ExplainNode -
1331 : : * Appends a description of a plan tree to es->str
1332 : : *
1333 : : * planstate points to the executor state node for the current plan node.
1334 : : * We need to work from a PlanState node, not just a Plan node, in order to
1335 : : * get at the instrumentation data (if any) as well as the list of subplans.
1336 : : *
1337 : : * ancestors is a list of parent Plan and SubPlan nodes, most-closely-nested
1338 : : * first. These are needed in order to interpret PARAM_EXEC Params.
1339 : : *
1340 : : * relationship describes the relationship of this plan node to its parent
1341 : : * (eg, "Outer", "Inner"); it can be null at top level. plan_name is an
1342 : : * optional name to be attached to the node.
1343 : : *
1344 : : * In text format, es->indent is controlled in this function since we only
1345 : : * want it to change at plan-node boundaries (but a few subroutines will
1346 : : * transiently increment it). In non-text formats, es->indent corresponds
1347 : : * to the nesting depth of logical output groups, and therefore is controlled
1348 : : * by ExplainOpenGroup/ExplainCloseGroup.
1349 : : */
1350 : : static void
5534 tgl@sss.pgh.pa.us 1351 : 42086 : ExplainNode(PlanState *planstate, List *ancestors,
1352 : : const char *relationship, const char *plan_name,
1353 : : ExplainState *es)
1354 : : {
1355 : 42086 : Plan *plan = planstate->plan;
1356 : : const char *pname; /* node type name for text output */
1357 : : const char *sname; /* node type name for non-text output */
5871 1358 : 42086 : const char *strategy = NULL;
3356 1359 : 42086 : const char *partialmode = NULL;
5810 1360 : 42086 : const char *operation = NULL;
3956 rhaas@postgresql.org 1361 : 42086 : const char *custom_name = NULL;
2051 tgl@sss.pgh.pa.us 1362 : 42086 : ExplainWorkersState *save_workers_state = es->workers_state;
5871 1363 : 42086 : int save_indent = es->indent;
1364 : : bool haschildren;
1365 : : bool isdisabled;
1366 : :
1367 : : /*
1368 : : * Prepare per-worker output buffers, if needed. We'll append the data in
1369 : : * these to the main output string further down.
1370 : : */
2051 1371 [ + + + - : 42086 : if (planstate->worker_instrument && es->analyze && !es->hide_workers)
+ - ]
1372 : 513 : es->workers_state = ExplainCreateWorkersState(planstate->worker_instrument->num_workers);
1373 : : else
1374 : 41573 : es->workers_state = NULL;
1375 : :
1376 : : /* Identify plan node type, and print generic details */
10226 bruce@momjian.us 1377 [ + + + + : 42086 : switch (nodeTag(plan))
+ + + + +
+ + + + +
+ + + + +
+ + + + +
+ + + + +
- + + + +
+ + + + +
+ + + - ]
1378 : : {
10225 1379 : 1462 : case T_Result:
5871 tgl@sss.pgh.pa.us 1380 : 1462 : pname = sname = "Result";
10225 bruce@momjian.us 1381 : 1462 : break;
3153 andres@anarazel.de 1382 : 102 : case T_ProjectSet:
1383 : 102 : pname = sname = "ProjectSet";
1384 : 102 : break;
5810 tgl@sss.pgh.pa.us 1385 : 553 : case T_ModifyTable:
1386 : 553 : sname = "ModifyTable";
1387 [ + + + + : 553 : switch (((ModifyTable *) plan)->operation)
- ]
1388 : : {
1389 : 137 : case CMD_INSERT:
1390 : 137 : pname = operation = "Insert";
1391 : 137 : break;
1392 : 224 : case CMD_UPDATE:
1393 : 224 : pname = operation = "Update";
1394 : 224 : break;
1395 : 93 : case CMD_DELETE:
1396 : 93 : pname = operation = "Delete";
1397 : 93 : break;
1258 alvherre@alvh.no-ip. 1398 : 99 : case CMD_MERGE:
1399 : 99 : pname = operation = "Merge";
1400 : 99 : break;
5810 tgl@sss.pgh.pa.us 1401 :UBC 0 : default:
1402 : 0 : pname = "???";
1403 : 0 : break;
1404 : : }
5810 tgl@sss.pgh.pa.us 1405 :CBC 553 : break;
10225 bruce@momjian.us 1406 : 1728 : case T_Append:
5871 tgl@sss.pgh.pa.us 1407 : 1728 : pname = sname = "Append";
10225 bruce@momjian.us 1408 : 1728 : break;
5441 tgl@sss.pgh.pa.us 1409 : 171 : case T_MergeAppend:
1410 : 171 : pname = sname = "Merge Append";
1411 : 171 : break;
6181 1412 : 27 : case T_RecursiveUnion:
5871 1413 : 27 : pname = sname = "Recursive Union";
6181 1414 : 27 : break;
7445 1415 : 21 : case T_BitmapAnd:
5871 1416 : 21 : pname = sname = "BitmapAnd";
7445 1417 : 21 : break;
1418 : 73 : case T_BitmapOr:
5871 1419 : 73 : pname = sname = "BitmapOr";
7445 1420 : 73 : break;
10225 bruce@momjian.us 1421 : 1853 : case T_NestLoop:
5871 tgl@sss.pgh.pa.us 1422 : 1853 : pname = sname = "Nested Loop";
10225 bruce@momjian.us 1423 : 1853 : break;
1424 : 391 : case T_MergeJoin:
5671 1425 : 391 : pname = "Merge"; /* "Join" gets added by jointype switch */
5871 tgl@sss.pgh.pa.us 1426 : 391 : sname = "Merge Join";
10225 bruce@momjian.us 1427 : 391 : break;
1428 : 1927 : case T_HashJoin:
5671 1429 : 1927 : pname = "Hash"; /* "Join" gets added by jointype switch */
5871 tgl@sss.pgh.pa.us 1430 : 1927 : sname = "Hash Join";
10225 bruce@momjian.us 1431 : 1927 : break;
1432 : 12923 : case T_SeqScan:
5871 tgl@sss.pgh.pa.us 1433 : 12923 : pname = sname = "Seq Scan";
10225 bruce@momjian.us 1434 : 12923 : break;
3696 tgl@sss.pgh.pa.us 1435 : 60 : case T_SampleScan:
1436 : 60 : pname = sname = "Sample Scan";
1437 : 60 : break;
3629 rhaas@postgresql.org 1438 : 313 : case T_Gather:
1439 : 313 : pname = sname = "Gather";
1440 : 313 : break;
3103 1441 : 111 : case T_GatherMerge:
1442 : 111 : pname = sname = "Gather Merge";
1443 : 111 : break;
10225 bruce@momjian.us 1444 : 2030 : case T_IndexScan:
5079 tgl@sss.pgh.pa.us 1445 : 2030 : pname = sname = "Index Scan";
1446 : 2030 : break;
1447 : 1409 : case T_IndexOnlyScan:
1448 : 1409 : pname = sname = "Index Only Scan";
10225 bruce@momjian.us 1449 : 1409 : break;
7445 tgl@sss.pgh.pa.us 1450 : 2152 : case T_BitmapIndexScan:
5871 1451 : 2152 : pname = sname = "Bitmap Index Scan";
7445 1452 : 2152 : break;
1453 : 2055 : case T_BitmapHeapScan:
5871 1454 : 2055 : pname = sname = "Bitmap Heap Scan";
7445 1455 : 2055 : break;
9108 1456 : 33 : case T_TidScan:
5871 1457 : 33 : pname = sname = "Tid Scan";
9108 1458 : 33 : break;
1652 drowley@postgresql.o 1459 : 42 : case T_TidRangeScan:
1460 : 42 : pname = sname = "Tid Range Scan";
1461 : 42 : break;
9108 tgl@sss.pgh.pa.us 1462 : 218 : case T_SubqueryScan:
5871 1463 : 218 : pname = sname = "Subquery Scan";
9108 1464 : 218 : break;
8518 1465 : 288 : case T_FunctionScan:
5871 1466 : 288 : pname = sname = "Function Scan";
8518 1467 : 288 : break;
3104 alvherre@alvh.no-ip. 1468 : 39 : case T_TableFuncScan:
1469 : 39 : pname = sname = "Table Function Scan";
1470 : 39 : break;
6975 mail@joeconway.com 1471 : 279 : case T_ValuesScan:
5871 tgl@sss.pgh.pa.us 1472 : 279 : pname = sname = "Values Scan";
6975 mail@joeconway.com 1473 : 279 : break;
6181 tgl@sss.pgh.pa.us 1474 : 125 : case T_CteScan:
5871 1475 : 125 : pname = sname = "CTE Scan";
6181 1476 : 125 : break;
3081 kgrittn@postgresql.o 1477 : 12 : case T_NamedTuplestoreScan:
1478 : 12 : pname = sname = "Named Tuplestore Scan";
1479 : 12 : break;
6181 tgl@sss.pgh.pa.us 1480 : 27 : case T_WorkTableScan:
5871 1481 : 27 : pname = sname = "WorkTable Scan";
6181 1482 : 27 : break;
5312 1483 : 425 : case T_ForeignScan:
3459 rhaas@postgresql.org 1484 : 425 : sname = "Foreign Scan";
1485 [ + - + + : 425 : switch (((ForeignScan *) plan)->operation)
- ]
1486 : : {
1487 : 393 : case CMD_SELECT:
1488 : 393 : pname = "Foreign Scan";
1489 : 393 : operation = "Select";
1490 : 393 : break;
3459 rhaas@postgresql.org 1491 :UBC 0 : case CMD_INSERT:
1492 : 0 : pname = "Foreign Insert";
1493 : 0 : operation = "Insert";
1494 : 0 : break;
3459 rhaas@postgresql.org 1495 :CBC 18 : case CMD_UPDATE:
1496 : 18 : pname = "Foreign Update";
1497 : 18 : operation = "Update";
1498 : 18 : break;
1499 : 14 : case CMD_DELETE:
1500 : 14 : pname = "Foreign Delete";
1501 : 14 : operation = "Delete";
1502 : 14 : break;
3459 rhaas@postgresql.org 1503 :UBC 0 : default:
1504 : 0 : pname = "???";
1505 : 0 : break;
1506 : : }
5312 tgl@sss.pgh.pa.us 1507 :CBC 425 : break;
3956 rhaas@postgresql.org 1508 :UBC 0 : case T_CustomScan:
1509 : 0 : sname = "Custom Scan";
1510 : 0 : custom_name = ((CustomScan *) plan)->methods->CustomName;
1511 [ # # ]: 0 : if (custom_name)
1512 : 0 : pname = psprintf("Custom Scan (%s)", custom_name);
1513 : : else
1514 : 0 : pname = sname;
1515 : 0 : break;
9518 tgl@sss.pgh.pa.us 1516 :CBC 550 : case T_Material:
5871 1517 : 550 : pname = sname = "Materialize";
9518 1518 : 550 : break;
1515 drowley@postgresql.o 1519 : 186 : case T_Memoize:
1520 : 186 : pname = sname = "Memoize";
1618 1521 : 186 : break;
10225 bruce@momjian.us 1522 : 2243 : case T_Sort:
5871 tgl@sss.pgh.pa.us 1523 : 2243 : pname = sname = "Sort";
10225 bruce@momjian.us 1524 : 2243 : break;
1979 tomas.vondra@postgre 1525 : 187 : case T_IncrementalSort:
1526 : 187 : pname = sname = "Incremental Sort";
1527 : 187 : break;
10225 bruce@momjian.us 1528 : 48 : case T_Group:
5871 tgl@sss.pgh.pa.us 1529 : 48 : pname = sname = "Group";
10225 bruce@momjian.us 1530 : 48 : break;
1531 : 4851 : case T_Agg:
1532 : : {
3517 rhaas@postgresql.org 1533 : 4851 : Agg *agg = (Agg *) plan;
1534 : :
3356 tgl@sss.pgh.pa.us 1535 : 4851 : sname = "Aggregate";
3517 rhaas@postgresql.org 1536 [ + + + + : 4851 : switch (agg->aggstrategy)
- ]
1537 : : {
1538 : 3649 : case AGG_PLAIN:
1539 : 3649 : pname = "Aggregate";
1540 : 3649 : strategy = "Plain";
1541 : 3649 : break;
1542 : 249 : case AGG_SORTED:
1543 : 249 : pname = "GroupAggregate";
1544 : 249 : strategy = "Sorted";
1545 : 249 : break;
1546 : 906 : case AGG_HASHED:
1547 : 906 : pname = "HashAggregate";
1548 : 906 : strategy = "Hashed";
1549 : 906 : break;
3085 rhodiumtoad@postgres 1550 : 47 : case AGG_MIXED:
1551 : 47 : pname = "MixedAggregate";
1552 : 47 : strategy = "Mixed";
1553 : 47 : break;
3517 rhaas@postgresql.org 1554 :UBC 0 : default:
1555 : 0 : pname = "Aggregate ???";
1556 : 0 : strategy = "???";
1557 : 0 : break;
1558 : : }
1559 : :
3356 tgl@sss.pgh.pa.us 1560 [ + + ]:CBC 4851 : if (DO_AGGSPLIT_SKIPFINAL(agg->aggsplit))
1561 : : {
1562 : 324 : partialmode = "Partial";
1563 : 324 : pname = psprintf("%s %s", partialmode, pname);
1564 : : }
1565 [ + + ]: 4527 : else if (DO_AGGSPLIT_COMBINE(agg->aggsplit))
1566 : : {
1567 : 235 : partialmode = "Finalize";
1568 : 235 : pname = psprintf("%s %s", partialmode, pname);
1569 : : }
1570 : : else
1571 : 4292 : partialmode = "Simple";
1572 : : }
10225 bruce@momjian.us 1573 : 4851 : break;
6096 tgl@sss.pgh.pa.us 1574 : 229 : case T_WindowAgg:
5871 1575 : 229 : pname = sname = "WindowAgg";
6096 1576 : 229 : break;
10225 bruce@momjian.us 1577 : 218 : case T_Unique:
5871 tgl@sss.pgh.pa.us 1578 : 218 : pname = sname = "Unique";
10225 bruce@momjian.us 1579 : 218 : break;
9102 tgl@sss.pgh.pa.us 1580 : 54 : case T_SetOp:
5871 1581 : 54 : sname = "SetOp";
6239 1582 [ + + - ]: 54 : switch (((SetOp *) plan)->strategy)
1583 : : {
1584 : 33 : case SETOP_SORTED:
5871 1585 : 33 : pname = "SetOp";
1586 : 33 : strategy = "Sorted";
9102 1587 : 33 : break;
6239 1588 : 21 : case SETOP_HASHED:
5871 1589 : 21 : pname = "HashSetOp";
1590 : 21 : strategy = "Hashed";
9102 1591 : 21 : break;
9102 tgl@sss.pgh.pa.us 1592 :UBC 0 : default:
1593 : 0 : pname = "SetOp ???";
5871 1594 : 0 : strategy = "???";
9102 1595 : 0 : break;
1596 : : }
9102 tgl@sss.pgh.pa.us 1597 :CBC 54 : break;
5808 1598 : 207 : case T_LockRows:
1599 : 207 : pname = sname = "LockRows";
1600 : 207 : break;
9081 1601 : 537 : case T_Limit:
5871 1602 : 537 : pname = sname = "Limit";
9081 1603 : 537 : break;
10225 bruce@momjian.us 1604 : 1927 : case T_Hash:
5871 tgl@sss.pgh.pa.us 1605 : 1927 : pname = sname = "Hash";
10225 bruce@momjian.us 1606 : 1927 : break;
10225 bruce@momjian.us 1607 :UBC 0 : default:
5871 tgl@sss.pgh.pa.us 1608 : 0 : pname = sname = "???";
10225 bruce@momjian.us 1609 : 0 : break;
1610 : : }
1611 : :
5871 tgl@sss.pgh.pa.us 1612 [ + + ]:CBC 42086 : ExplainOpenGroup("Plan",
1613 : : relationship ? NULL : "Plan",
1614 : : true, es);
1615 : :
1616 [ + + ]: 42086 : if (es->format == EXPLAIN_FORMAT_TEXT)
1617 : : {
1618 [ + + ]: 41542 : if (plan_name)
1619 : : {
2051 1620 : 923 : ExplainIndentText(es);
5871 1621 : 923 : appendStringInfo(es->str, "%s\n", plan_name);
1622 : 923 : es->indent++;
1623 : : }
1624 [ + + ]: 41542 : if (es->indent)
1625 : : {
2051 1626 : 29729 : ExplainIndentText(es);
5871 1627 : 29729 : appendStringInfoString(es->str, "-> ");
1628 : 29729 : es->indent += 2;
1629 : : }
3587 rhaas@postgresql.org 1630 [ + + ]: 41542 : if (plan->parallel_aware)
1631 : 657 : appendStringInfoString(es->str, "Parallel ");
1620 efujita@postgresql.o 1632 [ + + ]: 41542 : if (plan->async_capable)
1633 : 51 : appendStringInfoString(es->str, "Async ");
5871 tgl@sss.pgh.pa.us 1634 : 41542 : appendStringInfoString(es->str, pname);
1635 : 41542 : es->indent++;
1636 : : }
1637 : : else
1638 : : {
1639 : 544 : ExplainPropertyText("Node Type", sname, es);
1640 [ + + ]: 544 : if (strategy)
1641 : 79 : ExplainPropertyText("Strategy", strategy, es);
3356 1642 [ + + ]: 544 : if (partialmode)
1643 : 79 : ExplainPropertyText("Partial Mode", partialmode, es);
5810 1644 [ + + ]: 544 : if (operation)
1645 : 3 : ExplainPropertyText("Operation", operation, es);
5871 1646 [ + + ]: 544 : if (relationship)
1647 : 391 : ExplainPropertyText("Parent Relationship", relationship, es);
1648 [ - + ]: 544 : if (plan_name)
5871 tgl@sss.pgh.pa.us 1649 :UBC 0 : ExplainPropertyText("Subplan Name", plan_name, es);
3956 rhaas@postgresql.org 1650 [ - + ]:CBC 544 : if (custom_name)
3956 rhaas@postgresql.org 1651 :UBC 0 : ExplainPropertyText("Custom Plan Provider", custom_name, es);
3356 tgl@sss.pgh.pa.us 1652 :CBC 544 : ExplainPropertyBool("Parallel Aware", plan->parallel_aware, es);
1620 efujita@postgresql.o 1653 : 544 : ExplainPropertyBool("Async Capable", plan->async_capable, es);
1654 : : }
1655 : :
10226 bruce@momjian.us 1656 [ + + + + : 42086 : switch (nodeTag(plan))
+ + + +
+ ]
1657 : : {
9994 scrappy@hub.org 1658 : 16089 : case T_SeqScan:
1659 : : case T_SampleScan:
1660 : : case T_BitmapHeapScan:
1661 : : case T_TidScan:
1662 : : case T_TidRangeScan:
1663 : : case T_SubqueryScan:
1664 : : case T_FunctionScan:
1665 : : case T_TableFuncScan:
1666 : : case T_ValuesScan:
1667 : : case T_CteScan:
1668 : : case T_WorkTableScan:
3781 rhaas@postgresql.org 1669 : 16089 : ExplainScanTarget((Scan *) plan, es);
1670 : 16089 : break;
5312 tgl@sss.pgh.pa.us 1671 : 425 : case T_ForeignScan:
1672 : : case T_CustomScan:
3781 rhaas@postgresql.org 1673 [ + + ]: 425 : if (((Scan *) plan)->scanrelid > 0)
1674 : 300 : ExplainScanTarget((Scan *) plan, es);
5888 tgl@sss.pgh.pa.us 1675 : 425 : break;
5079 1676 : 2030 : case T_IndexScan:
1677 : : {
1678 : 2030 : IndexScan *indexscan = (IndexScan *) plan;
1679 : :
1680 : 2030 : ExplainIndexScanDetails(indexscan->indexid,
1681 : : indexscan->indexorderdir,
1682 : : es);
1683 : 2030 : ExplainScanTarget((Scan *) indexscan, es);
1684 : : }
1685 : 2030 : break;
1686 : 1409 : case T_IndexOnlyScan:
1687 : : {
1688 : 1409 : IndexOnlyScan *indexonlyscan = (IndexOnlyScan *) plan;
1689 : :
1690 : 1409 : ExplainIndexScanDetails(indexonlyscan->indexid,
1691 : : indexonlyscan->indexorderdir,
1692 : : es);
1693 : 1409 : ExplainScanTarget((Scan *) indexonlyscan, es);
1694 : : }
1695 : 1409 : break;
5888 1696 : 2152 : case T_BitmapIndexScan:
1697 : : {
5871 1698 : 2152 : BitmapIndexScan *bitmapindexscan = (BitmapIndexScan *) plan;
1699 : : const char *indexname =
841 1700 : 2152 : explain_get_index_name(bitmapindexscan->indexid);
1701 : :
5871 1702 [ + + ]: 2152 : if (es->format == EXPLAIN_FORMAT_TEXT)
1902 1703 : 2122 : appendStringInfo(es->str, " on %s",
1704 : : quote_identifier(indexname));
1705 : : else
5871 1706 : 30 : ExplainPropertyText("Index Name", indexname, es);
1707 : : }
1708 : 2152 : break;
5303 1709 : 553 : case T_ModifyTable:
1710 : 553 : ExplainModifyTarget((ModifyTable *) plan, es);
1711 : 553 : break;
5871 1712 : 4171 : case T_NestLoop:
1713 : : case T_MergeJoin:
1714 : : case T_HashJoin:
1715 : : {
1716 : : const char *jointype;
1717 : :
1718 [ + + + + : 4171 : switch (((Join *) plan)->jointype)
+ + + +
- ]
1719 : : {
1720 : 2374 : case JOIN_INNER:
1721 : 2374 : jointype = "Inner";
1722 : 2374 : break;
1723 : 890 : case JOIN_LEFT:
1724 : 890 : jointype = "Left";
1725 : 890 : break;
1726 : 266 : case JOIN_FULL:
1727 : 266 : jointype = "Full";
1728 : 266 : break;
1729 : 315 : case JOIN_RIGHT:
1730 : 315 : jointype = "Right";
1731 : 315 : break;
1732 : 159 : case JOIN_SEMI:
1733 : 159 : jointype = "Semi";
1734 : 159 : break;
1735 : 40 : case JOIN_ANTI:
1736 : 40 : jointype = "Anti";
1737 : 40 : break;
428 rguo@postgresql.org 1738 : 67 : case JOIN_RIGHT_SEMI:
1739 : 67 : jointype = "Right Semi";
1740 : 67 : break;
885 tgl@sss.pgh.pa.us 1741 : 60 : case JOIN_RIGHT_ANTI:
1742 : 60 : jointype = "Right Anti";
1743 : 60 : break;
5871 tgl@sss.pgh.pa.us 1744 :UBC 0 : default:
1745 : 0 : jointype = "???";
1746 : 0 : break;
1747 : : }
5871 tgl@sss.pgh.pa.us 1748 [ + + ]:CBC 4171 : if (es->format == EXPLAIN_FORMAT_TEXT)
1749 : : {
1750 : : /*
1751 : : * For historical reasons, the join type is interpolated
1752 : : * into the node type name...
1753 : : */
1754 [ + + ]: 4102 : if (((Join *) plan)->jointype != JOIN_INNER)
1755 : 1782 : appendStringInfo(es->str, " %s Join", jointype);
1756 [ + + ]: 2320 : else if (!IsA(plan, NestLoop))
4328 rhaas@postgresql.org 1757 : 1120 : appendStringInfoString(es->str, " Join");
1758 : : }
1759 : : else
5871 tgl@sss.pgh.pa.us 1760 : 69 : ExplainPropertyText("Join Type", jointype, es);
1761 : : }
1762 : 4171 : break;
1763 : 54 : case T_SetOp:
1764 : : {
1765 : : const char *setopcmd;
1766 : :
1767 [ + - + + : 54 : switch (((SetOp *) plan)->cmd)
- ]
1768 : : {
1769 : 27 : case SETOPCMD_INTERSECT:
1770 : 27 : setopcmd = "Intersect";
1771 : 27 : break;
5871 tgl@sss.pgh.pa.us 1772 :UBC 0 : case SETOPCMD_INTERSECT_ALL:
1773 : 0 : setopcmd = "Intersect All";
1774 : 0 : break;
5871 tgl@sss.pgh.pa.us 1775 :CBC 24 : case SETOPCMD_EXCEPT:
1776 : 24 : setopcmd = "Except";
1777 : 24 : break;
1778 : 3 : case SETOPCMD_EXCEPT_ALL:
1779 : 3 : setopcmd = "Except All";
1780 : 3 : break;
5871 tgl@sss.pgh.pa.us 1781 :UBC 0 : default:
1782 : 0 : setopcmd = "???";
1783 : 0 : break;
1784 : : }
5871 tgl@sss.pgh.pa.us 1785 [ + - ]:CBC 54 : if (es->format == EXPLAIN_FORMAT_TEXT)
1786 : 54 : appendStringInfo(es->str, " %s", setopcmd);
1787 : : else
5871 tgl@sss.pgh.pa.us 1788 :UBC 0 : ExplainPropertyText("Command", setopcmd, es);
1789 : : }
6181 tgl@sss.pgh.pa.us 1790 :CBC 54 : break;
10225 bruce@momjian.us 1791 : 15203 : default:
1792 : 15203 : break;
1793 : : }
1794 : :
5886 tgl@sss.pgh.pa.us 1795 [ + + ]: 42086 : if (es->costs)
1796 : : {
5871 1797 [ + + ]: 12539 : if (es->format == EXPLAIN_FORMAT_TEXT)
1798 : : {
1799 : 12066 : appendStringInfo(es->str, " (cost=%.2f..%.2f rows=%.0f width=%d)",
1800 : : plan->startup_cost, plan->total_cost,
1801 : : plan->plan_rows, plan->plan_width);
1802 : : }
1803 : : else
1804 : : {
2731 andres@anarazel.de 1805 : 473 : ExplainPropertyFloat("Startup Cost", NULL, plan->startup_cost,
1806 : : 2, es);
1807 : 473 : ExplainPropertyFloat("Total Cost", NULL, plan->total_cost,
1808 : : 2, es);
1809 : 473 : ExplainPropertyFloat("Plan Rows", NULL, plan->plan_rows,
1810 : : 0, es);
1811 : 473 : ExplainPropertyInteger("Plan Width", NULL, plan->plan_width,
1812 : : es);
1813 : : }
1814 : : }
1815 : :
1816 : : /*
1817 : : * We have to forcibly clean up the instrumentation state because we
1818 : : * haven't done ExecutorEnd yet. This is pretty grotty ...
1819 : : *
1820 : : * Note: contrib/auto_explain could cause instrumentation to be set up
1821 : : * even though we didn't ask for it here. Be careful not to print any
1822 : : * instrumentation results the user didn't ask for. But we do the
1823 : : * InstrEndLoop call anyway, if possible, to reduce the number of cases
1824 : : * auto_explain has to contend with.
1825 : : */
7399 neilc@samurai.com 1826 [ + + ]: 42086 : if (planstate->instrument)
1827 : 4001 : InstrEndLoop(planstate->instrument);
1828 : :
4127 tgl@sss.pgh.pa.us 1829 [ + + ]: 42086 : if (es->analyze &&
1830 [ + - + + ]: 3995 : planstate->instrument && planstate->instrument->nloops > 0)
7399 neilc@samurai.com 1831 : 3624 : {
1832 : 3624 : double nloops = planstate->instrument->nloops;
2731 andres@anarazel.de 1833 : 3624 : double startup_ms = 1000.0 * planstate->instrument->startup / nloops;
1834 : 3624 : double total_ms = 1000.0 * planstate->instrument->total / nloops;
5871 tgl@sss.pgh.pa.us 1835 : 3624 : double rows = planstate->instrument->ntuples / nloops;
1836 : :
1837 [ + + ]: 3624 : if (es->format == EXPLAIN_FORMAT_TEXT)
1838 : : {
148 drowley@postgresql.o 1839 : 3112 : appendStringInfoString(es->str, " (actual ");
1840 : :
4127 tgl@sss.pgh.pa.us 1841 [ + + ]: 3112 : if (es->timing)
197 rhaas@postgresql.org 1842 : 1669 : appendStringInfo(es->str, "time=%.3f..%.3f ", startup_ms, total_ms);
1843 : :
191 1844 : 3112 : appendStringInfo(es->str, "rows=%.2f loops=%.0f)", rows, nloops);
1845 : : }
1846 : : else
1847 : : {
4127 tgl@sss.pgh.pa.us 1848 [ + + ]: 512 : if (es->timing)
1849 : : {
1604 1850 : 464 : ExplainPropertyFloat("Actual Startup Time", "ms", startup_ms,
1851 : : 3, es);
1852 : 464 : ExplainPropertyFloat("Actual Total Time", "ms", total_ms,
1853 : : 3, es);
1854 : : }
191 rhaas@postgresql.org 1855 : 512 : ExplainPropertyFloat("Actual Rows", NULL, rows, 2, es);
1856 : 512 : ExplainPropertyFloat("Actual Loops", NULL, nloops, 0, es);
1857 : : }
1858 : : }
5886 tgl@sss.pgh.pa.us 1859 [ + + ]: 38462 : else if (es->analyze)
1860 : : {
5871 1861 [ + - ]: 371 : if (es->format == EXPLAIN_FORMAT_TEXT)
4328 rhaas@postgresql.org 1862 : 371 : appendStringInfoString(es->str, " (never executed)");
1863 : : else
1864 : : {
4127 tgl@sss.pgh.pa.us 1865 [ # # ]:UBC 0 : if (es->timing)
1866 : : {
2731 andres@anarazel.de 1867 : 0 : ExplainPropertyFloat("Actual Startup Time", "ms", 0.0, 3, es);
1868 : 0 : ExplainPropertyFloat("Actual Total Time", "ms", 0.0, 3, es);
1869 : : }
1870 : 0 : ExplainPropertyFloat("Actual Rows", NULL, 0.0, 0, es);
1871 : 0 : ExplainPropertyFloat("Actual Loops", NULL, 0.0, 0, es);
1872 : : }
1873 : : }
1874 : :
1875 : : /* in text format, first line ends here */
5871 tgl@sss.pgh.pa.us 1876 [ + + ]:CBC 42086 : if (es->format == EXPLAIN_FORMAT_TEXT)
1877 : 41542 : appendStringInfoChar(es->str, '\n');
1878 : :
1879 : :
330 drowley@postgresql.o 1880 : 42086 : isdisabled = plan_is_disabled(plan);
1881 [ + + + + ]: 42086 : if (es->format != EXPLAIN_FORMAT_TEXT || isdisabled)
1882 : 594 : ExplainPropertyBool("Disabled", isdisabled, es);
1883 : :
1884 : : /* prepare per-worker general execution details */
2051 tgl@sss.pgh.pa.us 1885 [ + + + + ]: 42086 : if (es->workers_state && es->verbose)
1886 : : {
1887 : 6 : WorkerInstrumentation *w = planstate->worker_instrument;
1888 : :
1889 [ + + ]: 30 : for (int n = 0; n < w->num_workers; n++)
1890 : : {
1891 : 24 : Instrumentation *instrument = &w->instrument[n];
1892 : 24 : double nloops = instrument->nloops;
1893 : : double startup_ms;
1894 : : double total_ms;
1895 : : double rows;
1896 : :
1897 [ - + ]: 24 : if (nloops <= 0)
2051 tgl@sss.pgh.pa.us 1898 :UBC 0 : continue;
2051 tgl@sss.pgh.pa.us 1899 :CBC 24 : startup_ms = 1000.0 * instrument->startup / nloops;
1900 : 24 : total_ms = 1000.0 * instrument->total / nloops;
1901 : 24 : rows = instrument->ntuples / nloops;
1902 : :
1903 : 24 : ExplainOpenWorker(n, es);
1904 : :
1905 [ - + ]: 24 : if (es->format == EXPLAIN_FORMAT_TEXT)
1906 : : {
2051 tgl@sss.pgh.pa.us 1907 :UBC 0 : ExplainIndentText(es);
148 drowley@postgresql.o 1908 : 0 : appendStringInfoString(es->str, "actual ");
2051 tgl@sss.pgh.pa.us 1909 [ # # ]: 0 : if (es->timing)
190 rhaas@postgresql.org 1910 : 0 : appendStringInfo(es->str, "time=%.3f..%.3f ", startup_ms, total_ms);
1911 : :
191 1912 : 0 : appendStringInfo(es->str, "rows=%.2f loops=%.0f\n", rows, nloops);
1913 : : }
1914 : : else
1915 : : {
2051 tgl@sss.pgh.pa.us 1916 [ + - ]:CBC 24 : if (es->timing)
1917 : : {
1918 : 24 : ExplainPropertyFloat("Actual Startup Time", "ms",
1919 : : startup_ms, 3, es);
1920 : 24 : ExplainPropertyFloat("Actual Total Time", "ms",
1921 : : total_ms, 3, es);
1922 : : }
1923 : :
191 rhaas@postgresql.org 1924 : 24 : ExplainPropertyFloat("Actual Rows", NULL, rows, 2, es);
1925 : 24 : ExplainPropertyFloat("Actual Loops", NULL, nloops, 0, es);
1926 : : }
1927 : :
2051 tgl@sss.pgh.pa.us 1928 : 24 : ExplainCloseWorker(n, es);
1929 : : }
1930 : : }
1931 : :
1932 : : /* target list */
5886 1933 [ + + ]: 42086 : if (es->verbose)
5534 1934 : 4598 : show_plan_tlist(planstate, ancestors, es);
1935 : :
1936 : : /* unique join */
3074 1937 [ + + ]: 42086 : switch (nodeTag(plan))
1938 : : {
1939 : 4171 : case T_NestLoop:
1940 : : case T_MergeJoin:
1941 : : case T_HashJoin:
1942 : : /* try not to be too chatty about this in text mode */
1943 [ + + ]: 4171 : if (es->format != EXPLAIN_FORMAT_TEXT ||
1944 [ + + + + ]: 4102 : (es->verbose && ((Join *) plan)->inner_unique))
1945 : 128 : ExplainPropertyBool("Inner Unique",
1946 : 128 : ((Join *) plan)->inner_unique,
1947 : : es);
1948 : 4171 : break;
1949 : 37915 : default:
1950 : 37915 : break;
1951 : : }
1952 : :
1953 : : /* quals, sort keys, etc */
8579 1954 [ + + + + : 42086 : switch (nodeTag(plan))
+ + + + +
+ + + + -
+ + + + +
+ + + + +
+ + + + +
+ ]
1955 : : {
1956 : 2030 : case T_IndexScan:
7439 1957 : 2030 : show_scan_qual(((IndexScan *) plan)->indexqualorig,
1958 : : "Index Cond", planstate, ancestors, es);
5098 1959 [ + + ]: 2030 : if (((IndexScan *) plan)->indexqualorig)
1960 : 1516 : show_instrumentation_count("Rows Removed by Index Recheck", 2,
1961 : : planstate, es);
5392 1962 : 2030 : show_scan_qual(((IndexScan *) plan)->indexorderbyorig,
1963 : : "Order By", planstate, ancestors, es);
5534 1964 : 2030 : show_scan_qual(plan->qual, "Filter", planstate, ancestors, es);
5098 1965 [ + + ]: 2030 : if (plan->qual)
1966 : 320 : show_instrumentation_count("Rows Removed by Filter", 1,
1967 : : planstate, es);
179 pg@bowt.ie 1968 : 2030 : show_indexsearches_info(planstate, es);
8579 tgl@sss.pgh.pa.us 1969 : 2030 : break;
5079 1970 : 1409 : case T_IndexOnlyScan:
1971 : 1409 : show_scan_qual(((IndexOnlyScan *) plan)->indexqual,
1972 : : "Index Cond", planstate, ancestors, es);
1342 1973 [ + + ]: 1409 : if (((IndexOnlyScan *) plan)->recheckqual)
5079 1974 : 907 : show_instrumentation_count("Rows Removed by Index Recheck", 2,
1975 : : planstate, es);
1976 : 1409 : show_scan_qual(((IndexOnlyScan *) plan)->indexorderby,
1977 : : "Order By", planstate, ancestors, es);
1978 : 1409 : show_scan_qual(plan->qual, "Filter", planstate, ancestors, es);
1979 [ + + ]: 1409 : if (plan->qual)
1980 : 66 : show_instrumentation_count("Rows Removed by Filter", 1,
1981 : : planstate, es);
4973 rhaas@postgresql.org 1982 [ + + ]: 1409 : if (es->analyze)
2706 alvherre@alvh.no-ip. 1983 : 68 : ExplainPropertyFloat("Heap Fetches", NULL,
1984 : 68 : planstate->instrument->ntuples2, 0, es);
179 pg@bowt.ie 1985 : 1409 : show_indexsearches_info(planstate, es);
5079 tgl@sss.pgh.pa.us 1986 : 1409 : break;
7445 1987 : 2152 : case T_BitmapIndexScan:
7439 1988 : 2152 : show_scan_qual(((BitmapIndexScan *) plan)->indexqualorig,
1989 : : "Index Cond", planstate, ancestors, es);
179 pg@bowt.ie 1990 : 2152 : show_indexsearches_info(planstate, es);
7445 tgl@sss.pgh.pa.us 1991 : 2152 : break;
1992 : 2055 : case T_BitmapHeapScan:
7439 1993 : 2055 : show_scan_qual(((BitmapHeapScan *) plan)->bitmapqualorig,
1994 : : "Recheck Cond", planstate, ancestors, es);
5098 1995 [ + + ]: 2055 : if (((BitmapHeapScan *) plan)->bitmapqualorig)
1996 : 2016 : show_instrumentation_count("Rows Removed by Index Recheck", 2,
1997 : : planstate, es);
4254 rhaas@postgresql.org 1998 : 2055 : show_scan_qual(plan->qual, "Filter", planstate, ancestors, es);
1999 [ + + ]: 2055 : if (plan->qual)
2000 : 174 : show_instrumentation_count("Rows Removed by Filter", 1,
2001 : : planstate, es);
424 drowley@postgresql.o 2002 : 2055 : show_tidbitmap_info((BitmapHeapScanState *) planstate, es);
4254 rhaas@postgresql.org 2003 : 2055 : break;
3696 tgl@sss.pgh.pa.us 2004 : 60 : case T_SampleScan:
2005 : 60 : show_tablesample(((SampleScan *) plan)->tablesample,
2006 : : planstate, ancestors, es);
2007 : : /* fall through to print additional fields the same as SeqScan */
2008 : : /* FALLTHROUGH */
8579 2009 : 13644 : case T_SeqScan:
2010 : : case T_ValuesScan:
2011 : : case T_CteScan:
2012 : : case T_NamedTuplestoreScan:
2013 : : case T_WorkTableScan:
2014 : : case T_SubqueryScan:
5534 2015 : 13644 : show_scan_qual(plan->qual, "Filter", planstate, ancestors, es);
5098 2016 [ + + ]: 13644 : if (plan->qual)
2017 : 7058 : show_instrumentation_count("Rows Removed by Filter", 1,
2018 : : planstate, es);
348 ishii@postgresql.org 2019 [ + + ]: 13644 : if (IsA(plan, CteScan))
2020 : 125 : show_ctescan_info(castNode(CteScanState, planstate), es);
8579 tgl@sss.pgh.pa.us 2021 : 13644 : break;
3629 rhaas@postgresql.org 2022 : 313 : case T_Gather:
2023 : : {
3440 tgl@sss.pgh.pa.us 2024 : 313 : Gather *gather = (Gather *) plan;
2025 : :
3629 rhaas@postgresql.org 2026 : 313 : show_scan_qual(plan->qual, "Filter", planstate, ancestors, es);
2027 [ - + ]: 313 : if (plan->qual)
3629 rhaas@postgresql.org 2028 :UBC 0 : show_instrumentation_count("Rows Removed by Filter", 1,
2029 : : planstate, es);
2731 andres@anarazel.de 2030 :CBC 313 : ExplainPropertyInteger("Workers Planned", NULL,
3629 rhaas@postgresql.org 2031 : 313 : gather->num_workers, es);
2032 : :
3431 2033 [ + + ]: 313 : if (es->analyze)
2034 : : {
2035 : : int nworkers;
2036 : :
2037 : 84 : nworkers = ((GatherState *) planstate)->nworkers_launched;
2731 andres@anarazel.de 2038 : 84 : ExplainPropertyInteger("Workers Launched", NULL,
2039 : : nworkers, es);
2040 : : }
2041 : :
3356 tgl@sss.pgh.pa.us 2042 [ + + + + ]: 313 : if (gather->single_copy || es->format != EXPLAIN_FORMAT_TEXT)
2043 : 52 : ExplainPropertyBool("Single Copy", gather->single_copy, es);
2044 : : }
3629 rhaas@postgresql.org 2045 : 313 : break;
3103 2046 : 111 : case T_GatherMerge:
2047 : : {
2048 : 111 : GatherMerge *gm = (GatherMerge *) plan;
2049 : :
2050 : 111 : show_scan_qual(plan->qual, "Filter", planstate, ancestors, es);
2051 [ - + ]: 111 : if (plan->qual)
3103 rhaas@postgresql.org 2052 :UBC 0 : show_instrumentation_count("Rows Removed by Filter", 1,
2053 : : planstate, es);
2731 andres@anarazel.de 2054 :CBC 111 : ExplainPropertyInteger("Workers Planned", NULL,
3103 rhaas@postgresql.org 2055 : 111 : gm->num_workers, es);
2056 : :
2057 [ + + ]: 111 : if (es->analyze)
2058 : : {
2059 : : int nworkers;
2060 : :
2061 : 6 : nworkers = ((GatherMergeState *) planstate)->nworkers_launched;
2731 andres@anarazel.de 2062 : 6 : ExplainPropertyInteger("Workers Launched", NULL,
2063 : : nworkers, es);
2064 : : }
2065 : : }
3103 rhaas@postgresql.org 2066 : 111 : break;
5492 tgl@sss.pgh.pa.us 2067 : 288 : case T_FunctionScan:
2068 [ + + ]: 288 : if (es->verbose)
2069 : : {
4307 2070 : 100 : List *fexprs = NIL;
2071 : : ListCell *lc;
2072 : :
2073 [ + - + + : 200 : foreach(lc, ((FunctionScan *) plan)->functions)
+ + ]
2074 : : {
2075 : 100 : RangeTblFunction *rtfunc = (RangeTblFunction *) lfirst(lc);
2076 : :
2077 : 100 : fexprs = lappend(fexprs, rtfunc->funcexpr);
2078 : : }
2079 : : /* We rely on show_expression to insert commas as needed */
2080 : 100 : show_expression((Node *) fexprs,
2081 : : "Function Call", planstate, ancestors,
5492 2082 : 100 : es->verbose, es);
2083 : : }
2084 : 288 : show_scan_qual(plan->qual, "Filter", planstate, ancestors, es);
5098 2085 [ + + ]: 288 : if (plan->qual)
2086 : 11 : show_instrumentation_count("Rows Removed by Filter", 1,
2087 : : planstate, es);
5492 2088 : 288 : break;
3104 alvherre@alvh.no-ip. 2089 : 39 : case T_TableFuncScan:
2090 [ + + ]: 39 : if (es->verbose)
2091 : : {
2092 : 36 : TableFunc *tablefunc = ((TableFuncScan *) plan)->tablefunc;
2093 : :
2094 : 36 : show_expression((Node *) tablefunc,
2095 : : "Table Function Call", planstate, ancestors,
2096 : 36 : es->verbose, es);
2097 : : }
2098 : 39 : show_scan_qual(plan->qual, "Filter", planstate, ancestors, es);
2099 [ + + ]: 39 : if (plan->qual)
2100 : 9 : show_instrumentation_count("Rows Removed by Filter", 1,
2101 : : planstate, es);
348 ishii@postgresql.org 2102 : 39 : show_table_func_scan_info(castNode(TableFuncScanState,
2103 : : planstate), es);
3104 alvherre@alvh.no-ip. 2104 : 39 : break;
7224 tgl@sss.pgh.pa.us 2105 : 33 : case T_TidScan:
2106 : : {
2107 : : /*
2108 : : * The tidquals list has OR semantics, so be sure to show it
2109 : : * as an OR condition.
2110 : : */
6912 bruce@momjian.us 2111 : 33 : List *tidquals = ((TidScan *) plan)->tidquals;
2112 : :
7224 tgl@sss.pgh.pa.us 2113 [ + + ]: 33 : if (list_length(tidquals) > 1)
2114 : 6 : tidquals = list_make1(make_orclause(tidquals));
5534 2115 : 33 : show_scan_qual(tidquals, "TID Cond", planstate, ancestors, es);
2116 : 33 : show_scan_qual(plan->qual, "Filter", planstate, ancestors, es);
5098 2117 [ + + ]: 33 : if (plan->qual)
2118 : 9 : show_instrumentation_count("Rows Removed by Filter", 1,
2119 : : planstate, es);
2120 : : }
7224 2121 : 33 : break;
1652 drowley@postgresql.o 2122 : 42 : case T_TidRangeScan:
2123 : : {
2124 : : /*
2125 : : * The tidrangequals list has AND semantics, so be sure to
2126 : : * show it as an AND condition.
2127 : : */
2128 : 42 : List *tidquals = ((TidRangeScan *) plan)->tidrangequals;
2129 : :
2130 [ + + ]: 42 : if (list_length(tidquals) > 1)
2131 : 6 : tidquals = list_make1(make_andclause(tidquals));
2132 : 42 : show_scan_qual(tidquals, "TID Cond", planstate, ancestors, es);
2133 : 42 : show_scan_qual(plan->qual, "Filter", planstate, ancestors, es);
2134 [ - + ]: 42 : if (plan->qual)
1652 drowley@postgresql.o 2135 :UBC 0 : show_instrumentation_count("Rows Removed by Filter", 1,
2136 : : planstate, es);
2137 : : }
1652 drowley@postgresql.o 2138 :CBC 42 : break;
5312 tgl@sss.pgh.pa.us 2139 : 425 : case T_ForeignScan:
2140 : 425 : show_scan_qual(plan->qual, "Filter", planstate, ancestors, es);
5098 2141 [ + + ]: 425 : if (plan->qual)
2142 : 52 : show_instrumentation_count("Rows Removed by Filter", 1,
2143 : : planstate, es);
5312 2144 : 425 : show_foreignscan_info((ForeignScanState *) planstate, es);
2145 : 425 : break;
3956 rhaas@postgresql.org 2146 :UBC 0 : case T_CustomScan:
2147 : : {
2148 : 0 : CustomScanState *css = (CustomScanState *) planstate;
2149 : :
2150 : 0 : show_scan_qual(plan->qual, "Filter", planstate, ancestors, es);
2151 [ # # ]: 0 : if (plan->qual)
2152 : 0 : show_instrumentation_count("Rows Removed by Filter", 1,
2153 : : planstate, es);
2154 [ # # ]: 0 : if (css->methods->ExplainCustomScan)
2155 : 0 : css->methods->ExplainCustomScan(css, ancestors, es);
2156 : : }
2157 : 0 : break;
8579 tgl@sss.pgh.pa.us 2158 :CBC 1853 : case T_NestLoop:
8569 2159 : 1853 : show_upper_qual(((NestLoop *) plan)->join.joinqual,
2160 : : "Join Filter", planstate, ancestors, es);
5098 2161 [ + + ]: 1853 : if (((NestLoop *) plan)->join.joinqual)
2162 : 568 : show_instrumentation_count("Rows Removed by Join Filter", 1,
2163 : : planstate, es);
5534 2164 : 1853 : show_upper_qual(plan->qual, "Filter", planstate, ancestors, es);
5098 2165 [ + + ]: 1853 : if (plan->qual)
2166 : 45 : show_instrumentation_count("Rows Removed by Filter", 2,
2167 : : planstate, es);
8579 2168 : 1853 : break;
2169 : 391 : case T_MergeJoin:
8569 2170 : 391 : show_upper_qual(((MergeJoin *) plan)->mergeclauses,
2171 : : "Merge Cond", planstate, ancestors, es);
2172 : 391 : show_upper_qual(((MergeJoin *) plan)->join.joinqual,
2173 : : "Join Filter", planstate, ancestors, es);
5098 2174 [ + + ]: 391 : if (((MergeJoin *) plan)->join.joinqual)
2175 : 13 : show_instrumentation_count("Rows Removed by Join Filter", 1,
2176 : : planstate, es);
5534 2177 : 391 : show_upper_qual(plan->qual, "Filter", planstate, ancestors, es);
5098 2178 [ + + ]: 391 : if (plan->qual)
2179 : 12 : show_instrumentation_count("Rows Removed by Filter", 2,
2180 : : planstate, es);
8579 2181 : 391 : break;
2182 : 1927 : case T_HashJoin:
8569 2183 : 1927 : show_upper_qual(((HashJoin *) plan)->hashclauses,
2184 : : "Hash Cond", planstate, ancestors, es);
2185 : 1927 : show_upper_qual(((HashJoin *) plan)->join.joinqual,
2186 : : "Join Filter", planstate, ancestors, es);
5098 2187 [ + + ]: 1927 : if (((HashJoin *) plan)->join.joinqual)
2188 : 12 : show_instrumentation_count("Rows Removed by Join Filter", 1,
2189 : : planstate, es);
5534 2190 : 1927 : show_upper_qual(plan->qual, "Filter", planstate, ancestors, es);
5098 2191 [ + + ]: 1927 : if (plan->qual)
2192 : 134 : show_instrumentation_count("Rows Removed by Filter", 2,
2193 : : planstate, es);
8579 2194 : 1927 : break;
2195 : 4851 : case T_Agg:
3145 andres@anarazel.de 2196 : 4851 : show_agg_keys(castNode(AggState, planstate), ancestors, es);
4286 tgl@sss.pgh.pa.us 2197 : 4851 : show_upper_qual(plan->qual, "Filter", planstate, ancestors, es);
1998 jdavis@postgresql.or 2198 : 4851 : show_hashagg_info((AggState *) planstate, es);
4286 tgl@sss.pgh.pa.us 2199 [ + + ]: 4851 : if (plan->qual)
2200 : 172 : show_instrumentation_count("Rows Removed by Filter", 1,
2201 : : planstate, es);
2202 : 4851 : break;
1247 drowley@postgresql.o 2203 : 229 : case T_WindowAgg:
179 tgl@sss.pgh.pa.us 2204 : 229 : show_window_def(castNode(WindowAggState, planstate), ancestors, es);
2205 : 229 : show_upper_qual(((WindowAgg *) plan)->runConditionOrig,
2206 : : "Run Condition", planstate, ancestors, es);
1247 drowley@postgresql.o 2207 : 229 : show_upper_qual(plan->qual, "Filter", planstate, ancestors, es);
2208 [ + + ]: 229 : if (plan->qual)
2209 : 3 : show_instrumentation_count("Rows Removed by Filter", 1,
2210 : : planstate, es);
354 ishii@postgresql.org 2211 : 229 : show_windowagg_info(castNode(WindowAggState, planstate), es);
1247 drowley@postgresql.o 2212 : 229 : break;
8579 tgl@sss.pgh.pa.us 2213 : 48 : case T_Group:
3145 andres@anarazel.de 2214 : 48 : show_group_keys(castNode(GroupState, planstate), ancestors, es);
5534 tgl@sss.pgh.pa.us 2215 : 48 : show_upper_qual(plan->qual, "Filter", planstate, ancestors, es);
5098 2216 [ - + ]: 48 : if (plan->qual)
5098 tgl@sss.pgh.pa.us 2217 :UBC 0 : show_instrumentation_count("Rows Removed by Filter", 1,
2218 : : planstate, es);
8579 tgl@sss.pgh.pa.us 2219 :CBC 48 : break;
8512 2220 : 2243 : case T_Sort:
3145 andres@anarazel.de 2221 : 2243 : show_sort_keys(castNode(SortState, planstate), ancestors, es);
2222 : 2243 : show_sort_info(castNode(SortState, planstate), es);
8512 tgl@sss.pgh.pa.us 2223 : 2243 : break;
1979 tomas.vondra@postgre 2224 : 187 : case T_IncrementalSort:
2225 : 187 : show_incremental_sort_keys(castNode(IncrementalSortState, planstate),
2226 : : ancestors, es);
2227 : 187 : show_incremental_sort_info(castNode(IncrementalSortState, planstate),
2228 : : es);
2229 : 187 : break;
5441 tgl@sss.pgh.pa.us 2230 : 171 : case T_MergeAppend:
3145 andres@anarazel.de 2231 : 171 : show_merge_append_keys(castNode(MergeAppendState, planstate),
2232 : : ancestors, es);
5441 tgl@sss.pgh.pa.us 2233 : 171 : break;
8579 2234 : 1462 : case T_Result:
2235 : 1462 : show_upper_qual((List *) ((Result *) plan)->resconstantqual,
2236 : : "One-Time Filter", planstate, ancestors, es);
5534 2237 : 1462 : show_upper_qual(plan->qual, "Filter", planstate, ancestors, es);
5098 2238 [ - + ]: 1462 : if (plan->qual)
5098 tgl@sss.pgh.pa.us 2239 :UBC 0 : show_instrumentation_count("Rows Removed by Filter", 1,
2240 : : planstate, es);
8579 tgl@sss.pgh.pa.us 2241 :CBC 1462 : break;
4563 2242 : 553 : case T_ModifyTable:
3145 andres@anarazel.de 2243 : 553 : show_modifytable_info(castNode(ModifyTableState, planstate), ancestors,
2244 : : es);
4563 tgl@sss.pgh.pa.us 2245 : 553 : break;
5696 rhaas@postgresql.org 2246 : 1927 : case T_Hash:
3145 andres@anarazel.de 2247 : 1927 : show_hash_info(castNode(HashState, planstate), es);
5696 rhaas@postgresql.org 2248 : 1927 : break;
428 drowley@postgresql.o 2249 : 550 : case T_Material:
2250 : 550 : show_material_info(castNode(MaterialState, planstate), es);
2251 : 550 : break;
1515 2252 : 186 : case T_Memoize:
2253 : 186 : show_memoize_info(castNode(MemoizeState, planstate), ancestors,
2254 : : es);
1618 2255 : 186 : break;
348 ishii@postgresql.org 2256 : 27 : case T_RecursiveUnion:
2257 : 27 : show_recursive_union_info(castNode(RecursiveUnionState,
2258 : : planstate), es);
2259 : 27 : break;
8579 tgl@sss.pgh.pa.us 2260 : 2940 : default:
2261 : 2940 : break;
2262 : : }
2263 : :
2264 : : /*
2265 : : * Prepare per-worker JIT instrumentation. As with the overall JIT
2266 : : * summary, this is printed only if printing costs is enabled.
2267 : : */
2051 2268 [ + + + + : 42086 : if (es->workers_state && es->costs && es->verbose)
+ + ]
2269 : : {
2270 : 6 : SharedJitInstrumentation *w = planstate->worker_jit_instrument;
2271 : :
2272 [ - + ]: 6 : if (w)
2273 : : {
2051 tgl@sss.pgh.pa.us 2274 [ # # ]:UBC 0 : for (int n = 0; n < w->num_workers; n++)
2275 : : {
2276 : 0 : ExplainOpenWorker(n, es);
2277 : 0 : ExplainPrintJIT(es, planstate->state->es_jit_flags,
2278 : : &w->jit_instr[n]);
2279 : 0 : ExplainCloseWorker(n, es);
2280 : : }
2281 : : }
2282 : : }
2283 : :
2284 : : /* Show buffer/WAL usage */
4127 tgl@sss.pgh.pa.us 2285 [ + + + - ]:CBC 42086 : if (es->buffers && planstate->instrument)
586 alvherre@alvh.no-ip. 2286 : 2099 : show_buffer_usage(es, &planstate->instrument->bufusage);
1979 akapila@postgresql.o 2287 [ - + - - ]: 42086 : if (es->wal && planstate->instrument)
1979 akapila@postgresql.o 2288 :UBC 0 : show_wal_usage(es, &planstate->instrument->walusage);
2289 : :
2290 : : /* Prepare per-worker buffer/WAL usage */
1979 akapila@postgresql.o 2291 [ + + + + :CBC 42086 : if (es->workers_state && (es->buffers || es->wal) && es->verbose)
- + + + ]
2292 : : {
3559 rhaas@postgresql.org 2293 : 6 : WorkerInstrumentation *w = planstate->worker_instrument;
2294 : :
2051 tgl@sss.pgh.pa.us 2295 [ + + ]: 30 : for (int n = 0; n < w->num_workers; n++)
2296 : : {
3559 rhaas@postgresql.org 2297 : 24 : Instrumentation *instrument = &w->instrument[n];
2298 : 24 : double nloops = instrument->nloops;
2299 : :
2300 [ - + ]: 24 : if (nloops <= 0)
3559 rhaas@postgresql.org 2301 :UBC 0 : continue;
2302 : :
2051 tgl@sss.pgh.pa.us 2303 :CBC 24 : ExplainOpenWorker(n, es);
1979 akapila@postgresql.o 2304 [ + - ]: 24 : if (es->buffers)
586 alvherre@alvh.no-ip. 2305 : 24 : show_buffer_usage(es, &instrument->bufusage);
1979 akapila@postgresql.o 2306 [ - + ]: 24 : if (es->wal)
1979 akapila@postgresql.o 2307 :UBC 0 : show_wal_usage(es, &instrument->walusage);
2051 tgl@sss.pgh.pa.us 2308 :CBC 24 : ExplainCloseWorker(n, es);
2309 : : }
2310 : : }
2311 : :
2312 : : /* Show per-worker details for this plan node, then pop that stack */
2313 [ + + ]: 42086 : if (es->workers_state)
2314 : 513 : ExplainFlushWorkersState(es);
2315 : 42086 : es->workers_state = save_workers_state;
2316 : :
2317 : : /* Allow plugins to print additional information */
172 rhaas@postgresql.org 2318 [ + + ]: 42086 : if (explain_per_node_hook)
2319 : 30 : (*explain_per_node_hook) (planstate, ancestors, relationship,
2320 : : plan_name, es);
2321 : :
2322 : : /*
2323 : : * If partition pruning was done during executor initialization, the
2324 : : * number of child plans we'll display below will be less than the number
2325 : : * of subplans that was specified in the plan. To make this a bit less
2326 : : * mysterious, emit an indication that this happened. Note that this
2327 : : * field is emitted now because we want it to be a property of the parent
2328 : : * node; it *cannot* be emitted within the Plans sub-node we'll open next.
2329 : : */
2041 tgl@sss.pgh.pa.us 2330 [ + + + ]: 42086 : switch (nodeTag(plan))
2331 : : {
2332 : 1728 : case T_Append:
2333 : 1728 : ExplainMissingMembers(((AppendState *) planstate)->as_nplans,
2334 : 1728 : list_length(((Append *) plan)->appendplans),
2335 : : es);
2336 : 1728 : break;
2337 : 171 : case T_MergeAppend:
2338 : 171 : ExplainMissingMembers(((MergeAppendState *) planstate)->ms_nplans,
2339 : 171 : list_length(((MergeAppend *) plan)->mergeplans),
2340 : : es);
2341 : 171 : break;
2342 : 40187 : default:
2343 : 40187 : break;
2344 : : }
2345 : :
2346 : : /* Get ready to display the child plans */
5534 2347 : 125689 : haschildren = planstate->initPlan ||
2348 [ + + ]: 41517 : outerPlanState(planstate) ||
2349 [ + - ]: 23010 : innerPlanState(planstate) ||
5871 2350 [ + + ]: 23010 : IsA(plan, Append) ||
5441 2351 [ + + ]: 21339 : IsA(plan, MergeAppend) ||
5871 2352 [ + + ]: 21171 : IsA(plan, BitmapAnd) ||
2353 [ + + ]: 21150 : IsA(plan, BitmapOr) ||
2354 [ + + ]: 21077 : IsA(plan, SubqueryScan) ||
3725 rhaas@postgresql.org 2355 [ - + ]: 20859 : (IsA(planstate, CustomScanState) &&
2356 [ + + - - ]: 83603 : ((CustomScanState *) planstate)->custom_ps != NIL) ||
5871 tgl@sss.pgh.pa.us 2357 [ + + ]: 20859 : planstate->subPlan;
2358 [ + + ]: 42086 : if (haschildren)
2359 : : {
2360 : 21414 : ExplainOpenGroup("Plans", "Plans", false, es);
2361 : : /* Pass current Plan as head of ancestors list for children */
2096 2362 : 21414 : ancestors = lcons(plan, ancestors);
2363 : : }
2364 : :
2365 : : /* initPlan-s */
5534 2366 [ + + ]: 42086 : if (planstate->initPlan)
2367 : 569 : ExplainSubPlans(planstate->initPlan, ancestors, "InitPlan", es);
2368 : :
2369 : : /* lefttree */
2370 [ + + ]: 42086 : if (outerPlanState(planstate))
2371 : 18702 : ExplainNode(outerPlanState(planstate), ancestors,
2372 : : "Outer", NULL, es);
2373 : :
2374 : : /* righttree */
2375 [ + + ]: 42086 : if (innerPlanState(planstate))
2376 : 4252 : ExplainNode(innerPlanState(planstate), ancestors,
2377 : : "Inner", NULL, es);
2378 : :
2379 : : /* special child plans */
5888 2380 [ + + + + : 42086 : switch (nodeTag(plan))
+ - + ]
2381 : : {
2382 : 1728 : case T_Append:
2709 alvherre@alvh.no-ip. 2383 : 1728 : ExplainMemberNodes(((AppendState *) planstate)->appendplans,
2384 : : ((AppendState *) planstate)->as_nplans,
2385 : : ancestors, es);
5888 tgl@sss.pgh.pa.us 2386 : 1728 : break;
5441 2387 : 171 : case T_MergeAppend:
2709 alvherre@alvh.no-ip. 2388 : 171 : ExplainMemberNodes(((MergeAppendState *) planstate)->mergeplans,
2389 : : ((MergeAppendState *) planstate)->ms_nplans,
2390 : : ancestors, es);
5441 tgl@sss.pgh.pa.us 2391 : 171 : break;
5888 2392 : 21 : case T_BitmapAnd:
2709 alvherre@alvh.no-ip. 2393 : 21 : ExplainMemberNodes(((BitmapAndState *) planstate)->bitmapplans,
2394 : : ((BitmapAndState *) planstate)->nplans,
2395 : : ancestors, es);
5888 tgl@sss.pgh.pa.us 2396 : 21 : break;
2397 : 73 : case T_BitmapOr:
2709 alvherre@alvh.no-ip. 2398 : 73 : ExplainMemberNodes(((BitmapOrState *) planstate)->bitmapplans,
2399 : : ((BitmapOrState *) planstate)->nplans,
2400 : : ancestors, es);
5888 tgl@sss.pgh.pa.us 2401 : 73 : break;
2402 : 218 : case T_SubqueryScan:
5534 2403 : 218 : ExplainNode(((SubqueryScanState *) planstate)->subplan, ancestors,
2404 : : "Subquery", NULL, es);
5888 2405 : 218 : break;
3725 rhaas@postgresql.org 2406 :UBC 0 : case T_CustomScan:
2407 : 0 : ExplainCustomChildren((CustomScanState *) planstate,
2408 : : ancestors, es);
2409 : 0 : break;
5888 tgl@sss.pgh.pa.us 2410 :CBC 39875 : default:
2411 : 39875 : break;
2412 : : }
2413 : :
2414 : : /* subPlan-s */
8311 2415 [ + + ]: 42086 : if (planstate->subPlan)
5534 2416 : 299 : ExplainSubPlans(planstate->subPlan, ancestors, "SubPlan", es);
2417 : :
2418 : : /* end of child plans */
5871 2419 [ + + ]: 42086 : if (haschildren)
2420 : : {
5401 peter_e@gmx.net 2421 : 21414 : ancestors = list_delete_first(ancestors);
5871 tgl@sss.pgh.pa.us 2422 : 21414 : ExplainCloseGroup("Plans", "Plans", false, es);
2423 : : }
2424 : :
2425 : : /* in text format, undo whatever indentation we added */
2426 [ + + ]: 42086 : if (es->format == EXPLAIN_FORMAT_TEXT)
2427 : 41542 : es->indent = save_indent;
2428 : :
2429 [ + + ]: 42086 : ExplainCloseGroup("Plan",
2430 : : relationship ? NULL : "Plan",
2431 : : true, es);
10651 scrappy@hub.org 2432 : 42086 : }
2433 : :
2434 : : /*
2435 : : * Show the targetlist of a plan node
2436 : : */
2437 : : static void
5534 tgl@sss.pgh.pa.us 2438 : 4598 : show_plan_tlist(PlanState *planstate, List *ancestors, ExplainState *es)
2439 : : {
2440 : 4598 : Plan *plan = planstate->plan;
2441 : : List *context;
5871 2442 : 4598 : List *result = NIL;
2443 : : bool useprefix;
2444 : : ListCell *lc;
2445 : :
2446 : : /* No work if empty tlist (this occurs eg in bitmap indexscans) */
6351 2447 [ + + ]: 4598 : if (plan->targetlist == NIL)
2448 : 253 : return;
2449 : : /* The tlist of an Append isn't real helpful, so suppress it */
2450 [ + + ]: 4345 : if (IsA(plan, Append))
2451 : 117 : return;
2452 : : /* Likewise for MergeAppend and RecursiveUnion */
5441 2453 [ + + ]: 4228 : if (IsA(plan, MergeAppend))
2454 : 20 : return;
6181 2455 [ + + ]: 4208 : if (IsA(plan, RecursiveUnion))
2456 : 24 : return;
2457 : :
2458 : : /*
2459 : : * Likewise for ForeignScan that executes a direct INSERT/UPDATE/DELETE
2460 : : *
2461 : : * Note: the tlist for a ForeignScan that executes a direct INSERT/UPDATE
2462 : : * might contain subplan output expressions that are confusing in this
2463 : : * context. The tlist for a ForeignScan that executes a direct UPDATE/
2464 : : * DELETE always contains "junk" target columns to identify the exact row
2465 : : * to update or delete, which would be confusing in this context. So, we
2466 : : * suppress it in all the cases.
2467 : : */
3459 rhaas@postgresql.org 2468 [ + + ]: 4184 : if (IsA(plan, ForeignScan) &&
2469 [ + + ]: 385 : ((ForeignScan *) plan)->operation != CMD_SELECT)
2470 : 32 : return;
2471 : :
2472 : : /* Set up deparsing context */
2096 tgl@sss.pgh.pa.us 2473 : 4152 : context = set_deparse_context_plan(es->deparse_cxt,
2474 : : plan,
2475 : : ancestors);
361 rguo@postgresql.org 2476 : 4152 : useprefix = es->rtable_size > 1;
2477 : :
2478 : : /* Deparse each result column (we now include resjunk ones) */
6351 tgl@sss.pgh.pa.us 2479 [ + - + + : 15216 : foreach(lc, plan->targetlist)
+ + ]
2480 : : {
2481 : 11064 : TargetEntry *tle = (TargetEntry *) lfirst(lc);
2482 : :
5871 2483 : 11064 : result = lappend(result,
5671 bruce@momjian.us 2484 : 11064 : deparse_expression((Node *) tle->expr, context,
2485 : : useprefix, false));
2486 : : }
2487 : :
2488 : : /* Print results */
5871 tgl@sss.pgh.pa.us 2489 : 4152 : ExplainPropertyList("Output", result, es);
2490 : : }
2491 : :
2492 : : /*
2493 : : * Show a generic expression
2494 : : */
2495 : : static void
5492 2496 : 18262 : show_expression(Node *node, const char *qlabel,
2497 : : PlanState *planstate, List *ancestors,
2498 : : bool useprefix, ExplainState *es)
2499 : : {
2500 : : List *context;
2501 : : char *exprstr;
2502 : :
2503 : : /* Set up deparsing context */
2096 2504 : 18262 : context = set_deparse_context_plan(es->deparse_cxt,
2505 : 18262 : planstate->plan,
2506 : : ancestors);
2507 : :
2508 : : /* Deparse the expression */
6770 2509 : 18262 : exprstr = deparse_expression(node, context, useprefix, false);
2510 : :
2511 : : /* And add to es->str */
5871 2512 : 18262 : ExplainPropertyText(qlabel, exprstr, es);
8579 2513 : 18262 : }
2514 : :
2515 : : /*
2516 : : * Show a qualifier expression (which is a List with implicit AND semantics)
2517 : : */
2518 : : static void
5492 2519 : 50517 : show_qual(List *qual, const char *qlabel,
2520 : : PlanState *planstate, List *ancestors,
2521 : : bool useprefix, ExplainState *es)
2522 : : {
2523 : : Node *node;
2524 : :
2525 : : /* No work if empty qual */
2526 [ + + ]: 50517 : if (qual == NIL)
2527 : 32391 : return;
2528 : :
2529 : : /* Convert AND list to explicit AND */
2530 : 18126 : node = (Node *) make_ands_explicit(qual);
2531 : :
2532 : : /* And show it */
2533 : 18126 : show_expression(node, qlabel, planstate, ancestors, useprefix, es);
2534 : : }
2535 : :
2536 : : /*
2537 : : * Show a qualifier expression for a scan plan node
2538 : : */
2539 : : static void
5888 2540 : 31549 : show_scan_qual(List *qual, const char *qlabel,
2541 : : PlanState *planstate, List *ancestors,
2542 : : ExplainState *es)
2543 : : {
2544 : : bool useprefix;
2545 : :
1939 2546 [ + + + + ]: 31549 : useprefix = (IsA(planstate->plan, SubqueryScan) || es->verbose);
5534 2547 : 31549 : show_qual(qual, qlabel, planstate, ancestors, useprefix, es);
5888 2548 : 31549 : }
2549 : :
2550 : : /*
2551 : : * Show a qualifier expression for an upper-level plan node
2552 : : */
2553 : : static void
5534 2554 : 18968 : show_upper_qual(List *qual, const char *qlabel,
2555 : : PlanState *planstate, List *ancestors,
2556 : : ExplainState *es)
2557 : : {
2558 : : bool useprefix;
2559 : :
361 rguo@postgresql.org 2560 [ + + + + ]: 18968 : useprefix = (es->rtable_size > 1 || es->verbose);
5534 tgl@sss.pgh.pa.us 2561 : 18968 : show_qual(qual, qlabel, planstate, ancestors, useprefix, es);
8579 2562 : 18968 : }
2563 : :
2564 : : /*
2565 : : * Show the sort keys for a Sort node.
2566 : : */
2567 : : static void
5534 2568 : 2243 : show_sort_keys(SortState *sortstate, List *ancestors, ExplainState *es)
2569 : : {
2570 : 2243 : Sort *plan = (Sort *) sortstate->ss.ps.plan;
2571 : :
4286 2572 : 2243 : show_sort_group_keys((PlanState *) sortstate, "Sort Key",
2573 : : plan->numCols, 0, plan->sortColIdx,
2574 : : plan->sortOperators, plan->collations,
2575 : : plan->nullsFirst,
2576 : : ancestors, es);
5441 2577 : 2243 : }
2578 : :
2579 : : /*
2580 : : * Show the sort keys for an IncrementalSort node.
2581 : : */
2582 : : static void
1979 tomas.vondra@postgre 2583 : 187 : show_incremental_sort_keys(IncrementalSortState *incrsortstate,
2584 : : List *ancestors, ExplainState *es)
2585 : : {
2586 : 187 : IncrementalSort *plan = (IncrementalSort *) incrsortstate->ss.ps.plan;
2587 : :
2588 : 187 : show_sort_group_keys((PlanState *) incrsortstate, "Sort Key",
2589 : : plan->sort.numCols, plan->nPresortedCols,
2590 : : plan->sort.sortColIdx,
2591 : : plan->sort.sortOperators, plan->sort.collations,
2592 : : plan->sort.nullsFirst,
2593 : : ancestors, es);
2594 : 187 : }
2595 : :
2596 : : /*
2597 : : * Likewise, for a MergeAppend node.
2598 : : */
2599 : : static void
5441 tgl@sss.pgh.pa.us 2600 : 171 : show_merge_append_keys(MergeAppendState *mstate, List *ancestors,
2601 : : ExplainState *es)
2602 : : {
2603 : 171 : MergeAppend *plan = (MergeAppend *) mstate->ps.plan;
2604 : :
4286 2605 : 171 : show_sort_group_keys((PlanState *) mstate, "Sort Key",
2606 : : plan->numCols, 0, plan->sortColIdx,
2607 : : plan->sortOperators, plan->collations,
2608 : : plan->nullsFirst,
2609 : : ancestors, es);
5441 2610 : 171 : }
2611 : :
2612 : : /*
2613 : : * Show the grouping keys for an Agg node.
2614 : : */
2615 : : static void
4286 2616 : 4851 : show_agg_keys(AggState *astate, List *ancestors,
2617 : : ExplainState *es)
2618 : : {
2619 : 4851 : Agg *plan = (Agg *) astate->ss.ps.plan;
2620 : :
3766 andres@anarazel.de 2621 [ + + + + ]: 4851 : if (plan->numCols > 0 || plan->groupingSets)
2622 : : {
2623 : : /* The key columns refer to the tlist of the child plan */
2096 tgl@sss.pgh.pa.us 2624 : 1197 : ancestors = lcons(plan, ancestors);
2625 : :
3766 andres@anarazel.de 2626 [ + + ]: 1197 : if (plan->groupingSets)
2627 : 117 : show_grouping_sets(outerPlanState(astate), plan, ancestors, es);
2628 : : else
2629 : 1080 : show_sort_group_keys(outerPlanState(astate), "Group Key",
2630 : : plan->numCols, 0, plan->grpColIdx,
2631 : : NULL, NULL, NULL,
2632 : : ancestors, es);
2633 : :
4286 tgl@sss.pgh.pa.us 2634 : 1197 : ancestors = list_delete_first(ancestors);
2635 : : }
2636 : 4851 : }
2637 : :
2638 : : static void
3766 andres@anarazel.de 2639 : 117 : show_grouping_sets(PlanState *planstate, Agg *agg,
2640 : : List *ancestors, ExplainState *es)
2641 : : {
2642 : : List *context;
2643 : : bool useprefix;
2644 : : ListCell *lc;
2645 : :
2646 : : /* Set up deparsing context */
2096 tgl@sss.pgh.pa.us 2647 : 117 : context = set_deparse_context_plan(es->deparse_cxt,
2648 : 117 : planstate->plan,
2649 : : ancestors);
361 rguo@postgresql.org 2650 [ + + + + ]: 117 : useprefix = (es->rtable_size > 1 || es->verbose);
2651 : :
3766 andres@anarazel.de 2652 : 117 : ExplainOpenGroup("Grouping Sets", "Grouping Sets", false, es);
2653 : :
2654 : 117 : show_grouping_set_keys(planstate, agg, NULL,
2655 : : context, useprefix, ancestors, es);
2656 : :
2657 [ + + + + : 306 : foreach(lc, agg->chain)
+ + ]
2658 : : {
3759 bruce@momjian.us 2659 : 189 : Agg *aggnode = lfirst(lc);
2660 : 189 : Sort *sortnode = (Sort *) aggnode->plan.lefttree;
2661 : :
3766 andres@anarazel.de 2662 : 189 : show_grouping_set_keys(planstate, aggnode, sortnode,
2663 : : context, useprefix, ancestors, es);
2664 : : }
2665 : :
2666 : 117 : ExplainCloseGroup("Grouping Sets", "Grouping Sets", false, es);
2667 : 117 : }
2668 : :
2669 : : static void
2670 : 306 : show_grouping_set_keys(PlanState *planstate,
2671 : : Agg *aggnode, Sort *sortnode,
2672 : : List *context, bool useprefix,
2673 : : List *ancestors, ExplainState *es)
2674 : : {
2675 : 306 : Plan *plan = planstate->plan;
2676 : : char *exprstr;
2677 : : ListCell *lc;
2678 : 306 : List *gsets = aggnode->groupingSets;
2679 : 306 : AttrNumber *keycols = aggnode->grpColIdx;
2680 : : const char *keyname;
2681 : : const char *keysetname;
2682 : :
3085 rhodiumtoad@postgres 2683 [ + + + + ]: 306 : if (aggnode->aggstrategy == AGG_HASHED || aggnode->aggstrategy == AGG_MIXED)
2684 : : {
2685 : 199 : keyname = "Hash Key";
2686 : 199 : keysetname = "Hash Keys";
2687 : : }
2688 : : else
2689 : : {
2690 : 107 : keyname = "Group Key";
2691 : 107 : keysetname = "Group Keys";
2692 : : }
2693 : :
3766 andres@anarazel.de 2694 : 306 : ExplainOpenGroup("Grouping Set", NULL, true, es);
2695 : :
2696 [ + + ]: 306 : if (sortnode)
2697 : : {
2698 : 27 : show_sort_group_keys(planstate, "Sort Key",
2699 : : sortnode->numCols, 0, sortnode->sortColIdx,
2700 : : sortnode->sortOperators, sortnode->collations,
2701 : : sortnode->nullsFirst,
2702 : : ancestors, es);
2703 [ + - ]: 27 : if (es->format == EXPLAIN_FORMAT_TEXT)
2704 : 27 : es->indent++;
2705 : : }
2706 : :
3085 rhodiumtoad@postgres 2707 : 306 : ExplainOpenGroup(keysetname, keysetname, false, es);
2708 : :
3766 andres@anarazel.de 2709 [ + - + + : 663 : foreach(lc, gsets)
+ + ]
2710 : : {
2711 : 357 : List *result = NIL;
2712 : : ListCell *lc2;
2713 : :
2714 [ + + + + : 742 : foreach(lc2, (List *) lfirst(lc))
+ + ]
2715 : : {
2716 : 385 : Index i = lfirst_int(lc2);
2717 : 385 : AttrNumber keyresno = keycols[i];
2718 : 385 : TargetEntry *target = get_tle_by_resno(plan->targetlist,
2719 : : keyresno);
2720 : :
2721 [ - + ]: 385 : if (!target)
3766 andres@anarazel.de 2722 [ # # ]:UBC 0 : elog(ERROR, "no tlist entry for key %d", keyresno);
2723 : : /* Deparse the expression, showing any top-level cast */
3766 andres@anarazel.de 2724 :CBC 385 : exprstr = deparse_expression((Node *) target->expr, context,
2725 : : useprefix, true);
2726 : :
2727 : 385 : result = lappend(result, exprstr);
2728 : : }
2729 : :
2730 [ + + + - ]: 357 : if (!result && es->format == EXPLAIN_FORMAT_TEXT)
3085 rhodiumtoad@postgres 2731 : 65 : ExplainPropertyText(keyname, "()", es);
2732 : : else
2733 : 292 : ExplainPropertyListNested(keyname, result, es);
2734 : : }
2735 : :
2736 : 306 : ExplainCloseGroup(keysetname, keysetname, false, es);
2737 : :
3766 andres@anarazel.de 2738 [ + + + - ]: 306 : if (sortnode && es->format == EXPLAIN_FORMAT_TEXT)
2739 : 27 : es->indent--;
2740 : :
2741 : 306 : ExplainCloseGroup("Grouping Set", NULL, true, es);
2742 : 306 : }
2743 : :
2744 : : /*
2745 : : * Show the grouping keys for a Group node.
2746 : : */
2747 : : static void
4286 tgl@sss.pgh.pa.us 2748 : 48 : show_group_keys(GroupState *gstate, List *ancestors,
2749 : : ExplainState *es)
2750 : : {
2751 : 48 : Group *plan = (Group *) gstate->ss.ps.plan;
2752 : :
2753 : : /* The key columns refer to the tlist of the child plan */
2096 2754 : 48 : ancestors = lcons(plan, ancestors);
4286 2755 : 48 : show_sort_group_keys(outerPlanState(gstate), "Group Key",
2756 : : plan->numCols, 0, plan->grpColIdx,
2757 : : NULL, NULL, NULL,
2758 : : ancestors, es);
2759 : 48 : ancestors = list_delete_first(ancestors);
2760 : 48 : }
2761 : :
2762 : : /*
2763 : : * Common code to show sort/group keys, which are represented in plan nodes
2764 : : * as arrays of targetlist indexes. If it's a sort key rather than a group
2765 : : * key, also pass sort operators/collations/nullsFirst arrays.
2766 : : */
2767 : : static void
2768 : 3756 : show_sort_group_keys(PlanState *planstate, const char *qlabel,
2769 : : int nkeys, int nPresortedKeys, AttrNumber *keycols,
2770 : : Oid *sortOperators, Oid *collations, bool *nullsFirst,
2771 : : List *ancestors, ExplainState *es)
2772 : : {
5441 2773 : 3756 : Plan *plan = planstate->plan;
2774 : : List *context;
5871 2775 : 3756 : List *result = NIL;
1979 tomas.vondra@postgre 2776 : 3756 : List *resultPresorted = NIL;
2777 : : StringInfoData sortkeybuf;
2778 : : bool useprefix;
2779 : : int keyno;
2780 : :
8512 tgl@sss.pgh.pa.us 2781 [ - + ]: 3756 : if (nkeys <= 0)
8512 tgl@sss.pgh.pa.us 2782 :UBC 0 : return;
2783 : :
3886 tgl@sss.pgh.pa.us 2784 :CBC 3756 : initStringInfo(&sortkeybuf);
2785 : :
2786 : : /* Set up deparsing context */
2096 2787 : 3756 : context = set_deparse_context_plan(es->deparse_cxt,
2788 : : plan,
2789 : : ancestors);
361 rguo@postgresql.org 2790 [ + + + + ]: 3756 : useprefix = (es->rtable_size > 1 || es->verbose);
2791 : :
8159 tgl@sss.pgh.pa.us 2792 [ + + ]: 9489 : for (keyno = 0; keyno < nkeys; keyno++)
2793 : : {
2794 : : /* find key expression in tlist */
2795 : 5733 : AttrNumber keyresno = keycols[keyno];
5441 2796 : 5733 : TargetEntry *target = get_tle_by_resno(plan->targetlist,
2797 : : keyresno);
2798 : : char *exprstr;
2799 : :
8062 2800 [ - + ]: 5733 : if (!target)
8084 tgl@sss.pgh.pa.us 2801 [ # # ]:UBC 0 : elog(ERROR, "no tlist entry for key %d", keyresno);
2802 : : /* Deparse the expression, showing any top-level cast */
8062 tgl@sss.pgh.pa.us 2803 :CBC 5733 : exprstr = deparse_expression((Node *) target->expr, context,
2804 : : useprefix, true);
3886 2805 : 5733 : resetStringInfo(&sortkeybuf);
2806 : 5733 : appendStringInfoString(&sortkeybuf, exprstr);
2807 : : /* Append sort order information, if relevant */
2808 [ + + ]: 5733 : if (sortOperators != NULL)
2809 : 3854 : show_sortorder_options(&sortkeybuf,
2810 : 3854 : (Node *) target->expr,
2811 : 3854 : sortOperators[keyno],
2812 : 3854 : collations[keyno],
2813 : 3854 : nullsFirst[keyno]);
2814 : : /* Emit one property-list item per sort key */
2815 : 5733 : result = lappend(result, pstrdup(sortkeybuf.data));
1979 tomas.vondra@postgre 2816 [ + + ]: 5733 : if (keyno < nPresortedKeys)
2817 : 205 : resultPresorted = lappend(resultPresorted, exprstr);
2818 : : }
2819 : :
4286 tgl@sss.pgh.pa.us 2820 : 3756 : ExplainPropertyList(qlabel, result, es);
1979 tomas.vondra@postgre 2821 [ + + ]: 3756 : if (nPresortedKeys > 0)
2822 : 187 : ExplainPropertyList("Presorted Key", resultPresorted, es);
2823 : : }
2824 : :
2825 : : /*
2826 : : * Append nondefault characteristics of the sort ordering of a column to buf
2827 : : * (collation, direction, NULLS FIRST/LAST)
2828 : : */
2829 : : static void
3886 tgl@sss.pgh.pa.us 2830 : 3854 : show_sortorder_options(StringInfo buf, Node *sortexpr,
2831 : : Oid sortOperator, Oid collation, bool nullsFirst)
2832 : : {
2833 : 3854 : Oid sortcoltype = exprType(sortexpr);
2834 : 3854 : bool reverse = false;
2835 : : TypeCacheEntry *typentry;
2836 : :
2837 : 3854 : typentry = lookup_type_cache(sortcoltype,
2838 : : TYPECACHE_LT_OPR | TYPECACHE_GT_OPR);
2839 : :
2840 : : /*
2841 : : * Print COLLATE if it's not default for the column's type. There are
2842 : : * some cases where this is redundant, eg if expression is a column whose
2843 : : * declared collation is that collation, but it's hard to distinguish that
2844 : : * here (and arguably, printing COLLATE explicitly is a good idea anyway
2845 : : * in such cases).
2846 : : */
2453 2847 [ + + + + ]: 3854 : if (OidIsValid(collation) && collation != get_typcollation(sortcoltype))
2848 : : {
3886 2849 : 55 : char *collname = get_collation_name(collation);
2850 : :
2851 [ - + ]: 55 : if (collname == NULL)
3886 tgl@sss.pgh.pa.us 2852 [ # # ]:UBC 0 : elog(ERROR, "cache lookup failed for collation %u", collation);
3886 tgl@sss.pgh.pa.us 2853 :CBC 55 : appendStringInfo(buf, " COLLATE %s", quote_identifier(collname));
2854 : : }
2855 : :
2856 : : /* Print direction if not ASC, or USING if non-default sort operator */
2857 [ + + ]: 3854 : if (sortOperator == typentry->gt_opr)
2858 : : {
2859 : 125 : appendStringInfoString(buf, " DESC");
2860 : 125 : reverse = true;
2861 : : }
2862 [ + + ]: 3729 : else if (sortOperator != typentry->lt_opr)
2863 : : {
2864 : 17 : char *opname = get_opname(sortOperator);
2865 : :
2866 [ - + ]: 17 : if (opname == NULL)
3886 tgl@sss.pgh.pa.us 2867 [ # # ]:UBC 0 : elog(ERROR, "cache lookup failed for operator %u", sortOperator);
3886 tgl@sss.pgh.pa.us 2868 :CBC 17 : appendStringInfo(buf, " USING %s", opname);
2869 : : /* Determine whether operator would be considered ASC or DESC */
2870 : 17 : (void) get_equality_op_for_ordering_op(sortOperator, &reverse);
2871 : : }
2872 : :
2873 : : /* Add NULLS FIRST/LAST only if it wouldn't be default */
2874 [ + + + + ]: 3854 : if (nullsFirst && !reverse)
2875 : : {
2876 : 18 : appendStringInfoString(buf, " NULLS FIRST");
2877 : : }
2878 [ + + - + ]: 3836 : else if (!nullsFirst && reverse)
2879 : : {
3886 tgl@sss.pgh.pa.us 2880 :UBC 0 : appendStringInfoString(buf, " NULLS LAST");
2881 : : }
3886 tgl@sss.pgh.pa.us 2882 :CBC 3854 : }
2883 : :
2884 : : /*
2885 : : * Show the window definition for a WindowAgg node.
2886 : : */
2887 : : static void
179 2888 : 229 : show_window_def(WindowAggState *planstate, List *ancestors, ExplainState *es)
2889 : : {
2890 : 229 : WindowAgg *wagg = (WindowAgg *) planstate->ss.ps.plan;
2891 : : StringInfoData wbuf;
2892 : 229 : bool needspace = false;
2893 : :
2894 : 229 : initStringInfo(&wbuf);
2895 : 229 : appendStringInfo(&wbuf, "%s AS (", quote_identifier(wagg->winname));
2896 : :
2897 : : /* The key columns refer to the tlist of the child plan */
2898 : 229 : ancestors = lcons(wagg, ancestors);
2899 [ + + ]: 229 : if (wagg->partNumCols > 0)
2900 : : {
2901 : 120 : appendStringInfoString(&wbuf, "PARTITION BY ");
2902 : 120 : show_window_keys(&wbuf, outerPlanState(planstate),
2903 : : wagg->partNumCols, wagg->partColIdx,
2904 : : ancestors, es);
2905 : 120 : needspace = true;
2906 : : }
2907 [ + + ]: 229 : if (wagg->ordNumCols > 0)
2908 : : {
2909 [ + + ]: 161 : if (needspace)
2910 : 80 : appendStringInfoChar(&wbuf, ' ');
2911 : 161 : appendStringInfoString(&wbuf, "ORDER BY ");
2912 : 161 : show_window_keys(&wbuf, outerPlanState(planstate),
2913 : : wagg->ordNumCols, wagg->ordColIdx,
2914 : : ancestors, es);
2915 : 161 : needspace = true;
2916 : : }
2917 : 229 : ancestors = list_delete_first(ancestors);
2918 [ + + ]: 229 : if (wagg->frameOptions & FRAMEOPTION_NONDEFAULT)
2919 : : {
2920 : : List *context;
2921 : : bool useprefix;
2922 : : char *framestr;
2923 : :
2924 : : /* Set up deparsing context for possible frame expressions */
2925 : 95 : context = set_deparse_context_plan(es->deparse_cxt,
2926 : : (Plan *) wagg,
2927 : : ancestors);
2928 [ + + + + ]: 95 : useprefix = (es->rtable_size > 1 || es->verbose);
2929 : 95 : framestr = get_window_frame_options_for_explain(wagg->frameOptions,
2930 : : wagg->startOffset,
2931 : : wagg->endOffset,
2932 : : context,
2933 : : useprefix);
2934 [ + + ]: 95 : if (needspace)
2935 : 88 : appendStringInfoChar(&wbuf, ' ');
2936 : 95 : appendStringInfoString(&wbuf, framestr);
2937 : 95 : pfree(framestr);
2938 : : }
2939 : 229 : appendStringInfoChar(&wbuf, ')');
2940 : 229 : ExplainPropertyText("Window", wbuf.data, es);
2941 : 229 : pfree(wbuf.data);
2942 : 229 : }
2943 : :
2944 : : /*
2945 : : * Append the keys of a window's PARTITION BY or ORDER BY clause to buf.
2946 : : * We can't use show_sort_group_keys for this because that's too opinionated
2947 : : * about how the result will be displayed.
2948 : : * Note that the "planstate" node should be the WindowAgg's child.
2949 : : */
2950 : : static void
2951 : 281 : show_window_keys(StringInfo buf, PlanState *planstate,
2952 : : int nkeys, AttrNumber *keycols,
2953 : : List *ancestors, ExplainState *es)
2954 : : {
2955 : 281 : Plan *plan = planstate->plan;
2956 : : List *context;
2957 : : bool useprefix;
2958 : :
2959 : : /* Set up deparsing context */
2960 : 281 : context = set_deparse_context_plan(es->deparse_cxt,
2961 : : plan,
2962 : : ancestors);
2963 [ + + + + ]: 281 : useprefix = (es->rtable_size > 1 || es->verbose);
2964 : :
2965 [ + + ]: 577 : for (int keyno = 0; keyno < nkeys; keyno++)
2966 : : {
2967 : : /* find key expression in tlist */
2968 : 296 : AttrNumber keyresno = keycols[keyno];
2969 : 296 : TargetEntry *target = get_tle_by_resno(plan->targetlist,
2970 : : keyresno);
2971 : : char *exprstr;
2972 : :
2973 [ - + ]: 296 : if (!target)
179 tgl@sss.pgh.pa.us 2974 [ # # ]:UBC 0 : elog(ERROR, "no tlist entry for key %d", keyresno);
2975 : : /* Deparse the expression, showing any top-level cast */
179 tgl@sss.pgh.pa.us 2976 :CBC 296 : exprstr = deparse_expression((Node *) target->expr, context,
2977 : : useprefix, true);
2978 [ + + ]: 296 : if (keyno > 0)
2979 : 15 : appendStringInfoString(buf, ", ");
2980 : 296 : appendStringInfoString(buf, exprstr);
2981 : 296 : pfree(exprstr);
2982 : :
2983 : : /*
2984 : : * We don't attempt to provide sort order information because
2985 : : * WindowAgg carries equality operators not comparison operators;
2986 : : * compare show_agg_keys.
2987 : : */
2988 : : }
2989 : 281 : }
2990 : :
2991 : : /*
2992 : : * Show information on storage method and maximum memory/disk space used.
2993 : : */
2994 : : static void
348 ishii@postgresql.org 2995 : 15 : show_storage_info(char *maxStorageType, int64 maxSpaceUsed, ExplainState *es)
2996 : : {
2997 : 15 : int64 maxSpaceUsedKB = BYTES_TO_KILOBYTES(maxSpaceUsed);
2998 : :
354 2999 [ - + ]: 15 : if (es->format != EXPLAIN_FORMAT_TEXT)
3000 : : {
354 ishii@postgresql.org 3001 :UBC 0 : ExplainPropertyText("Storage", maxStorageType, es);
3002 : 0 : ExplainPropertyInteger("Maximum Storage", "kB", maxSpaceUsedKB, es);
3003 : : }
3004 : : else
3005 : : {
354 ishii@postgresql.org 3006 :CBC 15 : ExplainIndentText(es);
3007 : 15 : appendStringInfo(es->str,
3008 : : "Storage: %s Maximum Storage: " INT64_FORMAT "kB\n",
3009 : : maxStorageType,
3010 : : maxSpaceUsedKB);
3011 : : }
3012 : 15 : }
3013 : :
3014 : : /*
3015 : : * Show TABLESAMPLE properties
3016 : : */
3017 : : static void
3696 tgl@sss.pgh.pa.us 3018 : 60 : show_tablesample(TableSampleClause *tsc, PlanState *planstate,
3019 : : List *ancestors, ExplainState *es)
3020 : : {
3021 : : List *context;
3022 : : bool useprefix;
3023 : : char *method_name;
3024 : 60 : List *params = NIL;
3025 : : char *repeatable;
3026 : : ListCell *lc;
3027 : :
3028 : : /* Set up deparsing context */
2096 3029 : 60 : context = set_deparse_context_plan(es->deparse_cxt,
3030 : 60 : planstate->plan,
3031 : : ancestors);
361 rguo@postgresql.org 3032 : 60 : useprefix = es->rtable_size > 1;
3033 : :
3034 : : /* Get the tablesample method name */
3696 tgl@sss.pgh.pa.us 3035 : 60 : method_name = get_func_name(tsc->tsmhandler);
3036 : :
3037 : : /* Deparse parameter expressions */
3038 [ + - + + : 120 : foreach(lc, tsc->args)
+ + ]
3039 : : {
3040 : 60 : Node *arg = (Node *) lfirst(lc);
3041 : :
3042 : 60 : params = lappend(params,
3043 : 60 : deparse_expression(arg, context,
3044 : : useprefix, false));
3045 : : }
3046 [ + + ]: 60 : if (tsc->repeatable)
3047 : 30 : repeatable = deparse_expression((Node *) tsc->repeatable, context,
3048 : : useprefix, false);
3049 : : else
3050 : 30 : repeatable = NULL;
3051 : :
3052 : : /* Print results */
3053 [ + - ]: 60 : if (es->format == EXPLAIN_FORMAT_TEXT)
3054 : : {
3055 : 60 : bool first = true;
3056 : :
2051 3057 : 60 : ExplainIndentText(es);
3696 3058 : 60 : appendStringInfo(es->str, "Sampling: %s (", method_name);
3059 [ + - + + : 120 : foreach(lc, params)
+ + ]
3060 : : {
3061 [ - + ]: 60 : if (!first)
3696 tgl@sss.pgh.pa.us 3062 :UBC 0 : appendStringInfoString(es->str, ", ");
3696 tgl@sss.pgh.pa.us 3063 :CBC 60 : appendStringInfoString(es->str, (const char *) lfirst(lc));
3064 : 60 : first = false;
3065 : : }
3066 : 60 : appendStringInfoChar(es->str, ')');
3067 [ + + ]: 60 : if (repeatable)
3068 : 30 : appendStringInfo(es->str, " REPEATABLE (%s)", repeatable);
3069 : 60 : appendStringInfoChar(es->str, '\n');
3070 : : }
3071 : : else
3072 : : {
3696 tgl@sss.pgh.pa.us 3073 :UBC 0 : ExplainPropertyText("Sampling Method", method_name, es);
3074 : 0 : ExplainPropertyList("Sampling Parameters", params, es);
3075 [ # # ]: 0 : if (repeatable)
3076 : 0 : ExplainPropertyText("Repeatable Seed", repeatable, es);
3077 : : }
3696 tgl@sss.pgh.pa.us 3078 :CBC 60 : }
3079 : :
3080 : : /*
3081 : : * If it's EXPLAIN ANALYZE, show tuplesort stats for a sort node
3082 : : */
3083 : : static void
5871 3084 : 2243 : show_sort_info(SortState *sortstate, ExplainState *es)
3085 : : {
2930 rhaas@postgresql.org 3086 [ + + ]: 2243 : if (!es->analyze)
3087 : 2162 : return;
3088 : :
3089 [ + + + - ]: 81 : if (sortstate->sort_Done && sortstate->tuplesortstate != NULL)
3090 : : {
5671 bruce@momjian.us 3091 : 78 : Tuplesortstate *state = (Tuplesortstate *) sortstate->tuplesortstate;
3092 : : TuplesortInstrumentation stats;
3093 : : const char *sortMethod;
3094 : : const char *spaceType;
3095 : : int64 spaceUsed;
3096 : :
2930 rhaas@postgresql.org 3097 : 78 : tuplesort_get_stats(state, &stats);
3098 : 78 : sortMethod = tuplesort_method_name(stats.sortMethod);
3099 : 78 : spaceType = tuplesort_space_type_name(stats.spaceType);
3100 : 78 : spaceUsed = stats.spaceUsed;
3101 : :
5871 tgl@sss.pgh.pa.us 3102 [ + + ]: 78 : if (es->format == EXPLAIN_FORMAT_TEXT)
3103 : : {
2051 3104 : 63 : ExplainIndentText(es);
1861 drowley@postgresql.o 3105 : 63 : appendStringInfo(es->str, "Sort Method: %s %s: " INT64_FORMAT "kB\n",
3106 : : sortMethod, spaceType, spaceUsed);
3107 : : }
3108 : : else
3109 : : {
5871 tgl@sss.pgh.pa.us 3110 : 15 : ExplainPropertyText("Sort Method", sortMethod, es);
2731 andres@anarazel.de 3111 : 15 : ExplainPropertyInteger("Sort Space Used", "kB", spaceUsed, es);
5871 tgl@sss.pgh.pa.us 3112 : 15 : ExplainPropertyText("Sort Space Type", spaceType, es);
3113 : : }
3114 : : }
3115 : :
3116 : : /*
3117 : : * You might think we should just skip this stanza entirely when
3118 : : * es->hide_workers is true, but then we'd get no sort-method output at
3119 : : * all. We have to make it look like worker 0's data is top-level data.
3120 : : * This is easily done by just skipping the OpenWorker/CloseWorker calls.
3121 : : * Currently, we don't worry about the possibility that there are multiple
3122 : : * workers in such a case; if there are, duplicate output fields will be
3123 : : * emitted.
3124 : : */
2930 rhaas@postgresql.org 3125 [ + + ]: 81 : if (sortstate->shared_info != NULL)
3126 : : {
3127 : : int n;
3128 : :
3129 [ + + ]: 30 : for (n = 0; n < sortstate->shared_info->num_workers; n++)
3130 : : {
3131 : : TuplesortInstrumentation *sinstrument;
3132 : : const char *sortMethod;
3133 : : const char *spaceType;
3134 : : int64 spaceUsed;
3135 : :
3136 : 24 : sinstrument = &sortstate->shared_info->sinstrument[n];
3137 [ - + ]: 24 : if (sinstrument->sortMethod == SORT_TYPE_STILL_IN_PROGRESS)
2930 rhaas@postgresql.org 3138 :UBC 0 : continue; /* ignore any unfilled slots */
2930 rhaas@postgresql.org 3139 :CBC 24 : sortMethod = tuplesort_method_name(sinstrument->sortMethod);
3140 : 24 : spaceType = tuplesort_space_type_name(sinstrument->spaceType);
3141 : 24 : spaceUsed = sinstrument->spaceUsed;
3142 : :
2051 tgl@sss.pgh.pa.us 3143 [ + - ]: 24 : if (es->workers_state)
3144 : 24 : ExplainOpenWorker(n, es);
3145 : :
2930 rhaas@postgresql.org 3146 [ + + ]: 24 : if (es->format == EXPLAIN_FORMAT_TEXT)
3147 : : {
2051 tgl@sss.pgh.pa.us 3148 : 12 : ExplainIndentText(es);
2930 rhaas@postgresql.org 3149 : 12 : appendStringInfo(es->str,
3150 : : "Sort Method: %s %s: " INT64_FORMAT "kB\n",
3151 : : sortMethod, spaceType, spaceUsed);
3152 : : }
3153 : : else
3154 : : {
3155 : 12 : ExplainPropertyText("Sort Method", sortMethod, es);
2731 andres@anarazel.de 3156 : 12 : ExplainPropertyInteger("Sort Space Used", "kB", spaceUsed, es);
2930 rhaas@postgresql.org 3157 : 12 : ExplainPropertyText("Sort Space Type", spaceType, es);
3158 : : }
3159 : :
2051 tgl@sss.pgh.pa.us 3160 [ + - ]: 24 : if (es->workers_state)
3161 : 24 : ExplainCloseWorker(n, es);
3162 : : }
3163 : : }
3164 : : }
3165 : :
3166 : : /*
3167 : : * Incremental sort nodes sort in (a potentially very large number of) batches,
3168 : : * so EXPLAIN ANALYZE needs to roll up the tuplesort stats from each batch into
3169 : : * an intelligible summary.
3170 : : *
3171 : : * This function is used for both a non-parallel node and each worker in a
3172 : : * parallel incremental sort node.
3173 : : */
3174 : : static void
1979 tomas.vondra@postgre 3175 : 27 : show_incremental_sort_group_info(IncrementalSortGroupInfo *groupInfo,
3176 : : const char *groupLabel, bool indent, ExplainState *es)
3177 : : {
3178 : : ListCell *methodCell;
3179 : 27 : List *methodNames = NIL;
3180 : :
3181 : : /* Generate a list of sort methods used across all groups. */
tgl@sss.pgh.pa.us 3182 [ + + ]: 135 : for (int bit = 0; bit < NUM_TUPLESORTMETHODS; bit++)
3183 : : {
3184 : 108 : TuplesortMethod sortMethod = (1 << bit);
3185 : :
3186 [ + + ]: 108 : if (groupInfo->sortMethods & sortMethod)
3187 : : {
3188 : 45 : const char *methodName = tuplesort_method_name(sortMethod);
3189 : :
tomas.vondra@postgre 3190 : 45 : methodNames = lappend(methodNames, unconstify(char *, methodName));
3191 : : }
3192 : : }
3193 : :
3194 [ + + ]: 27 : if (es->format == EXPLAIN_FORMAT_TEXT)
3195 : : {
3196 [ + - ]: 9 : if (indent)
3197 : 9 : appendStringInfoSpaces(es->str, es->indent * 2);
1943 3198 : 9 : appendStringInfo(es->str, "%s Groups: " INT64_FORMAT " Sort Method", groupLabel,
3199 : : groupInfo->groupCount);
3200 : : /* plural/singular based on methodNames size */
1979 3201 [ + + ]: 9 : if (list_length(methodNames) > 1)
1787 drowley@postgresql.o 3202 : 6 : appendStringInfoString(es->str, "s: ");
3203 : : else
3204 : 3 : appendStringInfoString(es->str, ": ");
1979 tomas.vondra@postgre 3205 [ + - + + : 24 : foreach(methodCell, methodNames)
+ + ]
3206 : : {
1787 drowley@postgresql.o 3207 : 15 : appendStringInfoString(es->str, (char *) methodCell->ptr_value);
1979 tomas.vondra@postgre 3208 [ + + ]: 15 : if (foreach_current_index(methodCell) < list_length(methodNames) - 1)
1787 drowley@postgresql.o 3209 : 6 : appendStringInfoString(es->str, ", ");
3210 : : }
3211 : :
1979 tomas.vondra@postgre 3212 [ + - ]: 9 : if (groupInfo->maxMemorySpaceUsed > 0)
3213 : : {
1861 drowley@postgresql.o 3214 : 9 : int64 avgSpace = groupInfo->totalMemorySpaceUsed / groupInfo->groupCount;
3215 : : const char *spaceTypeName;
3216 : :
1979 tomas.vondra@postgre 3217 : 9 : spaceTypeName = tuplesort_space_type_name(SORT_SPACE_TYPE_MEMORY);
1861 drowley@postgresql.o 3218 : 9 : appendStringInfo(es->str, " Average %s: " INT64_FORMAT "kB Peak %s: " INT64_FORMAT "kB",
3219 : : spaceTypeName, avgSpace,
3220 : : spaceTypeName, groupInfo->maxMemorySpaceUsed);
3221 : : }
3222 : :
1979 tomas.vondra@postgre 3223 [ - + ]: 9 : if (groupInfo->maxDiskSpaceUsed > 0)
3224 : : {
1861 drowley@postgresql.o 3225 :UBC 0 : int64 avgSpace = groupInfo->totalDiskSpaceUsed / groupInfo->groupCount;
3226 : :
3227 : : const char *spaceTypeName;
3228 : :
1979 tomas.vondra@postgre 3229 : 0 : spaceTypeName = tuplesort_space_type_name(SORT_SPACE_TYPE_DISK);
1861 drowley@postgresql.o 3230 : 0 : appendStringInfo(es->str, " Average %s: " INT64_FORMAT "kB Peak %s: " INT64_FORMAT "kB",
3231 : : spaceTypeName, avgSpace,
3232 : : spaceTypeName, groupInfo->maxDiskSpaceUsed);
3233 : : }
3234 : : }
3235 : : else
3236 : : {
3237 : : StringInfoData groupName;
3238 : :
1979 tomas.vondra@postgre 3239 :CBC 18 : initStringInfo(&groupName);
3240 : 18 : appendStringInfo(&groupName, "%s Groups", groupLabel);
3241 : 18 : ExplainOpenGroup("Incremental Sort Groups", groupName.data, true, es);
3242 : 18 : ExplainPropertyInteger("Group Count", NULL, groupInfo->groupCount, es);
3243 : :
3244 : 18 : ExplainPropertyList("Sort Methods Used", methodNames, es);
3245 : :
3246 [ + - ]: 18 : if (groupInfo->maxMemorySpaceUsed > 0)
3247 : : {
1861 drowley@postgresql.o 3248 : 18 : int64 avgSpace = groupInfo->totalMemorySpaceUsed / groupInfo->groupCount;
3249 : : const char *spaceTypeName;
3250 : : StringInfoData memoryName;
3251 : :
1979 tomas.vondra@postgre 3252 : 18 : spaceTypeName = tuplesort_space_type_name(SORT_SPACE_TYPE_MEMORY);
3253 : 18 : initStringInfo(&memoryName);
3254 : 18 : appendStringInfo(&memoryName, "Sort Space %s", spaceTypeName);
3255 : 18 : ExplainOpenGroup("Sort Space", memoryName.data, true, es);
3256 : :
3257 : 18 : ExplainPropertyInteger("Average Sort Space Used", "kB", avgSpace, es);
1978 3258 : 18 : ExplainPropertyInteger("Peak Sort Space Used", "kB",
3259 : : groupInfo->maxMemorySpaceUsed, es);
3260 : :
1779 tgl@sss.pgh.pa.us 3261 : 18 : ExplainCloseGroup("Sort Space", memoryName.data, true, es);
3262 : : }
1979 tomas.vondra@postgre 3263 [ - + ]: 18 : if (groupInfo->maxDiskSpaceUsed > 0)
3264 : : {
1861 drowley@postgresql.o 3265 :UBC 0 : int64 avgSpace = groupInfo->totalDiskSpaceUsed / groupInfo->groupCount;
3266 : : const char *spaceTypeName;
3267 : : StringInfoData diskName;
3268 : :
1979 tomas.vondra@postgre 3269 : 0 : spaceTypeName = tuplesort_space_type_name(SORT_SPACE_TYPE_DISK);
3270 : 0 : initStringInfo(&diskName);
3271 : 0 : appendStringInfo(&diskName, "Sort Space %s", spaceTypeName);
3272 : 0 : ExplainOpenGroup("Sort Space", diskName.data, true, es);
3273 : :
3274 : 0 : ExplainPropertyInteger("Average Sort Space Used", "kB", avgSpace, es);
1978 3275 : 0 : ExplainPropertyInteger("Peak Sort Space Used", "kB",
3276 : : groupInfo->maxDiskSpaceUsed, es);
3277 : :
1779 tgl@sss.pgh.pa.us 3278 : 0 : ExplainCloseGroup("Sort Space", diskName.data, true, es);
3279 : : }
3280 : :
1979 tomas.vondra@postgre 3281 :CBC 18 : ExplainCloseGroup("Incremental Sort Groups", groupName.data, true, es);
3282 : : }
3283 : 27 : }
3284 : :
3285 : : /*
3286 : : * If it's EXPLAIN ANALYZE, show tuplesort stats for an incremental sort node
3287 : : */
3288 : : static void
3289 : 187 : show_incremental_sort_info(IncrementalSortState *incrsortstate,
3290 : : ExplainState *es)
3291 : : {
3292 : : IncrementalSortGroupInfo *fullsortGroupInfo;
3293 : : IncrementalSortGroupInfo *prefixsortGroupInfo;
3294 : :
3295 : 187 : fullsortGroupInfo = &incrsortstate->incsort_info.fullsortGroupInfo;
3296 : :
3297 [ + + ]: 187 : if (!es->analyze)
3298 : 169 : return;
3299 : :
3300 : : /*
3301 : : * Since we never have any prefix groups unless we've first sorted a full
3302 : : * groups and transitioned modes (copying the tuples into a prefix group),
3303 : : * we don't need to do anything if there were 0 full groups.
3304 : : *
3305 : : * We still have to continue after this block if there are no full groups,
3306 : : * though, since it's possible that we have workers that did real work
3307 : : * even if the leader didn't participate.
3308 : : */
3309 [ + - ]: 18 : if (fullsortGroupInfo->groupCount > 0)
3310 : : {
3311 : 18 : show_incremental_sort_group_info(fullsortGroupInfo, "Full-sort", true, es);
3312 : 18 : prefixsortGroupInfo = &incrsortstate->incsort_info.prefixsortGroupInfo;
3313 [ + + ]: 18 : if (prefixsortGroupInfo->groupCount > 0)
3314 : : {
3315 [ + + ]: 9 : if (es->format == EXPLAIN_FORMAT_TEXT)
1787 drowley@postgresql.o 3316 : 3 : appendStringInfoChar(es->str, '\n');
1943 tomas.vondra@postgre 3317 : 9 : show_incremental_sort_group_info(prefixsortGroupInfo, "Pre-sorted", true, es);
3318 : : }
1979 3319 [ + + ]: 18 : if (es->format == EXPLAIN_FORMAT_TEXT)
1787 drowley@postgresql.o 3320 : 6 : appendStringInfoChar(es->str, '\n');
3321 : : }
3322 : :
1979 tomas.vondra@postgre 3323 [ - + ]: 18 : if (incrsortstate->shared_info != NULL)
3324 : : {
3325 : : int n;
3326 : : bool indent_first_line;
3327 : :
1979 tomas.vondra@postgre 3328 [ # # ]:UBC 0 : for (n = 0; n < incrsortstate->shared_info->num_workers; n++)
3329 : : {
3330 : 0 : IncrementalSortInfo *incsort_info =
841 tgl@sss.pgh.pa.us 3331 : 0 : &incrsortstate->shared_info->sinfo[n];
3332 : :
3333 : : /*
3334 : : * If a worker hasn't processed any sort groups at all, then
3335 : : * exclude it from output since it either didn't launch or didn't
3336 : : * contribute anything meaningful.
3337 : : */
1979 tomas.vondra@postgre 3338 : 0 : fullsortGroupInfo = &incsort_info->fullsortGroupInfo;
3339 : :
3340 : : /*
3341 : : * Since we never have any prefix groups unless we've first sorted
3342 : : * a full groups and transitioned modes (copying the tuples into a
3343 : : * prefix group), we don't need to do anything if there were 0
3344 : : * full groups.
3345 : : */
1946 3346 [ # # ]: 0 : if (fullsortGroupInfo->groupCount == 0)
1979 3347 : 0 : continue;
3348 : :
3349 [ # # ]: 0 : if (es->workers_state)
3350 : 0 : ExplainOpenWorker(n, es);
3351 : :
3352 [ # # # # ]: 0 : indent_first_line = es->workers_state == NULL || es->verbose;
3353 : 0 : show_incremental_sort_group_info(fullsortGroupInfo, "Full-sort",
3354 : : indent_first_line, es);
1946 3355 : 0 : prefixsortGroupInfo = &incsort_info->prefixsortGroupInfo;
1979 3356 [ # # ]: 0 : if (prefixsortGroupInfo->groupCount > 0)
3357 : : {
3358 [ # # ]: 0 : if (es->format == EXPLAIN_FORMAT_TEXT)
1787 drowley@postgresql.o 3359 : 0 : appendStringInfoChar(es->str, '\n');
1943 tomas.vondra@postgre 3360 : 0 : show_incremental_sort_group_info(prefixsortGroupInfo, "Pre-sorted", true, es);
3361 : : }
1979 3362 [ # # ]: 0 : if (es->format == EXPLAIN_FORMAT_TEXT)
1787 drowley@postgresql.o 3363 : 0 : appendStringInfoChar(es->str, '\n');
3364 : :
1979 tomas.vondra@postgre 3365 [ # # ]: 0 : if (es->workers_state)
3366 : 0 : ExplainCloseWorker(n, es);
3367 : : }
3368 : : }
3369 : : }
3370 : :
3371 : : /*
3372 : : * Show information on hash buckets/batches.
3373 : : */
3374 : : static void
5696 rhaas@postgresql.org 3375 :CBC 1927 : show_hash_info(HashState *hashstate, ExplainState *es)
3376 : : {
2805 andres@anarazel.de 3377 : 1927 : HashInstrumentation hinstrument = {0};
3378 : :
3379 : : /*
3380 : : * Collect stats from the local process, even when it's a parallel query.
3381 : : * In a parallel query, the leader process may or may not have run the
3382 : : * hash join, and even if it did it may not have built a hash table due to
3383 : : * timing (if it started late it might have seen no tuples in the outer
3384 : : * relation and skipped building the hash table). Therefore we have to be
3385 : : * prepared to get instrumentation data from all participants.
3386 : : */
1974 tgl@sss.pgh.pa.us 3387 [ + + ]: 1927 : if (hashstate->hinstrument)
3388 : 57 : memcpy(&hinstrument, hashstate->hinstrument,
3389 : : sizeof(HashInstrumentation));
3390 : :
3391 : : /*
3392 : : * Merge results from workers. In the parallel-oblivious case, the
3393 : : * results from all participants should be identical, except where
3394 : : * participants didn't run the join at all so have no data. In the
3395 : : * parallel-aware case, we need to consider all the results. Each worker
3396 : : * may have seen a different subset of batches and we want to report the
3397 : : * highest memory usage across all batches. We take the maxima of other
3398 : : * values too, for the same reasons as in ExecHashAccumInstrumentation.
3399 : : */
2805 andres@anarazel.de 3400 [ + + ]: 1927 : if (hashstate->shared_info)
3401 : : {
2832 3402 : 42 : SharedHashInfo *shared_info = hashstate->shared_info;
3403 : : int i;
3404 : :
3405 [ + + ]: 120 : for (i = 0; i < shared_info->num_workers; ++i)
3406 : : {
2805 3407 : 78 : HashInstrumentation *worker_hi = &shared_info->hinstrument[i];
3408 : :
1974 tgl@sss.pgh.pa.us 3409 : 78 : hinstrument.nbuckets = Max(hinstrument.nbuckets,
3410 : : worker_hi->nbuckets);
3411 : 78 : hinstrument.nbuckets_original = Max(hinstrument.nbuckets_original,
3412 : : worker_hi->nbuckets_original);
3413 : 78 : hinstrument.nbatch = Max(hinstrument.nbatch,
3414 : : worker_hi->nbatch);
3415 : 78 : hinstrument.nbatch_original = Max(hinstrument.nbatch_original,
3416 : : worker_hi->nbatch_original);
3417 : 78 : hinstrument.space_peak = Max(hinstrument.space_peak,
3418 : : worker_hi->space_peak);
3419 : : }
3420 : : }
3421 : :
2805 andres@anarazel.de 3422 [ + + ]: 1927 : if (hinstrument.nbatch > 0)
3423 : : {
478 drowley@postgresql.o 3424 : 57 : uint64 spacePeakKb = BYTES_TO_KILOBYTES(hinstrument.space_peak);
3425 : :
5696 rhaas@postgresql.org 3426 [ + + ]: 57 : if (es->format != EXPLAIN_FORMAT_TEXT)
3427 : : {
2731 andres@anarazel.de 3428 : 54 : ExplainPropertyInteger("Hash Buckets", NULL,
3429 : 54 : hinstrument.nbuckets, es);
3430 : 54 : ExplainPropertyInteger("Original Hash Buckets", NULL,
3431 : 54 : hinstrument.nbuckets_original, es);
3432 : 54 : ExplainPropertyInteger("Hash Batches", NULL,
3433 : 54 : hinstrument.nbatch, es);
3434 : 54 : ExplainPropertyInteger("Original Hash Batches", NULL,
3435 : 54 : hinstrument.nbatch_original, es);
478 drowley@postgresql.o 3436 : 54 : ExplainPropertyUInteger("Peak Memory Usage", "kB",
3437 : : spacePeakKb, es);
3438 : : }
2805 andres@anarazel.de 3439 [ + - ]: 3 : else if (hinstrument.nbatch_original != hinstrument.nbatch ||
3440 [ - + ]: 3 : hinstrument.nbuckets_original != hinstrument.nbuckets)
3441 : : {
2051 tgl@sss.pgh.pa.us 3442 :UBC 0 : ExplainIndentText(es);
5696 rhaas@postgresql.org 3443 : 0 : appendStringInfo(es->str,
3444 : : "Buckets: %d (originally %d) Batches: %d (originally %d) Memory Usage: " UINT64_FORMAT "kB\n",
3445 : : hinstrument.nbuckets,
3446 : : hinstrument.nbuckets_original,
3447 : : hinstrument.nbatch,
3448 : : hinstrument.nbatch_original,
3449 : : spacePeakKb);
3450 : : }
3451 : : else
3452 : : {
2051 tgl@sss.pgh.pa.us 3453 :CBC 3 : ExplainIndentText(es);
5696 rhaas@postgresql.org 3454 : 3 : appendStringInfo(es->str,
3455 : : "Buckets: %d Batches: %d Memory Usage: " UINT64_FORMAT "kB\n",
3456 : : hinstrument.nbuckets, hinstrument.nbatch,
3457 : : spacePeakKb);
3458 : : }
3459 : : }
3460 : 1927 : }
3461 : :
3462 : : /*
3463 : : * Show information on material node, storage method and maximum memory/disk
3464 : : * space used.
3465 : : */
3466 : : static void
428 drowley@postgresql.o 3467 : 550 : show_material_info(MaterialState *mstate, ExplainState *es)
3468 : : {
3469 : : char *maxStorageType;
3470 : : int64 maxSpaceUsed;
3471 : :
3472 : 550 : Tuplestorestate *tupstore = mstate->tuplestorestate;
3473 : :
3474 : : /*
3475 : : * Nothing to show if ANALYZE option wasn't used or if execution didn't
3476 : : * get as far as creating the tuplestore.
3477 : : */
3478 [ + + - + ]: 550 : if (!es->analyze || tupstore == NULL)
3479 : 544 : return;
3480 : :
348 ishii@postgresql.org 3481 : 6 : tuplestore_get_stats(tupstore, &maxStorageType, &maxSpaceUsed);
3482 : 6 : show_storage_info(maxStorageType, maxSpaceUsed, es);
3483 : : }
3484 : :
3485 : : /*
3486 : : * Show information on WindowAgg node, storage method and maximum memory/disk
3487 : : * space used.
3488 : : */
3489 : : static void
354 3490 : 229 : show_windowagg_info(WindowAggState *winstate, ExplainState *es)
3491 : : {
3492 : : char *maxStorageType;
3493 : : int64 maxSpaceUsed;
3494 : :
3495 : 229 : Tuplestorestate *tupstore = winstate->buffer;
3496 : :
3497 : : /*
3498 : : * Nothing to show if ANALYZE option wasn't used or if execution didn't
3499 : : * get as far as creating the tuplestore.
3500 : : */
3501 [ + + - + ]: 229 : if (!es->analyze || tupstore == NULL)
3502 : 220 : return;
3503 : :
348 3504 : 9 : tuplestore_get_stats(tupstore, &maxStorageType, &maxSpaceUsed);
3505 : 9 : show_storage_info(maxStorageType, maxSpaceUsed, es);
3506 : : }
3507 : :
3508 : : /*
3509 : : * Show information on CTE Scan node, storage method and maximum memory/disk
3510 : : * space used.
3511 : : */
3512 : : static void
3513 : 125 : show_ctescan_info(CteScanState *ctescanstate, ExplainState *es)
3514 : : {
3515 : : char *maxStorageType;
3516 : : int64 maxSpaceUsed;
3517 : :
3518 : 125 : Tuplestorestate *tupstore = ctescanstate->leader->cte_table;
3519 : :
3520 [ - + - - ]: 125 : if (!es->analyze || tupstore == NULL)
3521 : 125 : return;
3522 : :
348 ishii@postgresql.org 3523 :UBC 0 : tuplestore_get_stats(tupstore, &maxStorageType, &maxSpaceUsed);
3524 : 0 : show_storage_info(maxStorageType, maxSpaceUsed, es);
3525 : : }
3526 : :
3527 : : /*
3528 : : * Show information on Table Function Scan node, storage method and maximum
3529 : : * memory/disk space used.
3530 : : */
3531 : : static void
348 ishii@postgresql.org 3532 :CBC 39 : show_table_func_scan_info(TableFuncScanState *tscanstate, ExplainState *es)
3533 : : {
3534 : : char *maxStorageType;
3535 : : int64 maxSpaceUsed;
3536 : :
3537 : 39 : Tuplestorestate *tupstore = tscanstate->tupstore;
3538 : :
3539 [ - + - - ]: 39 : if (!es->analyze || tupstore == NULL)
3540 : 39 : return;
3541 : :
348 ishii@postgresql.org 3542 :UBC 0 : tuplestore_get_stats(tupstore, &maxStorageType, &maxSpaceUsed);
3543 : 0 : show_storage_info(maxStorageType, maxSpaceUsed, es);
3544 : : }
3545 : :
3546 : : /*
3547 : : * Show information on Recursive Union node, storage method and maximum
3548 : : * memory/disk space used.
3549 : : */
3550 : : static void
348 ishii@postgresql.org 3551 :CBC 27 : show_recursive_union_info(RecursiveUnionState *rstate, ExplainState *es)
3552 : : {
3553 : : char *maxStorageType,
3554 : : *tempStorageType;
3555 : : int64 maxSpaceUsed,
3556 : : tempSpaceUsed;
3557 : :
3558 [ + - ]: 27 : if (!es->analyze)
3559 : 27 : return;
3560 : :
3561 : : /*
3562 : : * Recursive union node uses two tuplestores. We employ the storage type
3563 : : * from one of them which consumed more memory/disk than the other. The
3564 : : * storage size is sum of the two.
3565 : : */
348 ishii@postgresql.org 3566 :UBC 0 : tuplestore_get_stats(rstate->working_table, &tempStorageType,
3567 : : &tempSpaceUsed);
3568 : 0 : tuplestore_get_stats(rstate->intermediate_table, &maxStorageType,
3569 : : &maxSpaceUsed);
3570 : :
3571 [ # # ]: 0 : if (tempSpaceUsed > maxSpaceUsed)
3572 : 0 : maxStorageType = tempStorageType;
3573 : :
3574 : 0 : maxSpaceUsed += tempSpaceUsed;
3575 : 0 : show_storage_info(maxStorageType, maxSpaceUsed, es);
3576 : : }
3577 : :
3578 : : /*
3579 : : * Show information on memoize hits/misses/evictions and memory usage.
3580 : : */
3581 : : static void
1515 drowley@postgresql.o 3582 :CBC 186 : show_memoize_info(MemoizeState *mstate, List *ancestors, ExplainState *es)
3583 : : {
3584 : 186 : Plan *plan = ((PlanState *) mstate)->plan;
39 drowley@postgresql.o 3585 :GNC 186 : Memoize *mplan = (Memoize *) plan;
3586 : : ListCell *lc;
3587 : : List *context;
3588 : : StringInfoData keystr;
1271 michael@paquier.xyz 3589 :CBC 186 : char *separator = "";
3590 : : bool useprefix;
3591 : : int64 memPeakKb;
3592 : :
1618 drowley@postgresql.o 3593 : 186 : initStringInfo(&keystr);
3594 : :
3595 : : /*
3596 : : * It's hard to imagine having a memoize node with fewer than 2 RTEs, but
3597 : : * let's just keep the same useprefix logic as elsewhere in this file.
3598 : : */
361 rguo@postgresql.org 3599 [ - + - - ]: 186 : useprefix = es->rtable_size > 1 || es->verbose;
3600 : :
3601 : : /* Set up deparsing context */
1618 drowley@postgresql.o 3602 : 186 : context = set_deparse_context_plan(es->deparse_cxt,
3603 : : plan,
3604 : : ancestors);
3605 : :
39 drowley@postgresql.o 3606 [ + - + + :GNC 390 : foreach(lc, mplan->param_exprs)
+ + ]
3607 : : {
1618 drowley@postgresql.o 3608 :CBC 204 : Node *expr = (Node *) lfirst(lc);
3609 : :
1271 michael@paquier.xyz 3610 : 204 : appendStringInfoString(&keystr, separator);
3611 : :
1618 drowley@postgresql.o 3612 : 204 : appendStringInfoString(&keystr, deparse_expression(expr, context,
3613 : : useprefix, false));
1271 michael@paquier.xyz 3614 : 204 : separator = ", ";
3615 : : }
3616 : :
169 drowley@postgresql.o 3617 : 186 : ExplainPropertyText("Cache Key", keystr.data, es);
3618 [ + + ]: 186 : ExplainPropertyText("Cache Mode", mstate->binary_mode ? "binary" : "logical", es);
3619 : :
1618 3620 : 186 : pfree(keystr.data);
3621 : :
39 drowley@postgresql.o 3622 [ + + ]:GNC 186 : if (es->costs)
3623 : : {
3624 [ + - ]: 58 : if (es->format == EXPLAIN_FORMAT_TEXT)
3625 : : {
3626 : 58 : ExplainIndentText(es);
3627 : 58 : appendStringInfo(es->str, "Estimates: capacity=%u distinct keys=%.0f lookups=%.0f hit percent=%.2f%%\n",
3628 : : mplan->est_entries, mplan->est_unique_keys,
3629 : 58 : mplan->est_calls, mplan->est_hit_ratio * 100.0);
3630 : : }
3631 : : else
3632 : : {
39 drowley@postgresql.o 3633 :UNC 0 : ExplainPropertyUInteger("Estimated Capacity", NULL, mplan->est_entries, es);
3634 : 0 : ExplainPropertyFloat("Estimated Distinct Lookup Keys", NULL, mplan->est_unique_keys, 0, es);
3635 : 0 : ExplainPropertyFloat("Estimated Lookups", NULL, mplan->est_calls, 0, es);
3636 : 0 : ExplainPropertyFloat("Estimated Hit Percent", NULL, mplan->est_hit_ratio * 100.0, 2, es);
3637 : : }
3638 : : }
3639 : :
1618 drowley@postgresql.o 3640 [ + + ]:CBC 186 : if (!es->analyze)
3641 : 186 : return;
3642 : :
1515 3643 [ + - ]: 45 : if (mstate->stats.cache_misses > 0)
3644 : : {
3645 : : /*
3646 : : * mem_peak is only set when we freed memory, so we must use mem_used
3647 : : * when mem_peak is 0.
3648 : : */
3649 [ + + ]: 45 : if (mstate->stats.mem_peak > 0)
478 3650 : 3 : memPeakKb = BYTES_TO_KILOBYTES(mstate->stats.mem_peak);
3651 : : else
3652 : 42 : memPeakKb = BYTES_TO_KILOBYTES(mstate->mem_used);
3653 : :
1618 3654 [ - + ]: 45 : if (es->format != EXPLAIN_FORMAT_TEXT)
3655 : : {
1515 drowley@postgresql.o 3656 :UBC 0 : ExplainPropertyInteger("Cache Hits", NULL, mstate->stats.cache_hits, es);
3657 : 0 : ExplainPropertyInteger("Cache Misses", NULL, mstate->stats.cache_misses, es);
3658 : 0 : ExplainPropertyInteger("Cache Evictions", NULL, mstate->stats.cache_evictions, es);
3659 : 0 : ExplainPropertyInteger("Cache Overflows", NULL, mstate->stats.cache_overflows, es);
1618 3660 : 0 : ExplainPropertyInteger("Peak Memory Usage", "kB", memPeakKb, es);
3661 : : }
3662 : : else
3663 : : {
1618 drowley@postgresql.o 3664 :CBC 45 : ExplainIndentText(es);
3665 : 45 : appendStringInfo(es->str,
3666 : : "Hits: " UINT64_FORMAT " Misses: " UINT64_FORMAT " Evictions: " UINT64_FORMAT " Overflows: " UINT64_FORMAT " Memory Usage: " INT64_FORMAT "kB\n",
3667 : : mstate->stats.cache_hits,
3668 : : mstate->stats.cache_misses,
3669 : : mstate->stats.cache_evictions,
3670 : : mstate->stats.cache_overflows,
3671 : : memPeakKb);
3672 : : }
3673 : : }
3674 : :
1515 3675 [ + - ]: 45 : if (mstate->shared_info == NULL)
1618 3676 : 45 : return;
3677 : :
3678 : : /* Show details from parallel workers */
1515 drowley@postgresql.o 3679 [ # # ]:UBC 0 : for (int n = 0; n < mstate->shared_info->num_workers; n++)
3680 : : {
3681 : : MemoizeInstrumentation *si;
3682 : :
3683 : 0 : si = &mstate->shared_info->sinstrument[n];
3684 : :
3685 : : /*
3686 : : * Skip workers that didn't do any work. We needn't bother checking
3687 : : * for cache hits as a miss will always occur before a cache hit.
3688 : : */
1590 3689 [ # # ]: 0 : if (si->cache_misses == 0)
3690 : 0 : continue;
3691 : :
1618 3692 [ # # ]: 0 : if (es->workers_state)
3693 : 0 : ExplainOpenWorker(n, es);
3694 : :
3695 : : /*
3696 : : * Since the worker's MemoizeState.mem_used field is unavailable to
3697 : : * us, ExecEndMemoize will have set the
3698 : : * MemoizeInstrumentation.mem_peak field for us. No need to do the
3699 : : * zero checks like we did for the serial case above.
3700 : : */
478 3701 : 0 : memPeakKb = BYTES_TO_KILOBYTES(si->mem_peak);
3702 : :
1618 3703 [ # # ]: 0 : if (es->format == EXPLAIN_FORMAT_TEXT)
3704 : : {
3705 : 0 : ExplainIndentText(es);
3706 : 0 : appendStringInfo(es->str,
3707 : : "Hits: " UINT64_FORMAT " Misses: " UINT64_FORMAT " Evictions: " UINT64_FORMAT " Overflows: " UINT64_FORMAT " Memory Usage: " INT64_FORMAT "kB\n",
3708 : : si->cache_hits, si->cache_misses,
3709 : : si->cache_evictions, si->cache_overflows,
3710 : : memPeakKb);
3711 : : }
3712 : : else
3713 : : {
3714 : 0 : ExplainPropertyInteger("Cache Hits", NULL,
3715 : 0 : si->cache_hits, es);
3716 : 0 : ExplainPropertyInteger("Cache Misses", NULL,
3717 : 0 : si->cache_misses, es);
3718 : 0 : ExplainPropertyInteger("Cache Evictions", NULL,
3719 : 0 : si->cache_evictions, es);
3720 : 0 : ExplainPropertyInteger("Cache Overflows", NULL,
3721 : 0 : si->cache_overflows, es);
3722 : 0 : ExplainPropertyInteger("Peak Memory Usage", "kB", memPeakKb,
3723 : : es);
3724 : : }
3725 : :
3726 [ # # ]: 0 : if (es->workers_state)
3727 : 0 : ExplainCloseWorker(n, es);
3728 : : }
3729 : : }
3730 : :
3731 : : /*
3732 : : * Show information on hash aggregate memory usage and batches.
3733 : : */
3734 : : static void
1998 jdavis@postgresql.or 3735 :CBC 4851 : show_hashagg_info(AggState *aggstate, ExplainState *es)
3736 : : {
1941 tgl@sss.pgh.pa.us 3737 : 4851 : Agg *agg = (Agg *) aggstate->ss.ps.plan;
478 drowley@postgresql.o 3738 : 4851 : int64 memPeakKb = BYTES_TO_KILOBYTES(aggstate->hash_mem_peak);
3739 : :
1998 jdavis@postgresql.or 3740 [ + + ]: 4851 : if (agg->aggstrategy != AGG_HASHED &&
3741 [ + + ]: 3945 : agg->aggstrategy != AGG_MIXED)
3742 : 3898 : return;
3743 : :
1905 drowley@postgresql.o 3744 [ - + ]: 953 : if (es->format != EXPLAIN_FORMAT_TEXT)
3745 : : {
1865 drowley@postgresql.o 3746 [ # # ]:UBC 0 : if (es->costs)
1905 3747 : 0 : ExplainPropertyInteger("Planned Partitions", NULL,
3748 : 0 : aggstate->hash_planned_partitions, es);
3749 : :
3750 : : /*
3751 : : * During parallel query the leader may have not helped out. We
3752 : : * detect this by checking how much memory it used. If we find it
3753 : : * didn't do any work then we don't show its properties.
3754 : : */
1856 3755 [ # # # # ]: 0 : if (es->analyze && aggstate->hash_mem_peak > 0)
3756 : : {
3757 : 0 : ExplainPropertyInteger("HashAgg Batches", NULL,
3758 : 0 : aggstate->hash_batches_used, es);
3759 : 0 : ExplainPropertyInteger("Peak Memory Usage", "kB", memPeakKb, es);
3760 : 0 : ExplainPropertyInteger("Disk Usage", "kB",
3761 : 0 : aggstate->hash_disk_used, es);
3762 : : }
3763 : : }
3764 : : else
3765 : : {
1905 drowley@postgresql.o 3766 :CBC 953 : bool gotone = false;
3767 : :
3768 [ + + - + ]: 953 : if (es->costs && aggstate->hash_planned_partitions > 0)
3769 : : {
1905 drowley@postgresql.o 3770 :UBC 0 : ExplainIndentText(es);
3771 : 0 : appendStringInfo(es->str, "Planned Partitions: %d",
3772 : : aggstate->hash_planned_partitions);
3773 : 0 : gotone = true;
3774 : : }
3775 : :
3776 : : /*
3777 : : * During parallel query the leader may have not helped out. We
3778 : : * detect this by checking how much memory it used. If we find it
3779 : : * didn't do any work then we don't show its properties.
3780 : : */
1856 drowley@postgresql.o 3781 [ + + + - ]:CBC 953 : if (es->analyze && aggstate->hash_mem_peak > 0)
3782 : : {
3783 [ + - ]: 291 : if (!gotone)
3784 : 291 : ExplainIndentText(es);
3785 : : else
960 drowley@postgresql.o 3786 :UBC 0 : appendStringInfoSpaces(es->str, 2);
3787 : :
1856 drowley@postgresql.o 3788 :CBC 291 : appendStringInfo(es->str, "Batches: %d Memory Usage: " INT64_FORMAT "kB",
3789 : : aggstate->hash_batches_used, memPeakKb);
3790 : 291 : gotone = true;
3791 : :
3792 : : /* Only display disk usage if we spilled to disk */
3793 [ - + ]: 291 : if (aggstate->hash_batches_used > 1)
3794 : : {
1856 drowley@postgresql.o 3795 :UBC 0 : appendStringInfo(es->str, " Disk Usage: " UINT64_FORMAT "kB",
3796 : : aggstate->hash_disk_used);
3797 : : }
3798 : : }
3799 : :
1856 drowley@postgresql.o 3800 [ + + ]:CBC 953 : if (gotone)
3801 : 291 : appendStringInfoChar(es->str, '\n');
3802 : : }
3803 : :
3804 : : /* Display stats for each parallel worker */
1905 3805 [ + + - + ]: 953 : if (es->analyze && aggstate->shared_info != NULL)
3806 : : {
1905 drowley@postgresql.o 3807 [ # # ]:UBC 0 : for (int n = 0; n < aggstate->shared_info->num_workers; n++)
3808 : : {
3809 : : AggregateInstrumentation *sinstrument;
3810 : : uint64 hash_disk_used;
3811 : : int hash_batches_used;
3812 : :
3813 : 0 : sinstrument = &aggstate->shared_info->sinstrument[n];
3814 : : /* Skip workers that didn't do anything */
1856 3815 [ # # ]: 0 : if (sinstrument->hash_mem_peak == 0)
3816 : 0 : continue;
1905 3817 : 0 : hash_disk_used = sinstrument->hash_disk_used;
3818 : 0 : hash_batches_used = sinstrument->hash_batches_used;
478 3819 : 0 : memPeakKb = BYTES_TO_KILOBYTES(sinstrument->hash_mem_peak);
3820 : :
1905 3821 [ # # ]: 0 : if (es->workers_state)
3822 : 0 : ExplainOpenWorker(n, es);
3823 : :
3824 [ # # ]: 0 : if (es->format == EXPLAIN_FORMAT_TEXT)
3825 : : {
3826 : 0 : ExplainIndentText(es);
3827 : :
1865 3828 : 0 : appendStringInfo(es->str, "Batches: %d Memory Usage: " INT64_FORMAT "kB",
3829 : : hash_batches_used, memPeakKb);
3830 : :
3831 : : /* Only display disk usage if we spilled to disk */
3832 [ # # ]: 0 : if (hash_batches_used > 1)
3833 : 0 : appendStringInfo(es->str, " Disk Usage: " UINT64_FORMAT "kB",
3834 : : hash_disk_used);
1905 3835 : 0 : appendStringInfoChar(es->str, '\n');
3836 : : }
3837 : : else
3838 : : {
1865 3839 : 0 : ExplainPropertyInteger("HashAgg Batches", NULL,
3840 : : hash_batches_used, es);
1905 3841 : 0 : ExplainPropertyInteger("Peak Memory Usage", "kB", memPeakKb,
3842 : : es);
1893 3843 : 0 : ExplainPropertyInteger("Disk Usage", "kB", hash_disk_used, es);
3844 : : }
3845 : :
1905 3846 [ # # ]: 0 : if (es->workers_state)
3847 : 0 : ExplainCloseWorker(n, es);
3848 : : }
3849 : : }
3850 : : }
3851 : :
3852 : : /*
3853 : : * Show the total number of index searches for a
3854 : : * IndexScan/IndexOnlyScan/BitmapIndexScan node
3855 : : */
3856 : : static void
179 pg@bowt.ie 3857 :CBC 5591 : show_indexsearches_info(PlanState *planstate, ExplainState *es)
3858 : : {
3859 : 5591 : Plan *plan = planstate->plan;
3860 : 5591 : SharedIndexScanInstrumentation *SharedInfo = NULL;
3861 : 5591 : uint64 nsearches = 0;
3862 : :
3863 [ + + ]: 5591 : if (!es->analyze)
3864 : 4933 : return;
3865 : :
3866 : : /* Initialize counters with stats from the local process first */
3867 [ + + + - ]: 658 : switch (nodeTag(plan))
3868 : : {
3869 : 336 : case T_IndexScan:
3870 : : {
3871 : 336 : IndexScanState *indexstate = ((IndexScanState *) planstate);
3872 : :
3873 : 336 : nsearches = indexstate->iss_Instrument.nsearches;
3874 : 336 : SharedInfo = indexstate->iss_SharedInfo;
3875 : 336 : break;
3876 : : }
3877 : 68 : case T_IndexOnlyScan:
3878 : : {
3879 : 68 : IndexOnlyScanState *indexstate = ((IndexOnlyScanState *) planstate);
3880 : :
3881 : 68 : nsearches = indexstate->ioss_Instrument.nsearches;
3882 : 68 : SharedInfo = indexstate->ioss_SharedInfo;
3883 : 68 : break;
3884 : : }
3885 : 254 : case T_BitmapIndexScan:
3886 : : {
3887 : 254 : BitmapIndexScanState *indexstate = ((BitmapIndexScanState *) planstate);
3888 : :
3889 : 254 : nsearches = indexstate->biss_Instrument.nsearches;
3890 : 254 : SharedInfo = indexstate->biss_SharedInfo;
3891 : 254 : break;
3892 : : }
179 pg@bowt.ie 3893 :UBC 0 : default:
3894 : 0 : break;
3895 : : }
3896 : :
3897 : : /* Next get the sum of the counters set within each and every process */
179 pg@bowt.ie 3898 [ + + ]:CBC 658 : if (SharedInfo)
3899 : : {
3900 [ + + ]: 270 : for (int i = 0; i < SharedInfo->num_workers; ++i)
3901 : : {
3902 : 135 : IndexScanInstrumentation *winstrument = &SharedInfo->winstrument[i];
3903 : :
3904 : 135 : nsearches += winstrument->nsearches;
3905 : : }
3906 : : }
3907 : :
3908 : 658 : ExplainPropertyUInteger("Index Searches", NULL, nsearches, es);
3909 : : }
3910 : :
3911 : : /*
3912 : : * Show exact/lossy pages for a BitmapHeapScan node
3913 : : */
3914 : : static void
4254 rhaas@postgresql.org 3915 : 2055 : show_tidbitmap_info(BitmapHeapScanState *planstate, ExplainState *es)
3916 : : {
424 drowley@postgresql.o 3917 [ + + ]: 2055 : if (!es->analyze)
3918 : 1804 : return;
3919 : :
4254 rhaas@postgresql.org 3920 [ + + ]: 251 : if (es->format != EXPLAIN_FORMAT_TEXT)
3921 : : {
425 drowley@postgresql.o 3922 : 30 : ExplainPropertyUInteger("Exact Heap Blocks", NULL,
3923 : : planstate->stats.exact_pages, es);
3924 : 30 : ExplainPropertyUInteger("Lossy Heap Blocks", NULL,
3925 : : planstate->stats.lossy_pages, es);
3926 : : }
3927 : : else
3928 : : {
424 3929 [ + + - + ]: 221 : if (planstate->stats.exact_pages > 0 || planstate->stats.lossy_pages > 0)
3930 : : {
2051 tgl@sss.pgh.pa.us 3931 : 143 : ExplainIndentText(es);
4072 fujii@postgresql.org 3932 : 143 : appendStringInfoString(es->str, "Heap Blocks:");
424 drowley@postgresql.o 3933 [ + - ]: 143 : if (planstate->stats.exact_pages > 0)
3934 : 143 : appendStringInfo(es->str, " exact=" UINT64_FORMAT, planstate->stats.exact_pages);
3935 [ - + ]: 143 : if (planstate->stats.lossy_pages > 0)
424 drowley@postgresql.o 3936 :UBC 0 : appendStringInfo(es->str, " lossy=" UINT64_FORMAT, planstate->stats.lossy_pages);
4072 fujii@postgresql.org 3937 :CBC 143 : appendStringInfoChar(es->str, '\n');
3938 : : }
3939 : : }
3940 : :
3941 : : /* Display stats for each parallel worker */
424 drowley@postgresql.o 3942 [ - + ]: 251 : if (planstate->pstate != NULL)
3943 : : {
424 drowley@postgresql.o 3944 [ # # ]:UBC 0 : for (int n = 0; n < planstate->sinstrument->num_workers; n++)
3945 : : {
3946 : 0 : BitmapHeapScanInstrumentation *si = &planstate->sinstrument->sinstrument[n];
3947 : :
3948 [ # # # # ]: 0 : if (si->exact_pages == 0 && si->lossy_pages == 0)
3949 : 0 : continue;
3950 : :
3951 [ # # ]: 0 : if (es->workers_state)
3952 : 0 : ExplainOpenWorker(n, es);
3953 : :
3954 [ # # ]: 0 : if (es->format == EXPLAIN_FORMAT_TEXT)
3955 : : {
3956 : 0 : ExplainIndentText(es);
3957 : 0 : appendStringInfoString(es->str, "Heap Blocks:");
3958 [ # # ]: 0 : if (si->exact_pages > 0)
3959 : 0 : appendStringInfo(es->str, " exact=" UINT64_FORMAT, si->exact_pages);
3960 [ # # ]: 0 : if (si->lossy_pages > 0)
3961 : 0 : appendStringInfo(es->str, " lossy=" UINT64_FORMAT, si->lossy_pages);
3962 : 0 : appendStringInfoChar(es->str, '\n');
3963 : : }
3964 : : else
3965 : : {
3966 : 0 : ExplainPropertyUInteger("Exact Heap Blocks", NULL,
3967 : : si->exact_pages, es);
3968 : 0 : ExplainPropertyUInteger("Lossy Heap Blocks", NULL,
3969 : : si->lossy_pages, es);
3970 : : }
3971 : :
3972 [ # # ]: 0 : if (es->workers_state)
3973 : 0 : ExplainCloseWorker(n, es);
3974 : : }
3975 : : }
3976 : : }
3977 : :
3978 : : /*
3979 : : * If it's EXPLAIN ANALYZE, show instrumentation information for a plan node
3980 : : *
3981 : : * "which" identifies which instrumentation counter to print
3982 : : */
3983 : : static void
5098 tgl@sss.pgh.pa.us 3984 :CBC 13124 : show_instrumentation_count(const char *qlabel, int which,
3985 : : PlanState *planstate, ExplainState *es)
3986 : : {
3987 : : double nfiltered;
3988 : : double nloops;
3989 : :
3990 [ + + - + ]: 13124 : if (!es->analyze || !planstate->instrument)
3991 : 11309 : return;
3992 : :
3993 [ + + ]: 1815 : if (which == 2)
3994 : 585 : nfiltered = planstate->instrument->nfiltered2;
3995 : : else
3996 : 1230 : nfiltered = planstate->instrument->nfiltered1;
3997 : 1815 : nloops = planstate->instrument->nloops;
3998 : :
3999 : : /* In text mode, suppress zero counts; they're not interesting enough */
4000 [ + + + + ]: 1815 : if (nfiltered > 0 || es->format != EXPLAIN_FORMAT_TEXT)
4001 : : {
4002 [ + - ]: 844 : if (nloops > 0)
2731 andres@anarazel.de 4003 : 844 : ExplainPropertyFloat(qlabel, NULL, nfiltered / nloops, 0, es);
4004 : : else
2731 andres@anarazel.de 4005 :UBC 0 : ExplainPropertyFloat(qlabel, NULL, 0.0, 0, es);
4006 : : }
4007 : : }
4008 : :
4009 : : /*
4010 : : * Show extra information for a ForeignScan node.
4011 : : */
4012 : : static void
5312 tgl@sss.pgh.pa.us 4013 :CBC 425 : show_foreignscan_info(ForeignScanState *fsstate, ExplainState *es)
4014 : : {
4015 : 425 : FdwRoutine *fdwroutine = fsstate->fdwroutine;
4016 : :
4017 : : /* Let the FDW emit whatever fields it wants */
3459 rhaas@postgresql.org 4018 [ + + ]: 425 : if (((ForeignScan *) fsstate->ss.ps.plan)->operation != CMD_SELECT)
4019 : : {
4020 [ + - ]: 32 : if (fdwroutine->ExplainDirectModify != NULL)
4021 : 32 : fdwroutine->ExplainDirectModify(fsstate, es);
4022 : : }
4023 : : else
4024 : : {
4025 [ + - ]: 393 : if (fdwroutine->ExplainForeignScan != NULL)
4026 : 393 : fdwroutine->ExplainForeignScan(fsstate, es);
4027 : : }
5312 tgl@sss.pgh.pa.us 4028 : 425 : }
4029 : :
4030 : : /*
4031 : : * Fetch the name of an index in an EXPLAIN
4032 : : *
4033 : : * We allow plugins to get control here so that plans involving hypothetical
4034 : : * indexes can be explained.
4035 : : *
4036 : : * Note: names returned by this function should be "raw"; the caller will
4037 : : * apply quoting if needed. Formerly the convention was to do quoting here,
4038 : : * but we don't want that in non-text output formats.
4039 : : */
4040 : : static const char *
6679 4041 : 5591 : explain_get_index_name(Oid indexId)
4042 : : {
4043 : : const char *result;
4044 : :
4045 [ - + ]: 5591 : if (explain_get_index_name_hook)
6679 tgl@sss.pgh.pa.us 4046 :UBC 0 : result = (*explain_get_index_name_hook) (indexId);
4047 : : else
6679 tgl@sss.pgh.pa.us 4048 :CBC 5591 : result = NULL;
4049 [ + - ]: 5591 : if (result == NULL)
4050 : : {
4051 : : /* default behavior: look it up in the catalogs */
4052 : 5591 : result = get_rel_name(indexId);
4053 [ - + ]: 5591 : if (result == NULL)
6679 tgl@sss.pgh.pa.us 4054 [ # # ]:UBC 0 : elog(ERROR, "cache lookup failed for index %u", indexId);
4055 : : }
6679 tgl@sss.pgh.pa.us 4056 :CBC 5591 : return result;
4057 : : }
4058 : :
4059 : : /*
4060 : : * Return whether show_buffer_usage would have anything to print, if given
4061 : : * the same 'usage' data. Note that when the format is anything other than
4062 : : * text, we print even if the counters are all zeroes.
4063 : : */
4064 : : static bool
586 alvherre@alvh.no-ip. 4065 : 11962 : peek_buffer_usage(ExplainState *es, const BufferUsage *usage)
4066 : : {
4067 : : bool has_shared;
4068 : : bool has_local;
4069 : : bool has_temp;
4070 : : bool has_shared_timing;
4071 : : bool has_local_timing;
4072 : : bool has_temp_timing;
4073 : :
4074 [ + + ]: 11962 : if (usage == NULL)
4075 : 10670 : return false;
4076 : :
4077 [ + + ]: 1292 : if (es->format != EXPLAIN_FORMAT_TEXT)
4078 : 122 : return true;
4079 : :
4080 : 3243 : has_shared = (usage->shared_blks_hit > 0 ||
4081 [ + + ]: 903 : usage->shared_blks_read > 0 ||
4082 [ + + + - ]: 2970 : usage->shared_blks_dirtied > 0 ||
4083 [ - + ]: 897 : usage->shared_blks_written > 0);
4084 : 3510 : has_local = (usage->local_blks_hit > 0 ||
4085 [ + - ]: 1170 : usage->local_blks_read > 0 ||
4086 [ + - + - ]: 3510 : usage->local_blks_dirtied > 0 ||
4087 [ - + ]: 1170 : usage->local_blks_written > 0);
4088 [ + - ]: 2340 : has_temp = (usage->temp_blks_read > 0 ||
4089 [ - + ]: 1170 : usage->temp_blks_written > 0);
4090 [ + - ]: 2340 : has_shared_timing = (!INSTR_TIME_IS_ZERO(usage->shared_blk_read_time) ||
4091 [ - + ]: 1170 : !INSTR_TIME_IS_ZERO(usage->shared_blk_write_time));
4092 [ + - ]: 2340 : has_local_timing = (!INSTR_TIME_IS_ZERO(usage->local_blk_read_time) ||
4093 [ - + ]: 1170 : !INSTR_TIME_IS_ZERO(usage->local_blk_write_time));
4094 [ + - ]: 2340 : has_temp_timing = (!INSTR_TIME_IS_ZERO(usage->temp_blk_read_time) ||
4095 [ - + ]: 1170 : !INSTR_TIME_IS_ZERO(usage->temp_blk_write_time));
4096 : :
4097 [ + - + - : 897 : return has_shared || has_local || has_temp || has_shared_timing ||
+ - + - ]
4098 [ + + - + ]: 2067 : has_local_timing || has_temp_timing;
4099 : : }
4100 : :
4101 : : /*
4102 : : * Show buffer usage details. This better be sync with peek_buffer_usage.
4103 : : */
4104 : : static void
4105 : 2521 : show_buffer_usage(ExplainState *es, const BufferUsage *usage)
4106 : : {
3559 rhaas@postgresql.org 4107 [ + + ]: 2521 : if (es->format == EXPLAIN_FORMAT_TEXT)
4108 : : {
4109 : 3877 : bool has_shared = (usage->shared_blks_hit > 0 ||
4110 [ + + ]: 61 : usage->shared_blks_read > 0 ||
4111 [ + + + - ]: 1987 : usage->shared_blks_dirtied > 0 ||
4112 [ - + ]: 18 : usage->shared_blks_written > 0);
4113 : 5724 : bool has_local = (usage->local_blks_hit > 0 ||
4114 [ + - ]: 1908 : usage->local_blks_read > 0 ||
4115 [ + - + - ]: 5724 : usage->local_blks_dirtied > 0 ||
4116 [ - + ]: 1908 : usage->local_blks_written > 0);
4117 [ + - ]: 3816 : bool has_temp = (usage->temp_blks_read > 0 ||
4118 [ - + ]: 1908 : usage->temp_blks_written > 0);
688 michael@paquier.xyz 4119 [ + - ]: 3816 : bool has_shared_timing = (!INSTR_TIME_IS_ZERO(usage->shared_blk_read_time) ||
4120 [ - + ]: 1908 : !INSTR_TIME_IS_ZERO(usage->shared_blk_write_time));
4121 [ + - ]: 3816 : bool has_local_timing = (!INSTR_TIME_IS_ZERO(usage->local_blk_read_time) ||
4122 [ - + ]: 1908 : !INSTR_TIME_IS_ZERO(usage->local_blk_write_time));
1247 4123 [ + - ]: 3816 : bool has_temp_timing = (!INSTR_TIME_IS_ZERO(usage->temp_blk_read_time) ||
4124 [ - + ]: 1908 : !INSTR_TIME_IS_ZERO(usage->temp_blk_write_time));
4125 : :
4126 : : /* Show only positive counter values. */
3559 rhaas@postgresql.org 4127 [ + + + - : 1908 : if (has_shared || has_local || has_temp)
- + ]
4128 : : {
2051 tgl@sss.pgh.pa.us 4129 : 1890 : ExplainIndentText(es);
3559 rhaas@postgresql.org 4130 : 1890 : appendStringInfoString(es->str, "Buffers:");
4131 : :
4132 [ + - ]: 1890 : if (has_shared)
4133 : : {
4134 : 1890 : appendStringInfoString(es->str, " shared");
4135 [ + + ]: 1890 : if (usage->shared_blks_hit > 0)
161 peter@eisentraut.org 4136 : 1847 : appendStringInfo(es->str, " hit=%" PRId64,
4137 : 1847 : usage->shared_blks_hit);
3559 rhaas@postgresql.org 4138 [ + + ]: 1890 : if (usage->shared_blks_read > 0)
161 peter@eisentraut.org 4139 : 107 : appendStringInfo(es->str, " read=%" PRId64,
4140 : 107 : usage->shared_blks_read);
3559 rhaas@postgresql.org 4141 [ + + ]: 1890 : if (usage->shared_blks_dirtied > 0)
161 peter@eisentraut.org 4142 : 19 : appendStringInfo(es->str, " dirtied=%" PRId64,
4143 : 19 : usage->shared_blks_dirtied);
3559 rhaas@postgresql.org 4144 [ + + ]: 1890 : if (usage->shared_blks_written > 0)
161 peter@eisentraut.org 4145 : 39 : appendStringInfo(es->str, " written=%" PRId64,
4146 : 39 : usage->shared_blks_written);
3559 rhaas@postgresql.org 4147 [ + - - + ]: 1890 : if (has_local || has_temp)
3559 rhaas@postgresql.org 4148 :UBC 0 : appendStringInfoChar(es->str, ',');
4149 : : }
3559 rhaas@postgresql.org 4150 [ - + ]:CBC 1890 : if (has_local)
4151 : : {
3559 rhaas@postgresql.org 4152 :UBC 0 : appendStringInfoString(es->str, " local");
4153 [ # # ]: 0 : if (usage->local_blks_hit > 0)
161 peter@eisentraut.org 4154 : 0 : appendStringInfo(es->str, " hit=%" PRId64,
4155 : 0 : usage->local_blks_hit);
3559 rhaas@postgresql.org 4156 [ # # ]: 0 : if (usage->local_blks_read > 0)
161 peter@eisentraut.org 4157 : 0 : appendStringInfo(es->str, " read=%" PRId64,
4158 : 0 : usage->local_blks_read);
3559 rhaas@postgresql.org 4159 [ # # ]: 0 : if (usage->local_blks_dirtied > 0)
161 peter@eisentraut.org 4160 : 0 : appendStringInfo(es->str, " dirtied=%" PRId64,
4161 : 0 : usage->local_blks_dirtied);
3559 rhaas@postgresql.org 4162 [ # # ]: 0 : if (usage->local_blks_written > 0)
161 peter@eisentraut.org 4163 : 0 : appendStringInfo(es->str, " written=%" PRId64,
4164 : 0 : usage->local_blks_written);
3559 rhaas@postgresql.org 4165 [ # # ]: 0 : if (has_temp)
4166 : 0 : appendStringInfoChar(es->str, ',');
4167 : : }
3559 rhaas@postgresql.org 4168 [ - + ]:CBC 1890 : if (has_temp)
4169 : : {
3559 rhaas@postgresql.org 4170 :UBC 0 : appendStringInfoString(es->str, " temp");
4171 [ # # ]: 0 : if (usage->temp_blks_read > 0)
161 peter@eisentraut.org 4172 : 0 : appendStringInfo(es->str, " read=%" PRId64,
4173 : 0 : usage->temp_blks_read);
3559 rhaas@postgresql.org 4174 [ # # ]: 0 : if (usage->temp_blks_written > 0)
161 peter@eisentraut.org 4175 : 0 : appendStringInfo(es->str, " written=%" PRId64,
4176 : 0 : usage->temp_blks_written);
4177 : : }
3559 rhaas@postgresql.org 4178 :CBC 1890 : appendStringInfoChar(es->str, '\n');
4179 : : }
4180 : :
4181 : : /* As above, show only positive counter values. */
688 michael@paquier.xyz 4182 [ + - + - : 1908 : if (has_shared_timing || has_local_timing || has_temp_timing)
- + ]
4183 : : {
2051 tgl@sss.pgh.pa.us 4184 :UBC 0 : ExplainIndentText(es);
3559 rhaas@postgresql.org 4185 : 0 : appendStringInfoString(es->str, "I/O Timings:");
4186 : :
688 michael@paquier.xyz 4187 [ # # ]: 0 : if (has_shared_timing)
4188 : : {
4189 : 0 : appendStringInfoString(es->str, " shared");
4190 [ # # ]: 0 : if (!INSTR_TIME_IS_ZERO(usage->shared_blk_read_time))
1247 4191 : 0 : appendStringInfo(es->str, " read=%0.3f",
688 4192 : 0 : INSTR_TIME_GET_MILLISEC(usage->shared_blk_read_time));
4193 [ # # ]: 0 : if (!INSTR_TIME_IS_ZERO(usage->shared_blk_write_time))
1247 4194 : 0 : appendStringInfo(es->str, " write=%0.3f",
688 4195 : 0 : INSTR_TIME_GET_MILLISEC(usage->shared_blk_write_time));
4196 [ # # # # ]: 0 : if (has_local_timing || has_temp_timing)
4197 : 0 : appendStringInfoChar(es->str, ',');
4198 : : }
4199 [ # # ]: 0 : if (has_local_timing)
4200 : : {
4201 : 0 : appendStringInfoString(es->str, " local");
4202 [ # # ]: 0 : if (!INSTR_TIME_IS_ZERO(usage->local_blk_read_time))
4203 : 0 : appendStringInfo(es->str, " read=%0.3f",
4204 : 0 : INSTR_TIME_GET_MILLISEC(usage->local_blk_read_time));
4205 [ # # ]: 0 : if (!INSTR_TIME_IS_ZERO(usage->local_blk_write_time))
4206 : 0 : appendStringInfo(es->str, " write=%0.3f",
4207 : 0 : INSTR_TIME_GET_MILLISEC(usage->local_blk_write_time));
1247 4208 [ # # ]: 0 : if (has_temp_timing)
4209 : 0 : appendStringInfoChar(es->str, ',');
4210 : : }
4211 [ # # ]: 0 : if (has_temp_timing)
4212 : : {
4213 : 0 : appendStringInfoString(es->str, " temp");
4214 [ # # ]: 0 : if (!INSTR_TIME_IS_ZERO(usage->temp_blk_read_time))
4215 : 0 : appendStringInfo(es->str, " read=%0.3f",
4216 : 0 : INSTR_TIME_GET_MILLISEC(usage->temp_blk_read_time));
4217 [ # # ]: 0 : if (!INSTR_TIME_IS_ZERO(usage->temp_blk_write_time))
4218 : 0 : appendStringInfo(es->str, " write=%0.3f",
4219 : 0 : INSTR_TIME_GET_MILLISEC(usage->temp_blk_write_time));
4220 : : }
3559 rhaas@postgresql.org 4221 : 0 : appendStringInfoChar(es->str, '\n');
4222 : : }
4223 : : }
4224 : : else
4225 : : {
2731 andres@anarazel.de 4226 :CBC 613 : ExplainPropertyInteger("Shared Hit Blocks", NULL,
4227 : 613 : usage->shared_blks_hit, es);
4228 : 613 : ExplainPropertyInteger("Shared Read Blocks", NULL,
4229 : 613 : usage->shared_blks_read, es);
4230 : 613 : ExplainPropertyInteger("Shared Dirtied Blocks", NULL,
4231 : 613 : usage->shared_blks_dirtied, es);
4232 : 613 : ExplainPropertyInteger("Shared Written Blocks", NULL,
4233 : 613 : usage->shared_blks_written, es);
4234 : 613 : ExplainPropertyInteger("Local Hit Blocks", NULL,
4235 : 613 : usage->local_blks_hit, es);
4236 : 613 : ExplainPropertyInteger("Local Read Blocks", NULL,
4237 : 613 : usage->local_blks_read, es);
4238 : 613 : ExplainPropertyInteger("Local Dirtied Blocks", NULL,
4239 : 613 : usage->local_blks_dirtied, es);
4240 : 613 : ExplainPropertyInteger("Local Written Blocks", NULL,
4241 : 613 : usage->local_blks_written, es);
4242 : 613 : ExplainPropertyInteger("Temp Read Blocks", NULL,
4243 : 613 : usage->temp_blks_read, es);
4244 : 613 : ExplainPropertyInteger("Temp Written Blocks", NULL,
4245 : 613 : usage->temp_blks_written, es);
3312 tgl@sss.pgh.pa.us 4246 [ + + ]: 613 : if (track_io_timing)
4247 : : {
688 michael@paquier.xyz 4248 : 6 : ExplainPropertyFloat("Shared I/O Read Time", "ms",
4249 : 6 : INSTR_TIME_GET_MILLISEC(usage->shared_blk_read_time),
4250 : : 3, es);
4251 : 6 : ExplainPropertyFloat("Shared I/O Write Time", "ms",
4252 : 6 : INSTR_TIME_GET_MILLISEC(usage->shared_blk_write_time),
4253 : : 3, es);
4254 : 6 : ExplainPropertyFloat("Local I/O Read Time", "ms",
4255 : 6 : INSTR_TIME_GET_MILLISEC(usage->local_blk_read_time),
4256 : : 3, es);
4257 : 6 : ExplainPropertyFloat("Local I/O Write Time", "ms",
4258 : 6 : INSTR_TIME_GET_MILLISEC(usage->local_blk_write_time),
4259 : : 3, es);
1247 4260 : 6 : ExplainPropertyFloat("Temp I/O Read Time", "ms",
4261 : 6 : INSTR_TIME_GET_MILLISEC(usage->temp_blk_read_time),
4262 : : 3, es);
4263 : 6 : ExplainPropertyFloat("Temp I/O Write Time", "ms",
4264 : 6 : INSTR_TIME_GET_MILLISEC(usage->temp_blk_write_time),
4265 : : 3, es);
4266 : : }
4267 : : }
3559 rhaas@postgresql.org 4268 : 2521 : }
4269 : :
4270 : : /*
4271 : : * Show WAL usage details.
4272 : : */
4273 : : static void
1979 akapila@postgresql.o 4274 :UBC 0 : show_wal_usage(ExplainState *es, const WalUsage *usage)
4275 : : {
4276 [ # # ]: 0 : if (es->format == EXPLAIN_FORMAT_TEXT)
4277 : : {
4278 : : /* Show only positive counter values. */
1950 4279 [ # # # # ]: 0 : if ((usage->wal_records > 0) || (usage->wal_fpi > 0) ||
201 michael@paquier.xyz 4280 [ # # # # ]: 0 : (usage->wal_bytes > 0) || (usage->wal_buffers_full > 0))
4281 : : {
1979 akapila@postgresql.o 4282 : 0 : ExplainIndentText(es);
4283 : 0 : appendStringInfoString(es->str, "WAL:");
4284 : :
4285 [ # # ]: 0 : if (usage->wal_records > 0)
161 peter@eisentraut.org 4286 : 0 : appendStringInfo(es->str, " records=%" PRId64,
4287 : 0 : usage->wal_records);
1950 akapila@postgresql.o 4288 [ # # ]: 0 : if (usage->wal_fpi > 0)
161 peter@eisentraut.org 4289 : 0 : appendStringInfo(es->str, " fpi=%" PRId64,
4290 : 0 : usage->wal_fpi);
1979 akapila@postgresql.o 4291 [ # # ]: 0 : if (usage->wal_bytes > 0)
161 peter@eisentraut.org 4292 : 0 : appendStringInfo(es->str, " bytes=%" PRIu64,
1979 akapila@postgresql.o 4293 : 0 : usage->wal_bytes);
201 michael@paquier.xyz 4294 [ # # ]: 0 : if (usage->wal_buffers_full > 0)
161 peter@eisentraut.org 4295 : 0 : appendStringInfo(es->str, " buffers full=%" PRId64,
4296 : 0 : usage->wal_buffers_full);
1979 akapila@postgresql.o 4297 : 0 : appendStringInfoChar(es->str, '\n');
4298 : : }
4299 : : }
4300 : : else
4301 : : {
1950 4302 : 0 : ExplainPropertyInteger("WAL Records", NULL,
1979 4303 : 0 : usage->wal_records, es);
1950 4304 : 0 : ExplainPropertyInteger("WAL FPI", NULL,
4305 : 0 : usage->wal_fpi, es);
4306 : 0 : ExplainPropertyUInteger("WAL Bytes", NULL,
1979 4307 : 0 : usage->wal_bytes, es);
201 michael@paquier.xyz 4308 : 0 : ExplainPropertyInteger("WAL Buffers Full", NULL,
4309 : 0 : usage->wal_buffers_full, es);
4310 : : }
1979 akapila@postgresql.o 4311 : 0 : }
4312 : :
4313 : : /*
4314 : : * Show memory usage details.
4315 : : */
4316 : : static void
586 alvherre@alvh.no-ip. 4317 :CBC 15 : show_memory_counters(ExplainState *es, const MemoryContextCounters *mem_counters)
4318 : : {
478 drowley@postgresql.o 4319 : 15 : int64 memUsedkB = BYTES_TO_KILOBYTES(mem_counters->totalspace -
4320 : : mem_counters->freespace);
4321 : 15 : int64 memAllocatedkB = BYTES_TO_KILOBYTES(mem_counters->totalspace);
4322 : :
586 alvherre@alvh.no-ip. 4323 [ + + ]: 15 : if (es->format == EXPLAIN_FORMAT_TEXT)
4324 : : {
4325 : 9 : ExplainIndentText(es);
4326 : 9 : appendStringInfo(es->str,
4327 : : "Memory: used=" INT64_FORMAT "kB allocated=" INT64_FORMAT "kB",
4328 : : memUsedkB, memAllocatedkB);
4329 : 9 : appendStringInfoChar(es->str, '\n');
4330 : : }
4331 : : else
4332 : : {
478 drowley@postgresql.o 4333 : 6 : ExplainPropertyInteger("Memory Used", "kB", memUsedkB, es);
4334 : 6 : ExplainPropertyInteger("Memory Allocated", "kB", memAllocatedkB, es);
4335 : : }
586 alvherre@alvh.no-ip. 4336 : 15 : }
4337 : :
4338 : :
4339 : : /*
4340 : : * Add some additional details about an IndexScan or IndexOnlyScan
4341 : : */
4342 : : static void
5079 tgl@sss.pgh.pa.us 4343 : 3439 : ExplainIndexScanDetails(Oid indexid, ScanDirection indexorderdir,
4344 : : ExplainState *es)
4345 : : {
4346 : 3439 : const char *indexname = explain_get_index_name(indexid);
4347 : :
4348 [ + + ]: 3439 : if (es->format == EXPLAIN_FORMAT_TEXT)
4349 : : {
4350 [ + + ]: 3418 : if (ScanDirectionIsBackward(indexorderdir))
4351 : 136 : appendStringInfoString(es->str, " Backward");
1902 4352 : 3418 : appendStringInfo(es->str, " using %s", quote_identifier(indexname));
4353 : : }
4354 : : else
4355 : : {
4356 : : const char *scandir;
4357 : :
5079 4358 [ - + - ]: 21 : switch (indexorderdir)
4359 : : {
5079 tgl@sss.pgh.pa.us 4360 :UBC 0 : case BackwardScanDirection:
4361 : 0 : scandir = "Backward";
4362 : 0 : break;
5079 tgl@sss.pgh.pa.us 4363 :CBC 21 : case ForwardScanDirection:
4364 : 21 : scandir = "Forward";
4365 : 21 : break;
5079 tgl@sss.pgh.pa.us 4366 :UBC 0 : default:
4367 : 0 : scandir = "???";
4368 : 0 : break;
4369 : : }
5079 tgl@sss.pgh.pa.us 4370 :CBC 21 : ExplainPropertyText("Scan Direction", scandir, es);
4371 : 21 : ExplainPropertyText("Index Name", indexname, es);
4372 : : }
4373 : 3439 : }
4374 : :
4375 : : /*
4376 : : * Show the target of a Scan node
4377 : : */
4378 : : static void
5888 4379 : 19828 : ExplainScanTarget(Scan *plan, ExplainState *es)
4380 : : {
5303 4381 : 19828 : ExplainTargetRel((Plan *) plan, plan->scanrelid, es);
4382 : 19828 : }
4383 : :
4384 : : /*
4385 : : * Show the target of a ModifyTable node
4386 : : *
4387 : : * Here we show the nominal target (ie, the relation that was named in the
4388 : : * original query). If the actual target(s) is/are different, we'll show them
4389 : : * in show_modifytable_info().
4390 : : */
4391 : : static void
4392 : 553 : ExplainModifyTarget(ModifyTable *plan, ExplainState *es)
4393 : : {
3854 4394 : 553 : ExplainTargetRel((Plan *) plan, plan->nominalRelation, es);
5303 4395 : 553 : }
4396 : :
4397 : : /*
4398 : : * Show the target relation of a scan or modify node
4399 : : */
4400 : : static void
4401 : 20651 : ExplainTargetRel(Plan *plan, Index rti, ExplainState *es)
4402 : : {
5888 4403 : 20651 : char *objectname = NULL;
5871 4404 : 20651 : char *namespace = NULL;
4405 : 20651 : const char *objecttag = NULL;
4406 : : RangeTblEntry *rte;
4407 : : char *refname;
4408 : :
5303 4409 : 20651 : rte = rt_fetch(rti, es->rtable);
4733 4410 : 20651 : refname = (char *) list_nth(es->rtable_names, rti - 1);
4632 4411 [ - + ]: 20651 : if (refname == NULL)
4632 tgl@sss.pgh.pa.us 4412 :UBC 0 : refname = rte->eref->aliasname;
4413 : :
5888 tgl@sss.pgh.pa.us 4414 [ + + + + :CBC 20651 : switch (nodeTag(plan))
+ - + + ]
4415 : : {
4416 : 19675 : case T_SeqScan:
4417 : : case T_SampleScan:
4418 : : case T_IndexScan:
4419 : : case T_IndexOnlyScan:
4420 : : case T_BitmapHeapScan:
4421 : : case T_TidScan:
4422 : : case T_TidRangeScan:
4423 : : case T_ForeignScan:
4424 : : case T_CustomScan:
4425 : : case T_ModifyTable:
4426 : : /* Assert it's on a real relation */
4427 [ - + ]: 19675 : Assert(rte->rtekind == RTE_RELATION);
4428 : 19675 : objectname = get_rel_name(rte->relid);
5871 4429 [ + + ]: 19675 : if (es->verbose)
1502 4430 : 1805 : namespace = get_namespace_name_or_temp(get_rel_namespace(rte->relid));
5871 4431 : 19675 : objecttag = "Relation Name";
5888 4432 : 19675 : break;
4433 : 288 : case T_FunctionScan:
4434 : : {
4307 4435 : 288 : FunctionScan *fscan = (FunctionScan *) plan;
4436 : :
4437 : : /* Assert it's on a RangeFunction */
5888 4438 [ - + ]: 288 : Assert(rte->rtekind == RTE_FUNCTION);
4439 : :
4440 : : /*
4441 : : * If the expression is still a function call of a single
4442 : : * function, we can get the real name of the function.
4443 : : * Otherwise, punt. (Even if it was a single function call
4444 : : * originally, the optimizer could have simplified it away.)
4445 : : */
4307 4446 [ + - ]: 288 : if (list_length(fscan->functions) == 1)
4447 : : {
4448 : 288 : RangeTblFunction *rtfunc = (RangeTblFunction *) linitial(fscan->functions);
4449 : :
4450 [ + + ]: 288 : if (IsA(rtfunc->funcexpr, FuncExpr))
4451 : : {
4452 : 276 : FuncExpr *funcexpr = (FuncExpr *) rtfunc->funcexpr;
4453 : 276 : Oid funcid = funcexpr->funcid;
4454 : :
4455 : 276 : objectname = get_func_name(funcid);
4456 [ + + ]: 276 : if (es->verbose)
1502 4457 : 88 : namespace = get_namespace_name_or_temp(get_func_namespace(funcid));
4458 : : }
4459 : : }
5871 4460 : 288 : objecttag = "Function Name";
4461 : : }
5888 4462 : 288 : break;
3104 alvherre@alvh.no-ip. 4463 : 39 : case T_TableFuncScan:
4464 : : {
520 amitlan@postgresql.o 4465 : 39 : TableFunc *tablefunc = ((TableFuncScan *) plan)->tablefunc;
4466 : :
4467 [ - + ]: 39 : Assert(rte->rtekind == RTE_TABLEFUNC);
4468 [ + + - ]: 39 : switch (tablefunc->functype)
4469 : : {
4470 : 18 : case TFT_XMLTABLE:
4471 : 18 : objectname = "xmltable";
4472 : 18 : break;
4473 : 21 : case TFT_JSON_TABLE:
4474 : 21 : objectname = "json_table";
4475 : 21 : break;
520 amitlan@postgresql.o 4476 :UBC 0 : default:
4477 [ # # ]: 0 : elog(ERROR, "invalid TableFunc type %d",
4478 : : (int) tablefunc->functype);
4479 : : }
520 amitlan@postgresql.o 4480 :CBC 39 : objecttag = "Table Function Name";
4481 : : }
3104 alvherre@alvh.no-ip. 4482 : 39 : break;
5888 tgl@sss.pgh.pa.us 4483 : 279 : case T_ValuesScan:
4484 [ - + ]: 279 : Assert(rte->rtekind == RTE_VALUES);
4485 : 279 : break;
4486 : 125 : case T_CteScan:
4487 : : /* Assert it's on a non-self-reference CTE */
4488 [ - + ]: 125 : Assert(rte->rtekind == RTE_CTE);
4489 [ - + ]: 125 : Assert(!rte->self_reference);
4490 : 125 : objectname = rte->ctename;
5871 4491 : 125 : objecttag = "CTE Name";
5888 4492 : 125 : break;
3081 kgrittn@postgresql.o 4493 :UBC 0 : case T_NamedTuplestoreScan:
4494 [ # # ]: 0 : Assert(rte->rtekind == RTE_NAMEDTUPLESTORE);
4495 : 0 : objectname = rte->enrname;
4496 : 0 : objecttag = "Tuplestore Name";
4497 : 0 : break;
5888 tgl@sss.pgh.pa.us 4498 :CBC 27 : case T_WorkTableScan:
4499 : : /* Assert it's on a self-reference CTE */
4500 [ - + ]: 27 : Assert(rte->rtekind == RTE_CTE);
4501 [ - + ]: 27 : Assert(rte->self_reference);
4502 : 27 : objectname = rte->ctename;
5871 4503 : 27 : objecttag = "CTE Name";
5888 4504 : 27 : break;
4505 : 218 : default:
4506 : 218 : break;
4507 : : }
4508 : :
5871 4509 [ + + ]: 20651 : if (es->format == EXPLAIN_FORMAT_TEXT)
4510 : : {
4511 : 20428 : appendStringInfoString(es->str, " on");
4512 [ + + ]: 20428 : if (namespace != NULL)
4513 : 1887 : appendStringInfo(es->str, " %s.%s", quote_identifier(namespace),
4514 : : quote_identifier(objectname));
4515 [ + + ]: 18541 : else if (objectname != NULL)
4516 : 18032 : appendStringInfo(es->str, " %s", quote_identifier(objectname));
4632 4517 [ + + + + ]: 20428 : if (objectname == NULL || strcmp(refname, objectname) != 0)
4733 4518 : 11816 : appendStringInfo(es->str, " %s", quote_identifier(refname));
4519 : : }
4520 : : else
4521 : : {
5871 4522 [ + - + - ]: 223 : if (objecttag != NULL && objectname != NULL)
4523 : 223 : ExplainPropertyText(objecttag, objectname, es);
4524 [ + + ]: 223 : if (namespace != NULL)
4525 : 6 : ExplainPropertyText("Schema", namespace, es);
4632 4526 : 223 : ExplainPropertyText("Alias", refname, es);
4527 : : }
5888 4528 : 20651 : }
4529 : :
4530 : : /*
4531 : : * Show extra information for a ModifyTable node
4532 : : *
4533 : : * We have three objectives here. First, if there's more than one target
4534 : : * table or it's different from the nominal target, identify the actual
4535 : : * target(s). Second, give FDWs a chance to display extra info about foreign
4536 : : * targets. Third, show information about ON CONFLICT.
4537 : : */
4538 : : static void
3774 andres@anarazel.de 4539 : 553 : show_modifytable_info(ModifyTableState *mtstate, List *ancestors,
4540 : : ExplainState *es)
4541 : : {
3821 tgl@sss.pgh.pa.us 4542 : 553 : ModifyTable *node = (ModifyTable *) mtstate->ps.plan;
4543 : : const char *operation;
4544 : : const char *foperation;
4545 : : bool labeltargets;
4546 : : int j;
3774 andres@anarazel.de 4547 : 553 : List *idxNames = NIL;
4548 : : ListCell *lst;
4549 : :
3821 tgl@sss.pgh.pa.us 4550 [ + + + + : 553 : switch (node->operation)
- ]
4551 : : {
4552 : 137 : case CMD_INSERT:
4553 : 137 : operation = "Insert";
4554 : 137 : foperation = "Foreign Insert";
4555 : 137 : break;
4556 : 224 : case CMD_UPDATE:
4557 : 224 : operation = "Update";
4558 : 224 : foperation = "Foreign Update";
4559 : 224 : break;
4560 : 93 : case CMD_DELETE:
4561 : 93 : operation = "Delete";
4562 : 93 : foperation = "Foreign Delete";
4563 : 93 : break;
1258 alvherre@alvh.no-ip. 4564 : 99 : case CMD_MERGE:
4565 : 99 : operation = "Merge";
4566 : : /* XXX unsupported for now, but avoid compiler noise */
4567 : 99 : foperation = "Foreign Merge";
4568 : 99 : break;
3821 tgl@sss.pgh.pa.us 4569 :UBC 0 : default:
4570 : 0 : operation = "???";
4571 : 0 : foperation = "Foreign ???";
4572 : 0 : break;
4573 : : }
4574 : :
4575 : : /*
4576 : : * Should we explicitly label target relations?
4577 : : *
4578 : : * If there's only one target relation, do not list it if it's the
4579 : : * relation named in the query, or if it has been pruned. (Normally
4580 : : * mtstate->resultRelInfo doesn't include pruned relations, but a single
4581 : : * pruned target relation may be present, if all other target relations
4582 : : * have been pruned. See ExecInitModifyTable().)
4583 : : */
1620 tgl@sss.pgh.pa.us 4584 [ + + ]:CBC 1029 : labeltargets = (mtstate->mt_nrels > 1 ||
4585 [ + - ]: 476 : (mtstate->mt_nrels == 1 &&
171 amitlan@postgresql.o 4586 [ + + + + ]: 542 : mtstate->resultRelInfo[0].ri_RangeTableIndex != node->nominalRelation &&
4587 : 66 : bms_is_member(mtstate->resultRelInfo[0].ri_RangeTableIndex,
4588 : 66 : mtstate->ps.state->es_unpruned_relids)));
4589 : :
3821 tgl@sss.pgh.pa.us 4590 [ + + ]: 553 : if (labeltargets)
4591 : 131 : ExplainOpenGroup("Target Tables", "Target Tables", false, es);
4592 : :
1620 4593 [ + + ]: 1245 : for (j = 0; j < mtstate->mt_nrels; j++)
4594 : : {
3821 4595 : 692 : ResultRelInfo *resultRelInfo = mtstate->resultRelInfo + j;
4596 : 692 : FdwRoutine *fdwroutine = resultRelInfo->ri_FdwRoutine;
4597 : :
4598 [ + + ]: 692 : if (labeltargets)
4599 : : {
4600 : : /* Open a group for this target */
4601 : 270 : ExplainOpenGroup("Target Table", NULL, true, es);
4602 : :
4603 : : /*
4604 : : * In text mode, decorate each target with operation type, so that
4605 : : * ExplainTargetRel's output of " on foo" will read nicely.
4606 : : */
4607 [ + - ]: 270 : if (es->format == EXPLAIN_FORMAT_TEXT)
4608 : : {
2051 4609 : 270 : ExplainIndentText(es);
3821 4610 [ + + ]: 270 : appendStringInfoString(es->str,
4611 : : fdwroutine ? foperation : operation);
4612 : : }
4613 : :
4614 : : /* Identify target */
4615 : 270 : ExplainTargetRel((Plan *) node,
4616 : : resultRelInfo->ri_RangeTableIndex,
4617 : : es);
4618 : :
4619 [ + - ]: 270 : if (es->format == EXPLAIN_FORMAT_TEXT)
4620 : : {
4621 : 270 : appendStringInfoChar(es->str, '\n');
4622 : 270 : es->indent++;
4623 : : }
4624 : : }
4625 : :
4626 : : /* Give FDW a chance if needed */
3459 rhaas@postgresql.org 4627 [ + + + + ]: 692 : if (!resultRelInfo->ri_usesFdwDirectModify &&
4628 : 46 : fdwroutine != NULL &&
4629 [ + - ]: 46 : fdwroutine->ExplainForeignModify != NULL)
4630 : : {
3821 tgl@sss.pgh.pa.us 4631 : 46 : List *fdw_private = (List *) list_nth(node->fdwPrivLists, j);
4632 : :
4633 : 46 : fdwroutine->ExplainForeignModify(mtstate,
4634 : : resultRelInfo,
4635 : : fdw_private,
4636 : : j,
4637 : : es);
4638 : : }
4639 : :
4640 [ + + ]: 692 : if (labeltargets)
4641 : : {
4642 : : /* Undo the indentation we added in text format */
4643 [ + - ]: 270 : if (es->format == EXPLAIN_FORMAT_TEXT)
4644 : 270 : es->indent--;
4645 : :
4646 : : /* Close the group */
4647 : 270 : ExplainCloseGroup("Target Table", NULL, true, es);
4648 : : }
4649 : : }
4650 : :
4651 : : /* Gather names of ON CONFLICT arbiter indexes */
3774 andres@anarazel.de 4652 [ + + + + : 652 : foreach(lst, node->arbiterIndexes)
+ + ]
4653 : : {
4654 : 99 : char *indexname = get_rel_name(lfirst_oid(lst));
4655 : :
4656 : 99 : idxNames = lappend(idxNames, indexname);
4657 : : }
4658 : :
4659 [ + + ]: 553 : if (node->onConflictAction != ONCONFLICT_NONE)
4660 : : {
2731 4661 : 72 : ExplainPropertyText("Conflict Resolution",
4662 [ + + ]: 72 : node->onConflictAction == ONCONFLICT_NOTHING ?
4663 : : "NOTHING" : "UPDATE",
4664 : : es);
4665 : :
4666 : : /*
4667 : : * Don't display arbiter indexes at all when DO NOTHING variant
4668 : : * implicitly ignores all conflicts
4669 : : */
3774 4670 [ + - ]: 72 : if (idxNames)
4671 : 72 : ExplainPropertyList("Conflict Arbiter Indexes", idxNames, es);
4672 : :
4673 : : /* ON CONFLICT DO UPDATE WHERE qual is specially displayed */
4674 [ + + ]: 72 : if (node->onConflictWhere)
4675 : : {
4676 : 27 : show_upper_qual((List *) node->onConflictWhere, "Conflict Filter",
4677 : : &mtstate->ps, ancestors, es);
4678 : 27 : show_instrumentation_count("Rows Removed by Conflict Filter", 1, &mtstate->ps, es);
4679 : : }
4680 : :
4681 : : /* EXPLAIN ANALYZE display of actual outcome for each tuple proposed */
4682 [ - + - - ]: 72 : if (es->analyze && mtstate->ps.instrument)
4683 : : {
4684 : : double total;
4685 : : double insert_path;
4686 : : double other_path;
4687 : :
1620 tgl@sss.pgh.pa.us 4688 :UBC 0 : InstrEndLoop(outerPlanState(mtstate)->instrument);
4689 : :
4690 : : /* count the number of source rows */
4691 : 0 : total = outerPlanState(mtstate)->instrument->ntuples;
2706 alvherre@alvh.no-ip. 4692 : 0 : other_path = mtstate->ps.instrument->ntuples2;
3774 andres@anarazel.de 4693 : 0 : insert_path = total - other_path;
4694 : :
2731 4695 : 0 : ExplainPropertyFloat("Tuples Inserted", NULL,
4696 : : insert_path, 0, es);
4697 : 0 : ExplainPropertyFloat("Conflicting Tuples", NULL,
4698 : : other_path, 0, es);
4699 : : }
4700 : : }
1258 alvherre@alvh.no-ip. 4701 [ + + ]:CBC 481 : else if (node->operation == CMD_MERGE)
4702 : : {
4703 : : /* EXPLAIN ANALYZE display of tuples processed */
4704 [ + + + - ]: 99 : if (es->analyze && mtstate->ps.instrument)
4705 : : {
4706 : : double total;
4707 : : double insert_path;
4708 : : double update_path;
4709 : : double delete_path;
4710 : : double skipped_path;
4711 : :
4712 : 24 : InstrEndLoop(outerPlanState(mtstate)->instrument);
4713 : :
4714 : : /* count the number of source rows */
4715 : 24 : total = outerPlanState(mtstate)->instrument->ntuples;
4716 : 24 : insert_path = mtstate->mt_merge_inserted;
4717 : 24 : update_path = mtstate->mt_merge_updated;
4718 : 24 : delete_path = mtstate->mt_merge_deleted;
4719 : 24 : skipped_path = total - insert_path - update_path - delete_path;
4720 [ - + ]: 24 : Assert(skipped_path >= 0);
4721 : :
1207 4722 [ + - ]: 24 : if (es->format == EXPLAIN_FORMAT_TEXT)
4723 : : {
4724 [ + + ]: 24 : if (total > 0)
4725 : : {
4726 : 21 : ExplainIndentText(es);
4727 : 21 : appendStringInfoString(es->str, "Tuples:");
4728 [ + + ]: 21 : if (insert_path > 0)
4729 : 6 : appendStringInfo(es->str, " inserted=%.0f", insert_path);
4730 [ + + ]: 21 : if (update_path > 0)
4731 : 12 : appendStringInfo(es->str, " updated=%.0f", update_path);
4732 [ + + ]: 21 : if (delete_path > 0)
4733 : 6 : appendStringInfo(es->str, " deleted=%.0f", delete_path);
4734 [ + + ]: 21 : if (skipped_path > 0)
4735 : 18 : appendStringInfo(es->str, " skipped=%.0f", skipped_path);
4736 : 21 : appendStringInfoChar(es->str, '\n');
4737 : : }
4738 : : }
4739 : : else
4740 : : {
1207 alvherre@alvh.no-ip. 4741 :UBC 0 : ExplainPropertyFloat("Tuples Inserted", NULL, insert_path, 0, es);
4742 : 0 : ExplainPropertyFloat("Tuples Updated", NULL, update_path, 0, es);
4743 : 0 : ExplainPropertyFloat("Tuples Deleted", NULL, delete_path, 0, es);
4744 : 0 : ExplainPropertyFloat("Tuples Skipped", NULL, skipped_path, 0, es);
4745 : : }
4746 : : }
4747 : : }
4748 : :
3821 tgl@sss.pgh.pa.us 4749 [ + + ]:CBC 553 : if (labeltargets)
4750 : 131 : ExplainCloseGroup("Target Tables", "Target Tables", false, es);
4563 4751 : 553 : }
4752 : :
4753 : : /*
4754 : : * Explain the constituent plans of an Append, MergeAppend,
4755 : : * BitmapAnd, or BitmapOr node.
4756 : : *
4757 : : * The ancestors list should already contain the immediate parent of these
4758 : : * plans.
4759 : : */
4760 : : static void
2041 4761 : 1993 : ExplainMemberNodes(PlanState **planstates, int nplans,
4762 : : List *ancestors, ExplainState *es)
4763 : : {
4764 : : int j;
4765 : :
4766 [ + + ]: 8018 : for (j = 0; j < nplans; j++)
5534 4767 : 6025 : ExplainNode(planstates[j], ancestors,
4768 : : "Member", NULL, es);
5888 4769 : 1993 : }
4770 : :
4771 : : /*
4772 : : * Report about any pruned subnodes of an Append or MergeAppend node.
4773 : : *
4774 : : * nplans indicates the number of live subplans.
4775 : : * nchildren indicates the original number of subnodes in the Plan;
4776 : : * some of these may have been pruned by the run-time pruning code.
4777 : : */
4778 : : static void
2041 4779 : 1899 : ExplainMissingMembers(int nplans, int nchildren, ExplainState *es)
4780 : : {
4781 [ + + + + ]: 1899 : if (nplans < nchildren || es->format != EXPLAIN_FORMAT_TEXT)
4782 : 126 : ExplainPropertyInteger("Subplans Removed", NULL,
4783 : 126 : nchildren - nplans, es);
4784 : 1899 : }
4785 : :
4786 : : /*
4787 : : * Explain a list of SubPlans (or initPlans, which also use SubPlan nodes).
4788 : : *
4789 : : * The ancestors list should already contain the immediate parent of these
4790 : : * SubPlans.
4791 : : */
4792 : : static void
5534 4793 : 868 : ExplainSubPlans(List *plans, List *ancestors,
4794 : : const char *relationship, ExplainState *es)
4795 : : {
4796 : : ListCell *lst;
4797 : :
5888 4798 [ + - + + : 1836 : foreach(lst, plans)
+ + ]
4799 : : {
4800 : 968 : SubPlanState *sps = (SubPlanState *) lfirst(lst);
3098 andres@anarazel.de 4801 : 968 : SubPlan *sp = sps->subplan;
4802 : :
4803 : : /*
4804 : : * There can be multiple SubPlan nodes referencing the same physical
4805 : : * subplan (same plan_id, which is its index in PlannedStmt.subplans).
4806 : : * We should print a subplan only once, so track which ones we already
4807 : : * printed. This state must be global across the plan tree, since the
4808 : : * duplicate nodes could be in different plan nodes, eg both a bitmap
4809 : : * indexscan's indexqual and its parent heapscan's recheck qual. (We
4810 : : * do not worry too much about which plan node we show the subplan as
4811 : : * attached to in such cases.)
4812 : : */
3344 tgl@sss.pgh.pa.us 4813 [ + + ]: 968 : if (bms_is_member(sp->plan_id, es->printed_subplans))
4814 : 45 : continue;
4815 : 923 : es->printed_subplans = bms_add_member(es->printed_subplans,
4816 : : sp->plan_id);
4817 : :
4818 : : /*
4819 : : * Treat the SubPlan node as an ancestor of the plan node(s) within
4820 : : * it, so that ruleutils.c can find the referents of subplan
4821 : : * parameters.
4822 : : */
2096 4823 : 923 : ancestors = lcons(sp, ancestors);
4824 : :
5534 4825 : 923 : ExplainNode(sps->planstate, ancestors,
4826 : 923 : relationship, sp->plan_name, es);
4827 : :
2096 4828 : 923 : ancestors = list_delete_first(ancestors);
4829 : : }
5871 4830 : 868 : }
4831 : :
4832 : : /*
4833 : : * Explain a list of children of a CustomScan.
4834 : : */
4835 : : static void
3725 rhaas@postgresql.org 4836 :UBC 0 : ExplainCustomChildren(CustomScanState *css, List *ancestors, ExplainState *es)
4837 : : {
4838 : : ListCell *cell;
4839 : 0 : const char *label =
841 tgl@sss.pgh.pa.us 4840 [ # # ]: 0 : (list_length(css->custom_ps) != 1 ? "children" : "child");
4841 : :
3696 4842 [ # # # # : 0 : foreach(cell, css->custom_ps)
# # ]
3725 rhaas@postgresql.org 4843 : 0 : ExplainNode((PlanState *) lfirst(cell), ancestors, label, NULL, es);
4844 : 0 : }
4845 : :
4846 : : /*
4847 : : * Create a per-plan-node workspace for collecting per-worker data.
4848 : : *
4849 : : * Output related to each worker will be temporarily "set aside" into a
4850 : : * separate buffer, which we'll merge into the main output stream once
4851 : : * we've processed all data for the plan node. This makes it feasible to
4852 : : * generate a coherent sub-group of fields for each worker, even though the
4853 : : * code that produces the fields is in several different places in this file.
4854 : : * Formatting of such a set-aside field group is managed by
4855 : : * ExplainOpenSetAsideGroup and ExplainSaveGroup/ExplainRestoreGroup.
4856 : : */
4857 : : static ExplainWorkersState *
2051 tgl@sss.pgh.pa.us 4858 :CBC 513 : ExplainCreateWorkersState(int num_workers)
4859 : : {
4860 : : ExplainWorkersState *wstate;
4861 : :
4862 : 513 : wstate = (ExplainWorkersState *) palloc(sizeof(ExplainWorkersState));
4863 : 513 : wstate->num_workers = num_workers;
4864 : 513 : wstate->worker_inited = (bool *) palloc0(num_workers * sizeof(bool));
4865 : 513 : wstate->worker_str = (StringInfoData *)
4866 : 513 : palloc0(num_workers * sizeof(StringInfoData));
4867 : 513 : wstate->worker_state_save = (int *) palloc(num_workers * sizeof(int));
4868 : 513 : return wstate;
4869 : : }
4870 : :
4871 : : /*
4872 : : * Begin or resume output into the set-aside group for worker N.
4873 : : */
4874 : : static void
4875 : 72 : ExplainOpenWorker(int n, ExplainState *es)
4876 : : {
4877 : 72 : ExplainWorkersState *wstate = es->workers_state;
4878 : :
4879 [ - + ]: 72 : Assert(wstate);
4880 [ + - - + ]: 72 : Assert(n >= 0 && n < wstate->num_workers);
4881 : :
4882 : : /* Save prior output buffer pointer */
4883 : 72 : wstate->prev_str = es->str;
4884 : :
4885 [ + + ]: 72 : if (!wstate->worker_inited[n])
4886 : : {
4887 : : /* First time through, so create the buffer for this worker */
4888 : 36 : initStringInfo(&wstate->worker_str[n]);
4889 : 36 : es->str = &wstate->worker_str[n];
4890 : :
4891 : : /*
4892 : : * Push suitable initial formatting state for this worker's field
4893 : : * group. We allow one extra logical nesting level, since this group
4894 : : * will eventually be wrapped in an outer "Workers" group.
4895 : : */
4896 : 36 : ExplainOpenSetAsideGroup("Worker", NULL, true, 2, es);
4897 : :
4898 : : /*
4899 : : * In non-TEXT formats we always emit a "Worker Number" field, even if
4900 : : * there's no other data for this worker.
4901 : : */
4902 [ + + ]: 36 : if (es->format != EXPLAIN_FORMAT_TEXT)
4903 : 24 : ExplainPropertyInteger("Worker Number", NULL, n, es);
4904 : :
4905 : 36 : wstate->worker_inited[n] = true;
4906 : : }
4907 : : else
4908 : : {
4909 : : /* Resuming output for a worker we've already emitted some data for */
4910 : 36 : es->str = &wstate->worker_str[n];
4911 : :
4912 : : /* Restore formatting state saved by last ExplainCloseWorker() */
4913 : 36 : ExplainRestoreGroup(es, 2, &wstate->worker_state_save[n]);
4914 : : }
4915 : :
4916 : : /*
4917 : : * In TEXT format, prefix the first output line for this worker with
4918 : : * "Worker N:". Then, any additional lines should be indented one more
4919 : : * stop than the "Worker N" line is.
4920 : : */
4921 [ + + ]: 72 : if (es->format == EXPLAIN_FORMAT_TEXT)
4922 : : {
4923 [ + - ]: 12 : if (es->str->len == 0)
4924 : : {
4925 : 12 : ExplainIndentText(es);
4926 : 12 : appendStringInfo(es->str, "Worker %d: ", n);
4927 : : }
4928 : :
4929 : 12 : es->indent++;
4930 : : }
4931 : 72 : }
4932 : :
4933 : : /*
4934 : : * End output for worker N --- must pair with previous ExplainOpenWorker call
4935 : : */
4936 : : static void
4937 : 72 : ExplainCloseWorker(int n, ExplainState *es)
4938 : : {
4939 : 72 : ExplainWorkersState *wstate = es->workers_state;
4940 : :
4941 [ - + ]: 72 : Assert(wstate);
4942 [ + - - + ]: 72 : Assert(n >= 0 && n < wstate->num_workers);
4943 [ - + ]: 72 : Assert(wstate->worker_inited[n]);
4944 : :
4945 : : /*
4946 : : * Save formatting state in case we do another ExplainOpenWorker(), then
4947 : : * pop the formatting stack.
4948 : : */
4949 : 72 : ExplainSaveGroup(es, 2, &wstate->worker_state_save[n]);
4950 : :
4951 : : /*
4952 : : * In TEXT format, if we didn't actually produce any output line(s) then
4953 : : * truncate off the partial line emitted by ExplainOpenWorker. (This is
4954 : : * to avoid bogus output if, say, show_buffer_usage chooses not to print
4955 : : * anything for the worker.) Also fix up the indent level.
4956 : : */
4957 [ + + ]: 72 : if (es->format == EXPLAIN_FORMAT_TEXT)
4958 : : {
4959 [ + - - + ]: 12 : while (es->str->len > 0 && es->str->data[es->str->len - 1] != '\n')
2051 tgl@sss.pgh.pa.us 4960 :UBC 0 : es->str->data[--(es->str->len)] = '\0';
4961 : :
2051 tgl@sss.pgh.pa.us 4962 :CBC 12 : es->indent--;
4963 : : }
4964 : :
4965 : : /* Restore prior output buffer pointer */
4966 : 72 : es->str = wstate->prev_str;
4967 : 72 : }
4968 : :
4969 : : /*
4970 : : * Print per-worker info for current node, then free the ExplainWorkersState.
4971 : : */
4972 : : static void
4973 : 513 : ExplainFlushWorkersState(ExplainState *es)
4974 : : {
4975 : 513 : ExplainWorkersState *wstate = es->workers_state;
4976 : :
4977 : 513 : ExplainOpenGroup("Workers", "Workers", false, es);
4978 [ + + ]: 1353 : for (int i = 0; i < wstate->num_workers; i++)
4979 : : {
4980 [ + + ]: 840 : if (wstate->worker_inited[i])
4981 : : {
4982 : : /* This must match previous ExplainOpenSetAsideGroup call */
4983 : 36 : ExplainOpenGroup("Worker", NULL, true, es);
4984 : 36 : appendStringInfoString(es->str, wstate->worker_str[i].data);
4985 : 36 : ExplainCloseGroup("Worker", NULL, true, es);
4986 : :
4987 : 36 : pfree(wstate->worker_str[i].data);
4988 : : }
4989 : : }
4990 : 513 : ExplainCloseGroup("Workers", "Workers", false, es);
4991 : :
4992 : 513 : pfree(wstate->worker_inited);
4993 : 513 : pfree(wstate->worker_str);
4994 : 513 : pfree(wstate->worker_state_save);
4995 : 513 : pfree(wstate);
4996 : 513 : }
|