From ed2d7b8c8ce53648a0ef1c3fc5e99bd69b17dfca Mon Sep 17 00:00:00 2001 From: Tom Lane Date: Fri, 12 Aug 2016 12:13:04 -0400 Subject: [PATCH] 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> --- src/backend/commands/explain.c | 18 +++++++++++++----- 1 file changed, 13 insertions(+), 5 deletions(-) diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index 5d06fa4ea65..11047f7982d 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -25,6 +25,7 @@ #include "optimizer/clauses.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" @@ -684,8 +685,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 { @@ -693,7 +697,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); } @@ -1600,8 +1605,11 @@ ExplainNode(PlanState *planstate, List *ancestors, 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); + } } } -- 2.39.5