Fix inappropriate printing of never-measured times in EXPLAIN.

EXPLAIN (ANALYZE, TIMING OFF) would print an elapsed time of zero for
a trigger function, because no measurement has been taken but it printed
the field anyway.  This isn't what EXPLAIN does elsewhere, so suppress it.

In the same vein, EXPLAIN (ANALYZE, BUFFERS) with non-text output format
would print buffer I/O timing numbers even when no measurement has been
taken because track_io_timing is off.  That seems not per policy, either,
so change it.

Back-patch to 9.2 where these features were introduced.

Maksim Milyutin

Discussion: <081c0540-ecaa-bd29-3fd2-6358f3b359a9@postgrespro.ru>

diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index dbd27e53bc3d49de749251917492002de2417f03..82ba58ef713947b3e595279b0fa004fb4578bdef 100644 (file)
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -27,6 +27,7 @@
 #include "optimizer/planmain.h"
 #include "parser/parsetree.h"
 #include "rewrite/rewriteHandler.h"
+#include "storage/bufmgr.h"
 #include "tcop/tcopprot.h"
 #include "utils/builtins.h"
 #include "utils/json.h"
@@ -698,8 +699,11 @@ report_triggers(ResultRelInfo *rInfo, bool show_relname, ExplainState *es)
                                appendStringInfo(es->str, " for constraint %s", conname);
                        if (show_relname)
                                appendStringInfo(es->str, " on %s", relname);
-                       appendStringInfo(es->str, ": time=%.3f calls=%.0f\n",
-                                                        1000.0 * instr->total, instr->ntuples);
+                       if (es->timing)
+                               appendStringInfo(es->str, ": time=%.3f calls=%.0f\n",
+                                                                1000.0 * instr->total, instr->ntuples);
+                       else
+                               appendStringInfo(es->str, ": calls=%.0f\n", instr->ntuples);
                }
                else
                {
@@ -707,7 +711,8 @@ report_triggers(ResultRelInfo *rInfo, bool show_relname, ExplainState *es)
                        if (conname)
                                ExplainPropertyText("Constraint Name", conname, es);
                        ExplainPropertyText("Relation", relname, es);
-                       ExplainPropertyFloat("Time", 1000.0 * instr->total, 3, es);
+                       if (es->timing)
+                               ExplainPropertyFloat("Time", 1000.0 * instr->total, 3, es);
                        ExplainPropertyFloat("Calls", instr->ntuples, 0, es);
                }
 
@@ -2429,8 +2434,11 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage)
                ExplainPropertyLong("Local Written Blocks", usage->local_blks_written, es);
                ExplainPropertyLong("Temp Read Blocks", usage->temp_blks_read, es);
                ExplainPropertyLong("Temp Written Blocks", usage->temp_blks_written, es);
-               ExplainPropertyFloat("I/O Read Time", INSTR_TIME_GET_MILLISEC(usage->blk_read_time), 3, es);
-               ExplainPropertyFloat("I/O Write Time", INSTR_TIME_GET_MILLISEC(usage->blk_write_time), 3, es);
+               if (track_io_timing)
+               {
+                       ExplainPropertyFloat("I/O Read Time", INSTR_TIME_GET_MILLISEC(usage->blk_read_time), 3, es);
+                       ExplainPropertyFloat("I/O Write Time", INSTR_TIME_GET_MILLISEC(usage->blk_write_time), 3, es);
+               }
        }
 }