diff --git a/doc/src/sgml/ref/explain.sgml b/doc/src/sgml/ref/explain.sgml index f14a58dfc6..6d909f1a97 100644 --- a/doc/src/sgml/ref/explain.sgml +++ b/doc/src/sgml/ref/explain.sgml @@ -41,6 +41,7 @@ EXPLAIN [ ANALYZE ] [ VERBOSE ] statementboolean ] BUFFERS [ boolean ] TIMING [ boolean ] + SUMMARY [ boolean ] FORMAT { TEXT | XML | JSON | YAML } @@ -196,6 +197,21 @@ ROLLBACK; + + SUMMARY + + + Include summary information (eg: totalled timing information) after the + query plan. Summary information is included by default when + ANALYZE is used but otherwise is not included by + default, but can be enabled using this option. Planning time in + EXPLAIN EXECUTE includes the time required to fetch + the plan from the cache and the time required for re-planning, if + necessary. + + + + FORMAT diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index 7a8d36c8db..6fd82e9d52 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -149,6 +149,7 @@ ExplainQuery(ParseState *pstate, ExplainStmt *stmt, const char *queryString, List *rewritten; ListCell *lc; bool timing_set = false; + bool summary_set = false; /* Parse options list. */ foreach(lc, stmt->options) @@ -168,6 +169,11 @@ ExplainQuery(ParseState *pstate, ExplainStmt *stmt, const char *queryString, timing_set = true; es->timing = defGetBoolean(opt); } + else if (strcmp(opt->defname, "summary") == 0) + { + summary_set = true; + es->summary = defGetBoolean(opt); + } else if (strcmp(opt->defname, "format") == 0) { char *p = defGetString(opt); @@ -209,8 +215,8 @@ ExplainQuery(ParseState *pstate, ExplainStmt *stmt, const char *queryString, (errcode(ERRCODE_INVALID_PARAMETER_VALUE), errmsg("EXPLAIN option TIMING requires ANALYZE"))); - /* currently, summary option is not exposed to users; just set it */ - es->summary = es->analyze; + /* if the summary was not set explicitly, set default value */ + es->summary = (summary_set) ? es->summary : es->analyze; /* * Parse analysis was done already, but we still have to run the rule @@ -571,7 +577,13 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es, totaltime += elapsed_time(&starttime); - if (es->summary) + /* + * We only report execution time if we actually ran the query (that is, + * the user specified ANALYZE), and if summary reporting is enabled (the + * user can set SUMMARY OFF to not have the timing information included in + * the output). By default, ANALYZE sets SUMMARY to true. + */ + if (es->summary && es->analyze) { if (es->format == EXPLAIN_FORMAT_TEXT) appendStringInfo(es->str, "Execution time: %.3f ms\n", diff --git a/src/backend/commands/prepare.c b/src/backend/commands/prepare.c index 116ed67547..1cf0d2b971 100644 --- a/src/backend/commands/prepare.c +++ b/src/backend/commands/prepare.c @@ -638,6 +638,10 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es, ListCell *p; ParamListInfo paramLI = NULL; EState *estate = NULL; + instr_time planstart; + instr_time planduration; + + INSTR_TIME_SET_CURRENT(planstart); /* Look it up in the hash table */ entry = FetchPreparedStatement(execstmt->name, true); @@ -666,6 +670,9 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es, /* Replan if needed, and acquire a transient refcount */ cplan = GetCachedPlan(entry->plansource, paramLI, true); + INSTR_TIME_SET_CURRENT(planduration); + INSTR_TIME_SUBTRACT(planduration, planstart); + plan_list = cplan->stmt_list; /* Explain each query */ @@ -674,7 +681,7 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es, PlannedStmt *pstmt = castNode(PlannedStmt, lfirst(p)); if (pstmt->commandType != CMD_UTILITY) - ExplainOnePlan(pstmt, into, es, query_string, paramLI, NULL); + ExplainOnePlan(pstmt, into, es, query_string, paramLI, &planduration); else ExplainOneUtility(pstmt->utilityStmt, into, es, query_string, paramLI); diff --git a/src/test/regress/expected/select.out b/src/test/regress/expected/select.out index f84f8ac767..1fab5136d2 100644 --- a/src/test/regress/expected/select.out +++ b/src/test/regress/expected/select.out @@ -752,6 +752,16 @@ select * from onek2 where unique2 = 11 and stringu1 = 'ATAAAA'; 494 | 11 | 0 | 2 | 4 | 14 | 4 | 94 | 94 | 494 | 494 | 8 | 9 | ATAAAA | LAAAAA | VVVVxx (1 row) +-- actually run the query with an analyze to use the partial index +explain (costs off, analyze on, timing off, summary off) +select * from onek2 where unique2 = 11 and stringu1 = 'ATAAAA'; + QUERY PLAN +----------------------------------------------------------------- + Index Scan using onek2_u2_prtl on onek2 (actual rows=1 loops=1) + Index Cond: (unique2 = 11) + Filter: (stringu1 = 'ATAAAA'::name) +(3 rows) + explain (costs off) select unique2 from onek2 where unique2 = 11 and stringu1 = 'ATAAAA'; QUERY PLAN diff --git a/src/test/regress/sql/select.sql b/src/test/regress/sql/select.sql index abdd785a77..c80429e7d0 100644 --- a/src/test/regress/sql/select.sql +++ b/src/test/regress/sql/select.sql @@ -195,6 +195,9 @@ SELECT * FROM foo ORDER BY f1 DESC NULLS LAST; explain (costs off) select * from onek2 where unique2 = 11 and stringu1 = 'ATAAAA'; select * from onek2 where unique2 = 11 and stringu1 = 'ATAAAA'; +-- actually run the query with an analyze to use the partial index +explain (costs off, analyze on, timing off, summary off) +select * from onek2 where unique2 = 11 and stringu1 = 'ATAAAA'; explain (costs off) select unique2 from onek2 where unique2 = 11 and stringu1 = 'ATAAAA'; select unique2 from onek2 where unique2 = 11 and stringu1 = 'ATAAAA';