Planning counters in pg_stat_statements (using pgss_store)

Hello

Thank you for picking this up! Did you register patch in CF app? I did not found entry.

Currently we have pg_stat_statements 1.7 version and this patch does not apply... My fast and small view:

-			 errmsg("could not read file \"%s\": %m",
+			 errmsg("could not read pg_stat_statement file \"%s\": %m",

Not sure this is need for this patch. Usually refactoring and new features are different topics.

+#define PG_STAT_STATEMENTS_COLS_V1_4 25

should not be actual version? I think version in names is relevant to extension version.

And this patch does not have documentation changes.

"I agree with the sentiment on the old thread that
{total,min,max,mean,stddev}_time now seem badly named, but adding
execution makes them so long...  Thoughts?"

What would you think about:
- userid
- dbid
- queryid
- query
- plans
- plan_time
- {min,max,mean,stddev}_plan_time
- calls
- exec_time
- {min,max,mean,stddev}_exec_time
- total_time (being the sum of plan_time and exec_time)
- rows
- ...

We have some consensus about backward incompatible changes in this function? *plan_time + *exec_time naming is ok for me

regards, Sergei

Hi Sergei,

Thank you for this review !

Did you register patch in CF app? I did not found entry.

I think it is related to https://commitfest.postgresql.org/16/1373/
but I don't know how to link it with.

Yes, there are many things to improve, but before to go deeper,
I would like to know if that way to do it (with 3 access to pgss hash)
has a chance to get consensus ?

Regards
PAscal

--
Sent from: http://www.postgresql-archive.org/PostgreSQL-hackers-f1928748.html

Hi

I think it is related to https://commitfest.postgresql.org/16/1373/
but I don't know how to link it with.

You can just add new entry in open commitfest and then attach previous thread. This is usual way for pick up old patches. For example, as i did here: https://commitfest.postgresql.org/20/1711/

Yes, there are many things to improve, but before to go deeper,
I would like to know if that way to do it (with 3 access to pgss hash)
has a chance to get consensus ?

I can not say something here, i am not experienced contributor here.
Can you post some performance test results with slowdown comparison between master branch and proposed patch?

regards, Sergei

Thank you Sergei for your comments,

Did you register patch in CF app? I did not found entry.

created today: https://commitfest.postgresql.org/22/1999/

Currently we have pg_stat_statements 1.7 version and this patch does not
apply...

will rebase and create a 1.8 version

-			 errmsg("could not read file \"%s\": %m",
+			 errmsg("could not read pg_stat_statement file \"%s\": %m",

this is a mistake, will fix

+#define PG_STAT_STATEMENTS_COLS_V1_4 25

I thought it was needed when adding new columns, isn't it ?

And this patch does not have documentation changes.

will fix

and will provide some kind of benchmark to compare with actual version.

Regards
PAscal

--
Sent from: http://www.postgresql-archive.org/PostgreSQL-hackers-f1928748.html

Hi

 +#define PG_STAT_STATEMENTS_COLS_V1_4 25

I thought it was needed when adding new columns, isn't it ?

Yes, this is needed. I mean it should be PG_STAT_STATEMENTS_COLS_V1_8: because such change was made for 1.8 pg_stat_statements version. Same thing for other version-specific places.

regards, Sergei

Hi PAscal,

On 2/15/19 11:32 AM, Sergei Kornilov wrote:

Hi

 +#define PG_STAT_STATEMENTS_COLS_V1_4 25

I thought it was needed when adding new columns, isn't it ?

Yes, this is needed. I mean it should be PG_STAT_STATEMENTS_COLS_V1_8: because such change was made for 1.8 pg_stat_statements version. Same thing for other version-specific places.

This patch has been waiting for an update for over a month. Do you know
when you will have one ready? Should we move the release target to PG13?

Regards,
--
-David
david@pgmasters.net

Hi,
Here is a rebased and corrected version .

Columns naming has not been modified, I would propose to change it to:
- plans: ok
- planning_time --> plan_time
- calls: ok
- total_time --> exec_time
- {min,max,mean,stddev}_time: ok
- new total_time (being the sum of plan_time and exec_time)

Regards
PAscal

On Fri, Mar 22, 2019 at 11:46 PM legrand legrand
<legrand_legrand@hotmail.com> wrote:

Here is a rebased and corrected version .

This patch has multiple trailing whitespace, indent and coding style
issues. You should consider running pg_indent before submitting a
patch. I attach the diff after running pgindent if you want more
details about the various issues.

- *     Track statement execution times across a whole database cluster.
+ *     Track statement planning and execution times across a whole cluster.

if we're changing this, we should also fix the fact that's it's not
tracking only the time but various resources?

+       /* calc differences of buffer counters. */
+       bufusage.shared_blks_hit =
+           pgBufferUsage.shared_blks_hit - bufusage_start.shared_blks_hit;
[...]

This is an exact duplication of pgss_ProcessUtility(), it's probably
better to create a macro or a function for that instead.

+               pgss_store("",
+                  parse->queryId,          /* signal that it's a
utility stmt */
+                  -1,

the comment makes no sense, and also you can't pass an empty query
string / unknown len. There's no guarantee that the entry for the
given queryId won't have been evicted, and in this case you'll create
a new and unrelated entry.

@@ -832,13 +931,13 @@ pgss_post_parse_analyze(ParseState *pstate, Query *query)
* the normalized string would be the same as the query text anyway, so
* there's no need for an early entry.
*/
- if (jstate.clocations_count > 0)
pgss_store(pstate->p_sourcetext,

Why did you remove this? pgss_store() isn't free, and asking to
generate a normalized query for a query that doesn't have any constant
or storing the entry early won't do anything useful AFAICT. Though if
that's useful, you definitely can't remove the test without adapting
the comment and the indentation.

@@ -1249,15 +1351,19 @@ pgss_store(const char *query, uint64 queryId,
if (e->counters.calls == 0)
e->counters.usage = USAGE_INIT;

-       e->counters.calls += 1;
-       e->counters.total_time += total_time;
-       if (e->counters.calls == 1)
+       if (planning_time == 0)
+       {
+           e->counters.calls += 1;
+           e->counters.total_time += total_time;
+       }
+
+       if (e->counters.calls == 1 && planning_time == 0)
        {
            e->counters.min_time = total_time;
            e->counters.max_time = total_time;
            e->counters.mean_time = total_time;
        }
-       else
+       else if(planning_time == 0)
        {
            /*
             * Welford's method for accurately computing variance. See
@@ -1276,6 +1382,9 @@ pgss_store(const char *query, uint64 queryId,
            if (e->counters.max_time < total_time)
                e->counters.max_time = total_time;
        }
+       if (planning_time > 0)
+           e->counters.plans += 1;
+       e->counters.planning_time += planning_time;

there are 4 tests to check if planning_time is zero or not, it's quite
messy. Could you refactor the code to avoid so many tests? It would
probably be useful to add some asserts to check that we don't provide
both planning_time == 0 and execution related values. The function's
comment would also need to be adapted to mention the new rationale
with planning_time.

     * hash table entry for the PREPARE (with hash calculated from the query
     * string), and then a different one with the same query string (but hash
     * calculated from the query tree) would be used to accumulate costs of
-    * ensuing EXECUTEs.  This would be confusing, and inconsistent with other
-    * cases where planning time is not included at all.
+    * ensuing EXECUTEs.

the comment about confusing behavior is still valid.

Columns naming has not been modified, I would propose to change it to:
- plans: ok
- planning_time --> plan_time
- calls: ok
- total_time --> exec_time
- {min,max,mean,stddev}_time: ok
- new total_time (being the sum of plan_time and exec_time)

plan_time and exec_time are accumulated counters, so we need to keep
the total_ prefix in any case. I think it's ok to break the function
output names if we keep some kind of compatibility at the view level
(which can keep total_time as the sum of total_plan_time and
total_exec_time), so current queries against the view wouldn't break,
and get what they probably wanted.

This patch has multiple trailing whitespace, indent and coding style
issues. You should consider running pg_indent before submitting a
patch. I attach the diff after running pgindent if you want more
details about the various issues.

fixed

- *     Track statement execution times across a whole database cluster.
+ *     Track statement planning and execution times across a whole cluster.

if we're changing this, we should also fix the fact that's it's not
tracking only the time but various resources?

fixed

+       /* calc differences of buffer counters. */
+       bufusage.shared_blks_hit =
+           pgBufferUsage.shared_blks_hit - bufusage_start.shared_blks_hit;> >
[...]

This is an exact duplication of pgss_ProcessUtility(), it's probably
better to create a macro or a function for that instead.

yes, maybe later (I don't know macros)

+               pgss_store("",
+                  parse->queryId,          /* signal that it's a
utility stmt */
+                  -1,

the comment makes no sense, and also you can't pass an empty query
string / unknown len. There's no guarantee that the entry for the
given queryId won't have been evicted, and in this case you'll create
a new and unrelated entry.

Fixed, comment was wrong
Query text is not available in pgss_planner_hook
that's why pgss_store execution is forced in pgss_post_parse_analyze
(to initialize pgss entry with its query text).

There is a very small risk that query has been evicted between
pgss_post_parse_analyze and pgss_planner_hook.

@@ -832,13 +931,13 @@ pgss_post_parse_analyze(ParseState *pstate, Query *query)
* the normalized string would be the same as the query text anyway, so
* there's no need for an early entry.
*/
- if (jstate.clocations_count > 0)
pgss_store(pstate->p_sourcetext,

Why did you remove this? pgss_store() isn't free, and asking to
generate a normalized query for a query that doesn't have any constant
or storing the entry early won't do anything useful AFAICT. Though if
that's useful, you definitely can't remove the test without adapting
the comment and the indentation.

See explanation in previous answer (comments have been updated accordingly)

there are 4 tests to check if planning_time is zero or not, it's quite
messy. Could you refactor the code to avoid so many tests? It would
probably be useful to add some asserts to check that we don't provide
both planning_time == 0 and execution related values. The function's
comment would also need to be adapted to mention the new rationale
with planning_time.

Fixed

* hash table entry for the PREPARE (with hash calculated from the query
* string), and then a different one with the same query string (but hash
* calculated from the query tree) would be used to accumulate costs of
-    * ensuing EXECUTEs.  This would be confusing, and inconsistent with other
-    * cases where planning time is not included at all.
+    * ensuing EXECUTEs.

the comment about confusing behavior is still valid.

Fixed

Columns naming has not been modified, I would propose to change it to:
- plans: ok
- planning_time --> plan_time
- calls: ok
- total_time --> exec_time
- {min,max,mean,stddev}_time: ok
- new total_time (being the sum of plan_time and exec_time)

plan_time and exec_time are accumulated counters, so we need to keep
the total_ prefix in any case. I think it's ok to break the function
output names if we keep some kind of compatibility at the view level
(which can keep total_time as the sum of total_plan_time and
total_exec_time), so current queries against the view wouldn't break,
and get what they probably wanted.

before to change this at all (view, function, code, doc) levels,
I would like to be sure that column names will be:
- plans
- total_plan_time
- calls
- total_exec_time
- min_time (without exec in name)
- max_time (without exec in name)
- mean_time (without exec in name)
- stddev_time (without exec in name)
- total_time (being the sum of total_plan_time and total_exec_time)

could other users confirm ?

On Sat, Mar 23, 2019 at 11:08 PM legrand legrand
<legrand_legrand@hotmail.com> wrote:

This patch has multiple trailing whitespace, indent and coding style
issues. You should consider running pg_indent before submitting a
patch. I attach the diff after running pgindent if you want more
details about the various issues.

fixed

There are still trailing whitespaces and comments wider than 80
characters in the C code that should be fixed.

+               pgss_store("",
+                  parse->queryId,          /* signal that it's a
utility stmt */
+                  -1,

the comment makes no sense, and also you can't pass an empty query
string / unknown len. There's no guarantee that the entry for the
given queryId won't have been evicted, and in this case you'll create
a new and unrelated entry.

Fixed, comment was wrong
Query text is not available in pgss_planner_hook
that's why pgss_store execution is forced in pgss_post_parse_analyze
(to initialize pgss entry with its query text).

There is a very small risk that query has been evicted between
pgss_post_parse_analyze and pgss_planner_hook.

@@ -832,13 +931,13 @@ pgss_post_parse_analyze(ParseState *pstate, Query *query)
* the normalized string would be the same as the query text anyway, so
* there's no need for an early entry.
*/
- if (jstate.clocations_count > 0)
pgss_store(pstate->p_sourcetext,

Why did you remove this? pgss_store() isn't free, and asking to
generate a normalized query for a query that doesn't have any constant
or storing the entry early won't do anything useful AFAICT. Though if
that's useful, you definitely can't remove the test without adapting
the comment and the indentation.

See explanation in previous answer (comments have been updated accordingly)

The alternative being to expose query text to the planner, which could
fix this (unlikely) issue and could also sometimes save a pgss_store()
call. I did a quick check and at least AQO and pg_hint_plan
extensions have some hacks to be able to access the query text from
the planner, so there are at least multiple needs for that. Perhaps
it's time to do it?

there are 4 tests to check if planning_time is zero or not, it's quite
messy. Could you refactor the code to avoid so many tests? It would
probably be useful to add some asserts to check that we don't provide
both planning_time == 0 and execution related values. The function's
comment would also need to be adapted to mention the new rationale
with planning_time.

Fixed

+       /* updating counters for execute OR planning */
+       Assert(planning_time > 0 && total_time > 0);
+       if (planning_time == 0)

This is obviously incorrect. The general sanity check for exclusion
between planning_time and total_time should be at the beginning of
pgss_store. Maybe some others asserts are needed to verify that
planning_time cannot be provided along jstate or other conditions.

On Sun, Mar 24, 2019 at 11:24 AM Julien Rouhaud <rjuju123@gmail.com> wrote:

there are 4 tests to check if planning_time is zero or not, it's quite
messy. Could you refactor the code to avoid so many tests? It would
probably be useful to add some asserts to check that we don't provide
both planning_time == 0 and execution related values. The function's
comment would also need to be adapted to mention the new rationale
with planning_time.

Fixed

+       /* updating counters for execute OR planning */
+       Assert(planning_time > 0 && total_time > 0);
+       if (planning_time == 0)

This is obviously incorrect. The general sanity check for exclusion
between planning_time and total_time should be at the beginning of
pgss_store. Maybe some others asserts are needed to verify that
planning_time cannot be provided along jstate or other conditions.

Actually, since pgss_store is now called to either:

- explicitly store a query text
- accumulate planning duration
- accumulate execution duration

and they're all mutually exclusive, It's probably better to change
pgss_store to pass an enum to describe what the call is for , and keep
a single time parameter. It should make the code simpler.

As there are now 3 locking times on pgss hash struct, one day or an other,
somebody will ask for a GUC to disable this feature (to be able to run pgss
unchanged with only one lock as today).

With this GUC, pgss_store should be able to store the query text and
accumulated
execution duration in the same call (as today).

Will try to provide this soon.

--
Sent from: http://www.postgresql-archive.org/PostgreSQL-hackers-f1928748.html

here is a new version:

- "track_planning" GUC added
to permit to keep previous behavior unchanged
- columns names have been changed / added:
total_plan_time, total_exec_time, total_time
- trailing whitespaces and comments wider than 80 characters
not fixed
- "if (jstate.clocations_count > 0) pgss_store(pstate->p_sourcetext,..."
has been reverted
- expose query text to the planner
won't fix (out of my knowledge)
- "Assert(planning_time > 0 && total_time > 0);"
moved at the beginning of pgss_store

Regards
PAscal

On Wed, Mar 27, 2019 at 12:21 AM legrand legrand
<legrand_legrand@hotmail.com> wrote:

here is a new version:

- "track_planning" GUC added
to permit to keep previous behavior unchanged

good

- trailing whitespaces and comments wider than 80 characters
not fixed

why? In case it's not clear, I'm talking about the .c file, not the
regression tests.

- "Assert(planning_time > 0 && total_time > 0);"
moved at the beginning of pgss_store

Have you tried to actually compile postgres and pg_stat_statements
with --enable-cassert? This test can *never* be true, since you
either provide the planning time or the execution time or neither. As
I said in my previous mail, adding a parameter to say which counter
you're updating, instead of adding another counter that's mutually
exclusive with the other would make everything clearer.

- trailing whitespaces and comments wider than 80 characters
not fixed

why? In case it's not clear, I'm talking about the .c file, not the
regression tests.

I work on a poor msys install on windows 7, where perl is broken ;o(
So no pgindent available.
Will fix that later, or as soon as I get a pgindent diff.

- "Assert(planning_time > 0 && total_time > 0);"
moved at the beginning of pgss_store

Have you tried to actually compile postgres and pg_stat_statements
with --enable-cassert? This test can *never* be true, since you
either provide the planning time or the execution time or neither. As
I said in my previous mail, adding a parameter to say which counter
you're updating, instead of adding another counter that's mutually
exclusive with the other would make everything clearer.

Yes this "assert" is useless as is ... I'll remove it.
I understand you proposal of pgss_store refactoring, but I don't have
much time available now ... and I would like to check that performances
are not broken before any other modification ...

Regards
PAscal

--
Sent from: http://www.postgresql-archive.org/PostgreSQL-hackers-f1928748.html

On Wed, Mar 27, 2019 at 9:36 PM legrand legrand
<legrand_legrand@hotmail.com> wrote:

- trailing whitespaces and comments wider than 80 characters
not fixed

why? In case it's not clear, I'm talking about the .c file, not the
regression tests.

I work on a poor msys install on windows 7, where perl is broken ;o(
So no pgindent available.
Will fix that later, or as soon as I get a pgindent diff.

- "Assert(planning_time > 0 && total_time > 0);"
moved at the beginning of pgss_store

Have you tried to actually compile postgres and pg_stat_statements
with --enable-cassert? This test can *never* be true, since you
either provide the planning time or the execution time or neither. As
I said in my previous mail, adding a parameter to say which counter
you're updating, instead of adding another counter that's mutually
exclusive with the other would make everything clearer.

Yes this "assert" is useless as is ... I'll remove it.
I understand you proposal of pgss_store refactoring, but I don't have
much time available now ... and I would like to check that performances
are not broken before any other modification ...

Ok, but keep in mind that this is the last commitfest for pg12, and
there are only 4 days left. Will you have time to take care of it, or
do you need help on it?

Julien Rouhaud wrote

On Wed, Mar 27, 2019 at 9:36 PM legrand legrand
&lt;

legrand_legrand@

&gt; wrote:

- trailing whitespaces and comments wider than 80 characters
not fixed

why? In case it's not clear, I'm talking about the .c file, not the
regression tests.

I work on a poor msys install on windows 7, where perl is broken ;o(
So no pgindent available.
Will fix that later, or as soon as I get a pgindent diff.

- "Assert(planning_time > 0 && total_time > 0);"
moved at the beginning of pgss_store

Have you tried to actually compile postgres and pg_stat_statements
with --enable-cassert? This test can *never* be true, since you
either provide the planning time or the execution time or neither. As
I said in my previous mail, adding a parameter to say which counter
you're updating, instead of adding another counter that's mutually
exclusive with the other would make everything clearer.

Yes this "assert" is useless as is ... I'll remove it.
I understand you proposal of pgss_store refactoring, but I don't have
much time available now ... and I would like to check that performances
are not broken before any other modification ...

Ok, but keep in mind that this is the last commitfest for pg12, and
there are only 4 days left. Will you have time to take care of it, or
do you need help on it?

Oups, sorry, I won't have time nor knowledge to finish in time ;o(
Any help is welcome !

Regards
PAscal

--
Sent from: http://www.postgresql-archive.org/PostgreSQL-hackers-f1928748.html

Hi

 Ok, but keep in mind that this is the last commitfest for pg12, and
 there are only 4 days left. Will you have time to take care of it, or
 do you need help on it?

Oups, sorry, I won't have time nor knowledge to finish in time ;o(
Any help is welcome !

No need to rush, this patch has is unlikely to get committed in pg12 even a month earlier. We have a general policy that we don't like complex patches that first show up for the last commitfest of a dev cycle. Current commitfest is last one before feature freeze.

I want such feature and will help with review in pg13 cycle.

regards, Sergei

On Thu, Mar 28, 2019 at 8:45 AM Sergei Kornilov <sk@zsrv.org> wrote:

Ok, but keep in mind that this is the last commitfest for pg12, and
there are only 4 days left. Will you have time to take care of it, or
do you need help on it?

Oups, sorry, I won't have time nor knowledge to finish in time ;o(
Any help is welcome !

No need to rush, this patch has is unlikely to get committed in pg12 even a month earlier. We have a general policy that we don't like complex patches that first show up for the last commitfest of a dev cycle. Current commitfest is last one before feature freeze.

yes, but this patch first showed up years ago:
https://commitfest.postgresql.org/16/1373/. Since nothing happened
since, it would be nice to have feedback on whether deeper changes on
the planning functions are required (so for pg13), or if current
approach is ok (and then I hope it'd be acceptable for pg12).