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

On Tue, Sep 7, 2021 at 12:02 AM <gkokolatos(at)pm(dot)me> wrote:
>
> Hi,
>
> ‐‐‐‐‐‐‐ Original Message ‐‐‐‐‐‐‐
> On Tuesday, August 24th, 2021 at 13:20, Ranier Vilela <ranier(dot)vf(at)gmail(dot)com> wrote:
>
> > 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
>
> <snip>
>
> > >
> > > I've attached the updated patch that incorporates the above comment.
> >
> > The patch looks fine to me.
> >
>

Thank you for the comments!

> The patch looks good to me too. However I do wonder why the timing is added only on
> the
>
> if (es->format == EXPLAIN_FORMAT_TEXT)
>
> block and is not added when, for example, the format is json. The instrumentation has
> clearly recorded the timings regardless of the output format.

Good point. Fixed.

>
> Also, it might be worth while to consider adding some regression tests. To my
> understanding, explain.sql provides a function, explain_filter, which helps create
> a stable result. For example, such a test case can be:
>
> set track_io_timing = 'on';
> select explain_filter('explain (analyze, buffers) select count(*) from generate_series(1,100000)');
>
> then it would be enough to verify that the line:
>
> I/O Timings: temp read=N.N write=N.N
>
> is present. The above would apply on the json output via `explain_filter_to_json`
> of course.

Agreed. I've added regression tests.

I've attached an updated patch. Please review it.

Regards,

--
Masahiko Sawada
EDB: https://www.enterprisedb.com/