Re: Record queryid when auto_explain.log_verbose is on - Mailing list pgsql-hackers

Hi,

On Tue, Jan 17, 2023 at 10:53:23PM +0900, torikoshia wrote:
> >
> > For interactive EXPLAIN the query identifier is printed just after the
> > plan,
> > before the triggers and the JIT summary so auto_explain should do the
> > same.
> Thanks for the comment!
> Agreed and updated the patch.

Thanks!

> On 2023-01-17 03:53, Justin Pryzby wrote:
> > On Mon, Jan 16, 2023 at 09:36:59PM +0900, torikoshia wrote:
> > > Attached patch makes auto_explain also print query identifiers.
> >
> > This was asked during the initial patch; does your patch address the
> > issues here ?
> >
> > https://www.postgresql.org/message-id/20200308142644.vlihk7djpwqjkp7w%40nol
>
> Thanks!
> I may misunderstand something, but it seems that the issue occurred since
> queryid was calculated in pgss_post_parse_analyze() at that time.
>
> ```
> --- queryid_exposure-v6.diff, which is the patch just before the discussion
> @@ -792,16 +801,34 @@ pgss_post_parse_analyze(ParseState *pstate, Query
> *query)
> ..snip..
>
>     if (query->utilityStmt)
>     {
> -       query->queryId = UINT64CONST(0);
> +       if (pgss_track_utility && PGSS_HANDLED_UTILITY(query->utilityStmt)
> +           && pstate->p_sourcetext)
> +       {
> +           const char *querytext = pstate->p_sourcetext;
> +           int query_location = query->stmt_location;
> +           int query_len = query->stmt_len;
> +
> +           /*
> +            * Confine our attention to the relevant part of the string, if
> the
> +            * query is a portion of a multi-statement source string.
> +            */
> +           querytext = pgss_clean_querytext(pstate->p_sourcetext,
> +                                            &query_location,
> +                                            &query_len);
> +
> +           query->queryId = pgss_compute_utility_queryid(querytext,
> query_len);
> ```
>
> Currently queryId is not calculated in pgss_post_parse_analyze() and the
> issue does not occur, doesn't it?
> I confirmed the attached patch logged queryid for some utility statements.
>
> ```
> LOG:  00000: duration: 0.017 ms  plan:
>         Query Text: prepare p1 as select 1;
>         Result  (cost=0.00..0.01 rows=1 width=4)
>           Output: 1
>         Query Identifier: -1801652217649936326
> ```

Yes, this problem was fixed a long time ago.  Just to be sure I checked that
auto_explain and explain agree on the queryid:

=# select count(*) from pg_class;
[...]
LOG:  duration: 0.239 ms  plan:
    Query Text: select count(*) from pg_class;
    Aggregate  (cost=15.45..15.46 rows=1 width=8)
      Output: count(*)
      ->  Index Only Scan using pg_class_tblspc_relfilenode_index on pg_catalog.pg_class  (cost=0.15..14.40 rows=417
width=0)
            Output: reltablespace, relfilenode
    Query Identifier: 2855866587085353326

=# explain (verbose) select count(*) from pg_class;
                                                        QUERY PLAN                                           >
------------------------------------------------------------------------------------------------------------->
 Aggregate  (cost=15.45..15.46 rows=1 width=8)
   Output: count(*)
   ->  Index Only Scan using pg_class_tblspc_relfilenode_index on pg_catalog.pg_class  (cost=0.15..14.40 rows>
         Output: reltablespace, relfilenode
 Query Identifier: 2855866587085353326

LOG:  duration: 0.000 ms  plan:
    Query Text: explain (verbose) select count(*) from pg_class;
    Aggregate  (cost=15.45..15.46 rows=1 width=8)
      Output: count(*)
      ->  Index Only Scan using pg_class_tblspc_relfilenode_index on pg_catalog.pg_class  (cost=0.15..14.40 rows=417
width=0)
            Output: reltablespace, relfilenode
    Query Identifier: 2855866587085353326

So the patch looks good to me.  I didn't find any entry in the commitfest, did
I miss it?  If not, could you create one (feel free to add me and Justin as
reviewer, and probably mark is as RfC).

It's a bit annoying that the info is missing since pg 14, but we probably can't
backpatch this as it might break log parser tools.