granicus.if.org Git - postgresql/blob - src/backend/commands/explain.c

   1 /*-------------------------------------------------------------------------
   2  *
   3  * explain.c
   4  *        Explain query execution plans
   5  *
   6  * Portions Copyright (c) 1996-2007, PostgreSQL Global Development Group
   7  * Portions Copyright (c) 1994-5, Regents of the University of California
   8  *
   9  * IDENTIFICATION
  10  *        $PostgreSQL: pgsql/src/backend/commands/explain.c,v 1.160 2007/03/13 00:33:39 tgl Exp $
  11  *
  12  *-------------------------------------------------------------------------
  13  */
  14 #include "postgres.h"
  15
  16 #include "access/xact.h"
  17 #include "catalog/pg_constraint.h"
  18 #include "catalog/pg_type.h"
  19 #include "commands/explain.h"
  20 #include "commands/prepare.h"
  21 #include "commands/trigger.h"
  22 #include "executor/instrument.h"
  23 #include "nodes/print.h"
  24 #include "optimizer/clauses.h"
  25 #include "optimizer/planner.h"
  26 #include "optimizer/var.h"
  27 #include "parser/parsetree.h"
  28 #include "rewrite/rewriteHandler.h"
  29 #include "tcop/tcopprot.h"
  30 #include "utils/builtins.h"
  31 #include "utils/guc.h"
  32 #include "utils/lsyscache.h"
  33
  34
  35 typedef struct ExplainState
  36 {
  37         /* options */
  38         bool            printNodes;             /* do nodeToString() too */
  39         bool            printAnalyze;   /* print actual times */
  40         /* other states */
  41         PlannedStmt *pstmt;                     /* top of plan */
  42         List       *rtable;                     /* range table */
  43 } ExplainState;
  44
  45 static void ExplainOneQuery(Query *query, bool isCursor, int cursorOptions,
  46                                                         ExplainStmt *stmt, const char *queryString,
  47                                                         ParamListInfo params, TupOutputState *tstate);
  48 static double elapsed_time(instr_time *starttime);
  49 static void explain_outNode(StringInfo str,
  50                                 Plan *plan, PlanState *planstate,
  51                                 Plan *outer_plan,
  52                                 int indent, ExplainState *es);
  53 static void show_scan_qual(List *qual, const char *qlabel,
  54                            int scanrelid, Plan *outer_plan, Plan *inner_plan,
  55                            StringInfo str, int indent, ExplainState *es);
  56 static void show_upper_qual(List *qual, const char *qlabel, Plan *plan,
  57                                 StringInfo str, int indent, ExplainState *es);
  58 static void show_sort_keys(Plan *sortplan, int nkeys, AttrNumber *keycols,
  59                            const char *qlabel,
  60                            StringInfo str, int indent, ExplainState *es);
  61
  62 /*
  63  * ExplainQuery -
  64  *        execute an EXPLAIN command
  65  */
  66 void
  67 ExplainQuery(ExplainStmt *stmt, const char *queryString,
  68                          ParamListInfo params, DestReceiver *dest)
  69 {
  70         Oid                *param_types;
  71         int                     num_params;
  72         TupOutputState *tstate;
  73         List       *rewritten;
  74         ListCell   *l;
  75
  76         /* Convert parameter type data to the form parser wants */
  77         getParamListTypes(params, &param_types, &num_params);
  78
  79         /*
  80          * Run parse analysis and rewrite.  Note this also acquires sufficient
  81          * locks on the source table(s).
  82          *
  83          * Because the parser and planner tend to scribble on their input, we
  84          * make a preliminary copy of the source querytree.  This prevents
  85          * problems in the case that the EXPLAIN is in a portal or plpgsql
  86          * function and is executed repeatedly.  (See also the same hack in
  87          * DECLARE CURSOR and PREPARE.)  XXX FIXME someday.
  88          */
  89         rewritten = pg_analyze_and_rewrite((Node *) copyObject(stmt->query),
  90                                                                            queryString, param_types, num_params);
  91
  92         /* prepare for projection of tuples */
  93         tstate = begin_tup_output_tupdesc(dest, ExplainResultDesc(stmt));
  94
  95         if (rewritten == NIL)
  96         {
  97                 /* In the case of an INSTEAD NOTHING, tell at least that */
  98                 do_text_output_oneline(tstate, "Query rewrites to nothing");
  99         }
 100         else
 101         {
 102                 /* Explain every plan */
 103                 foreach(l, rewritten)
 104                 {
 105                         ExplainOneQuery((Query *) lfirst(l), false, 0,
 106                                                         stmt, queryString, params, tstate);
 107                         /* put a blank line between plans */
 108                         if (lnext(l) != NULL)
 109                                 do_text_output_oneline(tstate, "");
 110                 }
 111         }
 112
 113         end_tup_output(tstate);
 114 }
 115
 116 /*
 117  * ExplainResultDesc -
 118  *        construct the result tupledesc for an EXPLAIN
 119  */
 120 TupleDesc
 121 ExplainResultDesc(ExplainStmt *stmt)
 122 {
 123         TupleDesc       tupdesc;
 124
 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);
 129         return tupdesc;
 130 }
 131
 132 /*
 133  * ExplainOneQuery -
 134  *        print out the execution plan for one Query
 135  */
 136 static void
 137 ExplainOneQuery(Query *query, bool isCursor, int cursorOptions,
 138                                 ExplainStmt *stmt, const char *queryString,
 139                                 ParamListInfo params, TupOutputState *tstate)
 140 {
 141         PlannedStmt *plan;
 142         QueryDesc  *queryDesc;
 143
 144         /* planner will not cope with utility statements */
 145         if (query->commandType == CMD_UTILITY)
 146         {
 147                 ExplainOneUtility(query->utilityStmt, stmt,
 148                                                   queryString, params, tstate);
 149                 return;
 150         }
 151
 152         /* plan the query */
 153         plan = planner(query, isCursor, cursorOptions, params);
 154
 155         /*
 156          * Update snapshot command ID to ensure this query sees results of any
 157          * previously executed queries.  (It's a bit cheesy to modify
 158          * ActiveSnapshot without making a copy, but for the limited ways in which
 159          * EXPLAIN can be invoked, I think it's OK, because the active snapshot
 160          * shouldn't be shared with anything else anyway.)
 161          */
 162         ActiveSnapshot->curcid = GetCurrentCommandId();
 163
 164         /* Create a QueryDesc requesting no output */
 165         queryDesc = CreateQueryDesc(plan,
 166                                                                 ActiveSnapshot, InvalidSnapshot,
 167                                                                 None_Receiver, params,
 168                                                                 stmt->analyze);
 169
 170         ExplainOnePlan(queryDesc, stmt, tstate);
 171 }
 172
 173 /*
 174  * ExplainOneUtility -
 175  *        print out the execution plan for one utility statement
 176  *        (In general, utility statements don't have plans, but there are some
 177  *        we treat as special cases)
 178  *
 179  * This is exported because it's called back from prepare.c in the
 180  * EXPLAIN EXECUTE case
 181  */
 182 void
 183 ExplainOneUtility(Node *utilityStmt, ExplainStmt *stmt,
 184                                   const char *queryString, ParamListInfo params,
 185                                   TupOutputState *tstate)
 186 {
 187         if (utilityStmt == NULL)
 188                 return;
 189
 190         if (IsA(utilityStmt, DeclareCursorStmt))
 191         {
 192                 DeclareCursorStmt *dcstmt = (DeclareCursorStmt *) utilityStmt;
 193                 Oid                *param_types;
 194                 int                     num_params;
 195                 Query      *query;
 196                 List       *rewritten;
 197                 ExplainStmt newstmt;
 198
 199                 /* Convert parameter type data to the form parser wants */
 200                 getParamListTypes(params, &param_types, &num_params);
 201
 202                 /*
 203                  * Run parse analysis and rewrite.  Note this also acquires sufficient
 204                  * locks on the source table(s).
 205                  *
 206                  * Because the parser and planner tend to scribble on their input, we
 207                  * make a preliminary copy of the source querytree.  This prevents
 208                  * problems in the case that the DECLARE CURSOR is in a portal or
 209                  * plpgsql function and is executed repeatedly.  (See also the same
 210                  * hack in COPY and PREPARE.)  XXX FIXME someday.
 211                  */
 212                 rewritten = pg_analyze_and_rewrite((Node *) copyObject(dcstmt->query),
 213                                                                                    queryString,
 214                                                                                    param_types, num_params);
 215
 216                 /* We don't expect more or less than one result query */
 217                 if (list_length(rewritten) != 1 || !IsA(linitial(rewritten), Query))
 218                         elog(ERROR, "unexpected rewrite result");
 219                 query = (Query *) linitial(rewritten);
 220                 if (query->commandType != CMD_SELECT)
 221                         elog(ERROR, "unexpected rewrite result");
 222
 223                 /* But we must explicitly disallow DECLARE CURSOR ... SELECT INTO */
 224                 if (query->into)
 225                         ereport(ERROR,
 226                                         (errcode(ERRCODE_INVALID_CURSOR_DEFINITION),
 227                                          errmsg("DECLARE CURSOR cannot specify INTO")));
 228
 229                 /* do not actually execute the underlying query! */
 230                 memcpy(&newstmt, stmt, sizeof(ExplainStmt));
 231                 newstmt.analyze = false;
 232                 ExplainOneQuery(query, true, dcstmt->options, &newstmt,
 233                                                 queryString, params, tstate);
 234         }
 235         else if (IsA(utilityStmt, ExecuteStmt))
 236                 ExplainExecuteQuery((ExecuteStmt *) utilityStmt, stmt,
 237                                                         queryString, params, tstate);
 238         else if (IsA(utilityStmt, NotifyStmt))
 239                 do_text_output_oneline(tstate, "NOTIFY");
 240         else
 241                 do_text_output_oneline(tstate,
 242                                                            "Utility statements have no plan structure");
 243 }
 244
 245 /*
 246  * ExplainOnePlan -
 247  *              given a planned query, execute it if needed, and then print
 248  *              EXPLAIN output
 249  *
 250  * This is exported because it's called back from prepare.c in the
 251  * EXPLAIN EXECUTE case
 252  *
 253  * Note: the passed-in QueryDesc is freed when we're done with it
 254  */
 255 void
 256 ExplainOnePlan(QueryDesc *queryDesc, ExplainStmt *stmt,
 257                            TupOutputState *tstate)
 258 {
 259         instr_time      starttime;
 260         double          totaltime = 0;
 261         ExplainState *es;
 262         StringInfoData buf;
 263         int                     eflags;
 264
 265         INSTR_TIME_SET_CURRENT(starttime);
 266
 267         /* If analyzing, we need to cope with queued triggers */
 268         if (stmt->analyze)
 269                 AfterTriggerBeginQuery();
 270
 271         /* Select execution options */
 272         if (stmt->analyze)
 273                 eflags = 0;                             /* default run-to-completion flags */
 274         else
 275                 eflags = EXEC_FLAG_EXPLAIN_ONLY;
 276
 277         /* call ExecutorStart to prepare the plan for execution */
 278         ExecutorStart(queryDesc, eflags);
 279
 280         /* Execute the plan for statistics if asked for */
 281         if (stmt->analyze)
 282         {
 283                 /* run the plan */
 284                 ExecutorRun(queryDesc, ForwardScanDirection, 0L);
 285
 286                 /* We can't clean up 'till we're done printing the stats... */
 287                 totaltime += elapsed_time(&starttime);
 288         }
 289
 290         es = (ExplainState *) palloc0(sizeof(ExplainState));
 291
 292         es->printNodes = stmt->verbose;
 293         es->printAnalyze = stmt->analyze;
 294         es->pstmt = queryDesc->plannedstmt;
 295         es->rtable = queryDesc->plannedstmt->rtable;
 296
 297         if (es->printNodes)
 298         {
 299                 char       *s;
 300                 char       *f;
 301
 302                 s = nodeToString(queryDesc->plannedstmt->planTree);
 303                 if (s)
 304                 {
 305                         if (Explain_pretty_print)
 306                                 f = pretty_format_node_dump(s);
 307                         else
 308                                 f = format_node_dump(s);
 309                         pfree(s);
 310                         do_text_output_multiline(tstate, f);
 311                         pfree(f);
 312                         do_text_output_oneline(tstate, ""); /* separator line */
 313                 }
 314         }
 315
 316         initStringInfo(&buf);
 317         explain_outNode(&buf,
 318                                         queryDesc->plannedstmt->planTree, queryDesc->planstate,
 319                                         NULL, 0, es);
 320
 321         /*
 322          * If we ran the command, run any AFTER triggers it queued.  (Note this
 323          * will not include DEFERRED triggers; since those don't run until end of
 324          * transaction, we can't measure them.)  Include into total runtime.
 325          */
 326         if (stmt->analyze)
 327         {
 328                 INSTR_TIME_SET_CURRENT(starttime);
 329                 AfterTriggerEndQuery(queryDesc->estate);
 330                 totaltime += elapsed_time(&starttime);
 331         }
 332
 333         /* Print info about runtime of triggers */
 334         if (es->printAnalyze)
 335         {
 336                 ResultRelInfo *rInfo;
 337                 int                     numrels = queryDesc->estate->es_num_result_relations;
 338                 int                     nr;
 339
 340                 rInfo = queryDesc->estate->es_result_relations;
 341                 for (nr = 0; nr < numrels; rInfo++, nr++)
 342                 {
 343                         int                     nt;
 344
 345                         if (!rInfo->ri_TrigDesc || !rInfo->ri_TrigInstrument)
 346                                 continue;
 347                         for (nt = 0; nt < rInfo->ri_TrigDesc->numtriggers; nt++)
 348                         {
 349                                 Trigger    *trig = rInfo->ri_TrigDesc->triggers + nt;
 350                                 Instrumentation *instr = rInfo->ri_TrigInstrument + nt;
 351                                 char       *conname;
 352
 353                                 /* Must clean up instrumentation state */
 354                                 InstrEndLoop(instr);
 355
 356                                 /*
 357                                  * We ignore triggers that were never invoked; they likely
 358                                  * aren't relevant to the current query type.
 359                                  */
 360                                 if (instr->ntuples == 0)
 361                                         continue;
 362
 363                                 if (OidIsValid(trig->tgconstraint) &&
 364                                         (conname = get_constraint_name(trig->tgconstraint)) != NULL)
 365                                 {
 366                                         appendStringInfo(&buf, "Trigger for constraint %s",
 367                                                                          conname);
 368                                         pfree(conname);
 369                                 }
 370                                 else
 371                                         appendStringInfo(&buf, "Trigger %s", trig->tgname);
 372
 373                                 if (numrels > 1)
 374                                         appendStringInfo(&buf, " on %s",
 375                                                         RelationGetRelationName(rInfo->ri_RelationDesc));
 376
 377                                 appendStringInfo(&buf, ": time=%.3f calls=%.0f\n",
 378                                                                  1000.0 * instr->total,
 379                                                                  instr->ntuples);
 380                         }
 381                 }
 382         }
 383
 384         /*
 385          * Close down the query and free resources.  Include time for this in the
 386          * total runtime (although it should be pretty minimal).
 387          */
 388         INSTR_TIME_SET_CURRENT(starttime);
 389
 390         ExecutorEnd(queryDesc);
 391
 392         FreeQueryDesc(queryDesc);
 393
 394         /* We need a CCI just in case query expanded to multiple plans */
 395         if (stmt->analyze)
 396                 CommandCounterIncrement();
 397
 398         totaltime += elapsed_time(&starttime);
 399
 400         if (stmt->analyze)
 401                 appendStringInfo(&buf, "Total runtime: %.3f ms\n",
 402                                                  1000.0 * totaltime);
 403         do_text_output_multiline(tstate, buf.data);
 404
 405         pfree(buf.data);
 406         pfree(es);
 407 }
 408
 409 /* Compute elapsed time in seconds since given timestamp */
 410 static double
 411 elapsed_time(instr_time *starttime)
 412 {
 413         instr_time      endtime;
 414
 415         INSTR_TIME_SET_CURRENT(endtime);
 416
 417 #ifndef WIN32
 418         endtime.tv_sec -= starttime->tv_sec;
 419         endtime.tv_usec -= starttime->tv_usec;
 420         while (endtime.tv_usec < 0)
 421         {
 422                 endtime.tv_usec += 1000000;
 423                 endtime.tv_sec--;
 424         }
 425 #else                                                   /* WIN32 */
 426         endtime.QuadPart -= starttime->QuadPart;
 427 #endif
 428
 429         return INSTR_TIME_GET_DOUBLE(endtime);
 430 }
 431
 432 /*
 433  * explain_outNode -
 434  *        converts a Plan node into ascii string and appends it to 'str'
 435  *
 436  * planstate points to the executor state node corresponding to the plan node.
 437  * We need this to get at the instrumentation data (if any) as well as the
 438  * list of subplans.
 439  *
 440  * outer_plan, if not null, references another plan node that is the outer
 441  * side of a join with the current node.  This is only interesting for
 442  * deciphering runtime keys of an inner indexscan.
 443  */
 444 static void
 445 explain_outNode(StringInfo str,
 446                                 Plan *plan, PlanState *planstate,
 447                                 Plan *outer_plan,
 448                                 int indent, ExplainState *es)
 449 {
 450         char       *pname;
 451         int                     i;
 452
 453         if (plan == NULL)
 454         {
 455                 appendStringInfoChar(str, '\n');
 456                 return;
 457         }
 458
 459         switch (nodeTag(plan))
 460         {
 461                 case T_Result:
 462                         pname = "Result";
 463                         break;
 464                 case T_Append:
 465                         pname = "Append";
 466                         break;
 467                 case T_BitmapAnd:
 468                         pname = "BitmapAnd";
 469                         break;
 470                 case T_BitmapOr:
 471                         pname = "BitmapOr";
 472                         break;
 473                 case T_NestLoop:
 474                         switch (((NestLoop *) plan)->join.jointype)
 475                         {
 476                                 case JOIN_INNER:
 477                                         pname = "Nested Loop";
 478                                         break;
 479                                 case JOIN_LEFT:
 480                                         pname = "Nested Loop Left Join";
 481                                         break;
 482                                 case JOIN_FULL:
 483                                         pname = "Nested Loop Full Join";
 484                                         break;
 485                                 case JOIN_RIGHT:
 486                                         pname = "Nested Loop Right Join";
 487                                         break;
 488                                 case JOIN_IN:
 489                                         pname = "Nested Loop IN Join";
 490                                         break;
 491                                 default:
 492                                         pname = "Nested Loop ??? Join";
 493                                         break;
 494                         }
 495                         break;
 496                 case T_MergeJoin:
 497                         switch (((MergeJoin *) plan)->join.jointype)
 498                         {
 499                                 case JOIN_INNER:
 500                                         pname = "Merge Join";
 501                                         break;
 502                                 case JOIN_LEFT:
 503                                         pname = "Merge Left Join";
 504                                         break;
 505                                 case JOIN_FULL:
 506                                         pname = "Merge Full Join";
 507                                         break;
 508                                 case JOIN_RIGHT:
 509                                         pname = "Merge Right Join";
 510                                         break;
 511                                 case JOIN_IN:
 512                                         pname = "Merge IN Join";
 513                                         break;
 514                                 default:
 515                                         pname = "Merge ??? Join";
 516                                         break;
 517                         }
 518                         break;
 519                 case T_HashJoin:
 520                         switch (((HashJoin *) plan)->join.jointype)
 521                         {
 522                                 case JOIN_INNER:
 523                                         pname = "Hash Join";
 524                                         break;
 525                                 case JOIN_LEFT:
 526                                         pname = "Hash Left Join";
 527                                         break;
 528                                 case JOIN_FULL:
 529                                         pname = "Hash Full Join";
 530                                         break;
 531                                 case JOIN_RIGHT:
 532                                         pname = "Hash Right Join";
 533                                         break;
 534                                 case JOIN_IN:
 535                                         pname = "Hash IN Join";
 536                                         break;
 537                                 default:
 538                                         pname = "Hash ??? Join";
 539                                         break;
 540                         }
 541                         break;
 542                 case T_SeqScan:
 543                         pname = "Seq Scan";
 544                         break;
 545                 case T_IndexScan:
 546                         pname = "Index Scan";
 547                         break;
 548                 case T_BitmapIndexScan:
 549                         pname = "Bitmap Index Scan";
 550                         break;
 551                 case T_BitmapHeapScan:
 552                         pname = "Bitmap Heap Scan";
 553                         break;
 554                 case T_TidScan:
 555                         pname = "Tid Scan";
 556                         break;
 557                 case T_SubqueryScan:
 558                         pname = "Subquery Scan";
 559                         break;
 560                 case T_FunctionScan:
 561                         pname = "Function Scan";
 562                         break;
 563                 case T_ValuesScan:
 564                         pname = "Values Scan";
 565                         break;
 566                 case T_Material:
 567                         pname = "Materialize";
 568                         break;
 569                 case T_Sort:
 570                         pname = "Sort";
 571                         break;
 572                 case T_Group:
 573                         pname = "Group";
 574                         break;
 575                 case T_Agg:
 576                         switch (((Agg *) plan)->aggstrategy)
 577                         {
 578                                 case AGG_PLAIN:
 579                                         pname = "Aggregate";
 580                                         break;
 581                                 case AGG_SORTED:
 582                                         pname = "GroupAggregate";
 583                                         break;
 584                                 case AGG_HASHED:
 585                                         pname = "HashAggregate";
 586                                         break;
 587                                 default:
 588                                         pname = "Aggregate ???";
 589                                         break;
 590                         }
 591                         break;
 592                 case T_Unique:
 593                         pname = "Unique";
 594                         break;
 595                 case T_SetOp:
 596                         switch (((SetOp *) plan)->cmd)
 597                         {
 598                                 case SETOPCMD_INTERSECT:
 599                                         pname = "SetOp Intersect";
 600                                         break;
 601                                 case SETOPCMD_INTERSECT_ALL:
 602                                         pname = "SetOp Intersect All";
 603                                         break;
 604                                 case SETOPCMD_EXCEPT:
 605                                         pname = "SetOp Except";
 606                                         break;
 607                                 case SETOPCMD_EXCEPT_ALL:
 608                                         pname = "SetOp Except All";
 609                                         break;
 610                                 default:
 611                                         pname = "SetOp ???";
 612                                         break;
 613                         }
 614                         break;
 615                 case T_Limit:
 616                         pname = "Limit";
 617                         break;
 618                 case T_Hash:
 619                         pname = "Hash";
 620                         break;
 621                 default:
 622                         pname = "???";
 623                         break;
 624         }
 625
 626         appendStringInfoString(str, pname);
 627         switch (nodeTag(plan))
 628         {
 629                 case T_IndexScan:
 630                         if (ScanDirectionIsBackward(((IndexScan *) plan)->indexorderdir))
 631                                 appendStringInfoString(str, " Backward");
 632                         appendStringInfo(str, " using %s",
 633                           quote_identifier(get_rel_name(((IndexScan *) plan)->indexid)));
 634                         /* FALL THRU */
 635                 case T_SeqScan:
 636                 case T_BitmapHeapScan:
 637                 case T_TidScan:
 638                         if (((Scan *) plan)->scanrelid > 0)
 639                         {
 640                                 RangeTblEntry *rte = rt_fetch(((Scan *) plan)->scanrelid,
 641                                                                                           es->rtable);
 642                                 char       *relname;
 643
 644                                 /* Assume it's on a real relation */
 645                                 Assert(rte->rtekind == RTE_RELATION);
 646
 647                                 /* We only show the rel name, not schema name */
 648                                 relname = get_rel_name(rte->relid);
 649
 650                                 appendStringInfo(str, " on %s",
 651                                                                  quote_identifier(relname));
 652                                 if (strcmp(rte->eref->aliasname, relname) != 0)
 653                                         appendStringInfo(str, " %s",
 654                                                                          quote_identifier(rte->eref->aliasname));
 655                         }
 656                         break;
 657                 case T_BitmapIndexScan:
 658                         appendStringInfo(str, " on %s",
 659                                                          quote_identifier(get_rel_name(((BitmapIndexScan *) plan)->indexid)));
 660                         break;
 661                 case T_SubqueryScan:
 662                         if (((Scan *) plan)->scanrelid > 0)
 663                         {
 664                                 RangeTblEntry *rte = rt_fetch(((Scan *) plan)->scanrelid,
 665                                                                                           es->rtable);
 666
 667                                 appendStringInfo(str, " %s",
 668                                                                  quote_identifier(rte->eref->aliasname));
 669                         }
 670                         break;
 671                 case T_FunctionScan:
 672                         if (((Scan *) plan)->scanrelid > 0)
 673                         {
 674                                 RangeTblEntry *rte = rt_fetch(((Scan *) plan)->scanrelid,
 675                                                                                           es->rtable);
 676                                 Node       *funcexpr;
 677                                 char       *proname;
 678
 679                                 /* Assert it's on a RangeFunction */
 680                                 Assert(rte->rtekind == RTE_FUNCTION);
 681
 682                                 /*
 683                                  * If the expression is still a function call, we can get the
 684                                  * real name of the function.  Otherwise, punt (this can
 685                                  * happen if the optimizer simplified away the function call,
 686                                  * for example).
 687                                  */
 688                                 funcexpr = ((FunctionScan *) plan)->funcexpr;
 689                                 if (funcexpr && IsA(funcexpr, FuncExpr))
 690                                 {
 691                                         Oid                     funcid = ((FuncExpr *) funcexpr)->funcid;
 692
 693                                         /* We only show the func name, not schema name */
 694                                         proname = get_func_name(funcid);
 695                                 }
 696                                 else
 697                                         proname = rte->eref->aliasname;
 698
 699                                 appendStringInfo(str, " on %s",
 700                                                                  quote_identifier(proname));
 701                                 if (strcmp(rte->eref->aliasname, proname) != 0)
 702                                         appendStringInfo(str, " %s",
 703                                                                          quote_identifier(rte->eref->aliasname));
 704                         }
 705                         break;
 706                 case T_ValuesScan:
 707                         if (((Scan *) plan)->scanrelid > 0)
 708                         {
 709                                 RangeTblEntry *rte = rt_fetch(((Scan *) plan)->scanrelid,
 710                                                                                           es->rtable);
 711                                 char       *valsname;
 712
 713                                 /* Assert it's on a values rte */
 714                                 Assert(rte->rtekind == RTE_VALUES);
 715
 716                                 valsname = rte->eref->aliasname;
 717
 718                                 appendStringInfo(str, " on %s",
 719                                                                  quote_identifier(valsname));
 720                         }
 721                         break;
 722                 default:
 723                         break;
 724         }
 725
 726         appendStringInfo(str, "  (cost=%.2f..%.2f rows=%.0f width=%d)",
 727                                          plan->startup_cost, plan->total_cost,
 728                                          plan->plan_rows, plan->plan_width);
 729
 730         /*
 731          * We have to forcibly clean up the instrumentation state because we
 732          * haven't done ExecutorEnd yet.  This is pretty grotty ...
 733          */
 734         if (planstate->instrument)
 735                 InstrEndLoop(planstate->instrument);
 736
 737         if (planstate->instrument && planstate->instrument->nloops > 0)
 738         {
 739                 double          nloops = planstate->instrument->nloops;
 740
 741                 appendStringInfo(str, " (actual time=%.3f..%.3f rows=%.0f loops=%.0f)",
 742                                                  1000.0 * planstate->instrument->startup / nloops,
 743                                                  1000.0 * planstate->instrument->total / nloops,
 744                                                  planstate->instrument->ntuples / nloops,
 745                                                  planstate->instrument->nloops);
 746         }
 747         else if (es->printAnalyze)
 748                 appendStringInfo(str, " (never executed)");
 749         appendStringInfoChar(str, '\n');
 750
 751         /* quals, sort keys, etc */
 752         switch (nodeTag(plan))
 753         {
 754                 case T_IndexScan:
 755                         show_scan_qual(((IndexScan *) plan)->indexqualorig,
 756                                                    "Index Cond",
 757                                                    ((Scan *) plan)->scanrelid,
 758                                                    outer_plan, NULL,
 759                                                    str, indent, es);
 760                         show_scan_qual(plan->qual,
 761                                                    "Filter",
 762                                                    ((Scan *) plan)->scanrelid,
 763                                                    outer_plan, NULL,
 764                                                    str, indent, es);
 765                         break;
 766                 case T_BitmapIndexScan:
 767                         show_scan_qual(((BitmapIndexScan *) plan)->indexqualorig,
 768                                                    "Index Cond",
 769                                                    ((Scan *) plan)->scanrelid,
 770                                                    outer_plan, NULL,
 771                                                    str, indent, es);
 772                         break;
 773                 case T_BitmapHeapScan:
 774                         /* XXX do we want to show this in production? */
 775                         show_scan_qual(((BitmapHeapScan *) plan)->bitmapqualorig,
 776                                                    "Recheck Cond",
 777                                                    ((Scan *) plan)->scanrelid,
 778                                                    outer_plan, NULL,
 779                                                    str, indent, es);
 780                         /* FALL THRU */
 781                 case T_SeqScan:
 782                 case T_FunctionScan:
 783                 case T_ValuesScan:
 784                         show_scan_qual(plan->qual,
 785                                                    "Filter",
 786                                                    ((Scan *) plan)->scanrelid,
 787                                                    outer_plan, NULL,
 788                                                    str, indent, es);
 789                         break;
 790                 case T_SubqueryScan:
 791                         show_scan_qual(plan->qual,
 792                                                    "Filter",
 793                                                    ((Scan *) plan)->scanrelid,
 794                                                    outer_plan,
 795                                                    ((SubqueryScan *) plan)->subplan,
 796                                                    str, indent, es);
 797                         break;
 798                 case T_TidScan:
 799                         {
 800                                 /*
 801                                  * The tidquals list has OR semantics, so be sure to show it
 802                                  * as an OR condition.
 803                                  */
 804                                 List       *tidquals = ((TidScan *) plan)->tidquals;
 805
 806                                 if (list_length(tidquals) > 1)
 807                                         tidquals = list_make1(make_orclause(tidquals));
 808                                 show_scan_qual(tidquals,
 809                                                            "TID Cond",
 810                                                            ((Scan *) plan)->scanrelid,
 811                                                            outer_plan, NULL,
 812                                                            str, indent, es);
 813                                 show_scan_qual(plan->qual,
 814                                                            "Filter",
 815                                                            ((Scan *) plan)->scanrelid,
 816                                                            outer_plan, NULL,
 817                                                            str, indent, es);
 818                         }
 819                         break;
 820                 case T_NestLoop:
 821                         show_upper_qual(((NestLoop *) plan)->join.joinqual,
 822                                                         "Join Filter", plan,
 823                                                         str, indent, es);
 824                         show_upper_qual(plan->qual,
 825                                                         "Filter", plan,
 826                                                         str, indent, es);
 827                         break;
 828                 case T_MergeJoin:
 829                         show_upper_qual(((MergeJoin *) plan)->mergeclauses,
 830                                                         "Merge Cond", plan,
 831                                                         str, indent, es);
 832                         show_upper_qual(((MergeJoin *) plan)->join.joinqual,
 833                                                         "Join Filter", plan,
 834                                                         str, indent, es);
 835                         show_upper_qual(plan->qual,
 836                                                         "Filter", plan,
 837                                                         str, indent, es);
 838                         break;
 839                 case T_HashJoin:
 840                         show_upper_qual(((HashJoin *) plan)->hashclauses,
 841                                                         "Hash Cond", plan,
 842                                                         str, indent, es);
 843                         show_upper_qual(((HashJoin *) plan)->join.joinqual,
 844                                                         "Join Filter", plan,
 845                                                         str, indent, es);
 846                         show_upper_qual(plan->qual,
 847                                                         "Filter", plan,
 848                                                         str, indent, es);
 849                         break;
 850                 case T_Agg:
 851                 case T_Group:
 852                         show_upper_qual(plan->qual,
 853                                                         "Filter", plan,
 854                                                         str, indent, es);
 855                         break;
 856                 case T_Sort:
 857                         show_sort_keys(plan,
 858                                                    ((Sort *) plan)->numCols,
 859                                                    ((Sort *) plan)->sortColIdx,
 860                                                    "Sort Key",
 861                                                    str, indent, es);
 862                         break;
 863                 case T_Result:
 864                         show_upper_qual((List *) ((Result *) plan)->resconstantqual,
 865                                                         "One-Time Filter", plan,
 866                                                         str, indent, es);
 867                         show_upper_qual(plan->qual,
 868                                                         "Filter", plan,
 869                                                         str, indent, es);
 870                         break;
 871                 default:
 872                         break;
 873         }
 874
 875         /* initPlan-s */
 876         if (plan->initPlan)
 877         {
 878                 ListCell   *lst;
 879
 880                 for (i = 0; i < indent; i++)
 881                         appendStringInfo(str, "  ");
 882                 appendStringInfo(str, "  InitPlan\n");
 883                 foreach(lst, planstate->initPlan)
 884                 {
 885                         SubPlanState *sps = (SubPlanState *) lfirst(lst);
 886                         SubPlan    *sp = (SubPlan *) sps->xprstate.expr;
 887
 888                         for (i = 0; i < indent; i++)
 889                                 appendStringInfo(str, "  ");
 890                         appendStringInfo(str, "    ->  ");
 891                         explain_outNode(str,
 892                                                         exec_subplan_get_plan(es->pstmt, sp),
 893                                                         sps->planstate,
 894                                                         NULL,
 895                                                         indent + 4, es);
 896                 }
 897         }
 898
 899         /* lefttree */
 900         if (outerPlan(plan))
 901         {
 902                 for (i = 0; i < indent; i++)
 903                         appendStringInfo(str, "  ");
 904                 appendStringInfo(str, "  ->  ");
 905
 906                 /*
 907                  * Ordinarily we don't pass down our own outer_plan value to our child
 908                  * nodes, but in bitmap scan trees we must, since the bottom
 909                  * BitmapIndexScan nodes may have outer references.
 910                  */
 911                 explain_outNode(str, outerPlan(plan),
 912                                                 outerPlanState(planstate),
 913                                                 IsA(plan, BitmapHeapScan) ? outer_plan : NULL,
 914                                                 indent + 3, es);
 915         }
 916
 917         /* righttree */
 918         if (innerPlan(plan))
 919         {
 920                 for (i = 0; i < indent; i++)
 921                         appendStringInfo(str, "  ");
 922                 appendStringInfo(str, "  ->  ");
 923                 explain_outNode(str, innerPlan(plan),
 924                                                 innerPlanState(planstate),
 925                                                 outerPlan(plan),
 926                                                 indent + 3, es);
 927         }
 928
 929         if (IsA(plan, Append))
 930         {
 931                 Append     *appendplan = (Append *) plan;
 932                 AppendState *appendstate = (AppendState *) planstate;
 933                 ListCell   *lst;
 934                 int                     j;
 935
 936                 j = 0;
 937                 foreach(lst, appendplan->appendplans)
 938                 {
 939                         Plan       *subnode = (Plan *) lfirst(lst);
 940
 941                         for (i = 0; i < indent; i++)
 942                                 appendStringInfo(str, "  ");
 943                         appendStringInfo(str, "  ->  ");
 944
 945                         /*
 946                          * Ordinarily we don't pass down our own outer_plan value to our
 947                          * child nodes, but in an Append we must, since we might be
 948                          * looking at an appendrel indexscan with outer references from
 949                          * the member scans.
 950                          */
 951                         explain_outNode(str, subnode,
 952                                                         appendstate->appendplans[j],
 953                                                         outer_plan,
 954                                                         indent + 3, es);
 955                         j++;
 956                 }
 957         }
 958
 959         if (IsA(plan, BitmapAnd))
 960         {
 961                 BitmapAnd  *bitmapandplan = (BitmapAnd *) plan;
 962                 BitmapAndState *bitmapandstate = (BitmapAndState *) planstate;
 963                 ListCell   *lst;
 964                 int                     j;
 965
 966                 j = 0;
 967                 foreach(lst, bitmapandplan->bitmapplans)
 968                 {
 969                         Plan       *subnode = (Plan *) lfirst(lst);
 970
 971                         for (i = 0; i < indent; i++)
 972                                 appendStringInfo(str, "  ");
 973                         appendStringInfo(str, "  ->  ");
 974
 975                         explain_outNode(str, subnode,
 976                                                         bitmapandstate->bitmapplans[j],
 977                                                         outer_plan, /* pass down same outer plan */
 978                                                         indent + 3, es);
 979                         j++;
 980                 }
 981         }
 982
 983         if (IsA(plan, BitmapOr))
 984         {
 985                 BitmapOr   *bitmaporplan = (BitmapOr *) plan;
 986                 BitmapOrState *bitmaporstate = (BitmapOrState *) planstate;
 987                 ListCell   *lst;
 988                 int                     j;
 989
 990                 j = 0;
 991                 foreach(lst, bitmaporplan->bitmapplans)
 992                 {
 993                         Plan       *subnode = (Plan *) lfirst(lst);
 994
 995                         for (i = 0; i < indent; i++)
 996                                 appendStringInfo(str, "  ");
 997                         appendStringInfo(str, "  ->  ");
 998
 999                         explain_outNode(str, subnode,
1000                                                         bitmaporstate->bitmapplans[j],
1001                                                         outer_plan, /* pass down same outer plan */
1002                                                         indent + 3, es);
1003                         j++;
1004                 }
1005         }
1006
1007         if (IsA(plan, SubqueryScan))
1008         {
1009                 SubqueryScan *subqueryscan = (SubqueryScan *) plan;
1010                 SubqueryScanState *subquerystate = (SubqueryScanState *) planstate;
1011                 Plan       *subnode = subqueryscan->subplan;
1012
1013                 for (i = 0; i < indent; i++)
1014                         appendStringInfo(str, "  ");
1015                 appendStringInfo(str, "  ->  ");
1016
1017                 explain_outNode(str, subnode,
1018                                                 subquerystate->subplan,
1019                                                 NULL,
1020                                                 indent + 3, es);
1021         }
1022
1023         /* subPlan-s */
1024         if (planstate->subPlan)
1025         {
1026                 ListCell   *lst;
1027
1028                 for (i = 0; i < indent; i++)
1029                         appendStringInfo(str, "  ");
1030                 appendStringInfo(str, "  SubPlan\n");
1031                 foreach(lst, planstate->subPlan)
1032                 {
1033                         SubPlanState *sps = (SubPlanState *) lfirst(lst);
1034                         SubPlan    *sp = (SubPlan *) sps->xprstate.expr;
1035
1036                         for (i = 0; i < indent; i++)
1037                                 appendStringInfo(str, "  ");
1038                         appendStringInfo(str, "    ->  ");
1039                         explain_outNode(str,
1040                                                         exec_subplan_get_plan(es->pstmt, sp),
1041                                                         sps->planstate,
1042                                                         NULL,
1043                                                         indent + 4, es);
1044                 }
1045         }
1046 }
1047
1048 /*
1049  * Show a qualifier expression for a scan plan node
1050  *
1051  * Note: outer_plan is the referent for any OUTER vars in the scan qual;
1052  * this would be the outer side of a nestloop plan.  inner_plan should be
1053  * NULL except for a SubqueryScan plan node, where it should be the subplan.
1054  */
1055 static void
1056 show_scan_qual(List *qual, const char *qlabel,
1057                            int scanrelid, Plan *outer_plan, Plan *inner_plan,
1058                            StringInfo str, int indent, ExplainState *es)
1059 {
1060         List       *context;
1061         bool            useprefix;
1062         Node       *node;
1063         char       *exprstr;
1064         int                     i;
1065
1066         /* No work if empty qual */
1067         if (qual == NIL)
1068                 return;
1069
1070         /* Convert AND list to explicit AND */
1071         node = (Node *) make_ands_explicit(qual);
1072
1073         /* Set up deparsing context */
1074         context = deparse_context_for_plan((Node *) outer_plan,
1075                                                                            (Node *) inner_plan,
1076                                                                            es->rtable);
1077         useprefix = (outer_plan != NULL || inner_plan != NULL);
1078
1079         /* Deparse the expression */
1080         exprstr = deparse_expression(node, context, useprefix, false);
1081
1082         /* And add to str */
1083         for (i = 0; i < indent; i++)
1084                 appendStringInfo(str, "  ");
1085         appendStringInfo(str, "  %s: %s\n", qlabel, exprstr);
1086 }
1087
1088 /*
1089  * Show a qualifier expression for an upper-level plan node
1090  */
1091 static void
1092 show_upper_qual(List *qual, const char *qlabel, Plan *plan,
1093                                 StringInfo str, int indent, ExplainState *es)
1094 {
1095         List       *context;
1096         bool            useprefix;
1097         Node       *node;
1098         char       *exprstr;
1099         int                     i;
1100
1101         /* No work if empty qual */
1102         if (qual == NIL)
1103                 return;
1104
1105         /* Set up deparsing context */
1106         context = deparse_context_for_plan((Node *) outerPlan(plan),
1107                                                                            (Node *) innerPlan(plan),
1108                                                                            es->rtable);
1109         useprefix = list_length(es->rtable) > 1;
1110
1111         /* Deparse the expression */
1112         node = (Node *) make_ands_explicit(qual);
1113         exprstr = deparse_expression(node, context, useprefix, false);
1114
1115         /* And add to str */
1116         for (i = 0; i < indent; i++)
1117                 appendStringInfo(str, "  ");
1118         appendStringInfo(str, "  %s: %s\n", qlabel, exprstr);
1119 }
1120
1121 /*
1122  * Show the sort keys for a Sort node.
1123  */
1124 static void
1125 show_sort_keys(Plan *sortplan, int nkeys, AttrNumber *keycols,
1126                            const char *qlabel,
1127                            StringInfo str, int indent, ExplainState *es)
1128 {
1129         List       *context;
1130         bool            useprefix;
1131         int                     keyno;
1132         char       *exprstr;
1133         int                     i;
1134
1135         if (nkeys <= 0)
1136                 return;
1137
1138         for (i = 0; i < indent; i++)
1139                 appendStringInfo(str, "  ");
1140         appendStringInfo(str, "  %s: ", qlabel);
1141
1142         /* Set up deparsing context */
1143         context = deparse_context_for_plan((Node *) outerPlan(sortplan),
1144                                                                            NULL,                /* Sort has no innerPlan */
1145                                                                            es->rtable);
1146         useprefix = list_length(es->rtable) > 1;
1147
1148         for (keyno = 0; keyno < nkeys; keyno++)
1149         {
1150                 /* find key expression in tlist */
1151                 AttrNumber      keyresno = keycols[keyno];
1152                 TargetEntry *target = get_tle_by_resno(sortplan->targetlist, keyresno);
1153
1154                 if (!target)
1155                         elog(ERROR, "no tlist entry for key %d", keyresno);
1156                 /* Deparse the expression, showing any top-level cast */
1157                 exprstr = deparse_expression((Node *) target->expr, context,
1158                                                                          useprefix, true);
1159                 /* And add to str */
1160                 if (keyno > 0)
1161                         appendStringInfo(str, ", ");
1162                 appendStringInfoString(str, exprstr);
1163         }
1164
1165         appendStringInfo(str, "\n");
1166 }