queryid is cleared too early with nested queries

[shinderuk]

Here is a demo using two sessions distinguished with indentation:

postgres=# select * from pg_wait_sampling_current where pid = 65936;
  pid  | event_type |   event    | queryid 
-------+------------+------------+---------
 65936 | Client     | ClientRead |       0
(1 row)

        postgres=# create function f(int) returns int as 'select pg_sleep(3); select $1' language sql;
        CREATE FUNCTION
        postgres=# select f(i) from generate_series(1, 3) i;
        ...

postgres=# select * from pg_wait_sampling_current where pid = 65936;
  pid  | event_type |  event  |       queryid       
-------+------------+---------+---------------------
 65936 | Timeout    | PgSleep | 8411540322399323155
(1 row)

postgres=# select * from pg_wait_sampling_current where pid = 65936;
  pid  | event_type |  event  | queryid 
-------+------------+---------+---------
 65936 | Timeout    | PgSleep |       0
(1 row)

         f 
        ---
         1
         2
         3
        (3 rows)

postgres=# select * from pg_wait_sampling_current where pid = 65936;
  pid  | event_type |   event    | queryid 
-------+------------+------------+---------
 65936 | Client     | ClientRead |       0
(1 row)

Another example with extra debug output:

postgres=# create function g(int) returns int as 'select 1; select $1 + 1' language sql;
CREATE FUNCTION
postgres=# select i, g(i) from generate_series(1, 3) i;
NOTICE:  planner_hook: set queryid to 4330984749448694052
NOTICE:  planner_hook: queryid is already set to 4330984749448694052 (ignore 15748251446205589984)
NOTICE:  planner_hook: queryid is already set to 4330984749448694052 (ignore 13006084060684650529)
NOTICE:  ExecutorEnd_hook: clear queryid (was 4330984749448694052)
NOTICE:  ExecutorEnd_hook: clear queryid (was 0)
NOTICE:  ExecutorEnd_hook: clear queryid (was 0)
NOTICE:  ExecutorEnd_hook: clear queryid (was 0)
NOTICE:  ExecutorEnd_hook: clear queryid (was 0)
NOTICE:  ExecutorEnd_hook: clear queryid (was 0)
NOTICE:  ExecutorEnd_hook: clear queryid (was 0)
 i | g 
---+---
 1 | 2
 2 | 3
 3 | 4
(3 rows)

Should pg_wait_sampling track nesting level like pg_stat_statements does?

[maksm90]

This issue is consequence that queryId is set for upper-level query but cleared by the first completed subquery.

Should pg_wait_sampling track nesting level like pg_stat_statements does?

Yeah, definitely in perspective. But now it doesn't support nested levels.

Thanks for this buggy case. It's a good augment to the issues around queryId for nested queries described in https://github.com/postgrespro/pg_wait_sampling/issues/43 .

[Medvecrab]

Fixed in v1.1.6