Skip to content

Commit ed2d7b8

Browse files
committed
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>
1 parent 4fc8e23 commit ed2d7b8

File tree

1 file changed

+13
-5
lines changed

1 file changed

+13
-5
lines changed

src/backend/commands/explain.c

Lines changed: 13 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -25,6 +25,7 @@
2525
#include "optimizer/clauses.h"
2626
#include "parser/parsetree.h"
2727
#include "rewrite/rewriteHandler.h"
28+
#include "storage/bufmgr.h"
2829
#include "tcop/tcopprot.h"
2930
#include "utils/builtins.h"
3031
#include "utils/json.h"
@@ -684,16 +685,20 @@ report_triggers(ResultRelInfo *rInfo, bool show_relname, ExplainState *es)
684685
appendStringInfo(es->str, " for constraint %s", conname);
685686
if (show_relname)
686687
appendStringInfo(es->str, " on %s", relname);
687-
appendStringInfo(es->str, ": time=%.3f calls=%.0f\n",
688-
1000.0 * instr->total, instr->ntuples);
688+
if (es->timing)
689+
appendStringInfo(es->str, ": time=%.3f calls=%.0f\n",
690+
1000.0 * instr->total, instr->ntuples);
691+
else
692+
appendStringInfo(es->str, ": calls=%.0f\n", instr->ntuples);
689693
}
690694
else
691695
{
692696
ExplainPropertyText("Trigger Name", trig->tgname, es);
693697
if (conname)
694698
ExplainPropertyText("Constraint Name", conname, es);
695699
ExplainPropertyText("Relation", relname, es);
696-
ExplainPropertyFloat("Time", 1000.0 * instr->total, 3, es);
700+
if (es->timing)
701+
ExplainPropertyFloat("Time", 1000.0 * instr->total, 3, es);
697702
ExplainPropertyFloat("Calls", instr->ntuples, 0, es);
698703
}
699704

@@ -1600,8 +1605,11 @@ ExplainNode(PlanState *planstate, List *ancestors,
16001605
ExplainPropertyLong("Local Written Blocks", usage->local_blks_written, es);
16011606
ExplainPropertyLong("Temp Read Blocks", usage->temp_blks_read, es);
16021607
ExplainPropertyLong("Temp Written Blocks", usage->temp_blks_written, es);
1603-
ExplainPropertyFloat("I/O Read Time", INSTR_TIME_GET_MILLISEC(usage->blk_read_time), 3, es);
1604-
ExplainPropertyFloat("I/O Write Time", INSTR_TIME_GET_MILLISEC(usage->blk_write_time), 3, es);
1608+
if (track_io_timing)
1609+
{
1610+
ExplainPropertyFloat("I/O Read Time", INSTR_TIME_GET_MILLISEC(usage->blk_read_time), 3, es);
1611+
ExplainPropertyFloat("I/O Write Time", INSTR_TIME_GET_MILLISEC(usage->blk_write_time), 3, es);
1612+
}
16051613
}
16061614
}
16071615

0 commit comments

Comments
 (0)