Re: Planning counters in pg_stat_statements (using pgss_store)

On Fri, Nov 8, 2019 at 5:35 AM imai(dot)yoshikazu(at)fujitsu(dot)com
<imai(dot)yoshikazu(at)fujitsu(dot)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.