Re: Showing I/O timings spent reading/writing temp buffers in EXPLAIN

Em ter., 24 de ago. de 2021 às 03:11, Masahiko Sawada <sawada(dot)mshk(at)gmail(dot)com>
escreveu:

> On Mon, Aug 23, 2021 at 10:46 AM Masahiko Sawada <sawada(dot)mshk(at)gmail(dot)com>
> wrote:
> >
> > On Thu, Aug 19, 2021 at 10:52 PM Ranier Vilela <ranier(dot)vf(at)gmail(dot)com>
> wrote:
> > >
> > > Em qui., 19 de ago. de 2021 às 09:21, Masahiko Sawada <
> sawada(dot)mshk(at)gmail(dot)com> escreveu:
> > >>
> > >> Hi all ,
> > >>
> > >> It's reported on pgsql-bugs[1] that I/O timings in EXPLAIN don't show
> > >> the one for temp files. I think it's not a bug but could be an item
> > >> for PG15. As mentioned on that thread, this would be useful for users
> > >> in a case where temp buffers I/O used most of the time. So I've
> > >> written the patch for that. Please note that the patch includes only
> > >> to show temp buffer I/O timing to EXPLAIN but not other possibly
> > >> related changes such as pg_stat_statement improvements yet.
> > >>
> > >> Before (w/o patch):
> > >> postgres(1:14101)=# explain (analyze, buffers) select count(*) from
> > >> generate_series(1,100000);
> > >> QUERY PLAN
> > >>
> -----------------------------------------------------------------------------------------------------------------------------------
> > >> Aggregate (cost=1250.00..1250.01 rows=1 width=8) (actual
> > >> time=59.025..59.026 rows=1 loops=1)
> > >> Buffers: temp read=171 written=171
> > >> -> Function Scan on generate_series (cost=0.00..1000.00
> > >> rows=100000 width=0) (actual time=21.695..45.524 rows=100000 loops=1)
> > >> Buffers: temp read=171 written=171
> > >> Planning Time: 0.041 ms
> > >> Execution Time: 70.867 ms
> > >> (6 rows)
> > >>
> > >> After (w/ patch):
> > >> postgres(1:28754)=# explain (analyze, buffers) select count(*) from
> > >> generate_series(1,100000);
> > >> QUERY PLAN
> > >>
> -----------------------------------------------------------------------------------------------------------------------------------
> > >> Aggregate (cost=1250.00..1250.01 rows=1 width=8) (actual
> > >> time=56.189..56.190 rows=1 loops=1)
> > >> Buffers: temp read=171 written=171
> > >> I/O Timings: temp read=0.487 write=2.073
> > >> -> Function Scan on generate_series (cost=0.00..1000.00
> > >> rows=100000 width=0) (actual time=21.072..42.886 rows=100000 loops=1)
> > >> Buffers: temp read=171 written=171
> > >> I/O Timings: temp read=0.487 write=2.073
> > >> Planning Time: 0.041 ms
> > >> Execution Time: 59.928 ms
> > >> (8 rows)
> > >>
> > >> Feedback is very welcome.
> > >
> >
> > Thank you for the comments!
> >
> > > The presentation seems a little confusing, wouldn't it be better?
> > >
> > > I/O Timings: shared/local read=xxxx write=xxx temp read=0.487
> write=2.073
> >
> > Yeah, it looks better to add "shared/local".
>
> I've attached the updated patch that incorporates the above comment.
>
The patch looks fine to me.

regards,
Ranier Vilela