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