Re: EXPLAIN: showing ReadStream / prefetch stats - Mailing list pgsql-hackers

From Nikolay Samokhvalov
Subject Re: EXPLAIN: showing ReadStream / prefetch stats
Date
Msg-id CAM527d87NihbtZNBCYSu+9cfOvFoZBotSMhY8575dAoKASdvCg@mail.gmail.com
Whole thread
In response to EXPLAIN: showing ReadStream / prefetch stats  (Tomas Vondra <tomas@vondra.me>)
Responses Re: EXPLAIN: showing ReadStream / prefetch stats
List pgsql-hackers
On Mar 15, 2026, Tomas Vondra <tomas@vondra.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.

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

Attachment

pgsql-hackers by date:

Previous
From: Jan Nidzwetzki
Date:
Subject: Re: Prevent object capture in CREATE/ALTER EXTENSION scripts
Next
From: Andres Freund
Date:
Subject: Re: Double content-lock acquisition silently leaks a lock