Skip to content

Commit

Permalink
Make use of in-core query id added by commit 5fd9dfa
Browse files Browse the repository at this point in the history 
Use the in-core query id computation for pg_stat_activity,
log_line_prefix, and EXPLAIN VERBOSE.

Similar to other fields in pg_stat_activity, only the queryid from the
top level statements are exposed, and if the backends status isn't
active then the queryid from the last executed statements is displayed.

Add a %Q placeholder to include the queryid in log_line_prefix, which
will also only expose top level statements.

For EXPLAIN VERBOSE, if a query identifier has been computed, either by
enabling compute_query_id or using a third-party module, display it.

Bump catalog version.

Discussion: https://postgr.es/m/20210407125726.tkvjdbw76hxnpwfi@nol

Author: Julien Rouhaud

Reviewed-by: Alvaro Herrera, Nitin Jadhav, Zhihong Yu
  • Loading branch information
@bmomjian
bmomjian committed Apr 7, 2021
1 parent ec7ffb8 commit 4f0b096
Show file tree
Hide file tree
Showing 21 changed files with 250 additions and 105 deletions.
112 changes: 44 additions & 68 deletions contrib/pg_stat_statements/pg_stat_statements.c
View file
Expand Up @@ -67,6 +67,7 @@
#include "tcop/utility.h"
#include "utils/acl.h"
#include "utils/builtins.h"
#include "utils/queryjumble.h"
#include "utils/memutils.h"
#include "utils/timestamp.h"

Expand Down Expand Up @@ -101,6 +102,14 @@ static const uint32 PGSS_PG_MAJOR_VERSION = PG_VERSION_NUM / 100;
#define USAGE_DEALLOC_PERCENT 5 /* free this % of entries at once */
#define IS_STICKY(c) ((c.calls[PGSS_PLAN] + c.calls[PGSS_EXEC]) == 0)

/*
* Utility statements that pgss_ProcessUtility and pgss_post_parse_analyze
* ignores.
*/
#define PGSS_HANDLED_UTILITY(n) (!IsA(n, ExecuteStmt) && \
!IsA(n, PrepareStmt) && \
!IsA(n, DeallocateStmt))

/*
* Extension version number, for supporting older extension versions' objects
*/
Expand Down Expand Up @@ -309,7 +318,6 @@ static void pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
ProcessUtilityContext context, ParamListInfo params,
QueryEnvironment *queryEnv,
DestReceiver *dest, QueryCompletion *qc);
static uint64 pgss_hash_string(const char *str, int len);
static void pgss_store(const char *query, uint64 queryId,
int query_location, int query_len,
pgssStoreKind kind,
Expand Down Expand Up @@ -806,16 +814,14 @@ pgss_post_parse_analyze(ParseState *pstate, Query *query, JumbleState *jstate)
return;

/*
* Utility statements get queryId zero. We do this even in cases where
* the statement contains an optimizable statement for which a queryId
* could be derived (such as EXPLAIN or DECLARE CURSOR). For such cases,
* runtime control will first go through ProcessUtility and then the
* executor, and we don't want the executor hooks to do anything, since we
* are already measuring the statement's costs at the utility level.
* Clear queryId for prepared statements related utility, as those will
* inherit from the underlying statement's one (except DEALLOCATE which is
* entirely untracked).
*/
if (query->utilityStmt)
{
query->queryId = UINT64CONST(0);
if (pgss_track_utility && !PGSS_HANDLED_UTILITY(query->utilityStmt))
query->queryId = UINT64CONST(0);
return;
}

Expand Down Expand Up @@ -1057,6 +1063,23 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
DestReceiver *dest, QueryCompletion *qc)
{
Node *parsetree = pstmt->utilityStmt;
uint64 saved_queryId = pstmt->queryId;

/*
* Force utility statements to get queryId zero. We do this even in cases
* where the statement contains an optimizable statement for which a
* queryId could be derived (such as EXPLAIN or DECLARE CURSOR). For such
* cases, runtime control will first go through ProcessUtility and then the
* executor, and we don't want the executor hooks to do anything, since we
* are already measuring the statement's costs at the utility level.
*
* Note that this is only done if pg_stat_statements is enabled and
* configured to track utility statements, in the unlikely possibility
* that user configured another extension to handle utility statements
* only.
*/
if (pgss_enabled(exec_nested_level) && pgss_track_utility)
pstmt->queryId = UINT64CONST(0);

/*
* If it's an EXECUTE statement, we don't track it and don't increment the
Expand All @@ -1073,9 +1096,7 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
* Likewise, we don't track execution of DEALLOCATE.
*/
if (pgss_track_utility && pgss_enabled(exec_nested_level) &&
!IsA(parsetree, ExecuteStmt) &&
!IsA(parsetree, PrepareStmt) &&
!IsA(parsetree, DeallocateStmt))
PGSS_HANDLED_UTILITY(parsetree))
{
instr_time start;
instr_time duration;
Expand Down Expand Up @@ -1130,7 +1151,7 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
WalUsageAccumDiff(&walusage, &pgWalUsage, &walusage_start);

pgss_store(queryString,
0, /* signal that it's a utility stmt */
saved_queryId,
pstmt->stmt_location,
pstmt->stmt_len,
PGSS_EXEC,
Expand All @@ -1153,23 +1174,12 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
}
}

/*
* Given an arbitrarily long query string, produce a hash for the purposes of
* identifying the query, without normalizing constants. Used when hashing
* utility statements.
*/
static uint64
pgss_hash_string(const char *str, int len)
{
return DatumGetUInt64(hash_any_extended((const unsigned char *) str,
len, 0));
}

/*
* Store some statistics for a statement.
*
* If queryId is 0 then this is a utility statement and we should compute
* a suitable queryId internally.
* If queryId is 0 then this is a utility statement for which we couldn't
* compute a queryId during parse analysis, and we should compute a suitable
* queryId internally.
*
* If jstate is not NULL then we're trying to create an entry for which
* we have no statistics as yet; we just want to record the normalized
Expand Down Expand Up @@ -1200,52 +1210,18 @@ pgss_store(const char *query, uint64 queryId,
return;

/*
* Confine our attention to the relevant part of the string, if the query
* is a portion of a multi-statement source string.
*
* First apply starting offset, unless it's -1 (unknown).
*/
if (query_location >= 0)
{
Assert(query_location <= strlen(query));
query += query_location;
/* Length of 0 (or -1) means "rest of string" */
if (query_len <= 0)
query_len = strlen(query);
else
Assert(query_len <= strlen(query));
}
else
{
/* If query location is unknown, distrust query_len as well */
query_location = 0;
query_len = strlen(query);
}

/*
* Discard leading and trailing whitespace, too. Use scanner_isspace()
* not libc's isspace(), because we want to match the lexer's behavior.
* Nothing to do if compute_query_id isn't enabled and no other module
* computed a query identifier.
*/
while (query_len > 0 && scanner_isspace(query[0]))
query++, query_location++, query_len--;
while (query_len > 0 && scanner_isspace(query[query_len - 1]))
query_len--;
if (queryId == UINT64CONST(0))
return;

/*
* For utility statements, we just hash the query string to get an ID.
* Confine our attention to the relevant part of the string, if the query
* is a portion of a multi-statement source string, and update query
* location and length if needed.
*/
if (queryId == UINT64CONST(0))
{
queryId = pgss_hash_string(query, query_len);

/*
* If we are unlucky enough to get a hash of zero(invalid), use
* queryID as 2 instead, queryID 1 is already in use for normal
* statements.
*/
if (queryId == UINT64CONST(0))
queryId = UINT64CONST(2);
}
query = CleanQuerytext(query, &query_location, &query_len);

/* Set up key for hashtable search */
key.userid = GetUserId();
Expand Down
29 changes: 21 additions & 8 deletions doc/src/sgml/config.sgml
View file
Expand Up @@ -7004,6 +7004,15 @@ local0.* /var/log/postgresql
session processes</entry>
<entry>no</entry>
</row>
<row>
<entry><literal>%Q</literal></entry>
<entry>query identifier of the current query. Query
identifiers are not computed by default, so this field
will be zero unless <xref linkend="guc-compute-query-id"/>
parameter is enabled or a third-party module that computes
query identifiers is configured.</entry>
<entry>yes</entry>
</row>
<row>
<entry><literal>%%</literal></entry>
<entry>Literal <literal>%</literal></entry>
Expand Down Expand Up @@ -7480,8 +7489,8 @@ COPY postgres_log FROM '/full/path/to/logfile.csv' WITH csv;
<listitem>
<para>
Enables the collection of information on the currently
executing command of each session, along with the time when
that command began execution. This parameter is on by
executing command of each session, along with its identifier and the
time when that command began execution. This parameter is on by
default. Note that even when enabled, this information is not
visible to all users, only to superusers and the user owning
the session being reported on, so it should not represent a
Expand Down Expand Up @@ -7630,12 +7639,16 @@ COPY postgres_log FROM '/full/path/to/logfile.csv' WITH csv;
</term>
<listitem>
<para>
Enables in-core computation of a query identifier. The <xref
linkend="pgstatstatements"/> extension requires a query identifier
to be computed. Note that an external module can alternatively
be used if the in-core query identifier computation method
isn't acceptable. In this case, in-core computation should
remain disabled. The default is <literal>off</literal>.
Enables in-core computation of a query identifier.
Query identifiers can be displayed in the <link
linkend="monitoring-pg-stat-activity-view"><structname>pg_stat_activity</structname></link>
view, using <command>EXPLAIN</command>, or emitted in the log if
configured via the <xref linkend="guc-log-line-prefix"/> parameter.
The <xref linkend="pgstatstatements"/> extension also requires a query
identifier to be computed. Note that an external module can
alternatively be used if the in-core query identifier computation
specification isn't acceptable. In this case, in-core computation
must be disabled. The default is <literal>off</literal>.
</para>
<note>
<para>
Expand Down
16 changes: 16 additions & 0 deletions doc/src/sgml/monitoring.sgml
View file
Expand Up @@ -910,6 +910,22 @@ postgres 27093 0.0 0.0 30096 2752 ? Ss 11:34 0:00 postgres: ser
</para></entry>
</row>

<row>
<entry role="catalog_table_entry"><para role="column_definition">
<structfield>queryid</structfield> <type>bigint</type>
</para>
<para>
Identifier of this backend's most recent query. If
<structfield>state</structfield> is <literal>active</literal> this
field shows the identifier of the currently executing query. In
all other states, it shows the identifier of last query that was
executed. Query identifiers are not computed by default so this
field will be null unless <xref linkend="guc-compute-query-id"/>
parameter is enabled or a third-party module that computes query
identifiers is configured.
</para></entry>
</row>

<row>
<entry role="catalog_table_entry"><para role="column_definition">
<structfield>query</structfield> <type>text</type>
Expand Down
6 changes: 4 additions & 2 deletions doc/src/sgml/ref/explain.sgml
View file
Expand Up @@ -136,8 +136,10 @@ ROLLBACK;
the output column list for each node in the plan tree, schema-qualify
table and function names, always label variables in expressions with
their range table alias, and always print the name of each trigger for
which statistics are displayed. This parameter defaults to
<literal>FALSE</literal>.
which statistics are displayed. The query identifier will also be
displayed if one has been computed, see <xref
linkend="guc-compute-query-id"/> for more details. This parameter
defaults to <literal>FALSE</literal>.
</para>
</listitem>
</varlistentry>
Expand Down
1 change: 1 addition & 0 deletions src/backend/catalog/system_views.sql
View file
Expand Up @@ -833,6 +833,7 @@ CREATE VIEW pg_stat_activity AS
S.state,
S.backend_xid,
s.backend_xmin,
S.queryid,
S.query,
S.backend_type
FROM pg_stat_get_activity(NULL) AS S
Expand Down
18 changes: 18 additions & 0 deletions src/backend/commands/explain.c
View file
Expand Up @@ -24,6 +24,7 @@
#include "nodes/extensible.h"
#include "nodes/makefuncs.h"
#include "nodes/nodeFuncs.h"
#include "parser/analyze.h"
#include "parser/parsetree.h"
#include "rewrite/rewriteHandler.h"
#include "storage/bufmgr.h"
Expand Down Expand Up @@ -165,6 +166,8 @@ ExplainQuery(ParseState *pstate, ExplainStmt *stmt,
{
ExplainState *es = NewExplainState();
TupOutputState *tstate;
JumbleState *jstate = NULL;
Query *query;
List *rewritten;
ListCell *lc;
bool timing_set = false;
Expand Down Expand Up @@ -241,6 +244,13 @@ ExplainQuery(ParseState *pstate, ExplainStmt *stmt,
/* if the summary was not set explicitly, set default value */
es->summary = (summary_set) ? es->summary : es->analyze;

query = castNode(Query, stmt->query);
if (compute_query_id)
jstate = JumbleQuery(query, pstate->p_sourcetext);

if (post_parse_analyze_hook)
(*post_parse_analyze_hook) (pstate, query, jstate);

/*
* Parse analysis was done already, but we still have to run the rule
* rewriter. We do not do AcquireRewriteLocks: we assume the query either
Expand Down Expand Up @@ -600,6 +610,14 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
/* Create textual dump of plan tree */
ExplainPrintPlan(es, queryDesc);

if (es->verbose && plannedstmt->queryId != UINT64CONST(0))
{
char buf[MAXINT8LEN+1];

pg_lltoa(plannedstmt->queryId, buf);
ExplainPropertyText("Query Identifier", buf, es);
}

/* Show buffer usage in planning */
if (bufusage)
{
Expand Down
9 changes: 9 additions & 0 deletions src/backend/executor/execMain.c
View file
Expand Up @@ -58,6 +58,7 @@
#include "storage/lmgr.h"
#include "tcop/utility.h"
#include "utils/acl.h"
#include "utils/backend_status.h"
#include "utils/lsyscache.h"
#include "utils/memutils.h"
#include "utils/partcache.h"
Expand Down Expand Up @@ -128,6 +129,14 @@ static void EvalPlanQualStart(EPQState *epqstate, Plan *planTree);
void
ExecutorStart(QueryDesc *queryDesc, int eflags)
{
/*
* In some cases (e.g. an EXECUTE statement) a query execution will skip
* parse analysis, which means that the queryid won't be reported. Note
* that it's harmless to report the queryid multiple time, as the call will
* be ignored if the top level queryid has already been reported.
*/
pgstat_report_queryid(queryDesc->plannedstmt->queryId, false);

if (ExecutorStart_hook)
(*ExecutorStart_hook) (queryDesc, eflags);
else
Expand Down
5 changes: 3 additions & 2 deletions src/backend/executor/execParallel.c
View file
Expand Up @@ -175,7 +175,7 @@ ExecSerializePlan(Plan *plan, EState *estate)
*/
pstmt = makeNode(PlannedStmt);
pstmt->commandType = CMD_SELECT;
pstmt->queryId = UINT64CONST(0);
pstmt->queryId = pgstat_get_my_queryid();
pstmt->hasReturning = false;
pstmt->hasModifyingCTE = false;
pstmt->canSetTag = true;
Expand Down Expand Up @@ -1421,8 +1421,9 @@ ParallelQueryMain(dsm_segment *seg, shm_toc *toc)
/* Setting debug_query_string for individual workers */
debug_query_string = queryDesc->sourceText;

/* Report workers' query for monitoring purposes */
/* Report workers' query and queryId for monitoring purposes */
pgstat_report_activity(STATE_RUNNING, debug_query_string);
pgstat_report_queryid(queryDesc->plannedstmt->queryId, false);

/* Attach to the dynamic shared memory area. */
area_space = shm_toc_lookup(toc, PARALLEL_KEY_DSA, false);
Expand Down
5 changes: 5 additions & 0 deletions src/backend/parser/analyze.c
View file
Expand Up @@ -45,6 +45,7 @@
#include "parser/parse_type.h"
#include "parser/parsetree.h"
#include "rewrite/rewriteManip.h"
#include "utils/backend_status.h"
#include "utils/builtins.h"
#include "utils/guc.h"
#include "utils/queryjumble.h"
Expand Down Expand Up @@ -130,6 +131,8 @@ parse_analyze(RawStmt *parseTree, const char *sourceText,

free_parsestate(pstate);

pgstat_report_queryid(query->queryId, false);

return query;
}

Expand Down Expand Up @@ -167,6 +170,8 @@ parse_analyze_varparams(RawStmt *parseTree, const char *sourceText,

free_parsestate(pstate);

pgstat_report_queryid(query->queryId, false);

return query;
}

Expand Down

0 comments on commit 4f0b096

Please sign in to comment.