Double ocurring Subplan

I am listing the query, it's explain output and explain analyze output at
the end.

The EXPLAIN output shows the 'Subplan 2' node only once, whereas EXPLAIN
ANALYZE output shows that the 'Subplan 2' is being executed twice . Is that
true? Or is it just the plan printer getting confused? Is the confusion
because of the 2 conditions in the WHERE clause of the correlated subquery?

PG Version:
PostgreSQL 9.0.3 on x86_64-unknown-linux-gnu, compiled by GCC gcc
(Ubuntu/Linaro 4.4.4-14ubuntu5) 4.4.5, 64-bit

The query:

select d.m1 - h.m1
from tz_test as d
join tz_test_history as h
on d.server_id = h.server_id
where d.server_id = 5
and h.recorded_time = (select max(recorded_time)
from tz_test_history as h2
where h2.server_id = d.server_id
and h2.recorded_time < d.recorded_time);

The explain output:
QUERY
PLAN
------------------------------------------------------------------------------------------------------------------------------------------------
Nested Loop (cost=2.26..15.54 rows=1 width=8)
-> Seq Scan on tz_test d (cost=0.00..1.62 rows=1 width=16)
Filter: (server_id = 5)
-> Index Scan using tz_test_hist_rec_time_idx on tz_test_history h
(cost=2.26..11.64 rows=1 width=16)
Index Cond: (h.recorded_time = (SubPlan 2))
Filter: (h.server_id = 5)
SubPlan 2
-> Result (cost=2.25..2.26 rows=1 width=0)
InitPlan 1 (returns $2)
-> Limit (cost=0.00..2.25 rows=1 width=8)
-> Index Scan Backward using
tz_test_hist_rec_time_idx on tz_test_history h2 (cost=0.00..10800.38
rows=4800 width=8)
Index Cond: ((recorded_time IS NOT NULL) AND
(recorded_time < $1))
Filter: (server_id = $0)

explain analyze output:

QUERY PLAN
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Nested Loop (cost=2.26..15.54 rows=1 width=8) (actual time=0.236..0.289
rows=1 loops=1)
-> Seq Scan on tz_test d (cost=0.00..1.62 rows=1 width=16) (actual
time=0.031..0.072 rows=1 loops=1)
Filter: (server_id = 5)
-> Index Scan using tz_test_hist_rec_time_idx on tz_test_history h
(cost=2.26..11.64 rows=1 width=16) (actual time=0.103..0.112 rows=1 loops=1)
Index Cond: (h.recorded_time = (SubPlan 2))
Filter: (h.server_id = 5)
SubPlan 2
-> Result (cost=2.25..2.26 rows=1 width=0) (actual
time=0.078..0.080 rows=1 loops=1)
InitPlan 1 (returns $2)
-> Limit (cost=0.00..2.25 rows=1 width=8) (actual
time=0.064..0.066 rows=1 loops=1)
-> Index Scan Backward using
tz_test_hist_rec_time_idx on tz_test_history h2 (cost=0.00..10800.38
rows=4800 width=8) (actual time=0.058..0.058 rows=1 loops=1)
Index Cond: ((recorded_time IS NOT NULL) AND
(recorded_time < $1))
Filter: (server_id = $0)
SubPlan 2
-> Result (cost=2.25..2.26 rows=1 width=0) (actual
time=0.078..0.080 rows=1 loops=1)
InitPlan 1 (returns $2)
-> Limit (cost=0.00..2.25 rows=1 width=8) (actual
time=0.064..0.066 rows=1 loops=1)
-> Index Scan Backward using
tz_test_hist_rec_time_idx on tz_test_history h2 (cost=0.00..10800.38
rows=4800 width=8) (actual time=0.058..0.058 rows=1 loops=1)
Index Cond: ((recorded_time IS NOT NULL) AND
(recorded_time < $1))
Filter: (server_id = $0)
Total runtime: 0.525 ms
(21 rows)

--
Gurjeet Singh
EnterpriseDB Corporation
The Enterprise PostgreSQL Company

Gurjeet Singh <singh(dot)gurjeet(at)gmail(dot)com> writes:
> I am listing the query, it's explain output and explain analyze output at
> the end.

> The EXPLAIN output shows the 'Subplan 2' node only once, whereas EXPLAIN
> ANALYZE output shows that the 'Subplan 2' is being executed twice . Is that
> true? Or is it just the plan printer getting confused? Is the confusion
> because of the 2 conditions in the WHERE clause of the correlated subquery?

The reason it looks like that is that the SubPlan is referenced in the
index condition, and there are actually two copies of that (indxqual and
indxqualorig). They both point at the same physical subplan, but there
are two entries in the parent node's subPlan list. In EXPLAIN you only
see one because ExecInitIndexScan skips initializing the indxquals in
EXPLAIN_ONLY mode.

In short: it's cosmetic.

We could probably suppress the duplicate printout when both references
are in the same plan node, but in bitmap scans the indxqual and
indxqualorig expressions are actually in different plan nodes (the
indexscan and heapscan respectively). I'm not sure how we could
suppress the duplicate printout in that case, or whether it would even
make sense to do so --- after all, the subplan can in fact get called by
both nodes.

regards, tom lane

On Fri, May 13, 2011 at 6:02 PM, Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us> wrote:

> Gurjeet Singh <singh(dot)gurjeet(at)gmail(dot)com> writes:
> > I am listing the query, it's explain output and explain analyze output at
> > the end.
>
> > The EXPLAIN output shows the 'Subplan 2' node only once, whereas EXPLAIN
> > ANALYZE output shows that the 'Subplan 2' is being executed twice . Is
> that
> > true? Or is it just the plan printer getting confused? Is the confusion
> > because of the 2 conditions in the WHERE clause of the correlated
> subquery?
>
> The reason it looks like that is that the SubPlan is referenced in the
> index condition, and there are actually two copies of that (indxqual and
> indxqualorig). They both point at the same physical subplan, but there
> are two entries in the parent node's subPlan list. In EXPLAIN you only
> see one because ExecInitIndexScan skips initializing the indxquals in
> EXPLAIN_ONLY mode.
>
> In short: it's cosmetic.
>

That's a relief

>
> We could probably suppress the duplicate printout when both references
> are in the same plan node, but in bitmap scans the indxqual and
> indxqualorig expressions are actually in different plan nodes (the
> indexscan and heapscan respectively). I'm not sure how we could
> suppress the duplicate printout in that case, or whether it would even
> make sense to do so --- after all, the subplan can in fact get called by
> both nodes.
>

As long as it's not being re-evaluated, it's not a big deal.

It does confuse the casual onlooker, though; and if there's any automatic
tool to parse and report explain analyze output, it might get its numbers
quite wrong.

Regards,
--
Gurjeet Singh
EnterpriseDB Corporation
The Enterprise PostgreSQL Company