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