Re: [HACKERS] auto_explain produces invalid JSON

2012-02-13 Thread Tom Lane
[ sorry for ignoring this over the weekend --- I wasn't feeling very well ]

Andrew Dunstan and...@dunslane.net writes:
 On 02/11/2012 03:22 PM, Tom Lane wrote:
 I'm inclined to think that this is auto_explain's error, not that of
 the core code, ie we should be changing the output.

 Well, maybe this is more to your taste, although it strikes me as more 
 than something of a kludge. At least it's short :-)

I see you've already committed this, but I agree that it's quite a
kluge.

After looking a bit more at the existing explain code, it seems like the
critical issue is that explain.c has ExplainOpenGroup/ExplainCloseGroup
calls around the ExplainPrintPlan call (see ExplainOnePlan), while
auto_explain does not.  I did not like your originally proposed patch
because it seemed to introduce yet another formatting concept into code
that has already got a few too many.  But couldn't we fix this by
exporting ExplainOpenGroup/ExplainCloseGroup and then calling those from
auto_explain?

regards, tom lane

-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers


Re: [HACKERS] auto_explain produces invalid JSON

2012-02-13 Thread Andrew Dunstan



On 02/13/2012 11:15 AM, Tom Lane wrote:

[ sorry for ignoring this over the weekend --- I wasn't feeling very well ]

Andrew Dunstanand...@dunslane.net  writes:

On 02/11/2012 03:22 PM, Tom Lane wrote:

I'm inclined to think that this is auto_explain's error, not that of
the core code, ie we should be changing the output.

Well, maybe this is more to your taste, although it strikes me as more
than something of a kludge. At least it's short :-)

I see you've already committed this, but I agree that it's quite a
kluge.

After looking a bit more at the existing explain code, it seems like the
critical issue is that explain.c has ExplainOpenGroup/ExplainCloseGroup
calls around the ExplainPrintPlan call (see ExplainOnePlan), while
auto_explain does not.  I did not like your originally proposed patch
because it seemed to introduce yet another formatting concept into code
that has already got a few too many.  But couldn't we fix this by
exporting ExplainOpenGroup/ExplainCloseGroup and then calling those from
auto_explain?


Yeah, maybe. We'd still have to do it conditionally (have to use 
ExplainBeginOutput for the XML case), but it would possibly be less kludgy.


cheers

andrew

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers


Re: [HACKERS] auto_explain produces invalid JSON

2012-02-13 Thread Tom Lane
Andrew Dunstan and...@dunslane.net writes:
 On 02/13/2012 11:15 AM, Tom Lane wrote:
 After looking a bit more at the existing explain code, it seems like the
 critical issue is that explain.c has ExplainOpenGroup/ExplainCloseGroup
 calls around the ExplainPrintPlan call (see ExplainOnePlan), while
 auto_explain does not.

 Yeah, maybe. We'd still have to do it conditionally (have to use 
 ExplainBeginOutput for the XML case), but it would possibly be less kludgy.

Hm?  I wasn't suggesting removing the ExplainBeginOutput call, but more
like

ExplainBeginOutput(es);
+   ExplainOpenGroup(...);
ExplainQueryText(es, queryDesc);
ExplainPrintPlan(es, queryDesc);
+   ExplainCloseGroup(...);
ExplainEndOutput(es);

Details still TBD; the point is just that it's not clear to me why
auto_explain should need a formatting concept that doesn't already exist
within explain.c.

regards, tom lane

-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers


Re: [HACKERS] auto_explain produces invalid JSON

2012-02-13 Thread Andrew Dunstan



On 02/13/2012 12:48 PM, Tom Lane wrote:

Andrew Dunstanand...@dunslane.net  writes:

On 02/13/2012 11:15 AM, Tom Lane wrote:

After looking a bit more at the existing explain code, it seems like the
critical issue is that explain.c has ExplainOpenGroup/ExplainCloseGroup
calls around the ExplainPrintPlan call (see ExplainOnePlan), while
auto_explain does not.

Yeah, maybe. We'd still have to do it conditionally (have to use
ExplainBeginOutput for the XML case), but it would possibly be less kludgy.

Hm?  I wasn't suggesting removing the ExplainBeginOutput call, but more
like

ExplainBeginOutput(es);
+   ExplainOpenGroup(...);
ExplainQueryText(es, queryDesc);
ExplainPrintPlan(es, queryDesc);
+   ExplainCloseGroup(...);
ExplainEndOutput(es);

Details still TBD; the point is just that it's not clear to me why
auto_explain should need a formatting concept that doesn't already exist
within explain.c.




This will introduce an extra level of nesting for no good reason.

But this would work:

-   ExplainBeginOutput(es);
+   if (auto_explain_log_format != EXPLAIN_FORMAT_JSON)
+   ExplainBeginOutput(es);
+   else
+   ExplainOpenGroup(NULL, NULL, true, es);
ExplainQueryText(es, queryDesc);
ExplainPrintPlan(es, queryDesc);
-   ExplainEndOutput(es);
+   if (auto_explain_log_format != EXPLAIN_FORMAT_JSON)
+   ExplainEndOutput(es);
+   else
+   ExplainCloseGroup(NULL, NULL, true, es);

cheers

andrew

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers


Re: [HACKERS] auto_explain produces invalid JSON

2012-02-13 Thread Andrew Dunstan



On 02/13/2012 01:33 PM, Andrew Dunstan wrote:



On 02/13/2012 12:48 PM, Tom Lane wrote:

Andrew Dunstanand...@dunslane.net  writes:

On 02/13/2012 11:15 AM, Tom Lane wrote:
After looking a bit more at the existing explain code, it seems 
like the
critical issue is that explain.c has 
ExplainOpenGroup/ExplainCloseGroup

calls around the ExplainPrintPlan call (see ExplainOnePlan), while
auto_explain does not.

Yeah, maybe. We'd still have to do it conditionally (have to use
ExplainBeginOutput for the XML case), but it would possibly be less 
kludgy.

Hm?  I wasn't suggesting removing the ExplainBeginOutput call, but more
like

ExplainBeginOutput(es);
+ExplainOpenGroup(...);
ExplainQueryText(es, queryDesc);
ExplainPrintPlan(es, queryDesc);
+ExplainCloseGroup(...);
ExplainEndOutput(es);

Details still TBD; the point is just that it's not clear to me why
auto_explain should need a formatting concept that doesn't already exist
within explain.c.




This will introduce an extra level of nesting for no good reason.

But this would work:

-   ExplainBeginOutput(es);
+   if (auto_explain_log_format != EXPLAIN_FORMAT_JSON)
+   ExplainBeginOutput(es);
+   else
+   ExplainOpenGroup(NULL, NULL, true, es);
ExplainQueryText(es, queryDesc);
ExplainPrintPlan(es, queryDesc);
-   ExplainEndOutput(es);
+   if (auto_explain_log_format != EXPLAIN_FORMAT_JSON)
+   ExplainEndOutput(es);
+   else
+   ExplainCloseGroup(NULL, NULL, true, es);




Except that it causes other problems.

I think we'd probably bet sleeping dogs lie.

cheers

andrew

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers


Re: [HACKERS] auto_explain produces invalid JSON

2012-02-11 Thread Andrew Dunstan



On 02/10/2012 01:14 PM, Peter Eisentraut wrote:

The auto_explain module appears to create invalid JSON (in all versions
since 9.0).  For example, with the settings

auto_explain.log_format = 'json'
auto_explain.log_min_duration = 0

the query

select * from pg_type;

produces this in the log:

LOG:  duration: 529.808 ms  plan:
 [
   Query Text: select * from pg_type;,
   Plan: {
 Node Type: Seq Scan,
 Relation Name: pg_type,
 Alias: pg_type,
 Startup Cost: 0.00,
 Total Cost: 9.87,
 Plan Rows: 287,
 Plan Width: 611
   }
 ]

Note that at the top level, it uses the array delimiters [ ] for what is
actually an object (key/value).  Running this through a JSON parser will
fail.

By contrast, EXPLAIN (FORMAT JSON) on the command line produces:

 QUERY PLAN
---
  [
{
  Plan: {
Node Type: Seq Scan,
Relation Name: pg_type,
Alias: pg_type,
Startup Cost: 0.00,
Total Cost: 9.87,
Plan Rows: 287,
Plan Width: 611
  }
}
  ]
(1 row)





Yeah, looks like this dates back to when we first got JSON output.

Auto-explain does this:

 ExplainBeginOutput(es);
 ExplainQueryText(es, queryDesc);
 ExplainPrintPlan(es, queryDesc);
 ExplainEndOutput(es);


But ExplainBeginOutput says:

 case EXPLAIN_FORMAT_JSON:
  /* top-level structure is an array of plans */
  appendStringInfoChar(es-str, '[');


Now that's not true in the auto-explain case, which prints one query + 
one plan.


Since this is an exposed API, I don't think we can just change it. We 
probably need a new API that does the right thing for beginning and 
ending auto_explain output. (ExplainBeginLabeledOutput?)


cheers

andrew


--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers


Re: [HACKERS] auto_explain produces invalid JSON

2012-02-11 Thread Andrew Dunstan



On 02/11/2012 01:18 PM, Andrew Dunstan wrote:



On 02/10/2012 01:14 PM, Peter Eisentraut wrote:

 [ auto-explain JSON output should be an object instead of an array ]




Yeah, looks like this dates back to when we first got JSON output.

Auto-explain does this:

 ExplainBeginOutput(es);
 ExplainQueryText(es, queryDesc);
 ExplainPrintPlan(es, queryDesc);
 ExplainEndOutput(es);


But ExplainBeginOutput says:

 case EXPLAIN_FORMAT_JSON:
  /* top-level structure is an array of plans */
  appendStringInfoChar(es-str, '[');


Now that's not true in the auto-explain case, which prints one query + 
one plan.


Since this is an exposed API, I don't think we can just change it. We 
probably need a new API that does the right thing for beginning and 
ending auto_explain output. (ExplainBeginLabeledOutput?)






PFA a patch along these lines, which seems to do the Right Thing (tm)

cheers

andrew


*** a/contrib/auto_explain/auto_explain.c
--- b/contrib/auto_explain/auto_explain.c
***
*** 290,299  explain_ExecutorEnd(QueryDesc *queryDesc)
  			es.buffers = (es.analyze  auto_explain_log_buffers);
  			es.format = auto_explain_log_format;
  
! 			ExplainBeginOutput(es);
  			ExplainQueryText(es, queryDesc);
  			ExplainPrintPlan(es, queryDesc);
! 			ExplainEndOutput(es);
  
  			/* Remove last line break */
  			if (es.str-len  0  es.str-data[es.str-len - 1] == '\n')
--- 290,299 
  			es.buffers = (es.analyze  auto_explain_log_buffers);
  			es.format = auto_explain_log_format;
  
! 			ExplainBeginLabeledOutput(es);
  			ExplainQueryText(es, queryDesc);
  			ExplainPrintPlan(es, queryDesc);
! 			ExplainEndLabeledOutput(es);
  
  			/* Remove last line break */
  			if (es.str-len  0  es.str-data[es.str-len - 1] == '\n')
*** a/src/backend/commands/explain.c
--- b/src/backend/commands/explain.c
***
*** 2258,2263  ExplainEndOutput(ExplainState *es)
--- 2258,2302 
  }
  
  /*
+  * Emit the start-of-output boilerplate, if it's labeled, as auto_explain
+  * JSON is. For non-json cases, fall back on ExplainBeginOutput.
+  *
+  */
+ void
+ ExplainBeginLabeledOutput(ExplainState *es)
+ {
+ 	switch (es-format)
+ 	{
+ 		case EXPLAIN_FORMAT_JSON:
+ 			/* top level is an object of labeled items */
+ 			appendStringInfoChar(es-str, '{');
+ 			es-grouping_stack = lcons_int(0, es-grouping_stack);
+ 			es-indent++;
+ 			break;
+ 		default:
+ 			ExplainBeginOutput(es);
+ 	}
+ }
+ 
+ /* 
+  * Companion to ExplainBeginLabeledOutput
+  */
+ void
+ ExplainEndLabeledOutput(ExplainState *es)
+ {
+ 	switch (es-format)
+ 	{
+ 		case EXPLAIN_FORMAT_JSON:
+ 			es-indent--;
+ 			appendStringInfoString(es-str, \n});
+ 			es-grouping_stack = list_delete_first(es-grouping_stack);
+ 			break;
+ 		default:
+ 			ExplainEndOutput(es);
+ 	}
+ }
+ 
+ /*
   * Put an appropriate separator between multiple plans
   */
  void
*** a/src/include/commands/explain.h
--- b/src/include/commands/explain.h
***
*** 71,76  extern void ExplainQueryText(ExplainState *es, QueryDesc *queryDesc);
--- 71,78 
  
  extern void ExplainBeginOutput(ExplainState *es);
  extern void ExplainEndOutput(ExplainState *es);
+ extern void ExplainBeginLabeledOutput(ExplainState *es);
+ extern void ExplainEndLabeledOutput(ExplainState *es);
  extern void ExplainSeparatePlans(ExplainState *es);
  
  extern void ExplainPropertyList(const char *qlabel, List *data,

-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers


Re: [HACKERS] auto_explain produces invalid JSON

2012-02-11 Thread Tom Lane
Andrew Dunstan and...@dunslane.net writes:
 But ExplainBeginOutput says:

   case EXPLAIN_FORMAT_JSON:
/* top-level structure is an array of plans */
appendStringInfoChar(es-str, '[');

 Now that's not true in the auto-explain case, which prints one query + 
 one plan.

What about queries that expand to multiple plans because of rules?

 Since this is an exposed API, I don't think we can just change it. We 
 probably need a new API that does the right thing for beginning and 
 ending auto_explain output. (ExplainBeginLabeledOutput?)

I'm inclined to think that this is auto_explain's error, not that of
the core code, ie we should be changing the output.

regards, tom lane

-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers


Re: [HACKERS] auto_explain produces invalid JSON

2012-02-11 Thread Andrew Dunstan



On 02/11/2012 03:22 PM, Tom Lane wrote:

Andrew Dunstanand...@dunslane.net  writes:

But ExplainBeginOutput says:
   case EXPLAIN_FORMAT_JSON:
/* top-level structure is an array of plans */
appendStringInfoChar(es-str, '[');
Now that's not true in the auto-explain case, which prints one query +
one plan.

What about queries that expand to multiple plans because of rules?


Oh, hmm, good point.





Since this is an exposed API, I don't think we can just change it. We
probably need a new API that does the right thing for beginning and
ending auto_explain output. (ExplainBeginLabeledOutput?)

I'm inclined to think that this is auto_explain's error, not that of
the core code, ie we should be changing the output.





It looks like it will be messy either way. ;-(

cheers

andrew




--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers


Re: [HACKERS] auto_explain produces invalid JSON

2012-02-11 Thread Andrew Dunstan



On 02/11/2012 03:22 PM, Tom Lane wrote:

Andrew Dunstanand...@dunslane.net  writes:

But ExplainBeginOutput says:
   case EXPLAIN_FORMAT_JSON:
/* top-level structure is an array of plans */
appendStringInfoChar(es-str, '[');
Now that's not true in the auto-explain case, which prints one query +
one plan.

What about queries that expand to multiple plans because of rules?



... and the answer is it logs them in separate pieces of JSON.




Since this is an exposed API, I don't think we can just change it. We
probably need a new API that does the right thing for beginning and
ending auto_explain output. (ExplainBeginLabeledOutput?)

I'm inclined to think that this is auto_explain's error, not that of
the core code, ie we should be changing the output.





Well, maybe this is more to your taste, although it strikes me as more 
than something of a kludge. At least it's short :-)


cheers

andrew

*** a/contrib/auto_explain/auto_explain.c
--- b/contrib/auto_explain/auto_explain.c
***
*** 299,304  explain_ExecutorEnd(QueryDesc *queryDesc)
--- 299,311 
  			if (es.str-len  0  es.str-data[es.str-len - 1] == '\n')
  es.str-data[--es.str-len] = '\0';
  
+ 			/* Fix JSON to output an object */
+ 			if (auto_explain_log_format == EXPLAIN_FORMAT_JSON)
+ 			{
+ es.str-data[0] = '{';
+ es.str-data[es.str-len - 1] = '}';
+ 			}
+ 
  			/*
  			 * Note: we rely on the existing logging of context or
  			 * debug_query_string to identify just which statement is being

-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers