55 * Portions Copyright (c) 1996-2002, PostgreSQL Global Development Group
66 * Portions Copyright (c) 1994-5, Regents of the University of California
77 *
8- * $Header: /cvsroot/pgsql/src/backend/commands/explain.c,v 1.93 2002/11/13 00:39:46 momjian Exp $
8+ * $Header: /cvsroot/pgsql/src/backend/commands/explain.c,v 1.94 2002/12/05 15:50:30 tgl Exp $
99 *
1010 */
1111
@@ -34,17 +34,19 @@ typedef struct ExplainState
3434{
3535/* options */
3636bool printCost ;/* print cost */
37- bool printNodes ;/* do nodeToString()instead */
38- bool printAnalyze ;/* print actual times */
37+ bool printNodes ;/* do nodeToString()too */
38+ bool printAnalyze ;/* print actual times */
3939/* other states */
4040List * rtable ;/* range table */
4141}ExplainState ;
4242
43- static StringInfo Explain_PlanToString (Plan * plan ,ExplainState * es );
4443static void ExplainOneQuery (Query * query ,ExplainStmt * stmt ,
4544TupOutputState * tstate );
46- static void explain_outNode (StringInfo str ,Plan * plan ,Plan * outer_plan ,
47- int indent ,ExplainState * es );
45+ static double elapsed_time (struct timeval * starttime );
46+ static void explain_outNode (StringInfo str ,
47+ Plan * plan ,PlanState * planstate ,
48+ Plan * outer_plan ,
49+ int indent ,ExplainState * es );
4850static void show_scan_qual (List * qual ,bool is_or_qual ,const char * qlabel ,
4951int scanrelid ,Plan * outer_plan ,
5052StringInfo str ,int indent ,ExplainState * es );
@@ -116,8 +118,11 @@ static void
116118ExplainOneQuery (Query * query ,ExplainStmt * stmt ,TupOutputState * tstate )
117119{
118120Plan * plan ;
121+ QueryDesc * queryDesc ;
119122ExplainState * es ;
123+ StringInfo str ;
120124double totaltime = 0 ;
125+ struct timeval starttime ;
121126
122127/* planner will not cope with utility statements */
123128if (query -> commandType == CMD_UTILITY )
@@ -136,41 +141,34 @@ ExplainOneQuery(Query *query, ExplainStmt *stmt, TupOutputState *tstate)
136141if (plan == NULL )
137142return ;
138143
144+ /* We don't support DECLARE CURSOR here */
145+ Assert (!query -> isPortal );
146+
147+ gettimeofday (& starttime ,NULL );
148+
149+ /* Create a QueryDesc requesting no output */
150+ queryDesc = CreateQueryDesc (query ,plan ,None ,NULL ,NULL ,
151+ stmt -> analyze );
152+
153+ /* call ExecutorStart to prepare the plan for execution */
154+ ExecutorStart (queryDesc );
155+
139156/* Execute the plan for statistics if asked for */
140157if (stmt -> analyze )
141158{
142- struct timeval starttime ;
143- struct timeval endtime ;
144-
145- /*
146- * Set up the instrumentation for the top node. This will cascade
147- * during plan initialisation
148- */
149- plan -> instrument = InstrAlloc ();
159+ /* run the plan */
160+ ExecutorRun (queryDesc ,ForwardScanDirection ,0L );
150161
151- gettimeofday (& starttime ,NULL );
152- ProcessQuery (query ,plan ,None ,NULL );
153- CommandCounterIncrement ();
154- gettimeofday (& endtime ,NULL );
162+ /* We can't clean up 'till we're done printing the stats... */
155163
156- endtime .tv_sec -= starttime .tv_sec ;
157- endtime .tv_usec -= starttime .tv_usec ;
158- while (endtime .tv_usec < 0 )
159- {
160- endtime .tv_usec += 1000000 ;
161- endtime .tv_sec -- ;
162- }
163- totaltime = (double )endtime .tv_sec +
164- (double )endtime .tv_usec /1000000.0 ;
164+ totaltime += elapsed_time (& starttime );
165165}
166166
167167es = (ExplainState * )palloc0 (sizeof (ExplainState ));
168168
169169es -> printCost = true;/* default */
170-
171- if (stmt -> verbose )
172- es -> printNodes = true;
173-
170+ es -> printNodes = stmt -> verbose ;
171+ es -> printAnalyze = stmt -> analyze ;
174172es -> rtable = query -> rtable ;
175173
176174if (es -> printNodes )
@@ -193,33 +191,73 @@ ExplainOneQuery(Query *query, ExplainStmt *stmt, TupOutputState *tstate)
193191}
194192}
195193
194+ str = makeStringInfo ();
195+
196196if (es -> printCost )
197197{
198- StringInfo str ;
198+ explain_outNode (str ,plan ,queryDesc -> planstate ,
199+ NULL ,0 ,es );
200+ }
199201
200- str = Explain_PlanToString (plan ,es );
202+ /*
203+ * Close down the query and free resources. Include time for this
204+ * in the total runtime.
205+ */
206+ gettimeofday (& starttime ,NULL );
207+
208+ ExecutorEnd (queryDesc );
209+ CommandCounterIncrement ();
210+
211+ totaltime += elapsed_time (& starttime );
212+
213+ if (es -> printCost )
214+ {
201215if (stmt -> analyze )
202216appendStringInfo (str ,"Total runtime: %.2f msec\n" ,
2032171000.0 * totaltime );
204218do_text_output_multiline (tstate ,str -> data );
205- pfree (str -> data );
206- pfree (str );
207219}
208220
221+ pfree (str -> data );
222+ pfree (str );
209223pfree (es );
210224}
211225
226+ /* Compute elapsed time in seconds since given gettimeofday() timestamp */
227+ static double
228+ elapsed_time (struct timeval * starttime )
229+ {
230+ struct timeval endtime ;
231+
232+ gettimeofday (& endtime ,NULL );
233+
234+ endtime .tv_sec -= starttime -> tv_sec ;
235+ endtime .tv_usec -= starttime -> tv_usec ;
236+ while (endtime .tv_usec < 0 )
237+ {
238+ endtime .tv_usec += 1000000 ;
239+ endtime .tv_sec -- ;
240+ }
241+ return (double )endtime .tv_sec +
242+ (double )endtime .tv_usec /1000000.0 ;
243+ }
212244
213245/*
214246 * explain_outNode -
215247 * converts a Plan node into ascii string and appends it to 'str'
216248 *
249+ * planstate points to the executor state node corresponding to the plan node.
250+ * We need this to get at the instrumentation data (if any) as well as the
251+ * list of subplans.
252+ *
217253 * outer_plan, if not null, references another plan node that is the outer
218254 * side of a join with the current node. This is only interesting for
219255 * deciphering runtime keys of an inner indexscan.
220256 */
221257static void
222- explain_outNode (StringInfo str ,Plan * plan ,Plan * outer_plan ,
258+ explain_outNode (StringInfo str ,
259+ Plan * plan ,PlanState * planstate ,
260+ Plan * outer_plan ,
223261int indent ,ExplainState * es )
224262{
225263List * l ;
@@ -410,18 +448,23 @@ explain_outNode(StringInfo str, Plan *plan, Plan *outer_plan,
410448plan -> startup_cost ,plan -> total_cost ,
411449plan -> plan_rows ,plan -> plan_width );
412450
413- if (plan -> instrument && plan -> instrument -> nloops > 0 )
451+ /*
452+ * We have to forcibly clean up the instrumentation state because
453+ * we haven't done ExecutorEnd yet. This is pretty grotty ...
454+ */
455+ InstrEndLoop (planstate -> instrument );
456+
457+ if (planstate -> instrument && planstate -> instrument -> nloops > 0 )
414458{
415- double nloops = plan -> instrument -> nloops ;
459+ double nloops = planstate -> instrument -> nloops ;
416460
417461appendStringInfo (str ," (actual time=%.2f..%.2f rows=%.0f loops=%.0f)" ,
418- 1000.0 * plan -> instrument -> startup /nloops ,
419- 1000.0 * plan -> instrument -> total /nloops ,
420- plan -> instrument -> ntuples /nloops ,
421- plan -> instrument -> nloops );
422- es -> printAnalyze = true;
462+ 1000.0 * planstate -> instrument -> startup /nloops ,
463+ 1000.0 * planstate -> instrument -> total /nloops ,
464+ planstate -> instrument -> ntuples /nloops ,
465+ planstate -> instrument -> nloops );
423466}
424- else if ( es -> printAnalyze )
467+ else if ( es -> printAnalyze )
425468{
426469appendStringInfo (str ," (never executed)" );
427470}
@@ -538,19 +581,26 @@ explain_outNode(StringInfo str, Plan *plan, Plan *outer_plan,
538581if (plan -> initPlan )
539582{
540583List * saved_rtable = es -> rtable ;
584+ List * pslist = planstate -> initPlan ;
541585List * lst ;
542586
543587for (i = 0 ;i < indent ;i ++ )
544588appendStringInfo (str ," " );
545589appendStringInfo (str ," InitPlan\n" );
546590foreach (lst ,plan -> initPlan )
547591{
548- es -> rtable = ((SubPlan * )lfirst (lst ))-> rtable ;
592+ SubPlan * subplan = (SubPlan * )lfirst (lst );
593+ SubPlanState * subplanstate = (SubPlanState * )lfirst (pslist );
594+
595+ es -> rtable = subplan -> rtable ;
549596for (i = 0 ;i < indent ;i ++ )
550597appendStringInfo (str ," " );
551598appendStringInfo (str ," -> " );
552- explain_outNode (str , ((SubPlan * )lfirst (lst ))-> plan ,NULL ,
599+ explain_outNode (str ,subplan -> plan ,
600+ subplanstate -> planstate ,
601+ NULL ,
553602indent + 4 ,es );
603+ pslist = lnext (pslist );
554604}
555605es -> rtable = saved_rtable ;
556606}
@@ -561,7 +611,10 @@ explain_outNode(StringInfo str, Plan *plan, Plan *outer_plan,
561611for (i = 0 ;i < indent ;i ++ )
562612appendStringInfo (str ," " );
563613appendStringInfo (str ," -> " );
564- explain_outNode (str ,outerPlan (plan ),NULL ,indent + 3 ,es );
614+ explain_outNode (str ,outerPlan (plan ),
615+ outerPlanState (planstate ),
616+ NULL ,
617+ indent + 3 ,es );
565618}
566619
567620/* righttree */
@@ -570,15 +623,20 @@ explain_outNode(StringInfo str, Plan *plan, Plan *outer_plan,
570623for (i = 0 ;i < indent ;i ++ )
571624appendStringInfo (str ," " );
572625appendStringInfo (str ," -> " );
573- explain_outNode (str ,innerPlan (plan ),outerPlan (plan ),
626+ explain_outNode (str ,innerPlan (plan ),
627+ innerPlanState (planstate ),
628+ outerPlan (plan ),
574629indent + 3 ,es );
575630}
576631
577632if (IsA (plan ,Append ))
578633{
579634Append * appendplan = (Append * )plan ;
635+ AppendState * appendstate = (AppendState * )planstate ;
580636List * lst ;
637+ int j ;
581638
639+ j = 0 ;
582640foreach (lst ,appendplan -> appendplans )
583641{
584642Plan * subnode = (Plan * )lfirst (lst );
@@ -587,13 +645,18 @@ explain_outNode(StringInfo str, Plan *plan, Plan *outer_plan,
587645appendStringInfo (str ," " );
588646appendStringInfo (str ," -> " );
589647
590- explain_outNode (str ,subnode ,NULL ,indent + 3 ,es );
648+ explain_outNode (str ,subnode ,
649+ appendstate -> appendplans [j ],
650+ NULL ,
651+ indent + 3 ,es );
652+ j ++ ;
591653}
592654}
593655
594656if (IsA (plan ,SubqueryScan ))
595657{
596658SubqueryScan * subqueryscan = (SubqueryScan * )plan ;
659+ SubqueryScanState * subquerystate = (SubqueryScanState * )planstate ;
597660Plan * subnode = subqueryscan -> subplan ;
598661RangeTblEntry * rte = rt_fetch (subqueryscan -> scan .scanrelid ,
599662es -> rtable );
@@ -606,43 +669,41 @@ explain_outNode(StringInfo str, Plan *plan, Plan *outer_plan,
606669appendStringInfo (str ," " );
607670appendStringInfo (str ," -> " );
608671
609- explain_outNode (str ,subnode ,NULL ,indent + 3 ,es );
672+ explain_outNode (str ,subnode ,
673+ subquerystate -> subplan ,
674+ NULL ,
675+ indent + 3 ,es );
610676
611677es -> rtable = saved_rtable ;
612678}
613679
614680/* subPlan-s */
615- if (plan -> subPlan )
681+ if (planstate -> subPlan )
616682{
617683List * saved_rtable = es -> rtable ;
618684List * lst ;
619685
620686for (i = 0 ;i < indent ;i ++ )
621687appendStringInfo (str ," " );
622688appendStringInfo (str ," SubPlan\n" );
623- foreach (lst ,plan -> subPlan )
689+ foreach (lst ,planstate -> subPlan )
624690{
625- es -> rtable = ((SubPlan * )lfirst (lst ))-> rtable ;
691+ SubPlanState * sps = (SubPlanState * )lfirst (lst );
692+ SubPlan * sp = (SubPlan * )sps -> ps .plan ;
693+
694+ es -> rtable = sp -> rtable ;
626695for (i = 0 ;i < indent ;i ++ )
627696appendStringInfo (str ," " );
628697appendStringInfo (str ," -> " );
629- explain_outNode (str , ((SubPlan * )lfirst (lst ))-> plan ,NULL ,
698+ explain_outNode (str ,sp -> plan ,
699+ sps -> planstate ,
700+ NULL ,
630701indent + 4 ,es );
631702}
632703es -> rtable = saved_rtable ;
633704}
634705}
635706
636- static StringInfo
637- Explain_PlanToString (Plan * plan ,ExplainState * es )
638- {
639- StringInfo str = makeStringInfo ();
640-
641- if (plan != NULL )
642- explain_outNode (str ,plan ,NULL ,0 ,es );
643- return str ;
644- }
645-
646707/*
647708 * Show a qualifier expression for a scan plan node
648709 */