Re: strange explain in upstream - subplan 1 twice - is it bug?

From: Pavel Stehule <pavel(dot)stehule(at)gmail(dot)com>
To: Robert Haas <robertmhaas(at)gmail(dot)com>
Cc: PostgreSQL Hackers <pgsql-hackers(at)postgresql(dot)org>
Subject: Re: strange explain in upstream - subplan 1 twice - is it bug?
Date: 2016-07-07 20:13:14
Message-ID: CAFj8pRDQ2Me_aLiQ64Vga8cMEb1VRhjmV18Yr6HJSNy7wsmkkw@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

2016-07-07 21:57 GMT+02:00 Robert Haas <robertmhaas(at)gmail(dot)com>:

> On Wed, Jun 1, 2016 at 7:29 AM, Pavel Stehule <pavel(dot)stehule(at)gmail(dot)com>
> wrote:
> > Hi
> >
> > When I tested some queries, I found strange plan
> >
> > postgres=# explain analyze select s.nazev, o.nazev, o.pocet_obyvatel from
> > (select nazev, array(select id from obce_pocet_obyvatel where okresy.id
> =
> > okres_id order by pocet_obyvatel desc limit 3) as obceids from okresy) s
> > join obce_pocet_obyvatel o on o.id = ANY(obceids) order by 1, 3 desc;
>
> The EXPLAIN plan you posted certainly looks weird, since I wouldn't
> expect SubPlan 1 to be displayed twice, but I'm wondering if it's a
> display artifact rather than an actual defect in the plan.
>
> Just out of curiosity, what does the output look like with FORMAT JSON
> or similar?
>

The test case was wrong, the view "" is necessary

create view obce_pocet_obyvatel as select id, okres_id, nazev, pocet_muzu +
pocet_zen as pocet_obyvatel from obce;

But the result is same (explain is ok, explain analyze is broken):

┌──────────────────────────────────────────────────────────────────────────────────────┐
│ QUERY
PLAN │
╞══════════════════════════════════════════════════════════════════════════════════════╡

[
↵│

{
↵│
│ "Plan":
{ ↵│
│ "Node Type":
"Sort", ↵│
│ "Startup Cost":
1599.86, ↵│
│ "Total Cost":
1601.79, ↵│
│ "Plan Rows":
769, ↵│
│ "Plan Width":
24, ↵│
│ "Actual Startup Time":
9.525, ↵│
│ "Actual Total Time":
9.547, ↵│
│ "Actual Rows":
227, ↵│
│ "Actual Loops":
1, ↵│
│ "Sort Key": ["okresy.nazev", "((obce.pocet_muzu + obce.pocet_zen))
DESC"], ↵│
│ "Sort Method":
"quicksort", ↵│
│ "Sort Space Used":
44, ↵│
│ "Sort Space Type":
"Memory", ↵│
│ "Plans":
[ ↵│

{
↵│
│ "Node Type": "Nested
Loop", ↵│
│ "Parent Relationship":
"Outer", ↵│
│ "Join Type":
"Inner", ↵│
│ "Startup Cost":
13.95, ↵│
│ "Total Cost":
1563.00, ↵│
│ "Plan Rows":
769, ↵│
│ "Plan Width":
24, ↵│
│ "Actual Startup Time":
0.212, ↵│
│ "Actual Total Time":
8.991, ↵│
│ "Actual Rows":
227, ↵│
│ "Actual Loops":
1, ↵│
│ "Plans":
[ ↵│

{ ↵│
│ "Node Type": "Seq
Scan", ↵│
│ "Parent Relationship":
"Outer", ↵│
│ "Relation Name":
"okresy", ↵│
│ "Alias":
"okresy", ↵│
│ "Startup Cost":
0.00, ↵│
│ "Total Cost":
1.77, ↵│
│ "Plan Rows":
77, ↵│
│ "Plan Width":
17, ↵│
│ "Actual Startup Time":
0.016, ↵│
│ "Actual Total Time":
0.042, ↵│
│ "Actual Rows":
77, ↵│
│ "Actual Loops":
1 ↵│

}, ↵│

{ ↵│
│ "Node Type": "Index
Scan", ↵│
│ "Parent Relationship":
"Inner", ↵│
│ "Scan Direction":
"Forward", ↵│
│ "Index Name":
"_obce_pkey", ↵│
│ "Relation Name":
"obce", ↵│
│ "Alias":
"obce", ↵│
│ "Startup Cost":
13.95, ↵│
│ "Total Cost":
20.15, ↵│
│ "Plan Rows":
10, ↵│
│ "Plan Width":
22, ↵│
│ "Actual Startup Time":
0.005, ↵│
│ "Actual Total Time":
0.012, ↵│
│ "Actual Rows":
3, ↵│
│ "Actual Loops":
77, ↵│
│ "Index Cond": "(id = ANY ((SubPlan
1)))", ↵│
│ "Rows Removed by Index Recheck":
0, ↵│
│ "Plans":
[ ↵│

{ ↵│
│ "Node Type":
"Limit", ↵│
│ "Parent Relationship":
"SubPlan", ↵│
│ "Subplan Name": "SubPlan
1", ↵│
│ "Startup Cost":
13.66, ↵│
│ "Total Cost":
13.67, ↵│
│ "Plan Rows":
3, ↵│
│ "Plan Width":
8, ↵│
│ "Actual Startup Time":
0.094, ↵│
│ "Actual Total Time":
0.095, ↵│
│ "Actual Rows":
3, ↵│
│ "Actual Loops":
77, ↵│
│ "Plans":
[ ↵│

{ ↵│
│ "Node Type":
"Sort", ↵│
│ "Parent Relationship":
"Outer", ↵│
│ "Startup Cost":
13.66, ↵│
│ "Total Cost":
13.86, ↵│
│ "Plan Rows":
81, ↵│
│ "Plan Width":
8, ↵│
│ "Actual Startup Time":
0.092, ↵│
│ "Actual Total Time":
0.093, ↵│
│ "Actual Rows":
3, ↵│
│ "Actual Loops":
77, ↵│
│ "Sort Key": ["((obce_1.pocet_muzu +
obce_1.pocet_zen)) DESC"],↵│
│ "Sort Method":
"quicksort", ↵│
│ "Sort Space Used":
25, ↵│
│ "Sort Space Type":
"Memory", ↵│
│ "Plans":
[ ↵│

{ ↵│
│ "Node Type": "Index
Scan", ↵│
│ "Parent Relationship":
"Outer", ↵│
│ "Scan Direction":
"Forward", ↵│
│ "Index Name":
"obce_okres_id_idx", ↵│
│ "Relation Name":
"obce", ↵│
│ "Alias":
"obce_1", ↵│
│ "Startup Cost":
0.28, ↵│
│ "Total Cost":
12.62, ↵│
│ "Plan Rows":
81, ↵│
│ "Plan Width":
8, ↵│
│ "Actual Startup Time":
0.015, ↵│
│ "Actual Total Time":
0.065, ↵│
│ "Actual Rows":
81, ↵│
│ "Actual Loops":
77, ↵│
│ "Index Cond": "(okresy.id =
(okres_id)::text)", ↵│
│ "Rows Removed by Index Recheck":
0 ↵│

} ↵│

] ↵│

} ↵│

] ↵│

}, ↵│

{ ↵│
│ "Node Type":
"Limit", ↵│
│ "Parent Relationship":
"SubPlan", ↵│
│ "Subplan Name": "SubPlan
1", ↵│
│ "Startup Cost":
13.66, ↵│
│ "Total Cost":
13.67, ↵│
│ "Plan Rows":
3, ↵│
│ "Plan Width":
8, ↵│
│ "Actual Startup Time":
0.094, ↵│
│ "Actual Total Time":
0.095, ↵│
│ "Actual Rows":
3, ↵│
│ "Actual Loops":
77, ↵│
│ "Plans":
[ ↵│

{ ↵│
│ "Node Type":
"Sort", ↵│
│ "Parent Relationship":
"Outer", ↵│
│ "Startup Cost":
13.66, ↵│
│ "Total Cost":
13.86, ↵│
│ "Plan Rows":
81, ↵│
│ "Plan Width":
8, ↵│
│ "Actual Startup Time":
0.092, ↵│
│ "Actual Total Time":
0.093, ↵│
│ "Actual Rows":
3, ↵│
│ "Actual Loops":
77, ↵│
│ "Sort Key": ["((obce_1.pocet_muzu +
obce_1.pocet_zen)) DESC"],↵│
│ "Sort Method":
"quicksort", ↵│
│ "Sort Space Used":
25, ↵│
│ "Sort Space Type":
"Memory", ↵│
│ "Plans":
[ ↵│

{ ↵│
│ "Node Type": "Index
Scan", ↵│
│ "Parent Relationship":
"Outer", ↵│
│ "Scan Direction":
"Forward", ↵│
│ "Index Name":
"obce_okres_id_idx", ↵│
│ "Relation Name":
"obce", ↵│
│ "Alias":
"obce_1", ↵│
│ "Startup Cost":
0.28, ↵│
│ "Total Cost":
12.62, ↵│
│ "Plan Rows":
81, ↵│
│ "Plan Width":
8, ↵│
│ "Actual Startup Time":
0.015, ↵│
│ "Actual Total Time":
0.065, ↵│
│ "Actual Rows":
81, ↵│
│ "Actual Loops":
77, ↵│
│ "Index Cond": "(okresy.id =
(okres_id)::text)", ↵│
│ "Rows Removed by Index Recheck":
0 ↵│

} ↵│

] ↵│

} ↵│

] ↵│

} ↵│

] ↵│

} ↵│

] ↵│

}
↵│

]
↵│

},
↵│
│ "Planning Time":
0.496, ↵│
│ "Triggers":
[ ↵│

],
↵│
│ "Execution Time":
9.634 ↵│

}
↵│

]

└──────────────────────────────────────────────────────────────────────────────────────┘
(1 row)

>
> --
> Robert Haas
> EnterpriseDB: http://www.enterprisedb.com
> The Enterprise PostgreSQL Company
>

In response to

Responses

Browse pgsql-hackers by date

  From Date Subject
Next Message Robert Haas 2016-07-07 20:15:58 Re: Comment typo in _readExtensibleNode()
Previous Message Robert Haas 2016-07-07 20:10:30 Re: A Modest Upgrade Proposal