Improve handling of utility statements containing plannable statements.

When tracking nested statements, contrib/pg_stat_statements formerly
double-counted the execution costs of utility statements that directly
contain an executable statement, such as EXPLAIN and DECLARE CURSOR.
This was not obvious since the ProcessUtility and Executor hooks
would each add their measured costs to the same stats table entry.
However, with the new implementation that hashes utility and plannable
statements differently, this showed up as seemingly-duplicate stats
entries.  Fix that by disabling the Executor hooks when the query has a
queryId of zero, which was the case already for such statements but is now
more clearly specified in the code.  (The zero queryId was causing problems
anyway because all such statements would add to a single bogus entry.)

The PREPARE/EXECUTE case still results in counting the same execution
in two different stats table entries, but it should be much less surprising
to users that there are two entries in such cases.

In passing, include a CommonTableExpr's ctename in the query hash.
I had left it out originally on the grounds that we wanted to omit all
inessential aliases, but since RTE_CTE RTEs are hashing their referenced
names, we'd better hash the CTE names too to make sure we don't hash
semantically different queries the same.
This commit is contained in:
Tom Lane 2012-03-29 15:32:50 -04:00
parent 2005b77b8f
commit e0e4ebe384

View File

@ -602,9 +602,19 @@ pgss_post_parse_analyze(ParseState *pstate, Query *query)
if (!pgss || !pgss_hash)
return;
/* We do nothing with utility statements at this stage */
/*
* 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.
*/
if (query->utilityStmt)
{
query->queryId = 0;
return;
}
/* Set up workspace for query jumbling */
jstate.jumble = (unsigned char *) palloc(JUMBLE_SIZE);
@ -618,6 +628,13 @@ pgss_post_parse_analyze(ParseState *pstate, Query *query)
JumbleQuery(&jstate, query);
query->queryId = hash_any(jstate.jumble, jstate.jumble_len);
/*
* If we are unlucky enough to get a hash of zero, use 1 instead, to
* prevent confusion with the utility-statement case.
*/
if (query->queryId == 0)
query->queryId = 1;
/*
* If we were able to identify any ignorable constants, we immediately
* create a hash table entry for the query, so that we can record the
@ -649,7 +666,12 @@ pgss_ExecutorStart(QueryDesc *queryDesc, int eflags)
else
standard_ExecutorStart(queryDesc, eflags);
if (pgss_enabled())
/*
* If query has queryId zero, don't track it. This prevents double
* counting of optimizable statements that are directly contained in
* utility statements.
*/
if (pgss_enabled() && queryDesc->plannedstmt->queryId != 0)
{
/*
* Set up to track total elapsed time in ExecutorRun. Make sure the
@ -719,13 +741,10 @@ pgss_ExecutorFinish(QueryDesc *queryDesc)
static void
pgss_ExecutorEnd(QueryDesc *queryDesc)
{
if (queryDesc->totaltime && pgss_enabled())
uint32 queryId = queryDesc->plannedstmt->queryId;
if (queryId != 0 && queryDesc->totaltime && pgss_enabled())
{
uint32 queryId;
/* Query's ID should have been filled in by post-analyze hook */
queryId = queryDesc->plannedstmt->queryId;
/*
* Make sure stats accumulation is done. (Note: it's okay if several
* levels of hook all do this.)
@ -1794,6 +1813,8 @@ JumbleExpr(pgssJumbleState * jstate, Node *node)
{
CommonTableExpr *cte = (CommonTableExpr *) node;
/* we store the string name because RTE_CTE RTEs need it */
APP_JUMB_STRING(cte->ctename);
JumbleQuery(jstate, (Query *) cte->ctequery);
}
break;