]> granicus.if.org Git - postgresql/commitdiff
Prevent auto_explain from changing the output of a user's EXPLAIN.
authorTom Lane <tgl@sss.pgh.pa.us>
Tue, 20 May 2014 16:20:57 +0000 (12:20 -0400)
committerTom Lane <tgl@sss.pgh.pa.us>
Tue, 20 May 2014 16:20:57 +0000 (12:20 -0400)
Commit af7914c6627bcf0b0ca614e9ce95d3f8056602bf, which introduced the
EXPLAIN (TIMING) option, for some reason coded explain.c to look at
planstate->instrument->need_timer rather than es->timing to decide
whether to print timing info.  However, the former flag might get set
as a result of contrib/auto_explain wanting timing information.  We
certainly don't want activation of auto_explain to change user-visible
statement behavior, so fix that.

Also fix an independent bug introduced in the same patch: in the code
path for a never-executed node with a machine-friendly output format,
if timing was selected, it would fail to print the Actual Rows and Actual
Loops items.

Per bug #10404 from Tomonari Katsumata.  Back-patch to 9.2 where the
faulty code was introduced.

src/backend/commands/explain.c

index a8e6bb56afeb0f69176728a6da6711834c73ec18..ae5bde754c71b4669d41db32ddbd03ca9c0a798f 100644 (file)
@@ -1006,11 +1006,18 @@ ExplainNode(PlanState *planstate, List *ancestors,
        /*
         * We have to forcibly clean up the instrumentation state because we
         * haven't done ExecutorEnd yet.  This is pretty grotty ...
+        *
+        * Note: contrib/auto_explain could cause instrumentation to be set up
+        * even though we didn't ask for it here.  Be careful not to print any
+        * instrumentation results the user didn't ask for.  But we do the
+        * InstrEndLoop call anyway, if possible, to reduce the number of cases
+        * auto_explain has to contend with.
         */
        if (planstate->instrument)
                InstrEndLoop(planstate->instrument);
 
-       if (planstate->instrument && planstate->instrument->nloops > 0)
+       if (es->analyze &&
+               planstate->instrument && planstate->instrument->nloops > 0)
        {
                double          nloops = planstate->instrument->nloops;
                double          startup_sec = 1000.0 * planstate->instrument->startup / nloops;
@@ -1019,7 +1026,7 @@ ExplainNode(PlanState *planstate, List *ancestors,
 
                if (es->format == EXPLAIN_FORMAT_TEXT)
                {
-                       if (planstate->instrument->need_timer)
+                       if (es->timing)
                                appendStringInfo(es->str,
                                                        " (actual time=%.3f..%.3f rows=%.0f loops=%.0f)",
                                                                 startup_sec, total_sec, rows, nloops);
@@ -1030,7 +1037,7 @@ ExplainNode(PlanState *planstate, List *ancestors,
                }
                else
                {
-                       if (planstate->instrument->need_timer)
+                       if (es->timing)
                        {
                                ExplainPropertyFloat("Actual Startup Time", startup_sec, 3, es);
                                ExplainPropertyFloat("Actual Total Time", total_sec, 3, es);
@@ -1041,20 +1048,18 @@ ExplainNode(PlanState *planstate, List *ancestors,
        }
        else if (es->analyze)
        {
-
                if (es->format == EXPLAIN_FORMAT_TEXT)
                        appendStringInfo(es->str, " (never executed)");
-               else if (planstate->instrument->need_timer)
-               {
-                       ExplainPropertyFloat("Actual Startup Time", 0.0, 3, es);
-                       ExplainPropertyFloat("Actual Total Time", 0.0, 3, es);
-               }
                else
                {
+                       if (es->timing)
+                       {
+                               ExplainPropertyFloat("Actual Startup Time", 0.0, 3, es);
+                               ExplainPropertyFloat("Actual Total Time", 0.0, 3, es);
+                       }
                        ExplainPropertyFloat("Actual Rows", 0.0, 0, es);
                        ExplainPropertyFloat("Actual Loops", 0.0, 0, es);
                }
-
        }
 
        /* in text format, first line ends here */
@@ -1220,7 +1225,7 @@ ExplainNode(PlanState *planstate, List *ancestors,
        }
 
        /* Show buffer usage */
-       if (es->buffers)
+       if (es->buffers && planstate->instrument)
        {
                const BufferUsage *usage = &planstate->instrument->bufusage;