Re: machine-readable explain output v4 - Mailing list pgsql-hackers

On Sunday 02 August 2009 23:34:04 Robert Haas wrote:
> On Sun, Aug 2, 2009 at 12:06 PM, Andres Freund<andres@anarazel.de> wrote:
> > Hi Robert, Hi all,
> >
> > On Thursday 30 July 2009 05:05:48 Robert Haas wrote:
> >> OK, here's the updated version of my machine-readable explain output
> >> patch.  This needed heavy updating as a result of the changes that Tom
> >> asked me to make to the explain options patch, and the further changes
> >> he made himself.  In addition to any regressions I may have introduced
> >> during the rebasing process, there is one definite problem here: in
> >> the previous version of this patch, explain (format xml) returned XML
> >> data; now, it's back to text.
> >>
> >> The reason for this regression is that Tom asked me to change
> >> ExplainStmt to just carry a list of nodes and to do all the parsing in
> >> ExplainQuery.  Unfortunately, the TupleDesc is constructed by
> >> ExplainResultDesc() which can't trivially be changed to take an
> >> ExplainState, because UtilityTupleDescriptor() also wants to call it.
> >> We could possibly fix this by a hack similar to the one we already
> >> added to GetCommandLogLevel(), but I haven't done that here.
> > Hm. I think its cleaner to move the option parsing into its own function
> > - its 3 places parsing options then and probably not going to get less. I
> > am not sure this is cleaner than including the parsed options in
> > ExplainStm though... (possibly in a separate struct to avoid changing
> > copy/equal-funcs everytime)
> Well, this is why we need Tom to weigh in.
Yes.

> > Some more comments on the (new) version of the patch:
> > - The regression tests are gone?
> Tom added some that look adequate to me to create_index.sql, as a
> separate commit, so I don't think I need to do this in my patch any
> more.  Maybe some of those examples should be changed to output JSON
> or XML, though, but I'd rather leave this up to Tom's discretion on
> commit because I think he has opinions about this and I think my
> chances of guessing what they are are low.
Yea, I was referring to ones using xml/json.

> > - Currently a value scan looks like »Values Scan on "*VALUES*"« What
> > about adding its alias at least in verbose mode? This currently is
> > inconsistent with other scans.
> I don't know why this doesn't work, but I think it's unrelated to this
> patch.
True.

> > Also he output columns of a VALUES scan are named column$N even
> > if names as specified like in AS foo(colname)
> This is consistent with how other types of scans are treated.
> rhaas=# explain verbose select x,y,z from (select * from pg_class)
> a(x,y,z); QUERY PLAN
> ----------------------------------------------------------------------
>  Seq Scan on pg_catalog.pg_class  (cost=0.00..8.44 rows=244 width=72)
>    Output: pg_class.relname, pg_class.relnamespace, pg_class.reltype
> (2 rows)
This is someone weird considering since using it directly in relations works
different:
explain (verbose) SELECT * FROM pg_namespace AS f(a,b,c);                                QUERY PLAN
           --------------------------------------------------------------------------- Seq Scan on
pg_catalog.pg_namespacef  (cost=0.00..1.06 rows=6 width=100)   Output: a, b, c(2 rows) 

Not your "guilt" though. Still its rather strange and looks worth fixable.

> > - why do xml/json contain no time units anymore? (e.g. Total Runtime).
> > Admittedly thats already inconsistent in the current text format...
> I'm not sure what you mean by "any more".  I don't think any version
> of these patches I ever submitted did otherwise, nor do I think it's
> particularly valuable.  Costs are implicitly in units of
> PostgreSQL-costing and times are implicitly in units of milliseconds,
> just as they are in the text format.  Changing this would require
> clients to strip off the trailing 'ms' before converting to a
> floating-point number, which seems like an irritation with no
> corresponding benefit.
I did not think any of your patches did - it was just a difference between the
original output and the new formats I just noted - as I said its not even
consistent in the text format.

> > - Code patterns like:
> >                if (es->format == EXPLAIN_FORMAT_TEXT)
> >                        appendStringInfo(es->str, "Total runtime: %.3f
> > ms\n", 1000.0 * totaltime); else if (es->format == EXPLAIN_FORMAT_XML)
> >                        appendStringInfo(es->str,
> >                                                         "
> >  <Total-Runtime>%.3f</Total-Runtime>\n", 1000.0 * totaltime); else if
> > (es->format == EXPLAIN_FORMAT_JSON)
> >                        appendStringInfo(es->str, ",\n    \"Total
> > runtime\" : %.3f", 1000.0 * totaltime); or
> >                        if (es->format == EXPLAIN_FORMAT_TEXT)
> >                                appendStringInfo(es->str, " for constraint
> > %s", conname); else if (es->format == EXPLAIN_FORMAT_XML) {
> >                                appendStringInfoString(es->str, "
> >  <Constraint-Name>"); escape_xml(es->str, conname);
> >                                appendStringInfoString(es->str,
> > "</Constraint-Name>\n"); }
> >                        else if (es->format == EXPLAIN_FORMAT_JSON)
> >                        {
> >                                appendStringInfo(es->str, "\n
> >  \"Constraint Name\": "); escape_json(es->str, conname);
> >                        }
> >
> > possibly could be simplified using ExplainPropertyText or a function
> > accepting a format string.
> > At least for the !EXPLAIN_FORMAT_TEXT this seems simple at multiple
> > places in ExplainOnePlan and report_triggers.
> Well, the whole explain output format is pretty idiosyncratic, and I
> had to work pretty hard to beat it into submission.  I think that it
> would not be totally trivial to do what you're suggesting here because
> it would require adding code to manage es->indent outside of
> ExplainPrintPlan(), which we currently don't.  I'm not sure whether
> that works out to a net win.
Thats why I suggested doing it for JSON/XML only. E.g. like in the attached
patch. The result looks simpler for my eyes.

While re-checking this I noticed a newly introduced bug in report_triggers() -
in case of a trigger/conname==false "Trigger Name" gets printed twice due to a
duplicated else - merge glitch? (fixed in attached patch as well)