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