Re: Planning counters in pg_stat_statements (using pgss_store) - Mailing list pgsql-hackers

On Fri, Nov 8, 2019 at 5:35 AM imai.yoshikazu@fujitsu.com
<imai.yoshikazu@fujitsu.com> wrote:
>
> On Tue, Sept 10, 2019 at 11:27 PM, Julien Rouhaud wrote:
> > > [0002 patch]
> > > In pgss_planner_hook:
> > >
> > > +               /* calc differences of buffer counters. */
> > > +               bufusage = compute_buffer_counters(bufusage_start, pgBufferUsage);
> > > +
> > > +               /*
> > > +                * we only store planning duration, query text has been initialized
> > > +                * during previous pgss_post_parse_analyze as it not available inside
> > > +                * pgss_planner_hook.
> > > +                */
> > > +               pgss_store(query_text,
> > >
> > > Do we need to calculate bufusage in here?
> > > We only store planning duration in the following pgss_store.
> >
> > Good point!  Postgres can definitely access some buffers while
> > planning a query (the most obvious example would be
> > get_actual_variable_range()), but as far as I can tell those were
> > previously not accounted for with pg_stat_statements as
> > queryDesc->totaltime->bufusage is only accumulating buffer usage in
> > the  executor, and indeed current patch also ignore such computed
> > counters.
> >
> > I think it would be better to keep this bufusage calculation during
> > planning and fix pgss_store() to process them, but this would add
> slightly more overhead.
>
> Sorry for my late reply.
> I think overhead would be trivial and we can include bufusage of planning from
> the POV of overhead, but yeah, it will be backward incompatibility if we
> include them.

Ok, let's keep planning's bufusage then.

> BTW, ISTM it is good for including {min,max,mean,stddev}_plan_time to
> pg_stat_statements. Generally plan_time would be almost the same time in each
> execution for the same query, but there are some exceptions. For example, if we
> use prepare statements which uses partition tables, time differs largely
> between creating a general plan and creating a custom plan.
>
> 1. Create partition table which has 1024 partitions.
> 2. Prepare select and update statements.
>   sel) prepare sel(int) as select * from pt where a = $1;
>   upd) prepare upd(int, int) as update pt set a = $2 where a = $1;
> 3. Execute each statement for 8 times.
>   3-1. Select from pg_stat_statements view after every execution.
>     select query, plans, total_plan_time, calls, total_exec_time from pg_stat_statements where query like
'prepare%';
>
>
> Results of pg_stat_statements of sel) are
> query                       | plans | total_plan_time | calls | total_exec_time
> ---------------------------------------------------+-------+-----------------+-------+-----------------
>  prepare sel(int) as select * from pt where a = $1 |     1 |        0.164361 |     1 |        0.004613
>  prepare sel(int) as select * from pt where a = $1 |     2 | 0.27715500000000004 |     2 |        0.009447
>  prepare sel(int) as select * from pt where a = $1 |     3 | 0.39100100000000004 |     3 |        0.014281
>  prepare sel(int) as select * from pt where a = $1 |     4 |        0.504004 |     4 |        0.019265
>  prepare sel(int) as select * from pt where a = $1 |     5 |        0.628242 |     5 |        0.024091
>  prepare sel(int) as select * from pt where a = $1 |     7 | 24.213586000000003 |     6 |        0.029144
>  prepare sel(int) as select * from pt where a = $1 |     8 | 24.368900000000004 |     7 |        0.034099
>  prepare sel(int) as select * from pt where a = $1 |     9 | 24.527956000000003 |     8 |        0.046152
>
>
> Results of pg_stat_statements of upd) are
>  prepare upd(int, int) as update pt set a = $2 where a = $1 |     1 |        0.280099 |     1 |        0.013138
>  prepare upd(int, int) as update pt set a = $2 where a = $1 |     2 |        0.405416 |     2 |         0.01894
>  prepare upd(int, int) as update pt set a = $2 where a = $1 |     3 |        0.532361 |     3 |        0.040716
>  prepare upd(int, int) as update pt set a = $2 where a = $1 |     4 |        0.671445 |     4 |        0.046566
>  prepare upd(int, int) as update pt set a = $2 where a = $1 |     5 |        0.798531 |     5 | 0.052729000000000005
>  prepare upd(int, int) as update pt set a = $2 where a = $1 |     7 |      896.915458 |     6 | 0.05888600000000001
>  prepare upd(int, int) as update pt set a = $2 where a = $1 |     8 |      897.043512 |     7 |        0.064446
>  prepare upd(int, int) as update pt set a = $2 where a = $1 |     9 |      897.169711 |     8 |        0.070644
>
>
> How do you think about that?

That's indeed a very valid point and something we should help user to
investigate.  I'll submit an updated patch with support for
min/max/mean/stddev plan time shortly.