Обсуждение: [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.

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.