Re: BUG #16171: Potential malformed JSON in explain output - Mailing list pgsql-bugs

From Daniel Gustafsson
Subject Re: BUG #16171: Potential malformed JSON in explain output
Date
Msg-id 495433FC-A268-4956-9B61-5FB135EE5B73@yesql.se
Whole thread Raw
In response to BUG #16171: Potential malformed JSON in explain output  (PG Bug reporting form <noreply@postgresql.org>)
List pgsql-bugs
> On 18 Dec 2019, at 11:28, PG Bug reporting form <noreply@postgresql.org> wrote:
>
> The following bug has been logged on the website:
>
> Bug reference:      16171
> Logged by:          Mahadevan Ramachandran
> Email address:      mahadevan@rapidloop.com
> 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


Attachment

pgsql-bugs by date:

Previous
From: Tomas Vondra
Date:
Subject: Re: Memory leak (possibly connected to postgis) leading to servercrash
Next
From: Tom Lane
Date:
Subject: Re: BUG #16161: pg_ctl stop fails sometimes (on Windows)