1 /*-------------------------------------------------------------------------
4 * Explain query execution plans
6 * Portions Copyright (c) 1996-2003, PostgreSQL Global Development Group
7 * Portions Copyright (c) 1994-5, Regents of the University of California
10 * $Header: /cvsroot/pgsql/src/backend/commands/explain.c,v 1.113 2003/08/04 02:39:58 momjian Exp $
12 *-------------------------------------------------------------------------
16 #include "access/genam.h"
17 #include "access/heapam.h"
18 #include "catalog/pg_type.h"
19 #include "commands/explain.h"
20 #include "commands/prepare.h"
21 #include "executor/executor.h"
22 #include "executor/instrument.h"
23 #include "lib/stringinfo.h"
24 #include "nodes/print.h"
25 #include "optimizer/clauses.h"
26 #include "optimizer/planner.h"
27 #include "optimizer/var.h"
28 #include "parser/parsetree.h"
29 #include "rewrite/rewriteHandler.h"
30 #include "tcop/pquery.h"
31 #include "utils/builtins.h"
32 #include "utils/guc.h"
33 #include "utils/lsyscache.h"
36 typedef struct ExplainState
39 bool printCost; /* print cost */
40 bool printNodes; /* do nodeToString() too */
41 bool printAnalyze; /* print actual times */
43 List *rtable; /* range table */
46 static void ExplainOneQuery(Query *query, ExplainStmt *stmt,
47 TupOutputState *tstate);
48 static double elapsed_time(struct timeval * starttime);
49 static void explain_outNode(StringInfo str,
50 Plan *plan, PlanState * planstate,
52 int indent, ExplainState *es);
53 static void show_scan_qual(List *qual, bool is_or_qual, const char *qlabel,
54 int scanrelid, Plan *outer_plan,
55 StringInfo str, int indent, ExplainState *es);
56 static void show_upper_qual(List *qual, const char *qlabel,
57 const char *outer_name, int outer_varno, Plan *outer_plan,
58 const char *inner_name, int inner_varno, Plan *inner_plan,
59 StringInfo str, int indent, ExplainState *es);
60 static void show_sort_keys(List *tlist, int nkeys, AttrNumber *keycols,
62 StringInfo str, int indent, ExplainState *es);
63 static Node *make_ors_ands_explicit(List *orclauses);
67 * execute an EXPLAIN command
70 ExplainQuery(ExplainStmt *stmt, DestReceiver *dest)
72 Query *query = stmt->query;
73 TupOutputState *tstate;
77 /* prepare for projection of tuples */
78 tstate = begin_tup_output_tupdesc(dest, ExplainResultDesc(stmt));
80 if (query->commandType == CMD_UTILITY)
82 /* Rewriter will not cope with utility statements */
83 if (query->utilityStmt && IsA(query->utilityStmt, DeclareCursorStmt))
84 ExplainOneQuery(query, stmt, tstate);
85 else if (query->utilityStmt && IsA(query->utilityStmt, ExecuteStmt))
86 ExplainExecuteQuery(stmt, tstate);
88 do_text_output_oneline(tstate, "Utility statements have no plan structure");
92 /* Rewrite through rule system */
93 rewritten = QueryRewrite(query);
97 /* In the case of an INSTEAD NOTHING, tell at least that */
98 do_text_output_oneline(tstate, "Query rewrites to nothing");
102 /* Explain every plan */
103 foreach(l, rewritten)
105 ExplainOneQuery(lfirst(l), stmt, tstate);
106 /* put a blank line between plans */
108 do_text_output_oneline(tstate, "");
113 end_tup_output(tstate);
117 * ExplainResultDesc -
118 * construct the result tupledesc for an EXPLAIN
121 ExplainResultDesc(ExplainStmt *stmt)
125 /* need a tuple descriptor representing a single TEXT column */
126 tupdesc = CreateTemplateTupleDesc(1, false);
127 TupleDescInitEntry(tupdesc, (AttrNumber) 1, "QUERY PLAN",
128 TEXTOID, -1, 0, false);
134 * print out the execution plan for one query
137 ExplainOneQuery(Query *query, ExplainStmt *stmt, TupOutputState *tstate)
140 QueryDesc *queryDesc;
141 bool isCursor = false;
142 int cursorOptions = 0;
144 /* planner will not cope with utility statements */
145 if (query->commandType == CMD_UTILITY)
147 if (query->utilityStmt && IsA(query->utilityStmt, DeclareCursorStmt))
149 DeclareCursorStmt *dcstmt;
152 dcstmt = (DeclareCursorStmt *) query->utilityStmt;
153 query = (Query *) dcstmt->query;
155 cursorOptions = dcstmt->options;
156 /* Still need to rewrite cursor command */
157 Assert(query->commandType == CMD_SELECT);
158 rewritten = QueryRewrite(query);
159 if (length(rewritten) != 1)
160 elog(ERROR, "unexpected rewrite result");
161 query = (Query *) lfirst(rewritten);
162 Assert(query->commandType == CMD_SELECT);
163 /* do not actually execute the underlying query! */
164 stmt->analyze = false;
166 else if (query->utilityStmt && IsA(query->utilityStmt, NotifyStmt))
168 do_text_output_oneline(tstate, "NOTIFY");
173 do_text_output_oneline(tstate, "UTILITY");
179 plan = planner(query, isCursor, cursorOptions);
181 /* Create a QueryDesc requesting no output */
182 queryDesc = CreateQueryDesc(query, plan, None_Receiver, NULL,
185 ExplainOnePlan(queryDesc, stmt, tstate);
190 * given a planned query, execute it if needed, and then print
193 * This is exported because it's called back from prepare.c in the
194 * EXPLAIN EXECUTE case
196 * Note: the passed-in QueryDesc is freed when we're done with it
199 ExplainOnePlan(QueryDesc *queryDesc, ExplainStmt *stmt,
200 TupOutputState *tstate)
202 struct timeval starttime;
203 double totaltime = 0;
207 gettimeofday(&starttime, NULL);
209 /* call ExecutorStart to prepare the plan for execution */
210 ExecutorStart(queryDesc, !stmt->analyze);
212 /* Execute the plan for statistics if asked for */
216 ExecutorRun(queryDesc, ForwardScanDirection, 0L);
218 /* We can't clean up 'till we're done printing the stats... */
219 totaltime += elapsed_time(&starttime);
222 es = (ExplainState *) palloc0(sizeof(ExplainState));
224 es->printCost = true; /* default */
225 es->printNodes = stmt->verbose;
226 es->printAnalyze = stmt->analyze;
227 es->rtable = queryDesc->parsetree->rtable;
234 s = nodeToString(queryDesc->plantree);
237 if (Explain_pretty_print)
238 f = pretty_format_node_dump(s);
240 f = format_node_dump(s);
242 do_text_output_multiline(tstate, f);
245 do_text_output_oneline(tstate, ""); /* separator line */
249 str = makeStringInfo();
253 explain_outNode(str, queryDesc->plantree, queryDesc->planstate,
258 * Close down the query and free resources. Include time for this in
261 gettimeofday(&starttime, NULL);
263 ExecutorEnd(queryDesc);
264 FreeQueryDesc(queryDesc);
266 CommandCounterIncrement();
268 totaltime += elapsed_time(&starttime);
273 appendStringInfo(str, "Total runtime: %.2f msec\n",
275 do_text_output_multiline(tstate, str->data);
283 /* Compute elapsed time in seconds since given gettimeofday() timestamp */
285 elapsed_time(struct timeval * starttime)
287 struct timeval endtime;
289 gettimeofday(&endtime, NULL);
291 endtime.tv_sec -= starttime->tv_sec;
292 endtime.tv_usec -= starttime->tv_usec;
293 while (endtime.tv_usec < 0)
295 endtime.tv_usec += 1000000;
298 return (double) endtime.tv_sec +
299 (double) endtime.tv_usec / 1000000.0;
304 * converts a Plan node into ascii string and appends it to 'str'
306 * planstate points to the executor state node corresponding to the plan node.
307 * We need this to get at the instrumentation data (if any) as well as the
310 * outer_plan, if not null, references another plan node that is the outer
311 * side of a join with the current node. This is only interesting for
312 * deciphering runtime keys of an inner indexscan.
315 explain_outNode(StringInfo str,
316 Plan *plan, PlanState * planstate,
318 int indent, ExplainState *es)
326 appendStringInfoChar(str, '\n');
330 switch (nodeTag(plan))
339 switch (((NestLoop *) plan)->join.jointype)
342 pname = "Nested Loop";
345 pname = "Nested Loop Left Join";
348 pname = "Nested Loop Full Join";
351 pname = "Nested Loop Right Join";
354 pname = "Nested Loop IN Join";
357 pname = "Nested Loop ??? Join";
362 switch (((MergeJoin *) plan)->join.jointype)
365 pname = "Merge Join";
368 pname = "Merge Left Join";
371 pname = "Merge Full Join";
374 pname = "Merge Right Join";
377 pname = "Merge IN Join";
380 pname = "Merge ??? Join";
385 switch (((HashJoin *) plan)->join.jointype)
391 pname = "Hash Left Join";
394 pname = "Hash Full Join";
397 pname = "Hash Right Join";
400 pname = "Hash IN Join";
403 pname = "Hash ??? Join";
411 pname = "Index Scan";
417 pname = "Subquery Scan";
420 pname = "Function Scan";
423 pname = "Materialize";
432 switch (((Agg *) plan)->aggstrategy)
438 pname = "GroupAggregate";
441 pname = "HashAggregate";
444 pname = "Aggregate ???";
452 switch (((SetOp *) plan)->cmd)
454 case SETOPCMD_INTERSECT:
455 pname = "SetOp Intersect";
457 case SETOPCMD_INTERSECT_ALL:
458 pname = "SetOp Intersect All";
460 case SETOPCMD_EXCEPT:
461 pname = "SetOp Except";
463 case SETOPCMD_EXCEPT_ALL:
464 pname = "SetOp Except All";
482 appendStringInfoString(str, pname);
483 switch (nodeTag(plan))
486 if (ScanDirectionIsBackward(((IndexScan *) plan)->indxorderdir))
487 appendStringInfoString(str, " Backward");
488 appendStringInfoString(str, " using ");
490 foreach(l, ((IndexScan *) plan)->indxid)
494 relation = index_open(lfirsto(l));
495 appendStringInfo(str, "%s%s",
496 (++i > 1) ? ", " : "",
497 quote_identifier(RelationGetRelationName(relation)));
498 index_close(relation);
503 if (((Scan *) plan)->scanrelid > 0)
505 RangeTblEntry *rte = rt_fetch(((Scan *) plan)->scanrelid,
509 /* Assume it's on a real relation */
510 Assert(rte->rtekind == RTE_RELATION);
512 /* We only show the rel name, not schema name */
513 relname = get_rel_name(rte->relid);
515 appendStringInfo(str, " on %s",
516 quote_identifier(relname));
517 if (strcmp(rte->eref->aliasname, relname) != 0)
518 appendStringInfo(str, " %s",
519 quote_identifier(rte->eref->aliasname));
523 if (((Scan *) plan)->scanrelid > 0)
525 RangeTblEntry *rte = rt_fetch(((Scan *) plan)->scanrelid,
528 appendStringInfo(str, " %s",
529 quote_identifier(rte->eref->aliasname));
533 if (((Scan *) plan)->scanrelid > 0)
535 RangeTblEntry *rte = rt_fetch(((Scan *) plan)->scanrelid,
539 /* Assert it's on a RangeFunction */
540 Assert(rte->rtekind == RTE_FUNCTION);
543 * If the expression is still a function call, we can get
544 * the real name of the function. Otherwise, punt (this
545 * can happen if the optimizer simplified away the
546 * function call, for example).
548 if (rte->funcexpr && IsA(rte->funcexpr, FuncExpr))
550 FuncExpr *funcexpr = (FuncExpr *) rte->funcexpr;
551 Oid funcid = funcexpr->funcid;
553 /* We only show the func name, not schema name */
554 proname = get_func_name(funcid);
557 proname = rte->eref->aliasname;
559 appendStringInfo(str, " on %s",
560 quote_identifier(proname));
561 if (strcmp(rte->eref->aliasname, proname) != 0)
562 appendStringInfo(str, " %s",
563 quote_identifier(rte->eref->aliasname));
571 appendStringInfo(str, " (cost=%.2f..%.2f rows=%.0f width=%d)",
572 plan->startup_cost, plan->total_cost,
573 plan->plan_rows, plan->plan_width);
576 * We have to forcibly clean up the instrumentation state because
577 * we haven't done ExecutorEnd yet. This is pretty grotty ...
579 InstrEndLoop(planstate->instrument);
581 if (planstate->instrument && planstate->instrument->nloops > 0)
583 double nloops = planstate->instrument->nloops;
585 appendStringInfo(str, " (actual time=%.2f..%.2f rows=%.0f loops=%.0f)",
586 1000.0 * planstate->instrument->startup / nloops,
587 1000.0 * planstate->instrument->total / nloops,
588 planstate->instrument->ntuples / nloops,
589 planstate->instrument->nloops);
591 else if (es->printAnalyze)
592 appendStringInfo(str, " (never executed)");
594 appendStringInfoChar(str, '\n');
596 /* quals, sort keys, etc */
597 switch (nodeTag(plan))
600 show_scan_qual(((IndexScan *) plan)->indxqualorig, true,
602 ((Scan *) plan)->scanrelid,
605 show_scan_qual(plan->qual, false,
607 ((Scan *) plan)->scanrelid,
615 show_scan_qual(plan->qual, false,
617 ((Scan *) plan)->scanrelid,
622 show_upper_qual(((NestLoop *) plan)->join.joinqual,
624 "outer", OUTER, outerPlan(plan),
625 "inner", INNER, innerPlan(plan),
627 show_upper_qual(plan->qual,
629 "outer", OUTER, outerPlan(plan),
630 "inner", INNER, innerPlan(plan),
634 show_upper_qual(((MergeJoin *) plan)->mergeclauses,
636 "outer", OUTER, outerPlan(plan),
637 "inner", INNER, innerPlan(plan),
639 show_upper_qual(((MergeJoin *) plan)->join.joinqual,
641 "outer", OUTER, outerPlan(plan),
642 "inner", INNER, innerPlan(plan),
644 show_upper_qual(plan->qual,
646 "outer", OUTER, outerPlan(plan),
647 "inner", INNER, innerPlan(plan),
651 show_upper_qual(((HashJoin *) plan)->hashclauses,
653 "outer", OUTER, outerPlan(plan),
654 "inner", INNER, innerPlan(plan),
656 show_upper_qual(((HashJoin *) plan)->join.joinqual,
658 "outer", OUTER, outerPlan(plan),
659 "inner", INNER, innerPlan(plan),
661 show_upper_qual(plan->qual,
663 "outer", OUTER, outerPlan(plan),
664 "inner", INNER, innerPlan(plan),
669 show_upper_qual(plan->qual,
671 "subplan", 0, outerPlan(plan),
676 show_sort_keys(plan->targetlist,
677 ((Sort *) plan)->numCols,
678 ((Sort *) plan)->sortColIdx,
683 show_upper_qual((List *) ((Result *) plan)->resconstantqual,
685 "subplan", OUTER, outerPlan(plan),
688 show_upper_qual(plan->qual,
690 "subplan", OUTER, outerPlan(plan),
701 List *saved_rtable = es->rtable;
704 for (i = 0; i < indent; i++)
705 appendStringInfo(str, " ");
706 appendStringInfo(str, " InitPlan\n");
707 foreach(lst, planstate->initPlan)
709 SubPlanState *sps = (SubPlanState *) lfirst(lst);
710 SubPlan *sp = (SubPlan *) sps->xprstate.expr;
712 es->rtable = sp->rtable;
713 for (i = 0; i < indent; i++)
714 appendStringInfo(str, " ");
715 appendStringInfo(str, " -> ");
716 explain_outNode(str, sp->plan,
721 es->rtable = saved_rtable;
727 for (i = 0; i < indent; i++)
728 appendStringInfo(str, " ");
729 appendStringInfo(str, " -> ");
730 explain_outNode(str, outerPlan(plan),
731 outerPlanState(planstate),
739 for (i = 0; i < indent; i++)
740 appendStringInfo(str, " ");
741 appendStringInfo(str, " -> ");
742 explain_outNode(str, innerPlan(plan),
743 innerPlanState(planstate),
748 if (IsA(plan, Append))
750 Append *appendplan = (Append *) plan;
751 AppendState *appendstate = (AppendState *) planstate;
756 foreach(lst, appendplan->appendplans)
758 Plan *subnode = (Plan *) lfirst(lst);
760 for (i = 0; i < indent; i++)
761 appendStringInfo(str, " ");
762 appendStringInfo(str, " -> ");
764 explain_outNode(str, subnode,
765 appendstate->appendplans[j],
772 if (IsA(plan, SubqueryScan))
774 SubqueryScan *subqueryscan = (SubqueryScan *) plan;
775 SubqueryScanState *subquerystate = (SubqueryScanState *) planstate;
776 Plan *subnode = subqueryscan->subplan;
777 RangeTblEntry *rte = rt_fetch(subqueryscan->scan.scanrelid,
779 List *saved_rtable = es->rtable;
781 Assert(rte->rtekind == RTE_SUBQUERY);
782 es->rtable = rte->subquery->rtable;
784 for (i = 0; i < indent; i++)
785 appendStringInfo(str, " ");
786 appendStringInfo(str, " -> ");
788 explain_outNode(str, subnode,
789 subquerystate->subplan,
793 es->rtable = saved_rtable;
797 if (planstate->subPlan)
799 List *saved_rtable = es->rtable;
802 for (i = 0; i < indent; i++)
803 appendStringInfo(str, " ");
804 appendStringInfo(str, " SubPlan\n");
805 foreach(lst, planstate->subPlan)
807 SubPlanState *sps = (SubPlanState *) lfirst(lst);
808 SubPlan *sp = (SubPlan *) sps->xprstate.expr;
810 es->rtable = sp->rtable;
811 for (i = 0; i < indent; i++)
812 appendStringInfo(str, " ");
813 appendStringInfo(str, " -> ");
814 explain_outNode(str, sp->plan,
819 es->rtable = saved_rtable;
824 * Show a qualifier expression for a scan plan node
827 show_scan_qual(List *qual, bool is_or_qual, const char *qlabel,
828 int scanrelid, Plan *outer_plan,
829 StringInfo str, int indent, ExplainState *es)
839 /* No work if empty qual */
844 if (lfirst(qual) == NIL && lnext(qual) == NIL)
848 /* Fix qual --- indexqual requires different processing */
850 node = make_ors_ands_explicit(qual);
852 node = (Node *) make_ands_explicit(qual);
854 /* Generate deparse context */
855 Assert(scanrelid > 0 && scanrelid <= length(es->rtable));
856 rte = rt_fetch(scanrelid, es->rtable);
857 scancontext = deparse_context_for_rte(rte);
860 * If we have an outer plan that is referenced by the qual, add it to
861 * the deparse context. If not, don't (so that we don't force
862 * prefixes unnecessarily).
866 Relids varnos = pull_varnos(node);
868 if (bms_is_member(OUTER, varnos))
869 outercontext = deparse_context_for_subplan("outer",
870 outer_plan->targetlist,
879 context = deparse_context_for_plan(scanrelid, scancontext,
883 /* Deparse the expression */
884 exprstr = deparse_expression(node, context, (outercontext != NULL), false);
887 for (i = 0; i < indent; i++)
888 appendStringInfo(str, " ");
889 appendStringInfo(str, " %s: %s\n", qlabel, exprstr);
893 * Show a qualifier expression for an upper-level plan node
896 show_upper_qual(List *qual, const char *qlabel,
897 const char *outer_name, int outer_varno, Plan *outer_plan,
898 const char *inner_name, int inner_varno, Plan *inner_plan,
899 StringInfo str, int indent, ExplainState *es)
908 /* No work if empty qual */
912 /* Generate deparse context */
914 outercontext = deparse_context_for_subplan(outer_name,
915 outer_plan->targetlist,
920 innercontext = deparse_context_for_subplan(inner_name,
921 inner_plan->targetlist,
925 context = deparse_context_for_plan(outer_varno, outercontext,
926 inner_varno, innercontext,
929 /* Deparse the expression */
930 node = (Node *) make_ands_explicit(qual);
931 exprstr = deparse_expression(node, context, (inner_plan != NULL), false);
934 for (i = 0; i < indent; i++)
935 appendStringInfo(str, " ");
936 appendStringInfo(str, " %s: %s\n", qlabel, exprstr);
940 * Show the sort keys for a Sort node.
943 show_sort_keys(List *tlist, int nkeys, AttrNumber *keycols,
945 StringInfo str, int indent, ExplainState *es)
958 for (i = 0; i < indent; i++)
959 appendStringInfo(str, " ");
960 appendStringInfo(str, " %s: ", qlabel);
963 * In this routine we expect that the plan node's tlist has not been
964 * processed by set_plan_references(). Normally, any Vars will
965 * contain valid varnos referencing the actual rtable. But we might
966 * instead be looking at a dummy tlist generated by prepunion.c; if
967 * there are Vars with zero varno, use the tlist itself to determine
970 varnos = pull_varnos((Node *) tlist);
971 if (bms_is_member(0, varnos))
975 outercontext = deparse_context_for_subplan("sort",
978 context = deparse_context_for_plan(0, outercontext,
985 context = deparse_context_for_plan(0, NULL,
988 useprefix = length(es->rtable) > 1;
992 for (keyno = 0; keyno < nkeys; keyno++)
994 /* find key expression in tlist */
995 AttrNumber keyresno = keycols[keyno];
999 TargetEntry *target = (TargetEntry *) lfirst(tl);
1001 if (target->resdom->resno == keyresno)
1003 /* Deparse the expression, showing any top-level cast */
1004 exprstr = deparse_expression((Node *) target->expr, context,
1006 /* And add to str */
1008 appendStringInfo(str, ", ");
1009 appendStringInfo(str, "%s", exprstr);
1014 elog(ERROR, "no tlist entry for key %d", keyresno);
1017 appendStringInfo(str, "\n");
1021 * Indexscan qual lists have an implicit OR-of-ANDs structure. Make it
1022 * explicit so deparsing works properly.
1025 make_ors_ands_explicit(List *orclauses)
1027 if (orclauses == NIL)
1028 return NULL; /* probably can't happen */
1029 else if (lnext(orclauses) == NIL)
1030 return (Node *) make_ands_explicit(lfirst(orclauses));
1036 FastListInit(&args);
1037 foreach(orptr, orclauses)
1038 FastAppend(&args, make_ands_explicit(lfirst(orptr)));
1040 return (Node *) make_orclause(FastListValue(&args));