BUG #5673: Optimizer creates strange execution plan leading to wrong results

From: "David Schmitt" <david(at)dasz(dot)at>
To: pgsql-bugs(at)postgresql(dot)org
Subject: BUG #5673: Optimizer creates strange execution plan leading to wrong results
Date: 2010-09-23 15:03:11
Message-ID: 201009231503.o8NF3Blt059661@wwwmaster.postgresql.org
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs


The following bug has been logged online:

Bug reference: 5673
Logged by: David Schmitt
Email address: david(at)dasz(dot)at
PostgreSQL version: 8.4.4
Operating system: Windows 7
Description: Optimizer creates strange execution plan leading to
wrong results
Details:

Background: The following statement is a slightly modfied version of a
statement created by the Entity Framework OR-Mapper when doing a specific
query involving the DefaultPropertyValues base class and the three child
classes CurrentDateTimeDefaultValues, NewGuidDefaultValues,
EnumDefaultValues. There are 60 unique rows in DefaultProperty Values, each
of which is referenced by exactly one row in either
CurrentDateTimeDefaultValues(5 rows), NewGuidDefaultValues(54 rows), or
EnumDefaultValues (1 row). All tables have an ID column and appropriate
PK/FK constraints modeling the inheritance.

Analysis: In the first case the optimizer creates a single Append operation
for the three sequential table scans (lines 10-13) and creates an additional
Index Scan on EnumDefaultValues (lines 14,15) which results in 61 rows
returned in 09. Particularily suspicious are the tow references to the
Extent5 alias on lines 13 and 14. In the second run, I dropped the primary
key on EnumDefaultValues. Now the Append on line 09 returns 60 rows and the
execution plan references EnumDefaultValues only once.

select *
from "dbo"."DefaultPropertyValues" AS "Extent1"
INNER JOIN "dbo"."DefaultPropertyValues" AS "Extent2" ON
"Extent1"."ID"="Extent2"."ID"
LEFT JOIN (
SELECT "UnionAll1"."ID" AS "C1","UnionAll1"."C1" AS "C2","UnionAll1"."C2"
AS "C3","UnionAll1"."C3" AS "C4","UnionAll1"."C4" AS "fk_EnumVal" FROM (
SELECT "Extent3"."ID" AS "ID",TRUE AS "C1",FALSE AS "C2",FALSE AS
"C3",CAST (NULL AS int4) AS "C4"
FROM "dbo"."CurrentDateTimeDefaultValues" AS "Extent3"
UNION ALL
SELECT "Extent4"."ID" AS "ID", TRUE AS "C1",FALSE AS "C2",TRUE AS
"C3",CAST (NULL AS int4) AS "C4"
FROM "dbo"."NewGuidDefaultValues" AS "Extent4") AS "UnionAll1"
UNION ALL
SELECT "Extent5"."ID" AS "ID",FALSE AS "C1",TRUE AS "C2",FALSE AS
"C3","Extent5"."fk_EnumValue" AS "fk_EnumValue"
FROM "dbo"."EnumDefaultValues" AS "Extent5") AS "UnionAll2"
ON "Extent2"."ID"="UnionAll2"."C1"
WHERE ("Extent1"."fk_Property" IS NOT NULL ) AND ("Extent1"."fk_Property"=
(((783))))

Result:
60;"2010-09-20 13:22:17.773308";"2010-09-20
13:22:17.773308";"ecbd6901-13e8-4beb-a6a2-0548eba345a8";;;783;60;"2010-09-20
13:22:17.773308";"2010-09-20
13:22:17.773308";"ecbd6901-13e8-4beb-a6a2-0548eba345a8";;;783;60;f;t;f;3
60;"2010-09-20 13:22:17.773308";"2010-09-20
13:22:17.773308";"ecbd6901-13e8-4beb-a6a2-0548eba345a8";;;783;60;"2010-09-20
13:22:17.773308";"2010-09-20
13:22:17.773308";"ecbd6901-13e8-4beb-a6a2-0548eba345a8";;;783;60;f;t;f;3

EXPLAIN ANALYZE:
01 "Nested Loop Left Join (cost=1.76..7.42 rows=1 width=100) (actual
time=0.121..0.134 rows=2 loops=1)"
02 " Join Filter: ("Extent2"."ID" = "Extent3"."ID")"
03 " -> Hash Join (cost=1.76..3.60 rows=1 width=96) (actual
time=0.061..0.061 rows=1 loops=1)"
04 " Hash Cond: ("Extent2"."ID" = "Extent1"."ID")"
05 " -> Seq Scan on "DefaultPropertyValues" "Extent2"
(cost=0.00..1.60 rows=60 width=48) (actual time=0.008..0.013 rows=60
loops=1)"
06 " -> Hash (cost=1.75..1.75 rows=1 width=48) (actual
time=0.025..0.025 rows=1 loops=1)"
07 " -> Seq Scan on "DefaultPropertyValues" "Extent1"
(cost=0.00..1.75 rows=1 width=48) (actual time=0.023..0.024 rows=1
loops=1)"
08 " Filter: (("fk_Property" IS NOT NULL) AND
("fk_Property" = 783))"
09 " -> Append (cost=0.00..4.07 rows=61 width=11) (actual
time=0.005..0.046 rows=61 loops=1)"
10 " -> Append (cost=0.00..3.60 rows=60 width=11) (actual
time=0.004..0.028 rows=60 loops=1)"
11 " -> Seq Scan on "CurrentDateTimeDefaultValues" "Extent3"
(cost=0.00..1.05 rows=5 width=11) (actual time=0.004..0.005 rows=5
loops=1)"
12 " -> Seq Scan on "NewGuidDefaultValues" "Extent4"
(cost=0.00..1.54 rows=54 width=11) (actual time=0.002..0.014 rows=54
loops=1)"
13 " -> Seq Scan on "EnumDefaultValues" "Extent5"
(cost=0.00..1.01 rows=1 width=11) (actual time=0.002..0.002 rows=1
loops=1)"
14 " -> Index Scan using "PK_[zbox].[dbo].[EnumDefaultValues]" on
"EnumDefaultValues" "Extent5" (cost=0.00..0.47 rows=1 width=11) (actual
time=0.009..0.010 rows=1 loops=1)"
15 " Index Cond: ("Extent2"."ID" = "Extent5"."ID")"
16 "Total runtime: 0.258 ms"

Result:
60;"2010-09-20 13:22:17.773308";"2010-09-20
13:22:17.773308";"ecbd6901-13e8-4beb-a6a2-0548eba345a8";;;783;60;"2010-09-20
13:22:17.773308";"2010-09-20
13:22:17.773308";"ecbd6901-13e8-4beb-a6a2-0548eba345a8";;;783;60;f;t;f;3

EXPLAIN ANALYZE:
01 "Nested Loop Left Join (cost=1.76..7.95 rows=1 width=100) (actual
time=0.109..0.111 rows=1 loops=1)"
02 " Join Filter: ("Extent2"."ID" = "Extent3"."ID")"
03 " -> Hash Join (cost=1.76..3.60 rows=1 width=96) (actual
time=0.057..0.058 rows=1 loops=1)"
04 " Hash Cond: ("Extent2"."ID" = "Extent1"."ID")"
05 " -> Seq Scan on "DefaultPropertyValues" "Extent2"
(cost=0.00..1.60 rows=60 width=48) (actual time=0.006..0.011 rows=60
loops=1)"
06 " -> Hash (cost=1.75..1.75 rows=1 width=48) (actual
time=0.024..0.024 rows=1 loops=1)"
07 " -> Seq Scan on "DefaultPropertyValues" "Extent1"
(cost=0.00..1.75 rows=1 width=48) (actual time=0.022..0.023 rows=1
loops=1)"
08 " Filter: (("fk_Property" IS NOT NULL) AND
("fk_Property" = 783))"
09 " -> Append (cost=0.00..3.60 rows=60 width=11) (actual
time=0.004..0.027 rows=60 loops=1)"
10 " -> Seq Scan on "CurrentDateTimeDefaultValues" "Extent3"
(cost=0.00..1.05 rows=5 width=11) (actual time=0.003..0.005 rows=5
loops=1)"
11 " -> Seq Scan on "NewGuidDefaultValues" "Extent4"
(cost=0.00..1.54 rows=54 width=11) (actual time=0.002..0.014 rows=54
loops=1)"
12 " -> Seq Scan on "EnumDefaultValues" "Extent5" (cost=0.00..1.01
rows=1 width=11) (actual time=0.002..0.002 rows=1 loops=1)"
13 "Total runtime: 0.214 ms"

Other versions:

Postgresql 8.3.11-0lenny1 on Debian lenny does not exhibit this problem.
The backported 8.4.4-1~bpo50+1 for lenny does exhibit the problem.

Responses

Browse pgsql-bugs by date

  From Date Subject
Next Message Tom Lane 2010-09-23 15:33:25 Re: BUG #5673: Optimizer creates strange execution plan leading to wrong results
Previous Message Tom Lane 2010-09-23 14:46:20 Re: Postgresql installation on P2020 board