Re: [PATCH v1 0/7] Wait event timing and tracing instrumentation

On Mon, Jul 13, 2026 at 4:09 AM Michael Paquier <michael(at)paquier(dot)xyz> wrote:
>
> The core point that seems to matter most is in v1-0002, where the
> patch decides to make what is now a cheap 32-bit volatile manipulation
> into an optional compilation-based expensive operation. I don't want
> to sound negative here, but I'd recommend to re-read the previous
> thread. This kind of change could lead us to make the addition of
> more wait events harder to think about, especially if these are in
> deeper parts of the backend stack.

Thanks for the pointers. I have read that thread end to end, and
I should have cited it in the cover letter. Having done so, I think
the cover letter also failed to distinguish two different forms of
opt-in, so let me be precise about what this series does and where it
differs from what Andres described there.

The series provides operational opt-in:

- Built without --enable-wait-event-timing (the default), the timing
condition is absent from the preprocessed inline wait_start/end
path; the stores are as today.

- Built with it, at wait_event_capture = off (the default), the
recording bodies are out of line and each boundary gains a load
of the process-local wait_event_capture value, a test, and a
not-taken branch. For one call site I examined (FileReadV around
preadv(), gcc 13 -O2, x86-64; other compilers and sites will
differ in detail):

mov 0x0(%rbp),%rax # my_wait_event_info
mov %ecx,(%rax) # *ptr = wait_event_info (as today)
mov (%rbx),%eax # wait_event_capture (new)
test %eax,%eax # (new)
jne <tail> # not taken at off (new)
... preadv() ...
mov (%rbx),%edi # wait_event_capture (new)
test %edi,%edi # (new)
jne <tail> # not taken at off (new)
mov 0x0(%rbp),%rax
movl $0x0,(%rax) # *ptr = 0 (as today)

with the calls placed at the tail of the function, reached only
when capture is enabled.

- When capture is enabled for a backend, the path is intentionally
more expensive: stats takes two timestamps per completed wait and
updates count/total/max and a histogram; trace additionally writes
a ring record.

wait_event_capture is PGC_SUSET and per-backend, so this can be
scoped to selected sessions rather than a whole cluster; but within
an enabled backend, v1 times every wait event it reaches. A newly
added wait event automatically becomes a timed event in that
configuration. The generated lookup tables and the non-persistent
per-backend storage mean a new wait event needs no manual table or
stats-file work, including in stable branches -- but they do not
remove that performance coupling, and I understand your "harder to
think about, deeper in the backend stack" as being exactly about it.

Rereading the recording path with that lens also found one thing I
will change in the next version regardless of the API discussion:
the recorder currently raises an ereport(WARNING) when an overflow
counter first increments, and a recorder has no business calling
ereport() from arbitrarily deep call sites. The same information
is already exposed by pg_stat_wait_event_timing_overflow (0003), so
the WARNINGs will go and the view becomes the only signal.

So, having reread Andres's messages: what he described is explicit
per-call-site opt-in -- code changed over to an extended form, each
conversion reasoned about or measured. v1 does not implement that
split; it makes a different tradeoff: whole-taxonomy per-session
capture behind a runtime level. I chose that deliberately, because
it is a large part of the diagnostic value: selective conversion
leaves blind spots in a wait profile and gaps in the ordered trace,
and the profile of an incident you have not predicted is precisely
where blind spots hurt.
Where the series does follow that thread directly is the payload:
"the extended wait events need to count both the number of
encounters as well as the duration, the number of encounters is not
useful on its own" -- each aggregate here is count, total, max and a
32-bucket log2 histogram, and the trace preserves ordering and query
attribution, which is what lets interval snapshots distinguish more
waits from longer waits -- the distinction Robert pointed out bare
counters cannot make.

On measurement, since methodology was the other half of that thread:
I did not attempt to measure the gate with probes or rdtsc pairs.
The numbers in my second message on this thread are end-to-end
TPS; the observed run-to-run spread on that machine was roughly
+/- 1-2%. They could not distinguish the compiled-in/off
configuration from the unpatched build within that variation, and a
control experiment with the
gate #ifdef'd out showed signed deltas of a few percent that were
consistent with binary-layout effects rather than attributable to
the gate (which is also why the earlier unlikely() annotation was
dropped: identical codegen either way). For enabled capture, the
four stress scenarios in that message showed stats-vs-off deltas of
+0.1%, -0.3%, -2.4% and -4.5%, the last on a deliberately contended
hot-row workload. Those are evidence about the existing call sites
on that machine, not a platform-independent ceiling, and they do not
prove that any future call site would be cheap enough -- which I
take to be part of your point.

I also do not see this as replacing the alternatives proposed in
that thread. Sampling (Andres's suggestion) is cheaper for finding
where time goes; the purpose-built lock or SLRU instrumentation
Robert described can answer domain questions this cannot; and there
is real overlap between some I/O waits and
track_io_timing/pg_stat_io, which I can quantify if that is useful.
The per-backend histograms and the ordered trace are aimed at what
those do not provide.

That leaves two API directions I can see:

1. Keep pgstat_report_wait_start()/end() at their current cost and
add an explicit extended form for selected call sites, each
conversion justified or benchmarked -- closest to what Andres
proposed, at the price of incomplete profiles and traces.

2. Retain session-wide capture as an explicitly diagnostic mode,
with an explicit escape hatch for call sites whose frequency
makes the timing overhead unacceptable -- at the price that the
enabled-path cost of future wait events remains a tradeoff to
acknowledge when they are added.

My preference is the second, because session-wide coverage is the
feature I am trying to provide. But I agree the off-state numbers
alone do not settle your concern. Would you consider that
direction viable, or do you regard explicit per-call-site opt-in as
a prerequisite for the next version?

Regards,
Dmitry Fomin