diff options
author | Robert Haas <rhaas@postgresql.org> | 2014-01-29 16:04:19 -0500 |
---|---|---|
committer | Robert Haas <rhaas@postgresql.org> | 2014-01-29 16:09:15 -0500 |
commit | 9347baa5bbc70368f2f01438bbb8116863dac1ec (patch) | |
tree | d39dd1fe9188f59ebd7b17810afb30c20e6c8b6d /src/backend/commands/explain.c | |
parent | 5264d9154178d3aeaa0359b43a450298a7ce7281 (diff) | |
download | postgresql-9347baa5bbc70368f2f01438bbb8116863dac1ec.tar.gz postgresql-9347baa5bbc70368f2f01438bbb8116863dac1ec.zip |
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.
Diffstat (limited to 'src/backend/commands/explain.c')
-rw-r--r-- | src/backend/commands/explain.c | 24 |
1 files changed, 21 insertions, 3 deletions
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index 0dba9283f1c..08f3167f10d 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); |