1
0
mirror of https://github.com/postgres/postgres.git synced 2025-06-30 21:42:05 +03:00

Include planning time in EXPLAIN ANALYZE output.

This doesn't work for prepared queries, but it's not too easy to get
the information in that case and there's some debate as to exactly
what the right thing to measure is, so just do this for now.

Andreas Karlsson, with slight doc changes by me.
This commit is contained in:
Robert Haas
2014-01-29 16:04:19 -05:00
parent 5264d91541
commit 9347baa5bb
5 changed files with 63 additions and 11 deletions

View File

@ -320,13 +320,19 @@ ExplainOneQuery(Query *query, IntoClause *into, ExplainState *es,
(*ExplainOneQuery_hook) (query, into, es, queryString, params);
else
{
PlannedStmt *plan;
PlannedStmt *plan;
instr_time planstart, planduration;
INSTR_TIME_SET_CURRENT(planstart);
/* plan the query */
plan = pg_plan_query(query, 0, params);
INSTR_TIME_SET_CURRENT(planduration);
INSTR_TIME_SUBTRACT(planduration, planstart);
/* run it (if needed) and produce output */
ExplainOnePlan(plan, into, es, queryString, params);
ExplainOnePlan(plan, into, es, queryString, params, &planduration);
}
}
@ -403,7 +409,8 @@ ExplainOneUtility(Node *utilityStmt, IntoClause *into, ExplainState *es,
*/
void
ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
const char *queryString, ParamListInfo params)
const char *queryString, ParamListInfo params,
const instr_time *planduration)
{
DestReceiver *dest;
QueryDesc *queryDesc;
@ -484,6 +491,17 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
/* Create textual dump of plan tree */
ExplainPrintPlan(es, queryDesc);
if (es->costs && planduration)
{
double plantime = INSTR_TIME_GET_DOUBLE(*planduration);
if (es->format == EXPLAIN_FORMAT_TEXT)
appendStringInfo(es->str, "Planning time: %.3f ms\n",
1000.0 * plantime);
else
ExplainPropertyFloat("Planning Time", 1000.0 * plantime, 3, es);
}
/* Print info about runtime of triggers */
if (es->analyze)
ExplainPrintTriggers(es, queryDesc);