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

On Tue, Apr 05, 2022 at 12:51:12AM +0900, Masahiko Sawada wrote:
> On Mon, Apr 4, 2022 at 1:30 PM Julien Rouhaud <rjuju123(at)gmail(dot)com> wrote:
> >
> > Hmm, but AFAICS the json format would be stable as the counters are always
> > shown even if zero. So just doing the json format first and then the text
> > format should also work. Although if you're really unlucky there could be a
> > cache invalidation in between so we could just ignore the text format. But I
> > think we should at least keep a regression test with the json format, with a
> > comment explain why only this one is tested.
>
> Fair point. By commit 7e12256b478 we disabled track_io_timing, but
> probably we can temporarily enable it and run one query with "buffers"
> and "format json" options.

Yes, enabling it for just this query. It can't really find any problem with
the values themselves but at least the new code path would be partially
executed.

> >
> > - not really your patch fault I guess, but I see that extendBufFile() isn't
> > handled. There shouldn't be much activity there so maybe it's ok.
> > This is likely because smgr_extend is also not handled, but this one seems
> > much more likely to take quite some time, and therefore should bump the
> > timing counters.
>
> You mean we should include the time for opening files as write time?

Yes. In normal circumstances it shouldn't need a lot of time to do that, but
I'm not so sure with e.g. network filesystems. I'm not strongly in favor of
counting it, especially since smgrextend doesn't either.

> IIUC smgrextend() writes data while extending file whereas
> extendBufFile() doesn't do that but just opens a new file.

Note that smgrextend can also call register_dirty_segment(), which can also
take some time, so we can't just assume that all the time there is IO time.