Re: EXPLAIN: showing ReadStream / prefetch stats

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

In response to

Responses

Browse pgsql-hackers by date

  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