From 10d3995057b2ea89e56adb571c1beb2b972d1c6f Mon Sep 17 00:00:00 2001 From: Tom Lane Date: Sun, 24 Mar 2002 04:31:09 +0000 Subject: [PATCH] EXPLAIN output now comes out as a query result, not a NOTICE message. Also, fix debug logging of parse/plan trees so that the messages actually go through elog(), not directly to stdout. --- doc/src/sgml/perform.sgml | 103 ++++++----- doc/src/sgml/ref/explain.sgml | 86 +++++---- doc/src/sgml/release.sgml | 3 +- doc/src/sgml/runtime.sgml | 12 +- src/backend/commands/explain.c | 172 ++++++++++++++---- src/backend/nodes/print.c | 154 +++++++++++++--- src/backend/tcop/postgres.c | 48 +---- src/backend/tcop/utility.c | 8 +- src/backend/utils/misc/guc.c | 8 +- src/backend/utils/misc/postgresql.conf.sample | 2 + src/bin/psql/tab-complete.c | 3 +- src/include/commands/explain.h | 4 +- src/include/nodes/print.h | 14 +- src/include/utils/guc.h | 4 +- 14 files changed, 410 insertions(+), 211 deletions(-) diff --git a/doc/src/sgml/perform.sgml b/doc/src/sgml/perform.sgml index 94f49921f7..6b13d6ae3a 100644 --- a/doc/src/sgml/perform.sgml +++ b/doc/src/sgml/perform.sgml @@ -1,5 +1,5 @@ @@ -47,8 +47,8 @@ $Header: /cvsroot/pgsql/doc/src/sgml/perform.sgml,v 1.18 2002/03/22 19:20:17 pet - 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). @@ -92,13 +92,13 @@ $Header: /cvsroot/pgsql/doc/src/sgml/perform.sgml,v 1.18 2002/03/22 19:20:17 pet 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): 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) @@ -120,9 +120,10 @@ SELECT * FROM pg_class WHERE relname = 'tenk1'; regression=# EXPLAIN SELECT * FROM tenk1 WHERE unique1 < 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 < 1000) 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) regression=# EXPLAIN SELECT * FROM tenk1 WHERE unique1 < 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 < 50) 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) regression=# EXPLAIN SELECT * FROM tenk1 WHERE unique1 < 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 < 50) + Filter: (stringu1 = 'xxx'::name) - The added clause stringu1 = 'xxx' reduces the output-rows estimate, - but not the cost because we still have to visit the same set of tuples. + The added clause stringu1 = 'xxx' reduces the + output-rows estimate, but not the cost because we still have to visit the + same set of tuples. Notice that the stringu1 clause + cannot be applied as an index condition (since this index is only on + the 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. @@ -179,13 +188,15 @@ Index Scan using tenk1_unique1 on tenk1 (cost=0.00..181.22 rows=1 width=148) regression=# EXPLAIN SELECT * FROM tenk1 t1, tenk2 t2 WHERE t1.unique1 < 50 regression-# AND t1.unique2 = t2.unique2; -INFO: QUERY PLAN: - -Nested Loop (cost=0.00..330.41 rows=49 width=296) - -> Index Scan using tenk1_unique1 on tenk1 t1 - (cost=0.00..181.09 rows=49 width=148) - -> 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) + -> Index Scan using tenk1_unique1 on tenk1 t1 + (cost=0.00..179.33 rows=49 width=148) + Index Filter: (unique1 < 50) + -> Index Scan using tenk2_unique2 on tenk2 t2 + (cost=0.00..3.01 rows=1 width=148) + Index Filter: ("outer".unique2 = t2.unique2) @@ -227,14 +238,15 @@ regression=# set enable_nestloop = off; SET VARIABLE regression=# EXPLAIN SELECT * FROM tenk1 t1, tenk2 t2 WHERE t1.unique1 < 50 regression-# AND t1.unique2 = t2.unique2; -INFO: QUERY PLAN: - -Hash Join (cost=181.22..564.83 rows=49 width=296) - -> Seq Scan on tenk2 t2 - (cost=0.00..333.00 rows=10000 width=148) - -> Hash (cost=181.09..181.09 rows=49 width=148) - -> 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) + -> Seq Scan on tenk2 t2 (cost=0.00..333.00 rows=10000 width=148) + -> Hash (cost=179.33..179.33 rows=49 width=148) + -> Index Scan using tenk1_unique1 on tenk1 t1 + (cost=0.00..179.33 rows=49 width=148) + Index Filter: (unique1 < 50) This plan proposes to extract the 50 interesting rows of tenk1 @@ -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 tenk2. 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. @@ -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 < 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) - -> 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) - -> 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) + -> 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 < 50) + -> 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 Note that the actual time 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. diff --git a/doc/src/sgml/ref/explain.sgml b/doc/src/sgml/ref/explain.sgml index 33c9add453..28172aac5b 100644 --- a/doc/src/sgml/ref/explain.sgml +++ b/doc/src/sgml/ref/explain.sgml @@ -1,5 +1,5 @@ @@ -49,7 +49,7 @@ EXPLAIN [ ANALYZE ] [ VERBOSE ] queryVERBOSE - Flag to show detailed query plan. + Flag to show detailed query plan dump. @@ -76,28 +76,24 @@ EXPLAIN [ ANALYZE ] [ VERBOSE ] query - -INFO: QUERY PLAN: -plan - + Query plan - Explicit query plan from the PostgreSQL backend. - - - - - -EXPLAIN - - - - Flag sent after query plan is shown. + Explicit query plan from the PostgreSQL + planner. + + + + Prior to PostgreSQL 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). + + @@ -141,13 +137,6 @@ EXPLAIN are close to reality. - - 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 - PostgreSQL. - - Keep in mind that the query is actually executed when ANALYZE is used. @@ -165,6 +154,15 @@ ROLLBACK; + + 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 + PostgreSQL. The VERBOSE dump is either + pretty-printed or not, depending on the setting of the + configuration parameter. + + 1998-04-15 @@ -188,50 +186,48 @@ ROLLBACK; To show a query plan for a simple query on a table with a single - int4 column and 128 rows: + int4 column and 10000 rows: EXPLAIN SELECT * FROM foo; -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) - For the same table with an index to support an - equijoin condition on the query, + If there is an index and we use a query with an indexable WHERE condition, EXPLAIN will show a different plan: EXPLAIN SELECT * FROM foo WHERE i = 4; -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) - And finally, for the same table with an index to support an - equijoin condition on the query, - EXPLAIN will show the following for a query + And here is an example of a query plan for a query using an aggregate function: -EXPLAIN SELECT sum(i) FROM foo WHERE i = 4; +EXPLAIN SELECT sum(i) FROM foo WHERE i < 4; -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) diff --git a/doc/src/sgml/release.sgml b/doc/src/sgml/release.sgml index 4900f1b748..f0af67599d 100644 --- a/doc/src/sgml/release.sgml +++ b/doc/src/sgml/release.sgml @@ -1,5 +1,5 @@ @@ -24,6 +24,7 @@ CDATA means the content is "SGML-free", so you can write without worries about funny characters. --> @@ -870,6 +870,16 @@ env PGOPTIONS='-c geqo=off' psql + + EXPLAIN_PRETTY_PRINT (boolean) + + + Determines whether EXPLAIN VERBOSE uses the indented + or non-indented format for displaying detailed querytree dumps. + + + + HOSTNAME_LOOKUP (boolean) diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index 19df98531c..25b9f13fe2 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -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); +} diff --git a/src/backend/nodes/print.c b/src/backend/nodes/print.c index 7254d46c17..a1fd2b9387 100644 --- a/src/backend/nodes/print.c +++ b/src/backend/nodes/print.c @@ -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 } /* diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c index 68358f4966..bef1b8064c 100644 --- a/src/backend/tcop/postgres.c +++ b/src/backend/tcop/postgres.c @@ -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"); } /* diff --git a/src/backend/tcop/utility.c b/src/backend/tcop/utility.c index af6b943e34..cfa00e4cb5 100644 --- a/src/backend/tcop/utility.c +++ b/src/backend/tcop/utility.c @@ -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 diff --git a/src/backend/utils/misc/guc.c b/src/backend/utils/misc/guc.c index ee1926a56d..d1f6d2bdb0 100644 --- a/src/backend/utils/misc/guc.c +++ b/src/backend/utils/misc/guc.c @@ -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 . @@ -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 }, diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample index fa1ca8459e..a40b6ce7fa 100644 --- a/src/backend/utils/misc/postgresql.conf.sample +++ b/src/backend/utils/misc/postgresql.conf.sample @@ -136,6 +136,8 @@ #debug_print_plan = false #debug_pretty_print = false +#explain_pretty_print = true + # requires USE_ASSERT_CHECKING #debug_assertions = true diff --git a/src/bin/psql/tab-complete.c b/src/bin/psql/tab-complete.c index eefbb1e7b6..003ec9fe33 100644 --- a/src/bin/psql/tab-complete.c +++ b/src/bin/psql/tab-complete.c @@ -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", diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h index c1686f64cc..9c0e3ecce1 100644 --- a/src/include/commands/explain.h +++ b/src/include/commands/explain.h @@ -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 */ diff --git a/src/include/nodes/print.h b/src/include/nodes/print.h index dbbe81fade..550e944f34 100644 --- a/src/include/nodes/print.h +++ b/src/include/nodes/print.h @@ -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 $ * *------------------------------------------------------------------------- */ @@ -17,13 +17,15 @@ #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); diff --git a/src/include/utils/guc.h b/src/include/utils/guc.h index d58b9ef66f..a6eb17f6cf 100644 --- a/src/include/utils/guc.h +++ b/src/include/utils/guc.h @@ -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; -- GitLab