Re: BUG #16171: Potential malformed JSON in explain output

> On 18 Dec 2019, at 11:28, PG Bug reporting form <[email protected]> wrote:
> 
> The following bug has been logged on the website:
> 
> Bug reference:      16171
> Logged by:          Mahadevan Ramachandran
> Email address:      [email protected]
> PostgreSQL version: 12.1
> Operating system:   any
> Description:        
> 
> Refer src/backend/commands/explain.c, version 12.1.
> 
> When a plan node has children, the function ExplainNode starts a JSON array
> with the key "Plans" (line 1955), like so:
> 
>    "Plans": [ 
> 
> with the intention of creating an array of "Plan" objects, one for each
> child:
> 
>    "Plans": [
>        { .. a child plan goes here ..},
>        { .. a child plan goes here ..}
>    ]
> 
> However, if the node (the current, parent one) is of a certain type (see
> switch at line 1975), then ExplainMemberNodes is called, which does this
> (lines 3335-6):
> 
> 	if (nsubnodes < nplans)
> 		ExplainPropertyInteger("Subplans Removed", NULL, nplans - nsubnodes,
> es);
> 
> This can potentially cause a malformed JSON output like this:
> 
>    "Plans": [
>        { .. a child plan goes here ..},
>        "Subplans Removed": 5,
>        { .. a child plan goes here ..}
>    ]

Nice catch!  That seems like a correct analysis to me.  The same error is
present in YAML output as well AFAICT.

> I don't have a sample explain output that exhibits this error, this was
> found while reviewing the code.

A tip for when you're struggling to get the output you want for testing
something: grep for it in src/test/regress.  Chances are there is already a
test covering the precise output you're interested in.  For the example at
hand, the partition_prune.sql suite contains quite a few such queries.

Looking at the output from one of them, in text as well as JSON exemplifies the
bug clearly:

                       QUERY PLAN
--------------------------------------------------------
 Append (actual rows=1 loops=1)
   InitPlan 1 (returns $0)
     ->  Result (actual rows=1 loops=1)
   Subplans Removed: 2
   ->  Seq Scan on mc3p1 mc3p_1 (actual rows=1 loops=1)
         Filter: ((a = $1) AND (abs(b) < $0))
(6 rows)

                      QUERY PLAN
------------------------------------------------------
 [                                                   +
   {                                                 +
     "Plan": {                                       +
       "Node Type": "Append",                        +
       "Parallel Aware": false,                      +
       "Actual Rows": 2,                             +
       "Actual Loops": 1,                            +
       "Plans": [                                    +
         {                                           +
           "Node Type": "Result",                    +
           "Parent Relationship": "InitPlan",        +
           "Subplan Name": "InitPlan 1 (returns $0)",+
           "Parallel Aware": false,                  +
           "Actual Rows": 1,                         +
           "Actual Loops": 1                         +
         },                                          +
         "Subplans Removed": 1,                      +
         {                                           +
           "Node Type": "Seq Scan",                  +
           "Parent Relationship": "Member",          +
           "Parallel Aware": false,                  +
           "Relation Name": "mc3p0",                 +
           "Alias": "mc3p_1",                        +
           "Actual Rows": 1,                         +
           "Actual Loops": 1,                        +
           "Filter": "((a <= $1) AND (abs(b) < $0))",+
           "Rows Removed by Filter": 0               +
         },                                          +
         {                                           +
           "Node Type": "Seq Scan",                  +
           "Parent Relationship": "Member",          +
           "Parallel Aware": false,                  +
           "Relation Name": "mc3p1",                 +
           "Alias": "mc3p_2",                        +
           "Actual Rows": 1,                         +
           "Actual Loops": 1,                        +
           "Filter": "((a <= $1) AND (abs(b) < $0))",+
           "Rows Removed by Filter": 0               +
         }                                           +
       ]                                             +
     },                                              +
     "Triggers": [                                   +
     ]                                               +
   }                                                 +
 ]
(1 row)

Moving the "Subplans Removed" into a Plan group seems like the least bad option
to clearly identify it while keeping the formatting legal.  The attached patch
generates the following output for JSON instead:


       "Plans": [                                    +
         {                                           +
           "Node Type": "Result",                    +
           "Parent Relationship": "InitPlan",        +
           "Subplan Name": "InitPlan 1 (returns $0)",+
           "Parallel Aware": false,                  +
           "Actual Rows": 1,                         +
           "Actual Loops": 1                         +
         },                                          +
         {                                           +
           "Subplans Removed": 2                     +
         },                                          +
         {                                           +
           "Node Type": "Seq Scan",                  +
           "Parent Relationship": "Member",          +
           "Parallel Aware": false,                  +
           "Relation Name": "mc3p1",                 +
           "Alias": "mc3p_1",                        +
           "Actual Rows": 1,                         +
           "Actual Loops": 1,                        +
           "Filter": "((a = $1) AND (abs(b) < $0))", +
           "Rows Removed by Filter": 0               +
         }                                           +

cheers ./daniel

From 0240114f145b1386f13ef50b106ca8d7761b7729 Mon Sep 17 00:00:00 2001
From: Daniel Gustafsson <[email protected]>
Date: Wed, 18 Dec 2019 16:04:52 +0100
Subject: [PATCH] Move subplan pruning info in EXPLAIN into group

The "Subplans Removed" information is printed in the Plans output
group, where for structured formats JSON and YAML each entry must
be in its own group in order for the outout to be legally formatted.

Bug: #16171
Reported-by: Mahadevan Ramachandran
---
 src/backend/commands/explain.c | 4 ++++
 1 file changed, 4 insertions(+)

diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index 949fefa23a..abab5532bd 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -3360,7 +3360,11 @@ ExplainMemberNodes(PlanState **planstates, int nsubnodes, int nplans,
 	 * here that this has happened.
 	 */
 	if (nsubnodes < nplans)
+	{
+		ExplainOpenGroup("Plan", NULL, true, es);
 		ExplainPropertyInteger("Subplans Removed", NULL, nplans - nsubnodes, es);
+		ExplainCloseGroup("Plan", NULL, true, es);
+	}
 
 	for (j = 0; j < nsubnodes; j++)
 		ExplainNode(planstates[j], ancestors,
-- 
2.21.0 (Apple Git-122.2)