[PATCH] Avoid unnecessary code execution in Instrument.c when TIMING is FALSE
Hi,
Even when using EXPLAIN ANALYZE with TIMING=FALSE, the functions
InstrStopNode(), InstrEndLoop(), and InstrAggNode() in Instrument.c
still execute code related to the "starttime", "counter", "firsttuple",
"startup", and "total" fields within the Instrumentation structure.
These operations are unnecessary when timing is disabled, and since
these functions are called very frequently, I have created a patch to
address this.
As far as I can tell, this change has no side effects and clarifies the
intent of each line, but please let me know if you notice any issues.
Best regards,
H.S.
Attachments:
v1_avoid_unnecessary_code_execution_in_instrumentation.patchtext/plain; charset=UTF-8; name=v1_avoid_unnecessary_code_execution_in_instrumentation.patchDownload
diff --git a/src/backend/executor/instrument.c b/src/backend/executor/instrument.c
index 56e635f4700..e4274a28525 100644
--- a/src/backend/executor/instrument.c
+++ b/src/backend/executor/instrument.c
@@ -114,7 +114,8 @@ InstrStopNode(Instrumentation *instr, double nTuples)
if (!instr->running)
{
instr->running = true;
- instr->firsttuple = INSTR_TIME_GET_DOUBLE(instr->counter);
+ if (instr->need_timer)
+ instr->firsttuple = INSTR_TIME_GET_DOUBLE(instr->counter);
}
else
{
@@ -122,7 +123,7 @@ InstrStopNode(Instrumentation *instr, double nTuples)
* In async mode, if the plan node hadn't emitted any tuples before,
* this might be the first tuple
*/
- if (instr->async_mode && save_tuplecount < 1.0)
+ if (instr->need_timer && instr->async_mode && save_tuplecount < 1.0)
instr->firsttuple = INSTR_TIME_GET_DOUBLE(instr->counter);
}
}
@@ -149,18 +150,24 @@ InstrEndLoop(Instrumentation *instr)
elog(ERROR, "InstrEndLoop called on running node");
/* Accumulate per-cycle statistics into totals */
- totaltime = INSTR_TIME_GET_DOUBLE(instr->counter);
+ if (instr->need_timer)
+ {
+ totaltime = INSTR_TIME_GET_DOUBLE(instr->counter);
- instr->startup += instr->firsttuple;
- instr->total += totaltime;
+ instr->startup += instr->firsttuple;
+ instr->total += totaltime;
+ }
instr->ntuples += instr->tuplecount;
instr->nloops += 1;
/* Reset for next cycle (if any) */
instr->running = false;
- INSTR_TIME_SET_ZERO(instr->starttime);
- INSTR_TIME_SET_ZERO(instr->counter);
- instr->firsttuple = 0;
+ if (instr->need_timer)
+ {
+ INSTR_TIME_SET_ZERO(instr->starttime);
+ INSTR_TIME_SET_ZERO(instr->counter);
+ instr->firsttuple = 0;
+ }
instr->tuplecount = 0;
}
@@ -171,16 +178,21 @@ InstrAggNode(Instrumentation *dst, Instrumentation *add)
if (!dst->running && add->running)
{
dst->running = true;
- dst->firsttuple = add->firsttuple;
+ if (dst->need_timer && add->need_timer)
+ dst->firsttuple = add->firsttuple;
}
- else if (dst->running && add->running && dst->firsttuple > add->firsttuple)
+ else if (dst->need_timer && add->need_timer && dst->running && add->running
+ && dst->firsttuple > add->firsttuple)
dst->firsttuple = add->firsttuple;
- INSTR_TIME_ADD(dst->counter, add->counter);
+ if (dst->need_timer && add->need_timer)
+ {
+ INSTR_TIME_ADD(dst->counter, add->counter);
+ dst->startup += add->startup;
+ dst->total += add->total;
+ }
dst->tuplecount += add->tuplecount;
- dst->startup += add->startup;
- dst->total += add->total;
dst->ntuples += add->ntuples;
dst->ntuples2 += add->ntuples2;
dst->nloops += add->nloops;
On Sat, Jul 26, 2025 at 12:26:21AM +0900, Hironobu SUZUKI wrote:
Even when using EXPLAIN ANALYZE with TIMING=FALSE, the functions
InstrStopNode(), InstrEndLoop(), and InstrAggNode() in Instrument.c still
execute code related to the "starttime", "counter", "firsttuple", "startup",
and "total" fields within the Instrumentation structure.
These operations are unnecessary when timing is disabled, and since these
functions are called very frequently, I have created a patch to address
this.As far as I can tell, this change has no side effects and clarifies the
intent of each line, but please let me know if you notice any issues.
Spoiler: this has been discussed during a meetup attended by most of
the PostgreSQL hackers based in Tokyo and surroundings on the 18th of
July, where Suzuki-san has noticed that the work done by the backend
was pointless when using the instrumentation while hacking on an
extension that relied at least on the explain hook. One of the
remarks was that this seemed worth a submission to upstream when
timers are disabled. The performance really took a hit when the timer
was disabled, making the extension do a lot of unnecessary work for
nothing.
--
Michael
On 2025/07/26 9:29, Michael Paquier wrote:
On Sat, Jul 26, 2025 at 12:26:21AM +0900, Hironobu SUZUKI wrote:
Even when using EXPLAIN ANALYZE with TIMING=FALSE, the functions
InstrStopNode(), InstrEndLoop(), and InstrAggNode() in Instrument.c still
execute code related to the "starttime", "counter", "firsttuple", "startup",
and "total" fields within the Instrumentation structure.
These operations are unnecessary when timing is disabled, and since these
functions are called very frequently, I have created a patch to address
this.As far as I can tell, this change has no side effects and clarifies the
intent of each line, but please let me know if you notice any issues.Spoiler: this has been discussed during a meetup attended by most of
the PostgreSQL hackers based in Tokyo and surroundings on the 18th of
July, where Suzuki-san has noticed that the work done by the backend
was pointless when using the instrumentation while hacking on an
extension that relied at least on the explain hook. One of the
remarks was that this seemed worth a submission to upstream when
timers are disabled. The performance really took a hit when the timer
was disabled, making the extension do a lot of unnecessary work for
nothing.
--
Michael
Thanks for the spoilers!
Actually, I was confused while reading the Instrument module’s source
code since some sections ran even when timing was disabled, unlike
other parts guarded by if statements.
This patch mainly clarifies the coding intent, so I intentionally avoided
adding comments.
(The essential improvement proposals for internal monitoring will be
presented on another occasion.)
Best,
On 2025-07-26 00:26, Hironobu SUZUKI wrote:
Thanks for the proposal!
Hi,
Even when using EXPLAIN ANALYZE with TIMING=FALSE, the functions
InstrStopNode(), InstrEndLoop(), and InstrAggNode() in Instrument.c
still execute code related to the "starttime", "counter",
"firsttuple", "startup", and "total" fields within the
Instrumentation structure.
These operations are unnecessary when timing is disabled, and since
these functions are called very frequently, I have created a patch to
address this.
Is the main purpose of this patch to reduce unnecessary performance
overhead? Or is it rather to make it explicit that these values are not
retrieved when the timing option is off?
Since you mentioned that "these functions are called very frequently", I
assume the former is your main concern.
During the meetup, I had understood that even with 'timing' disabled,
there were still costly operations such as calls to functions that
retrieve timestamps.
However, when I looked at the patch, I couldn't find operations that
looked particularly expensive, so I'd like to confirm this.
- instr->firsttuple = INSTR_TIME_GET_DOUBLE(instr->counter);
+ if (instr->need_timer)
+ instr->firsttuple = INSTR_TIME_GET_DOUBLE(instr->counter);For example, if 'timing' is off, instr->counter would just be zero, and
INSTR_TIME_GET_DOUBLE() is a macro that does not seem to perform any
heavy operation.
Given that, I'm unsure whether the added if statement provides a net
performance benefit.
If there is indeed a measurable performance overhead, could you please
share an example workload where performance improves before and after
applying the patch?
Regards,
--
Atsushi Torikoshi
Seconded from NTT DATA Japan Corporation to SRA OSS K.K.