Skip to content

Commit

Permalink
Make auto_explain print the query identifier in verbose mode
Browse files Browse the repository at this point in the history
When auto_explain.log_verbose is on, auto_explain should print in the
logs plans equivalent to the EXPLAIN (VERBOSE).  However, when
compute_query_id is on, query identifiers were not showing up, being
only handled by EXPLAIN (VERBOSE).  This brings auto_explain on par with
EXPLAIN regarding that.  Note that like EXPLAIN, auto_explain does not
show the query identifier when compute_query_id=regress.

The change is done so as the choice of printing the query identifier is
done in ExplainPrintPlan() rather than in ExplainOnePlan(), to avoid a
duplication of the logic dealing with the query ID.  auto_explain is the
only in-core caller of ExplainPrintPlan().

While looking at the area, I have noticed that more consolidation
between EXPLAIN and auto_explain would be in order for the logging of
the plan duration and the buffer usage.  This refactoring is left as a
future change.

Author: Atsushi Torikoshi
Reviewed-by: Justin Pryzby, Julien Rouhaud
Discussion: https://postgr.es/m/1ea21936981f161bccfce05765c03bee@oss.nttdata.com
  • Loading branch information
michaelpq committed Jan 26, 2023
1 parent ffcf6f4 commit 9d2d972
Show file tree
Hide file tree
Showing 2 changed files with 45 additions and 16 deletions.
29 changes: 29 additions & 0 deletions contrib/auto_explain/t/001_auto_explain.pl
Expand Up @@ -106,6 +106,35 @@ sub query_log
qr/Query Parameters:/,
"query parameters not logged when disabled, text mode");

# Query Identifier.
# Logging enabled.
$log_contents = query_log(
$node,
"SELECT * FROM pg_class;",
{
"auto_explain.log_verbose" => "on",
"compute_query_id" => "on"
});

like(
$log_contents,
qr/Query Identifier:/,
"query identifier logged with compute_query_id=on, text mode");

# Logging disabled.
$log_contents = query_log(
$node,
"SELECT * FROM pg_class;",
{
"auto_explain.log_verbose" => "on",
"compute_query_id" => "regress"
});

unlike(
$log_contents,
qr/Query Identifier:/,
"query identifier not logged with compute_query_id=regress, text mode");

# JSON format.
$log_contents = query_log(
$node,
Expand Down
32 changes: 16 additions & 16 deletions src/backend/commands/explain.c
Expand Up @@ -604,22 +604,6 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
/* Create textual dump of plan tree */
ExplainPrintPlan(es, queryDesc);

/*
* COMPUTE_QUERY_ID_REGRESS means COMPUTE_QUERY_ID_AUTO, but we don't show
* the queryid in any of the EXPLAIN plans to keep stable the results
* generated by regression test suites.
*/
if (es->verbose && plannedstmt->queryId != UINT64CONST(0) &&
compute_query_id != COMPUTE_QUERY_ID_REGRESS)
{
/*
* Output the queryid as an int64 rather than a uint64 so we match
* what would be seen in the BIGINT pg_stat_statements.queryid column.
*/
ExplainPropertyInteger("Query Identifier", NULL, (int64)
plannedstmt->queryId, es);
}

/* Show buffer usage in planning */
if (bufusage)
{
Expand Down Expand Up @@ -791,6 +775,22 @@ ExplainPrintPlan(ExplainState *es, QueryDesc *queryDesc)
* don't match the built-in defaults.
*/
ExplainPrintSettings(es);

/*
* COMPUTE_QUERY_ID_REGRESS means COMPUTE_QUERY_ID_AUTO, but we don't show
* the queryid in any of the EXPLAIN plans to keep stable the results
* generated by regression test suites.
*/
if (es->verbose && queryDesc->plannedstmt->queryId != UINT64CONST(0) &&
compute_query_id != COMPUTE_QUERY_ID_REGRESS)
{
/*
* Output the queryid as an int64 rather than a uint64 so we match
* what would be seen in the BIGINT pg_stat_statements.queryid column.
*/
ExplainPropertyInteger("Query Identifier", NULL, (int64)
queryDesc->plannedstmt->queryId, es);
}
}

/*
Expand Down

0 comments on commit 9d2d972

Please sign in to comment.