Re: RFC: Allow EXPLAIN to Output Page Fault Information

Hi,

On 2025-02-10 18:30:56 -0500, Andres Freund wrote:
> On 2025-02-10 23:52:17 +0100, Jelte Fennema-Nio wrote:
> > On Mon, 10 Feb 2025 at 14:31, Andres Freund <andres(at)anarazel(dot)de> wrote:
> > > But this will also not work with AIO w/ Buffered IO. Which we hope to use much
> > > more commonly.
> >
> > To be clear, here you mean worker based AIO right? Because it would
> > work with io_uring based AIO, right?
>
> I mostly meant worker based AIO, yes. I haven't checked how accurately these
> are kept for io_uring. I would hope they are...

It does look like it is tracked.

> > > If suddenly I have to reimplement something like this to work with worker
> > > based IO, it'll certainly take longer to get to AIO.
> >
> > I totally understand. But in my opinion it would be completely fine to
> > decide that these new IO stats are simply not available for worker
> > based IO. Just like they're not available for Windows either with this
> > patch.
>
> The thing is that you'd often get completely misleading stats. Some of the IO
> will still be done by the backend itself, so there will be a non-zero
> value. But it will be a significant undercount, because the asynchronously
> executed IO won't be tracked (if worker mode is used).

<clear cache>

postgres[985394][1]=# SHOW io_method ;
┌───────────┐
│ io_method │
├───────────┤
│ worker │
└───────────┘
(1 row)

postgres[985394][1]=# EXPLAIN ANALYZE SELECT count(*) FROM manyrows ;
┌──────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┐
│ QUERY PLAN │
├──────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┤
│ Aggregate (cost=17906.00..17906.01 rows=1 width=8) (actual time=199.494..199.494 rows=1 loops=1) │
│ Buffers: shared read=5406 │
│ I/O Timings: shared read=57.906 │
│ -> Seq Scan on manyrows (cost=0.00..15406.00 rows=1000000 width=0) (actual time=0.380..140.671 rows=1000000 loops=1) │
│ Buffers: shared read=5406 │
│ I/O Timings: shared read=57.906 │
│ Planning: │
│ Buffers: shared hit=41 read=12 │
│ Storage I/O: read=192 times write=0 times │
│ Planning Time: 1.869 ms │
│ Execution Time: 199.554 ms │
└──────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┘

<clear cache>

postgres[1014152][1]=# SHOW io_method ;
┌───────────┐
│ io_method │
├───────────┤
│ io_uring │
└───────────┘
(1 row)

postgres[1014152][1]=# EXPLAIN ANALYZE SELECT count(*) FROM manyrows ;
┌─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┐
│ QUERY PLAN │
├─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┤
│ Aggregate (cost=17906.00..17906.01 rows=1 width=8) (actual time=111.591..111.593 rows=1 loops=1) │
│ Buffers: shared read=5406 │
│ I/O Timings: shared read=14.342 │
│ -> Seq Scan on manyrows (cost=0.00..15406.00 rows=1000000 width=0) (actual time=0.161..70.843 rows=1000000 loops=1) │
│ Buffers: shared read=5406 │
│ I/O Timings: shared read=14.342 │
│ Planning: │
│ Buffers: shared hit=41 read=12 │
│ Storage I/O: read=192 times write=0 times │
│ Planning Time: 1.768 ms │
│ Execution: │
│ Storage I/O: read=86496 times write=0 times │
│ Execution Time: 111.670 ms │
└─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┘

Independent to of this, it's probably not good that we're tracking shared
buffer hits after io combining, if I interpret this correctly... That looks to
be an issue in master, not just the AIO branch.

Greetings,

Andres Freund