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

From: Daniel Gustafsson <daniel(at)yesql(dot)se>
To: mahadevan(at)rapidloop(dot)com, PostgreSQL mailing lists <pgsql-bugs(at)lists(dot)postgresql(dot)org>
Subject: Re: BUG #16171: Potential malformed JSON in explain output
Date: 2019-12-18 15:15:29
Message-ID: 495433FC-A268-4956-9B61-5FB135EE5B73@yesql.se
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs pgsql-hackers

> On 18 Dec 2019, at 11:28, PG Bug reporting form <noreply(at)postgresql(dot)org> wrote:
>
> The following bug has been logged on the website:
>
> Bug reference: 16171
> Logged by: Mahadevan Ramachandran
> Email address: mahadevan(at)rapidloop(dot)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 Content-Type Size
explain_subplan_remove.patch application/octet-stream 1.1 KB

In response to

Responses

Browse pgsql-bugs by date

  From Date Subject
Next Message Tom Lane 2019-12-18 16:03:11 Re: BUG #16161: pg_ctl stop fails sometimes (on Windows)
Previous Message Tomas Vondra 2019-12-18 14:55:21 Re: Memory leak (possibly connected to postgis) leading to server crash

Browse pgsql-hackers by date

  From Date Subject
Next Message Simon Riggs 2019-12-18 15:17:48 Re: Read Uncommitted
Previous Message Simon Riggs 2019-12-18 15:14:20 Re: Read Uncommitted