| From: | Tomas Vondra <tomas(at)vondra(dot)me> |
|---|---|
| To: | Nikolay Samokhvalov <nik(at)postgres(dot)ai> |
| Cc: | PostgreSQL Hackers <pgsql-hackers(at)lists(dot)postgresql(dot)org> |
| Subject: | Re: EXPLAIN: showing ReadStream / prefetch stats |
| Date: | 2026-09-22 15:22:59 |
| Message-ID: | 40e8de7b-c11a-4d67-9c64-2200d359eaa0@vondra.me |
| Views: | Whole Thread | Raw Message | Download mbox | Resend email |
| Thread: | |
| Lists: | pgsql-hackers |
On 9/22/26 17:07, Nikolay Samokhvalov wrote:
> On Mar 15, 2026, Tomas Vondra <tomas(at)vondra(dot)me> wrote:
>> The first line "Prefetch" tracks the look-ahead distance, i.e. how many
>> blocks ahead the ReadStream is requesting.
>> The second line "I/O" is about the I/O requests actually issued - how
>> many times we had to wait for the block (when we get to process it),
>> average size of a request (in BLCKSZ blocks), and average number of
>> in-progress requests.
>
> Our new AI harness for testing found that a rescan can include buffers that
> never reach the consumer in the Prefetch average, and prepared the attached
> patch. On a clean cluster with io_method=worker, this is a complete
> reproducer:
>
> \set ON_ERROR_STOP on
> create extension pg_buffercache;
> set jit = off;
> set max_parallel_workers_per_gather = 0;
> set enable_seqscan = off;
> set effective_io_concurrency = 16;
>
> create unlogged table reset_t as
> select g as id, repeat(md5(g::text), 16) as payload
> from generate_series(1, 80000) as g;
> vacuum (analyze, freeze) reset_t;
> checkpoint;
> select pg_buffercache_evict_relation('reset_t');
>
> explain (analyze, buffers, io, timing off, summary off, costs off)
> select r.startblock, s.ctid
> from (values (0), (300), (600), (900), (1200),
> (1500), (1800), (2100), (2400), (2700)) r(startblock)
> cross join lateral (
> select t.ctid
> from reset_t t
> where t.ctid >= format('(%s,1)', r.startblock)::tid
> and t.ctid < format('(%s,1)', r.startblock + 200)::tid
> offset 0 limit 1
> ) s;
>
> The inner TID Range Scan reports:
>
> Prefetch: avg=1.32 max=2
> I/O: count=20 waits=19 size=1.50 in-progress=1.00
> Buffers: shared read=30
>
> Each of the ten loops returns one buffer to the consumer at distance one.
> A single-loop control reports avg=1.00 max=1.
>
> read_stream_reset() drains unread buffers by calling
> read_stream_next_buffer(), which also calls read_stream_count_prefetch().
> The nine rescans above add 18 cleanup samples with distance sum 27, so the
> reported average is (10 + 27) / (10 + 18) = 1.321428... and max becomes 2.
>
> The attached patch preserves prefetch_count, distance_sum, and distance_max
> around that internal drain, while leaving the real I/O statistics
> cumulative. It adds a test that checks all three fields with worker and
> sync I/O.
>
It's not clear to me why this would be desirable. The query execution
clearly *does* perform the I/O, even if the buffers end up not being
used. Hiding that would be very confusing / misleading.
In other words, I/O and buffers may disagree - that's not a bug. Those
counters are tracking different things.
To handle this correctly, we'd need to find a way to not issue the I/O
at all (since 862092932c9479b79732f3b441da05453ea5e06d we discard I/O
that was not initiated yet).
> On master d39fda1c the test fails without the read_stream.c change and
> passes with it; the full test_aio and core regression suites pass. The
> same patch applies to REL_19_STABLE b73d13c3, where the reproducer shows
> the same avg=1.32 max=2 result and test_aio passes with the fix.
>
> Nik
--
Tomas Vondra
| From | Date | Subject | |
|---|---|---|---|
| Next Message | Andres Freund | 2026-09-22 15:26:41 | Re: Teach pg_upgrade to deal with invalid databases |
| Previous Message | Nitin Jadhav | 2026-09-22 15:20:43 | Re: aio: Async fsyncs for crash recovery and checkpointer |