Expose explain's SUMMARY option

This exposes the existing explain summary option to users to allow them
to choose if they wish to have the planning time and totalled run time
included in the EXPLAIN result.  The existing default behavior is
retained if SUMMARY is not specified- running explain without analyze
will not print the summary lines (just the planning time, currently)
while running explain with analyze will include the summary lines (both
the planning time and the totalled execution time).

Users who wish to see the summary information for plain explain can now
use: EXPLAIN (SUMMARY ON) query;  Users who do not want to have the
summary printed for an analyze run can use:
EXPLAIN (ANALYZE ON, SUMMARY OFF) query;

With this, we can now also have EXPLAIN ANALYZE queries included in our
regression tests by using:
EXPLAIN (ANALYZE ON, TIMING OFF, SUMMARY off) query;

I went ahead and added an example of this, which will hopefully not make
the buildfarm complain.

Author: Ashutosh Bapat
Discussion: https://postgr.es/m/CAFjFpReE5z2h98U2Vuia8hcEkpRRwrauRjHmyE44hNv8-xk+XA@mail.gmail.com
This commit is contained in:
Stephen Frost 2017-03-08 15:14:03 -05:00
parent 15d03e5976
commit f9b1a0dd40
5 changed files with 52 additions and 4 deletions

View File

@ -41,6 +41,7 @@ EXPLAIN [ ANALYZE ] [ VERBOSE ] <replaceable class="parameter">statement</replac
COSTS [ <replaceable class="parameter">boolean</replaceable> ]
BUFFERS [ <replaceable class="parameter">boolean</replaceable> ]
TIMING [ <replaceable class="parameter">boolean</replaceable> ]
SUMMARY [ <replaceable class="parameter">boolean</replaceable> ]
FORMAT { TEXT | XML | JSON | YAML }
</synopsis>
</refsynopsisdiv>
@ -196,6 +197,21 @@ ROLLBACK;
</listitem>
</varlistentry>
<varlistentry>
<term><literal>SUMMARY</literal></term>
<listitem>
<para>
Include summary information (eg: totalled timing information) after the
query plan. Summary information is included by default when
<literal>ANALYZE</literal> is used but otherwise is not included by
default, but can be enabled using this option. Planning time in
<command>EXPLAIN EXECUTE</command> includes the time required to fetch
the plan from the cache and the time required for re-planning, if
necessary.
</para>
</listitem>
</varlistentry>
<varlistentry>
<term><literal>FORMAT</literal></term>
<listitem>

View File

@ -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",

View File

@ -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);

View File

@ -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

View File

@ -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';