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

diff --git a/doc/src/sgml/ref/explain.sgml b/doc/src/sgml/ref/explain.sgml
index f14a58dfc6353a55e705e9dcfccd52ba8d5ed0a0..6d909f1a9782769670f8166002fcd44ac37503ed 100644 (file)
--- a/doc/src/sgml/ref/explain.sgml
+++ b/doc/src/sgml/ref/explain.sgml
@@ -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>

diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index 7a8d36c8db106abfc390e7a82322daec645cc337..6fd82e9d52f4c57ad2fbdbdf28716b340bbc0e75 100644 (file)
--- 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 116ed67547e96f3cd286bd06e26a5f79c26fa366..1cf0d2b971a370f97d4959dcc417e49f5a03cac9 100644 (file)
--- 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 f84f8ac767ddb8b742eaeb6f59b2256b238066b8..1fab5136d29f6c92605407ffc8a39d16a1a739df 100644 (file)
--- 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 abdd785a770724a89efeca8f77e8ebeea542d229..c80429e7d0333151ccfcb6e5912a90b8c3b214eb 100644 (file)
--- 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';