Re: Record queryid when auto_explain.log_verbose is on

On 2023-01-16 22:07, Julien Rouhaud wrote:
> Hi,
> 
> On Mon, Jan 16, 2023 at 09:36:59PM +0900, torikoshia wrote:
>> 
>> As far as I read the manual below, auto_explain.log_verbose should 
>> record
>> logs equivalent to VERBOSE option of EXPLAIN.
> 
> Ah good catch, that's clearly an oversight!
> 
>> Attached patch makes auto_explain also print query identifiers.
>> 
>> What do you think?
> 
> @@ -407,6 +408,9 @@ explain_ExecutorEnd(QueryDesc *queryDesc)
>                  ExplainPrintTriggers(es, queryDesc);
>              if (es->costs)
>                  ExplainPrintJITSummary(es, queryDesc);
> +            if (es->verbose && queryDesc->plannedstmt->queryId != 
> UINT64CONST(0))
> +                ExplainPropertyInteger("Query Identifier", NULL, (int64)
> +                                       queryDesc->plannedstmt->queryId, es);
> 
> 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.


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
```

-- 
Regards,

--
Atsushi Torikoshi
NTT DATA CORPORATION