EXPLAIN output now comes out as a query result, not a NOTICE message.
authorTom Lane <tgl@sss.pgh.pa.us>
Sun, 24 Mar 2002 04:31:09 +0000 (04:31 +0000)
committerTom Lane <tgl@sss.pgh.pa.us>
Sun, 24 Mar 2002 04:31:09 +0000 (04:31 +0000)
Also, fix debug logging of parse/plan trees so that the messages actually
go through elog(), not directly to stdout.

14 files changed:
doc/src/sgml/perform.sgml
doc/src/sgml/ref/explain.sgml
doc/src/sgml/release.sgml
doc/src/sgml/runtime.sgml
src/backend/commands/explain.c
src/backend/nodes/print.c
src/backend/tcop/postgres.c
src/backend/tcop/utility.c
src/backend/utils/misc/guc.c
src/backend/utils/misc/postgresql.conf.sample
src/bin/psql/tab-complete.c
src/include/commands/explain.h
src/include/nodes/print.h
src/include/utils/guc.h

index 94f49921f7e039988daab237caee836911a4003f..6b13d6ae3afc6d94fd3fd8bd9d838aee66d9d3f6 100644 (file)
@@ -1,5 +1,5 @@
 <!--
-$Header: /cvsroot/pgsql/doc/src/sgml/perform.sgml,v 1.18 2002/03/22 19:20:17 petere Exp $
+$Header: /cvsroot/pgsql/doc/src/sgml/perform.sgml,v 1.19 2002/03/24 04:31:05 tgl Exp $
 -->
 
  <chapter id="performance-tips">
@@ -47,8 +47,8 @@ $Header: /cvsroot/pgsql/doc/src/sgml/perform.sgml,v 1.18 2002/03/22 19:20:17 pet
 
      <listitem>
       <para>
-       Estimated number of rows output by this plan node (again, without
-       regard for any LIMIT).
+       Estimated number of rows output by this plan node (again, only if
+       executed to completion).
       </para>
      </listitem>
 
@@ -92,13 +92,13 @@ $Header: /cvsroot/pgsql/doc/src/sgml/perform.sgml,v 1.18 2002/03/22 19:20:17 pet
 
    <para>
     Here are some examples (using the regress test database after a
-    vacuum analyze, and 7.2 development sources):
+    vacuum analyze, and 7.3 development sources):
 
     <programlisting>
 regression=# EXPLAIN SELECT * FROM tenk1;
-INFO:  QUERY PLAN:
-
-Seq Scan on tenk1  (cost=0.00..333.00 rows=10000 width=148)
+                         QUERY PLAN
+-------------------------------------------------------------
+ Seq Scan on tenk1  (cost=0.00..333.00 rows=10000 width=148)
     </programlisting>
    </para>
 
@@ -120,9 +120,10 @@ SELECT * FROM pg_class WHERE relname = 'tenk1';
 
     <programlisting>
 regression=# EXPLAIN SELECT * FROM tenk1 WHERE unique1 &lt; 1000;
-INFO:  QUERY PLAN:
-
-Seq Scan on tenk1  (cost=0.00..358.00 rows=1007 width=148)
+                         QUERY PLAN
+------------------------------------------------------------
+ Seq Scan on tenk1  (cost=0.00..358.00 rows=1033 width=148)
+   Filter: (unique1 &lt; 1000)
     </programlisting>
 
     The estimate of output rows has gone down because of the WHERE clause.
@@ -145,9 +146,10 @@ Seq Scan on tenk1  (cost=0.00..358.00 rows=1007 width=148)
 
     <programlisting>
 regression=# EXPLAIN SELECT * FROM tenk1 WHERE unique1 &lt; 50;
-INFO:  QUERY PLAN:
-
-Index Scan using tenk1_unique1 on tenk1  (cost=0.00..181.09 rows=49 width=148)
+                                   QUERY PLAN
+-------------------------------------------------------------------------------
+ Index Scan using tenk1_unique1 on tenk1  (cost=0.00..179.33 rows=49 width=148)
+   Index Filter: (unique1 &lt; 50)
     </programlisting>
 
     and you will see that if we make the WHERE condition selective
@@ -164,13 +166,20 @@ Index Scan using tenk1_unique1 on tenk1  (cost=0.00..181.09 rows=49 width=148)
     <programlisting>
 regression=# EXPLAIN SELECT * FROM tenk1 WHERE unique1 &lt; 50 AND
 regression-# stringu1 = 'xxx';
-INFO:  QUERY PLAN:
-
-Index Scan using tenk1_unique1 on tenk1  (cost=0.00..181.22 rows=1 width=148)
+                                  QUERY PLAN
+-------------------------------------------------------------------------------
+ Index Scan using tenk1_unique1 on tenk1  (cost=0.00..179.45 rows=1 width=148)
+   Index Filter: (unique1 &lt; 50)
+   Filter: (stringu1 = 'xxx'::name)
     </programlisting>
 
-    The added clause <literal>stringu1 = 'xxx'</literal> reduces the output-rows estimate,
-    but not the cost because we still have to visit the same set of tuples.
+    The added clause <literal>stringu1 = 'xxx'</literal> reduces the
+    output-rows estimate, but not the cost because we still have to visit the
+    same set of tuples.  Notice that the <literal>stringu1</> clause
+    cannot be applied as an index condition (since this index is only on
+    the <literal>unique1</> column).  Instead it is applied as a filter on
+    the rows retrieved by the index.  Thus the cost has actually gone up
+    a little bit to reflect this extra checking.
    </para>
 
    <para>
@@ -179,13 +188,15 @@ Index Scan using tenk1_unique1 on tenk1  (cost=0.00..181.22 rows=1 width=148)
     <programlisting>
 regression=# EXPLAIN SELECT * FROM tenk1 t1, tenk2 t2 WHERE t1.unique1 &lt; 50
 regression-# AND t1.unique2 = t2.unique2;
-INFO:  QUERY PLAN:
-
-Nested Loop  (cost=0.00..330.41 rows=49 width=296)
-  -&gt;  Index Scan using tenk1_unique1 on tenk1 t1
-               (cost=0.00..181.09 rows=49 width=148)
-  -&gt;  Index Scan using tenk2_unique2 on tenk2 t2
-               (cost=0.00..3.01 rows=1 width=148)
+                               QUERY PLAN
+----------------------------------------------------------------------------
+ Nested Loop  (cost=0.00..327.02 rows=49 width=296)
+   -&gt;  Index Scan using tenk1_unique1 on tenk1 t1
+                                      (cost=0.00..179.33 rows=49 width=148)
+         Index Filter: (unique1 &lt; 50)
+   -&gt;  Index Scan using tenk2_unique2 on tenk2 t2
+                                      (cost=0.00..3.01 rows=1 width=148)
+         Index Filter: ("outer".unique2 = t2.unique2)
     </programlisting>
    </para>
 
@@ -227,14 +238,15 @@ regression=# set enable_nestloop = off;
 SET VARIABLE
 regression=# EXPLAIN SELECT * FROM tenk1 t1, tenk2 t2 WHERE t1.unique1 &lt; 50
 regression-# AND t1.unique2 = t2.unique2;
-INFO:  QUERY PLAN:
-
-Hash Join  (cost=181.22..564.83 rows=49 width=296)
-  -&gt;  Seq Scan on tenk2 t2
-               (cost=0.00..333.00 rows=10000 width=148)
-  -&gt;  Hash  (cost=181.09..181.09 rows=49 width=148)
-        -&gt;  Index Scan using tenk1_unique1 on tenk1 t1
-               (cost=0.00..181.09 rows=49 width=148)
+                               QUERY PLAN
+--------------------------------------------------------------------------
+ Hash Join  (cost=179.45..563.06 rows=49 width=296)
+   Hash Cond: ("outer".unique2 = "inner".unique2)
+   -&gt;  Seq Scan on tenk2 t2  (cost=0.00..333.00 rows=10000 width=148)
+   -&gt;  Hash  (cost=179.33..179.33 rows=49 width=148)
+         -&gt;  Index Scan using tenk1_unique1 on tenk1 t1
+                                    (cost=0.00..179.33 rows=49 width=148)
+               Index Filter: (unique1 &lt; 50)
     </programlisting>
 
     This plan proposes to extract the 50 interesting rows of <classname>tenk1</classname>
@@ -245,7 +257,7 @@ Hash Join  (cost=181.22..564.83 rows=49 width=296)
     cost for the hash join, since we won't get any tuples out until we can
     start reading <classname>tenk2</classname>.  The total time estimate for the join also
     includes a hefty charge for CPU time to probe the hash table
-    10000 times.  Note, however, that we are NOT charging 10000 times 181.09;
+    10000 times.  Note, however, that we are NOT charging 10000 times 179.33;
     the hash table setup is only done once in this plan type.
    </para>
 
@@ -260,14 +272,19 @@ Hash Join  (cost=181.22..564.83 rows=49 width=296)
 regression=# EXPLAIN ANALYZE
 regression-# SELECT * FROM tenk1 t1, tenk2 t2
 regression-# WHERE t1.unique1 &lt; 50 AND t1.unique2 = t2.unique2;
-INFO:  QUERY PLAN:
-
-Nested Loop  (cost=0.00..330.41 rows=49 width=296) (actual time=1.31..28.90 rows=50 loops=1)
-  -&gt;  Index Scan using tenk1_unique1 on tenk1 t1
-               (cost=0.00..181.09 rows=49 width=148) (actual time=0.69..8.84 rows=50 loops=1)
-  -&gt;  Index Scan using tenk2_unique2 on tenk2 t2
-               (cost=0.00..3.01 rows=1 width=148) (actual time=0.28..0.31 rows=1 loops=50)
-Total runtime: 30.67 msec
+                                   QUERY PLAN
+-------------------------------------------------------------------------------
+ Nested Loop  (cost=0.00..327.02 rows=49 width=296)
+                                 (actual time=1.18..29.82 rows=50 loops=1)
+   -&gt;  Index Scan using tenk1_unique1 on tenk1 t1
+                  (cost=0.00..179.33 rows=49 width=148)
+                                 (actual time=0.63..8.91 rows=50 loops=1)
+         Index Filter: (unique1 &lt; 50)
+   -&gt;  Index Scan using tenk2_unique2 on tenk2 t2
+                  (cost=0.00..3.01 rows=1 width=148)
+                                 (actual time=0.29..0.32 rows=1 loops=50)
+         Index Filter: ("outer".unique2 = t2.unique2)
+ Total runtime: 31.60 msec
 </screen>
 
     Note that the <quote>actual time</quote> values are in milliseconds of
@@ -296,7 +313,7 @@ Total runtime: 30.67 msec
     little larger than the total time reported for the top-level plan node.
     For INSERT, UPDATE, and DELETE queries, the total run time may be
     considerably larger, because it includes the time spent processing the
-    output tuples.  In these queries, the time for the top plan node
+    result tuples.  In these queries, the time for the top plan node
     essentially is the time spent computing the new tuples and/or locating
     the old ones, but it doesn't include the time spent making the changes.
    </para>
index 33c9add4531c3aec197cddf029631e4393300dbf..28172aac5b7bad276fa97c91cfdce834ef3fd017 100644 (file)
@@ -1,5 +1,5 @@
 <!--
-$Header: /cvsroot/pgsql/doc/src/sgml/ref/explain.sgml,v 1.16 2002/03/22 19:20:40 petere Exp $
+$Header: /cvsroot/pgsql/doc/src/sgml/ref/explain.sgml,v 1.17 2002/03/24 04:31:07 tgl Exp $
 PostgreSQL documentation
 -->
 
@@ -49,7 +49,7 @@ EXPLAIN [ ANALYZE ] [ VERBOSE ] <replaceable class="PARAMETER">query</replaceabl
       <term>VERBOSE</term>
       <listitem>
        <para>
-   Flag to show detailed query plan.
+   Flag to show detailed query plan dump.
        </para>
       </listitem>
      </varlistentry>
@@ -76,28 +76,24 @@ EXPLAIN [ ANALYZE ] [ VERBOSE ] <replaceable class="PARAMETER">query</replaceabl
 
     <variablelist>
      <varlistentry>
-      <term><computeroutput>
-INFO:  QUERY PLAN:
-<replaceable>plan</replaceable>
-      </computeroutput></term>
+      <term>Query plan</term>
       <listitem>
        <para>
-   Explicit query plan from the <productname>PostgreSQL</productname> backend.
-       </para>
-      </listitem>
-     </varlistentry>
-     <varlistentry>
-      <term><computeroutput>
-EXPLAIN
-       </computeroutput></term>
-      <listitem>
-       <para>
-   Flag sent after query plan is shown.
+   Explicit query plan from the <productname>PostgreSQL</productname>
+   planner.
        </para>
       </listitem>
      </varlistentry>
     </variablelist>
    </para>
+
+   <note>
+    <para>
+     Prior to <application>PostgreSQL</application> 7.3, the query plan
+     was emitted in the form of a NOTICE message.  Now it appears as a
+     query result (formatted like a table with a single text column).
+    </para>
+   </note>
   </refsect2>
  </refsynopsisdiv>
 
@@ -141,13 +137,6 @@ EXPLAIN
    are close to reality.
   </para>
 
-  <para>
-   The VERBOSE option emits the full internal representation of the plan tree,
-   rather than just a summary (and sends it to the postmaster log file, too).
-   Usually this option is only useful for debugging
-   <application>PostgreSQL</application>. 
-  </para>
-
   <caution>
    <para>
     Keep in mind that the query is actually executed when ANALYZE is used.
@@ -165,6 +154,15 @@ ROLLBACK;
    </para>
   </caution>
 
+  <para>
+   The VERBOSE option emits the full internal representation of the plan tree,
+   rather than just a summary.
+   Usually this option is only useful for debugging
+   <application>PostgreSQL</application>.   The VERBOSE dump is either
+   pretty-printed or not, depending on the setting of the
+   <option>EXPLAIN_PRETTY_PRINT</option> configuration parameter.
+  </para>
+
   <refsect2 id="R2-SQL-EXPLAIN-3">
    <refsect2info>
     <date>1998-04-15</date>
@@ -188,50 +186,48 @@ ROLLBACK;
 
   <para>
    To show a query plan for a simple query on a table with a single
-   <type>int4</type> column and 128 rows:
+   <type>int4</type> column and 10000 rows:
 
    <programlisting>
 EXPLAIN SELECT * FROM foo;
     <computeroutput>
-INFO:  QUERY PLAN:
-
-Seq Scan on foo  (cost=0.00..2.28 rows=128 width=4)
-
-EXPLAIN
+                       QUERY PLAN
+---------------------------------------------------------
+ Seq Scan on foo  (cost=0.00..155.00 rows=10000 width=4)
+(1 row)
     </computeroutput>
    </programlisting>
   </para>
 
   <para>
-   For the same table with an index to support an
-   <firstterm>equijoin</firstterm> condition on the query,
+   If there is an index and we use a query with an indexable WHERE condition,
    <command>EXPLAIN</command> will show a different plan:
 
    <programlisting>
 EXPLAIN SELECT * FROM foo WHERE i = 4;
     <computeroutput>
-INFO:  QUERY PLAN:
-
-Index Scan using fi on foo  (cost=0.00..0.42 rows=1 width=4)
-
-EXPLAIN
+                         QUERY PLAN
+--------------------------------------------------------------
+ Index Scan using fi on foo  (cost=0.00..5.98 rows=1 width=4)
+   Index Filter: (i = 4)
+(2 rows)
     </computeroutput>
    </programlisting>
   </para>
 
   <para>
-   And finally, for the same table with an index to support an
-   <firstterm>equijoin</firstterm> condition on the query,
-   <command>EXPLAIN</command> will show the following for a query
+   And here is an example of a query plan for a query
    using an aggregate function:
 
    <programlisting>
-EXPLAIN SELECT sum(i) FROM foo WHERE i = 4;
+EXPLAIN SELECT sum(i) FROM foo WHERE i < 4;
     <computeroutput>
-INFO:  QUERY PLAN:
-
-Aggregate  (cost=0.42..0.42 rows=1 width=4)
-  ->  Index Scan using fi on foo  (cost=0.00..0.42 rows=1 width=4)
+                             QUERY PLAN
+---------------------------------------------------------------------
+ Aggregate  (cost=23.93..23.93 rows=1 width=4)
+   ->  Index Scan using fi on foo  (cost=0.00..23.92 rows=6 width=4)
+         Index Filter: (i < 10)
+(3 rows)
     </computeroutput>
    </programlisting>
   </para>
index 4900f1b7482be0edc65573fc4b0ea509327d227d..f0af67599dbad760e162aa8b98d8930c8aa6ecce 100644 (file)
@@ -1,5 +1,5 @@
 <!--
-$Header: /cvsroot/pgsql/doc/src/sgml/release.sgml,v 1.125 2002/03/22 19:20:22 petere Exp $
+$Header: /cvsroot/pgsql/doc/src/sgml/release.sgml,v 1.126 2002/03/24 04:31:05 tgl Exp $
 -->
 
 <appendix id="release">
@@ -24,6 +24,7 @@ CDATA means the content is "SGML-free", so you can write without
 worries about funny characters.
 -->
 <literallayout><![CDATA[
+EXPLAIN output comes out as a query result, not a NOTICE message
 DOMAINs (types that are constrained versions of base types)
 Access privileges on functions
 Access privileges on procedural languages
index ddeac7ce1da219f7e0407494440758633ed691d9..9c118d2be250e0ff9db2d80d6ed14a0ec36b9c14 100644 (file)
@@ -1,5 +1,5 @@
 <!--
-$Header: /cvsroot/pgsql/doc/src/sgml/runtime.sgml,v 1.109 2002/03/22 19:20:28 petere Exp $
+$Header: /cvsroot/pgsql/doc/src/sgml/runtime.sgml,v 1.110 2002/03/24 04:31:06 tgl Exp $
 -->
 
 <Chapter Id="runtime">
@@ -870,6 +870,16 @@ env PGOPTIONS='-c geqo=off' psql
       </listitem>
      </varlistentry>
 
+     <varlistentry>
+      <term><varname>EXPLAIN_PRETTY_PRINT</varname> (<type>boolean</type>)</term>
+      <listitem>
+       <para>
+        Determines whether <command>EXPLAIN VERBOSE</> uses the indented
+   or non-indented format for displaying detailed querytree dumps.
+       </para>
+      </listitem>
+     </varlistentry>
+
      <varlistentry>
       <term><varname>HOSTNAME_LOOKUP</varname> (<type>boolean</type>)</term>
       <listitem>
index 19df98531c55e77be15868f63a2152b36b3c41cb..25b9f13fe201c88ea7b7db3a9131912d43962f14 100644 (file)
@@ -5,12 +5,14 @@
  * Portions Copyright (c) 1996-2001, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994-5, Regents of the University of California
  *
- * $Header: /cvsroot/pgsql/src/backend/commands/explain.c,v 1.73 2002/03/22 02:56:31 tgl Exp $
+ * $Header: /cvsroot/pgsql/src/backend/commands/explain.c,v 1.74 2002/03/24 04:31:07 tgl Exp $
  *
  */
 
 #include "postgres.h"
 
+#include "access/heapam.h"
+#include "catalog/pg_type.h"
 #include "commands/explain.h"
 #include "executor/instrument.h"
 #include "lib/stringinfo.h"
@@ -22,6 +24,7 @@
 #include "rewrite/rewriteHandler.h"
 #include "tcop/pquery.h"
 #include "utils/builtins.h"
+#include "utils/guc.h"
 #include "utils/lsyscache.h"
 #include "utils/relcache.h"
 
@@ -35,9 +38,15 @@ typedef struct ExplainState
    List       *rtable;         /* range table */
 } ExplainState;
 
+typedef struct TextOutputState
+{
+   TupleDesc   tupdesc;
+   DestReceiver *destfunc;
+} TextOutputState;
+
 static StringInfo Explain_PlanToString(Plan *plan, ExplainState *es);
-static void ExplainOneQuery(Query *query, bool verbose, bool analyze,
-                           CommandDest dest);
+static void ExplainOneQuery(Query *query, ExplainStmt *stmt,
+                           TextOutputState *tstate);
 static void explain_outNode(StringInfo str, Plan *plan, Plan *outer_plan,
                            int indent, ExplainState *es);
 static void show_scan_qual(List *qual, bool is_or_qual, const char *qlabel,
@@ -48,6 +57,10 @@ static void show_upper_qual(List *qual, const char *qlabel,
                            const char *inner_name, int inner_varno, Plan *inner_plan,
                            StringInfo str, int indent, ExplainState *es);
 static Node *make_ors_ands_explicit(List *orclauses);
+static TextOutputState *begin_text_output(CommandDest dest, char *title);
+static void do_text_output(TextOutputState *tstate, char *aline);
+static void do_text_output_multiline(TextOutputState *tstate, char *text);
+static void end_text_output(TextOutputState *tstate);
 
 /* Convert a null string pointer into "<>" */
 #define stringStringInfo(s) (((s) == NULL) ? "<>" : (s))
@@ -55,42 +68,47 @@ static Node *make_ors_ands_explicit(List *orclauses);
 
 /*
  * ExplainQuery -
- *   print out the execution plan for a given query
+ *   execute an EXPLAIN command
  */
 void
-ExplainQuery(Query *query, bool verbose, bool analyze, CommandDest dest)
+ExplainQuery(ExplainStmt *stmt, CommandDest dest)
 {
+   Query      *query = stmt->query;
+   TextOutputState *tstate;
    List       *rewritten;
    List       *l;
 
-   /* rewriter and planner may not work in aborted state? */
-   if (IsAbortedTransactionBlockState())
-   {
-       elog(WARNING, "(transaction aborted): %s",
-            "queries ignored until END");
-       return;
-   }
+   tstate = begin_text_output(dest, "QUERY PLAN");
 
-   /* rewriter will not cope with utility statements */
    if (query->commandType == CMD_UTILITY)
    {
-       elog(NOTICE, "Utility statements have no plan structure");
-       return;
+       /* rewriter will not cope with utility statements */
+       do_text_output(tstate, "Utility statements have no plan structure");
    }
-
-   /* Rewrite through rule system */
-   rewritten = QueryRewrite(query);
-
-   /* In the case of an INSTEAD NOTHING, tell at least that */
-   if (rewritten == NIL)
+   else
    {
-       elog(NOTICE, "Query rewrites to nothing");
-       return;
+       /* Rewrite through rule system */
+       rewritten = QueryRewrite(query);
+
+       if (rewritten == NIL)
+       {
+           /* In the case of an INSTEAD NOTHING, tell at least that */
+           do_text_output(tstate, "Query rewrites to nothing");
+       }
+       else
+       {
+           /* Explain every plan */
+           foreach(l, rewritten)
+           {
+               ExplainOneQuery(lfirst(l), stmt, tstate);
+               /* put a blank line between plans */
+               if (lnext(l) != NIL)
+                   do_text_output(tstate, "");
+           }
+       }
    }
 
-   /* Explain every plan */
-   foreach(l, rewritten)
-       ExplainOneQuery(lfirst(l), verbose, analyze, dest);
+   end_text_output(tstate);
 }
 
 /*
@@ -98,7 +116,7 @@ ExplainQuery(Query *query, bool verbose, bool analyze, CommandDest dest)
  *   print out the execution plan for one query
  */
 static void
-ExplainOneQuery(Query *query, bool verbose, bool analyze, CommandDest dest)
+ExplainOneQuery(Query *query, ExplainStmt *stmt, TextOutputState *tstate)
 {
    Plan       *plan;
    ExplainState *es;
@@ -108,9 +126,9 @@ ExplainOneQuery(Query *query, bool verbose, bool analyze, CommandDest dest)
    if (query->commandType == CMD_UTILITY)
    {
        if (query->utilityStmt && IsA(query->utilityStmt, NotifyStmt))
-           elog(INFO, "QUERY PLAN:\n\nNOTIFY\n");
+           do_text_output(tstate, "NOTIFY");
        else
-           elog(INFO, "QUERY PLAN:\n\nUTILITY\n");
+           do_text_output(tstate, "UTILITY");
        return;
    }
 
@@ -122,7 +140,7 @@ ExplainOneQuery(Query *query, bool verbose, bool analyze, CommandDest dest)
        return;
 
    /* Execute the plan for statistics if asked for */
-   if (analyze)
+   if (stmt->analyze)
    {
        struct timeval starttime;
        struct timeval endtime;
@@ -154,7 +172,7 @@ ExplainOneQuery(Query *query, bool verbose, bool analyze, CommandDest dest)
 
    es->printCost = true;       /* default */
 
-   if (verbose)
+   if (stmt->verbose)
        es->printNodes = true;
 
    es->rtable = query->rtable;
@@ -162,12 +180,20 @@ ExplainOneQuery(Query *query, bool verbose, bool analyze, CommandDest dest)
    if (es->printNodes)
    {
        char       *s;
+       char       *f;
 
        s = nodeToString(plan);
        if (s)
        {
-           elog(INFO, "QUERY DUMP:\n\n%s", s);
+           if (Explain_pretty_print)
+               f = pretty_format_node_dump(s);
+           else
+               f = format_node_dump(s);
            pfree(s);
+           do_text_output_multiline(tstate, f);
+           pfree(f);
+           if (es->printCost)
+               do_text_output(tstate, ""); /* separator line */
        }
    }
 
@@ -176,17 +202,14 @@ ExplainOneQuery(Query *query, bool verbose, bool analyze, CommandDest dest)
        StringInfo  str;
 
        str = Explain_PlanToString(plan, es);
-       if (analyze)
+       if (stmt->analyze)
            appendStringInfo(str, "Total runtime: %.2f msec\n",
                             1000.0 * totaltime);
-       elog(INFO, "QUERY PLAN:\n\n%s", str->data);
+       do_text_output_multiline(tstate, str->data);
        pfree(str->data);
        pfree(str);
    }
 
-   if (es->printNodes)
-       pprint(plan);           /* display in postmaster log file */
-
    pfree(es);
 }
 
@@ -709,3 +732,78 @@ make_ors_ands_explicit(List *orclauses)
        return (Node *) make_orclause(args);
    }
 }
+
+
+/*
+ * Functions for sending text to the frontend (or other specified destination)
+ * as though it is a SELECT result.
+ *
+ * We tell the frontend that the table structure is a single TEXT column.
+ */
+
+static TextOutputState *
+begin_text_output(CommandDest dest, char *title)
+{
+   TextOutputState *tstate;
+   TupleDesc   tupdesc;
+
+   tstate = (TextOutputState *) palloc(sizeof(TextOutputState));
+
+   /* need a tuple descriptor representing a single TEXT column */
+   tupdesc = CreateTemplateTupleDesc(1);
+   TupleDescInitEntry(tupdesc, (AttrNumber) 1, title,
+                      TEXTOID, -1, 0, false);
+
+   tstate->tupdesc = tupdesc;
+   tstate->destfunc = DestToFunction(dest);
+
+   (*tstate->destfunc->setup) (tstate->destfunc, (int) CMD_SELECT,
+                               NULL, tupdesc);
+
+   return tstate;
+}
+
+/* write a single line of text */
+static void
+do_text_output(TextOutputState *tstate, char *aline)
+{
+   HeapTuple   tuple;
+   Datum       values[1];
+   char        nulls[1];
+
+   /* form a tuple and send it to the receiver */
+   values[0] = DirectFunctionCall1(textin, CStringGetDatum(aline));
+   nulls[0] = ' ';
+   tuple = heap_formtuple(tstate->tupdesc, values, nulls);
+   (*tstate->destfunc->receiveTuple) (tuple,
+                                      tstate->tupdesc,
+                                      tstate->destfunc);
+   pfree(DatumGetPointer(values[0]));
+   heap_freetuple(tuple);
+}
+
+/* write a chunk of text, breaking at newline characters */
+/* NB: scribbles on its input! */
+static void
+do_text_output_multiline(TextOutputState *tstate, char *text)
+{
+   while (*text)
+   {
+       char   *eol;
+
+       eol = strchr(text, '\n');
+       if (eol)
+           *eol++ = '\0';
+       else
+           eol = text + strlen(text);
+       do_text_output(tstate, text);
+       text = eol;
+   }
+}
+
+static void
+end_text_output(TextOutputState *tstate)
+{
+   (*tstate->destfunc->cleanup) (tstate->destfunc);
+   pfree(tstate);
+}
index 7254d46c17843efd7e2125fb02ace76438948304..a1fd2b9387081db754e060e2f13b4d9f57e6f0ef 100644 (file)
@@ -8,7 +8,7 @@
  *
  *
  * IDENTIFICATION
- *   $Header: /cvsroot/pgsql/src/backend/nodes/print.c,v 1.53 2002/03/22 02:56:32 tgl Exp $
+ *   $Header: /cvsroot/pgsql/src/backend/nodes/print.c,v 1.54 2002/03/24 04:31:07 tgl Exp $
  *
  * HISTORY
  *   AUTHOR            DATE            MAJOR EVENT
@@ -21,6 +21,7 @@
 
 #include "access/printtup.h"
 #include "catalog/pg_type.h"
+#include "lib/stringinfo.h"
 #include "nodes/print.h"
 #include "optimizer/clauses.h"
 #include "parser/parsetree.h"
@@ -37,31 +38,129 @@ void
 print(void *obj)
 {
    char       *s;
+   char       *f;
 
    s = nodeToString(obj);
-   printf("%s\n", s);
-   fflush(stdout);
+   f = format_node_dump(s);
    pfree(s);
+   printf("%s\n", f);
+   fflush(stdout);
+   pfree(f);
 }
 
 /*
- * pretty print hack extraordinaire.  -ay 10/94
+ * pprint
+ *   pretty-print contents of Node to stdout
  */
 void
 pprint(void *obj)
 {
-#define INDENTSTOP 3
-#define MAXINDENT  60
-#define LINELEN        80
    char       *s;
+   char       *f;
+
+   s = nodeToString(obj);
+   f = pretty_format_node_dump(s);
+   pfree(s);
+   printf("%s\n", f);
+   fflush(stdout);
+   pfree(f);
+}
+
+/*
+ * elog_node_display
+ *   send pretty-printed contents of Node to postmaster log
+ */
+void
+elog_node_display(int lev, const char *title, void *obj, bool pretty)
+{
+   char       *s;
+   char       *f;
+
+   s = nodeToString(obj);
+   if (pretty)
+       f = pretty_format_node_dump(s);
+   else
+       f = format_node_dump(s);
+   pfree(s);
+   elog(lev, "%s:\n%s", title, f);
+   pfree(f);
+}
+
+/*
+ * Format a nodeToString output for display on a terminal.
+ *
+ * The result is a palloc'd string.
+ *
+ * This version just tries to break at whitespace.
+ */
+char *
+format_node_dump(const char *dump)
+{
+#define LINELEN        78
+   char        line[LINELEN+1];
+   StringInfoData str;
    int         i;
-   char        line[LINELEN];
+   int         j;
+   int         k;
+
+   initStringInfo(&str);
+   i = 0;
+   for (;;)
+   {
+       for (j = 0; j < LINELEN && dump[i] != '\0'; i++, j++)
+           line[j] = dump[i];
+       if (dump[i] == '\0')
+           break;
+       if (dump[i] == ' ')
+       {
+           /* ok to break at adjacent space */
+           i++;
+       }
+       else
+       {
+           for (k = j-1; k > 0; k--)
+               if (line[k] == ' ')
+                   break;
+           if (k > 0)
+           {
+               /* back up; will reprint all after space */
+               i -= (j-k-1);
+               j = k;
+           }
+       }
+       line[j] = '\0';
+       appendStringInfo(&str, "%s\n", line);
+   }
+   if (j > 0)
+   {
+       line[j] = '\0';
+       appendStringInfo(&str, "%s\n", line);
+   }
+   return str.data;
+#undef LINELEN
+}
+
+/*
+ * Format a nodeToString output for display on a terminal.
+ *
+ * The result is a palloc'd string.
+ *
+ * This version tries to indent intelligently.
+ */
+char *
+pretty_format_node_dump(const char *dump)
+{
+#define INDENTSTOP 3
+#define MAXINDENT  60
+#define LINELEN        78
+   char        line[LINELEN+1];
+   StringInfoData str;
    int         indentLev;
    int         indentDist;
+   int         i;
    int         j;
 
-   s = nodeToString(obj);
-
+   initStringInfo(&str);
    indentLev = 0;              /* logical indent level */
    indentDist = 0;             /* physical indent distance */
    i = 0;
@@ -69,9 +168,9 @@ pprint(void *obj)
    {
        for (j = 0; j < indentDist; j++)
            line[j] = ' ';
-       for (; j < LINELEN-1 && s[i] != '\0'; i++, j++)
+       for (; j < LINELEN && dump[i] != '\0'; i++, j++)
        {
-           line[j] = s[i];
+           line[j] = dump[i];
            switch (line[j])
            {
                case '}':
@@ -79,11 +178,12 @@ pprint(void *obj)
                    {
                        /* print data before the } */
                        line[j] = '\0';
-                       printf("%s\n", line);
+                       appendStringInfo(&str, "%s\n", line);
                    }
                    /* print the } at indentDist */
-                   line[indentDist] = '\0';
-                   printf("%s}\n", line);
+                   line[indentDist] = '}';
+                   line[indentDist+1] = '\0';
+                   appendStringInfo(&str, "%s\n", line);
                    /* outdent */
                    if (indentLev > 0)
                    {
@@ -96,7 +196,7 @@ pprint(void *obj)
                case ')':
                    /* force line break after ')' */
                    line[j + 1] = '\0';
-                   printf("%s\n", line);
+                   appendStringInfo(&str, "%s\n", line);
                    j = indentDist - 1;
                    break;
                case '{':
@@ -104,36 +204,38 @@ pprint(void *obj)
                    if (j != indentDist)
                    {
                        line[j] = '\0';
-                       printf("%s\n", line);
+                       appendStringInfo(&str, "%s\n", line);
                    }
                    /* indent */
                    indentLev++;
                    indentDist = Min(indentLev * INDENTSTOP, MAXINDENT);
                    for (j = 0; j < indentDist; j++)
                        line[j] = ' ';
-                   line[j] = s[i];
+                   line[j] = dump[i];
                    break;
                case ':':
                    /* force line break before : */
                    if (j != indentDist)
                    {
                        line[j] = '\0';
-                       printf("%s\n", line);
+                       appendStringInfo(&str, "%s\n", line);
                    }
                    j = indentDist;
-                   line[j] = s[i];
+                   line[j] = dump[i];
                    break;
            }
        }
        line[j] = '\0';
-       if (s[i] == '\0')
+       if (dump[i] == '\0')
            break;
-       printf("%s\n", line);
+       appendStringInfo(&str, "%s\n", line);
    }
-   if (j != 0)
-       printf("%s\n", line);
-   fflush(stdout);
-   pfree(s);
+   if (j > 0)
+       appendStringInfo(&str, "%s\n", line);
+   return str.data;
+#undef INDENTSTOP
+#undef MAXINDENT
+#undef LINELEN
 }
 
 /*
index 68358f4966dc361c6d6564e23a1781f400571077..bef1b8064c7b68089a969a6b5e3ff2cd867b53d1 100644 (file)
@@ -8,7 +8,7 @@
  *
  *
  * IDENTIFICATION
- *   $Header: /cvsroot/pgsql/src/backend/tcop/postgres.c,v 1.259 2002/03/22 02:56:35 tgl Exp $
+ *   $Header: /cvsroot/pgsql/src/backend/tcop/postgres.c,v 1.260 2002/03/24 04:31:07 tgl Exp $
  *
  * NOTES
  *   this is the "main" module of the postgres backend and
@@ -426,15 +426,8 @@ pg_analyze_and_rewrite(Node *parsetree)
        querytree = (Query *) lfirst(list_item);
 
        if (Debug_print_parse)
-       {
-           if (Debug_pretty_print)
-           {
-               elog(LOG, "parse tree:");
-               nodeDisplay(querytree);
-           }
-           else
-               elog(LOG, "parse tree: %s", nodeToString(querytree));
-       }
+           elog_node_display(LOG, "parse tree", querytree,
+                             Debug_pretty_print);
 
        if (querytree->commandType == CMD_UTILITY)
        {
@@ -470,27 +463,8 @@ pg_analyze_and_rewrite(Node *parsetree)
 #endif
 
    if (Debug_print_rewritten)
-   {
-       if (Debug_pretty_print)
-       {
-           elog(LOG, "rewritten parse tree:");
-           foreach(list_item, querytree_list)
-           {
-               querytree = (Query *) lfirst(list_item);
-               nodeDisplay(querytree);
-               printf("\n");
-           }
-       }
-       else
-       {
-           elog(LOG, "rewritten parse tree:");
-           foreach(list_item, querytree_list)
-           {
-               querytree = (Query *) lfirst(list_item);
-               elog(LOG, "%s", nodeToString(querytree));
-           }
-       }
-   }
+       elog_node_display(LOG, "rewritten parse tree", querytree_list,
+                         Debug_pretty_print);
 
    return querytree_list;
 }
@@ -538,15 +512,7 @@ pg_plan_query(Query *querytree)
     * Print plan if debugging.
     */
    if (Debug_print_plan)
-   {
-       if (Debug_pretty_print)
-       {
-           elog(LOG, "plan:");
-           nodeDisplay(plan);
-       }
-       else
-           elog(LOG, "plan: %s", nodeToString(plan));
-   }
+       elog_node_display(LOG, "plan", plan, Debug_pretty_print);
 
    return plan;
 }
@@ -1722,7 +1688,7 @@ PostgresMain(int argc, char *argv[], const char *username)
    if (!IsUnderPostmaster)
    {
        puts("\nPOSTGRES backend interactive interface ");
-       puts("$Revision: 1.259 $ $Date: 2002/03/22 02:56:35 $\n");
+       puts("$Revision: 1.260 $ $Date: 2002/03/24 04:31:07 $\n");
    }
 
    /*
index af6b943e34969f671ebb7be510ba5bf2ae60b838..cfa00e4cb595db23b8ea0938d022fd284a604335 100644 (file)
@@ -10,7 +10,7 @@
  *
  *
  * IDENTIFICATION
- *   $Header: /cvsroot/pgsql/src/backend/tcop/utility.c,v 1.138 2002/03/22 02:56:35 tgl Exp $
+ *   $Header: /cvsroot/pgsql/src/backend/tcop/utility.c,v 1.139 2002/03/24 04:31:08 tgl Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -650,11 +650,7 @@ ProcessUtility(Node *parsetree,
            break;
 
        case T_ExplainStmt:
-           {
-               ExplainStmt *stmt = (ExplainStmt *) parsetree;
-
-               ExplainQuery(stmt->query, stmt->verbose, stmt->analyze, dest);
-           }
+           ExplainQuery((ExplainStmt *) parsetree, dest);
            break;
 
 #ifdef NOT_USED
index ee1926a56de01ccab2e1e87d594878717d71b134..d1f6d2bdb00a63f8738fc5cc52f4c2d8003dc789 100644 (file)
@@ -4,7 +4,7 @@
  * Support for grand unified configuration scheme, including SET
  * command, configuration file, and command line options.
  *
- * $Header: /cvsroot/pgsql/src/backend/utils/misc/guc.c,v 1.62 2002/03/06 06:10:27 momjian Exp $
+ * $Header: /cvsroot/pgsql/src/backend/utils/misc/guc.c,v 1.63 2002/03/24 04:31:08 tgl Exp $
  *
  * Copyright 2000 by PostgreSQL Global Development Group
  * Written by Peter Eisentraut <peter_e@gmx.net>.
@@ -82,6 +82,8 @@ bool      Show_query_stats = false;   /* this is sort of all three above
                                         * together */
 bool       Show_btree_build_stats = false;
 
+bool       Explain_pretty_print = true;
+
 bool       SQL_inheritance = true;
 
 bool       Australian_timezones = false;
@@ -293,6 +295,10 @@ static struct config_bool
    },
 #endif
 
+   {
+       "explain_pretty_print", PGC_USERSET, PGC_S_DEFAULT, &Explain_pretty_print, true, NULL
+   },
+
    {
        "stats_start_collector", PGC_POSTMASTER, PGC_S_DEFAULT, &pgstat_collect_startcollector, true, NULL
    },
index fa1ca8459eef2a7686cf26d3a784eda84e5c18af..a40b6ce7fac0e957aa180736119afc0c9b26a64a 100644 (file)
 #debug_print_plan = false
 #debug_pretty_print = false
 
+#explain_pretty_print = true
+
 # requires USE_ASSERT_CHECKING
 #debug_assertions = true
 
index eefbb1e7b683041b241268753ae6172ff016655b..003ec9fe33667493b8df99751fb8b96a052bd201 100644 (file)
@@ -3,7 +3,7 @@
  *
  * Copyright 2000 by PostgreSQL Global Development Group
  *
- * $Header: /cvsroot/pgsql/src/bin/psql/tab-complete.c,v 1.45 2002/03/07 20:48:41 momjian Exp $
+ * $Header: /cvsroot/pgsql/src/bin/psql/tab-complete.c,v 1.46 2002/03/24 04:31:08 tgl Exp $
  */
 
 /*----------------------------------------------------------------------
@@ -242,6 +242,7 @@ psql_completion(char *text, int start, int end)
        "show_executor_stats",
        "show_query_stats",
        "trace_notify",
+       "explain_pretty_print",
        "sql_inheritance",
        "australian_timezones",
        "password_encryption",
index c1686f64ccf3309c3ab34dc04bf85e1ecc28374a..9c0e3ecce1dae57d80a4840fc4401c441bdd16a9 100644 (file)
@@ -6,7 +6,7 @@
  * Portions Copyright (c) 1996-2001, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994-5, Regents of the University of California
  *
- * $Id: explain.h,v 1.15 2001/11/05 17:46:33 momjian Exp $
+ * $Id: explain.h,v 1.16 2002/03/24 04:31:09 tgl Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -16,6 +16,6 @@
 #include "nodes/parsenodes.h"
 #include "tcop/dest.h"
 
-extern void ExplainQuery(Query *query, bool verbose, bool analyze, CommandDest dest);
+extern void ExplainQuery(ExplainStmt *stmt, CommandDest dest);
 
 #endif   /* EXPLAIN_H */
index dbbe81fade3a91561058d5682060f16859eba19f..550e944f34cbcd7d2750e9b3b0b40ebdd11b02b1 100644 (file)
@@ -1,13 +1,13 @@
 /*-------------------------------------------------------------------------
  *
- * execnodes.h
- *   definitions for executor state nodes
+ * print.h
+ *   definitions for nodes/print.c
  *
  *
  * Portions Copyright (c) 1996-2001, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994, Regents of the University of California
  *
- * $Id: print.h,v 1.16 2001/11/05 17:46:34 momjian Exp $
+ * $Id: print.h,v 1.17 2002/03/24 04:31:09 tgl Exp $
  *
  *-------------------------------------------------------------------------
  */
 #include "nodes/parsenodes.h"
 #include "nodes/plannodes.h"
 
-/*
- * nodes/{outfuncs.c,print.c}
- */
+
 #define nodeDisplay        pprint
 
 extern void print(void *obj);
 extern void pprint(void *obj);
+extern void elog_node_display(int lev, const char *title,
+                             void *obj, bool pretty);
+extern char *format_node_dump(const char *dump);
+extern char *pretty_format_node_dump(const char *dump);
 extern void print_rt(List *rtable);
 extern void print_expr(Node *expr, List *rtable);
 extern void print_pathkeys(List *pathkeys, List *rtable);
index d58b9ef66ff5bf2caa00ad0bd46bb885c2417b07..a6eb17f6cfe84791bc34d3bbc58baa038cdb92ab 100644 (file)
@@ -4,7 +4,7 @@
  * External declarations pertaining to backend/utils/misc/guc.c and
  * backend/utils/misc/guc-file.l
  *
- * $Id: guc.h,v 1.15 2002/03/01 22:45:18 petere Exp $
+ * $Id: guc.h,v 1.16 2002/03/24 04:31:09 tgl Exp $
  */
 #ifndef GUC_H
 #define GUC_H
@@ -92,6 +92,8 @@ extern bool Show_executor_stats;
 extern bool Show_query_stats;
 extern bool Show_btree_build_stats;
 
+extern bool Explain_pretty_print;
+
 extern bool SQL_inheritance;
 extern bool Australian_timezones;