RE: Planning counters in pg_stat_statements (using pgss_store)

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.

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?

--
Yoshikazu Imai