From 9347baa5bbc70368f2f01438bbb8116863dac1ec Mon Sep 17 00:00:00 2001 From: Robert Haas Date: Wed, 29 Jan 2014 16:04:19 -0500 Subject: 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. --- src/backend/commands/explain.c | 24 +++++++++++++++++++++--- 1 file changed, 21 insertions(+), 3 deletions(-) (limited to 'src/backend/commands/explain.c') diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index 0dba9283f1..08f3167f10 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -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); -- cgit v1.2.1