Skip to content

Commit 16cc6d2

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 942ff00 commit 16cc6d2

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
@@ -23,6 +23,7 @@
2323
#include "optimizer/clauses.h"
2424
#include "parser/parsetree.h"
2525
#include "rewrite/rewriteHandler.h"
26+
#include "storage/bufmgr.h"
2627
#include "tcop/tcopprot.h"
2728
#include "utils/builtins.h"
2829
#include "utils/json.h"
@@ -630,16 +631,20 @@ report_triggers(ResultRelInfo *rInfo, bool show_relname, ExplainState *es)
630631
appendStringInfo(es->str, " for constraint %s", conname);
631632
if (show_relname)
632633
appendStringInfo(es->str, " on %s", relname);
633-
appendStringInfo(es->str, ": time=%.3f calls=%.0f\n",
634-
1000.0 * instr->total, instr->ntuples);
634+
if (es->timing)
635+
appendStringInfo(es->str, ": time=%.3f calls=%.0f\n",
636+
1000.0 * instr->total, instr->ntuples);
637+
else
638+
appendStringInfo(es->str, ": calls=%.0f\n", instr->ntuples);
635639
}
636640
else
637641
{
638642
ExplainPropertyText("Trigger Name", trig->tgname, es);
639643
if (conname)
640644
ExplainPropertyText("Constraint Name", conname, es);
641645
ExplainPropertyText("Relation", relname, es);
642-
ExplainPropertyFloat("Time", 1000.0 * instr->total, 3, es);
646+
if (es->timing)
647+
ExplainPropertyFloat("Time", 1000.0 * instr->total, 3, es);
643648
ExplainPropertyFloat("Calls", instr->ntuples, 0, es);
644649
}
645650

@@ -1475,8 +1480,11 @@ ExplainNode(PlanState *planstate, List *ancestors,
14751480
ExplainPropertyLong("Local Written Blocks", usage->local_blks_written, es);
14761481
ExplainPropertyLong("Temp Read Blocks", usage->temp_blks_read, es);
14771482
ExplainPropertyLong("Temp Written Blocks", usage->temp_blks_written, es);
1478-
ExplainPropertyFloat("I/O Read Time", INSTR_TIME_GET_MILLISEC(usage->blk_read_time), 3, es);
1479-
ExplainPropertyFloat("I/O Write Time", INSTR_TIME_GET_MILLISEC(usage->blk_write_time), 3, es);
1483+
if (track_io_timing)
1484+
{
1485+
ExplainPropertyFloat("I/O Read Time", INSTR_TIME_GET_MILLISEC(usage->blk_read_time), 3, es);
1486+
ExplainPropertyFloat("I/O Write Time", INSTR_TIME_GET_MILLISEC(usage->blk_write_time), 3, es);
1487+
}
14801488
}
14811489
}
14821490

0 commit comments

Comments
 (0)