Re: index prefetching

On 7/23/25 17:09, Andres Freund wrote:
> Hi,
>
> On 2025-07-23 14:50:15 +0200, Tomas Vondra wrote:
>> On 7/23/25 02:59, Andres Freund wrote:
>>> Hi,
>>>
>>> On 2025-07-23 02:50:04 +0200, Tomas Vondra wrote:
>>>> But I don't see why would this have any effect on the prefetch distance,
>>>> queue depth etc. Or why decreasing INDEX_SCAN_MAX_BATCHES should improve
>>>> that. I'd have expected exactly the opposite behavior.
>>>>
>>>> Could be bug, of course. But it'd be helpful to see the dataset/query.
>>>
>>> Pgbench scale 500, with the simpler query from my message.
>>>
>>
>> I tried to reproduce this, but I'm not seeing behavior. I'm not sure how
>> you monitor the queue depth (presumably iostat?)
>
> Yes, iostat, since I was looking at what the "actually required" lookahead
> distance is.
>
> Do you actually get the query to be entirely CPU bound? What amount of IO
> waiting do you see EXPLAIN (ANALYZE, TIMING OFF) with track_io_timing=on
> report?
>

No, it definitely needs to wait for I/O (FWIW it's on the xeon, with a
single NVMe SSD).

> Ah - I was using a very high effective_io_concurrency. With a high
> effective_io_concurrency value I see a lot of stalls, even at
> INDEX_SCAN_MAX_BATCHES = 64. And a lower prefetch distance, which seems
> somewhat odd.
>

I think that's a bug in the explain patch. The counters were updated at
the beginning of _next_buffer(), but that's wrong - a single call to
_next_buffer() can prefetch multiple blocks. This skewed the stats, as
the prefetches are not counted with "distance=0". With higher eic this
happens sooner, so the average distance seemed to decrease.

The attached patch does the updates in _get_block(), which I think is
better. And "stall" now means (distance == 1), which I think detects
requests without prefetching.

I also added a separate "Count" for the actual number of prefetched
blocks, and "Skipped" for duplicate blocks skipped (which the read
stream never even sees, because it's skipped in the callback).

>
> FWIW, in my tests I was just evicting lineitem from shared buffers, since I
> wanted to test the heap prefetching, without stalls induced by blocking on
> index reads. But what I described happens with either.
>
> ;SET effective_io_concurrency = 256;SELECT pg_buffercache_evict_relation('pgbench_accounts'); explain (analyze, costs off, timing off) SELECT max(abalance) FROM (SELECT * FROM pgbench_accounts ORDER BY aid LIMIT 10000000);
> ┌──────────────────────────────────────────────────────────────────────────────────────────────────────────┐
> │ QUERY PLAN │
> ├──────────────────────────────────────────────────────────────────────────────────────────────────────────┤
> │ Aggregate (actual rows=1.00 loops=1) │
> │ Buffers: shared hit=27369 read=164191 │
> │ I/O Timings: shared read=358.795 │
> │ -> Limit (actual rows=10000000.00 loops=1) │
> │ Buffers: shared hit=27369 read=164191 │
> │ I/O Timings: shared read=358.795 │
> │ -> Index Scan using pgbench_accounts_pkey on pgbench_accounts (actual rows=10000000.00 loops=1) │
> │ Index Searches: 1 │
> │ Prefetch Distance: 256.989 │
> │ Prefetch Stalls: 3 │
> │ Prefetch Resets: 3 │
> │ Buffers: shared hit=27369 read=164191 │
> │ I/O Timings: shared read=358.795 │
> │ Planning Time: 0.086 ms │
> │ Execution Time: 4194.845 ms │
> └──────────────────────────────────────────────────────────────────────────────────────────────────────────┘
>
> ;SET effective_io_concurrency = 512;SELECT pg_buffercache_evict_relation('pgbench_accounts'); explain (analyze, costs off, timing off) SELECT max(abalance) FROM (SELECT * FROM pgbench_accounts ORDER BY aid LIMIT 10000000);
> ┌──────────────────────────────────────────────────────────────────────────────────────────────────────────┐
> │ QUERY PLAN │
> ├──────────────────────────────────────────────────────────────────────────────────────────────────────────┤
> │ Aggregate (actual rows=1.00 loops=1) │
> │ Buffers: shared hit=27368 read=164190 │
> │ I/O Timings: shared read=832.515 │
> │ -> Limit (actual rows=10000000.00 loops=1) │
> │ Buffers: shared hit=27368 read=164190 │
> │ I/O Timings: shared read=832.515 │
> │ -> Index Scan using pgbench_accounts_pkey on pgbench_accounts (actual rows=10000000.00 loops=1) │
> │ Index Searches: 1 │
> │ Prefetch Distance: 56.778 │
> │ Prefetch Stalls: 160569 │
> │ Prefetch Resets: 423 │
> │ Buffers: shared hit=27368 read=164190 │
> │ I/O Timings: shared read=832.515 │
> │ Planning Time: 0.084 ms │
> │ Execution Time: 4413.058 ms │
> └──────────────────────────────────────────────────────────────────────────────────────────────────────────┘
>
> Greetings,
>

The attached v2 explain patch should fix that. I'm also attaching logs
from my explain, for 64 and 16 batches. I think the output makes much
more sense now.

cheers

--
Tomas Vondra