public inbox for [email protected]
help / color / mirror / Atom feedFrom: Julien Rouhaud <[email protected]>
To: Masahiko Sawada <[email protected]>
Cc: [email protected]
Cc: Ranier Vilela <[email protected]>
Cc: PostgreSQL-development <[email protected]>
Cc: [email protected]
Subject: Re: Showing I/O timings spent reading/writing temp buffers in EXPLAIN
Date: Mon, 4 Apr 2022 12:30:20 +0800
Message-ID: <Ykp0XP37Gj/sT5hB@jrouhaud> (raw)
In-Reply-To: <CAD21AoAca6EdwRhhqbLuAsOxMsKKZB9qMX_m9LenLS2NE6fM1A@mail.gmail.com>
References: <CAD21AoAJgotTeP83p6HiAGDhs_9Fw9pZ2J=_tYTsiO5Ob-V5GQ@mail.gmail.com>
<CAEudQApKndnEgtkL5o9DxfP7sNKXSw0uuWcvD4HYh6GWmkeJ1g@mail.gmail.com>
<CAD21AoC7uaV2qiVoWPSjxyY5YAqyHa5w5XAuFCqrLtXAhwCiSQ@mail.gmail.com>
<CAD21AoAdwWBxBn8YQucsRGEB3ToYH4C6wjGU+qajKLmiJDCJkw@mail.gmail.com>
<CAEudQAogZVHURE7fSfbOmOZMPK7tR+FMR4b=5WKVU7BersxaOQ@mail.gmail.com>
<2sAuEW1zGE4cTWCRPgzvAshfUAM44kW02tc3i31iLLCujLE-tczA8xOGFhs6c2EiEVM5uSQy_cJyvgAA1EKyxRtqnWM_mrirKwsTJ6Kxaaw=@pm.me>
<CAD21AoDXgYRVrzWpAV_CoX0nbg68++Bx4RbkzY40hKm5h1mEtg@mail.gmail.com>
<20220119085236.iuuq4rtzm6qxvzls@jrouhaud>
<CAD21AoAca6EdwRhhqbLuAsOxMsKKZB9qMX_m9LenLS2NE6fM1A@mail.gmail.com>
Hi,
On Tue, Mar 01, 2022 at 11:35:32AM +0900, Masahiko Sawada wrote:
> On Wed, Jan 19, 2022 at 5:52 PM Julien Rouhaud <[email protected]> wrote:
> >
> > It seems that the regression tests aren't entirely stable, per cfbot:
> > https://cirrus-ci.com/github/postgresql-cfbot/postgresql/commitfest/36/3298.
> >
> > The failures look like:
> >
> > diff -U3 /tmp/cirrus-ci-build/src/test/recovery/../regress/expected/explain.out /tmp/cirrus-ci-build/src/test/recovery/tmp_check/results/explain.out
> > --- /tmp/cirrus-ci-build/src/test/recovery/../regress/expected/explain.out 2022-01-19 03:50:37.087931908 +0000
> > +++ /tmp/cirrus-ci-build/src/test/recovery/tmp_check/results/explain.out 2022-01-19 03:57:41.013616137 +0000
> > @@ -512,9 +512,10 @@
> > I/O Timings: temp read=N.N write=N.N
> > -> Function Scan on generate_series (cost=N.N..N.N rows=N width=N) (actual time=N.N..N.N rows=N loops=N)
> > I/O Timings: temp read=N.N write=N.N
> > + I/O Timings: shared/local read=N.N
> > Planning Time: N.N ms
> > Execution Time: N.N ms
> > -(6 rows)
> > +(7 rows)
> >
> > select explain_filter('explain (analyze, buffers, format json) select count(*) from generate_series(1, 100000)');
> > explain_filter
> >
> >
> > I don't see any obvious error in the code, so I'm wondering if it's simply
> > the result of populating the cache with generate_series() info.
>
> Thank you for reporting.
>
> You're right, the regression test with track_io_timing = on is not
> entirely stable because we may read catalog data during planning time,
> resulting in an additional line in the EXPLAIN output. I've removed
> the regression tests.
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.
> I've attached updated patches. I've included an improvement of
> pg_stat_statement support to support temp I/O timing.
Great!
Some other considerations:
- should we update pg_stat_statements documentation (and comments) for
blk_(read|write)_time to mention that it's for *data file* blocks rather than
simply blocks? It seems obvious now that we'd have
temp_blk_(read|write)_time, but still. This part should probably be
backpatched.
- 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.
view thread (24+ messages) latest in thread
reply
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: [email protected]
Cc: [email protected], [email protected], [email protected], [email protected], [email protected]
Subject: Re: Showing I/O timings spent reading/writing temp buffers in EXPLAIN
In-Reply-To: <Ykp0XP37Gj/sT5hB@jrouhaud>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox