I had never changed `join_collapse_limit` it is still out commented is this not default.
When I try to run EXPLAIN ANALYZE on my query in PostgreSQL 9.2.1 it runs for 6
hours (21724001 ms) and then gives this error:
ERROR: could not load library "C:/Program
Files/PostgreSQL/9.2/lib/postgis-2.0.dll": Invalid access to memory location.
********** Error **********
ERROR: could not load library "C:/Program
Files/PostgreSQL/9.2/lib/postgis-2.0.dll": Invalid access to memory location.
SQL state: 58P01
Running EXPLAIN ANALYZE on the query under 9.2.0 is no problem and it gives
this result:
"HashAggregate (cost=3160.16..3160.19 rows=1 width=963) (actual
time=191.083..192.107 rows=2171 loops=1)"
" -> Nested Loop (cost=395.14..3160.10 rows=1 width=963) (actual
time=3.147..185.751 rows=2171 loops=1)"
" -> Nested Loop (cost=395.14..3153.84 rows=1 width=965) (actual
time=3.128..174.052 rows=2171 loops=1)"
" Join Filter: (o."ObjectId" = a16."ObjectId")"
" -> Nested Loop (cost=395.14..3147.73 rows=1 width=1025)
(actual time=3.125..168.864 rows=2171 loops=1)"
" -> Nested Loop (cost=395.14..3141.50 rows=1 width=1027)
(actual time=3.121..163.960 rows=2171 loops=1)"
" Join Filter: (o."ObjectId" = a15."ObjectId")"
" -> Nested Loop (cost=395.14..3135.38 rows=1
width=1019) (actual time=3.118..158.695 rows=2197 loops=1)"
" -> Nested Loop (cost=395.14..3129.12 rows=1
width=1021) (actual time=3.114..153.753 rows=2197 loops=1)"
" Join Filter: (o."ObjectId" =
a14."ObjectId")"
" -> Nested Loop (cost=395.14..3123.00
rows=1 width=1013) (actual time=3.111..148.162 rows=2197 loops=1)"
" -> Nested Loop
(cost=395.14..3116.77 rows=1 width=1015) (actual time=3.107..143.292 rows=2197
loops=1)"
" Join Filter: (o."ObjectId" =
a13."ObjectId")"
" -> Nested Loop
(cost=395.14..3110.65 rows=1 width=1007) (actual time=3.103..137.994 rows=2197
loops=1)"
" -> Nested Loop
(cost=395.14..3104.42 rows=1 width=1009) (actual time=3.100..132.970 rows=2197
loops=1)"
" Join Filter:
(o."ObjectId" = a12."ObjectId")"
" -> Nested Loop
(cost=395.14..3098.30 rows=1 width=1001) (actual time=3.096..127.668 rows=2197
loops=1)"
" -> Nested
Loop (cost=395.14..3092.05 rows=1 width=1003) (actual time=3.092..122.811
rows=2197 loops=1)"
" Join
Filter: (o."ObjectId" = a11."ObjectId")"
" ->
Nested Loop (cost=395.14..3085.93 rows=1 width=995) (actual
time=3.089..117.657 rows=2197 loops=1)"
"
-> Nested Loop (cost=395.14..3079.68 rows=1 width=997) (actual
time=3.085..112.684 rows=2197 loops=1)"
"
Join Filter: (o."ObjectId" = a10."ObjectId")"
"
-> Nested Loop (cost=395.14..3073.56 rows=1 width=989) (actual
time=3.080..107.390 rows=2197 loops=1)"
"
-> Nested Loop (cost=395.14..3067.32 rows=1 width=991) (actual
time=3.077..102.504 rows=2197 loops=1)"
"
Join Filter: (o."ObjectId" = a9."ObjectId")"
"
-> Nested Loop (cost=395.14..3061.20 rows=1 width=983)
(actual time=3.073..97.326 rows=2197 loops=1)"
"
-> Nested Loop (cost=395.14..3054.97 rows=1
width=985) (actual time=3.069..92.368 rows=2197 loops=1)"
"
Join Filter: (o."ObjectId" = a8."ObjectId")"
"
-> Nested Loop (cost=395.14..3048.85 rows=1
width=977) (actual time=3.064..87.042 rows=2197 loops=1)"
"
-> Nested Loop (cost=395.14..3042.63
rows=1 width=979) (actual time=3.062..82.081 rows=2197 loops=1)"
"
Join Filter: (o."ObjectId" =
a7."ObjectId")"
"
-> Nested Loop
(cost=395.14..3036.51 rows=1 width=971) (actual time=3.058..76.742 rows=2197
loops=1)"
"
-> Nested Loop
(cost=395.14..3030.32 rows=1 width=973) (actual time=3.054..71.805 rows=2197
loops=1)"
"
Join Filter:
(o."ObjectId" = a6."ObjectId")"
"
-> Nested Loop
(cost=395.14..3024.20 rows=1 width=965) (actual time=3.050..66.507 rows=2197
loops=1)"
"
-> Nested Loop
(cost=395.14..3018.00 rows=1 width=967) (actual time=3.047..61.582 rows=2197
loops=1)"
"
Join Filter:
(o."ObjectId" = a5."ObjectId")"
"
-> Nested
Loop (cost=395.14..3011.88 rows=1 width=959) (actual time=3.043..56.385
rows=2197 loops=1)"
"
->
Nested Loop (cost=395.14..3005.68 rows=1 width=961) (actual time=3.039..51.412
rows=2197 loops=1)"
"
Join Filter: (o."ObjectId" = a4."ObjectId")"
"
-> Nested Loop (cost=395.14..2999.57 rows=1 width=953) (actual
time=3.035..46.059 rows=2197 loops=1)"
"
-> Nested Loop (cost=395.14..2993.31 rows=1 width=955) (actual
time=3.032..41.045 rows=2197 loops=1)"
"
Join Filter: (o."ObjectId" = a3."ObjectId")"
"
-> Nested Loop (cost=395.14..2932.13 rows=10 width=947) (actual
time=3.027..35.512 rows=2197 loops=1)"
"
-> Nested Loop (cost=395.14..2869.57 rows=10 width=949)
(actual time=3.021..30.310 rows=2197 loops=1)"
"
-> Nested Loop Left Join (cost=395.14..2807.16 rows=10
width=951) (actual time=3.015..24.158 rows=2197 loops=1)"
"
-> Nested Loop (cost=395.14..2754.55 rows=10
width=942) (actual time=3.009..19.635 rows=2197 loops=1)"
"
-> Nested Loop (cost=395.14..2697.92
rows=10 width=48) (actual time=3.004..14.230 rows=2197 loops=1)"
"
Join Filter: (o."ObjectId" =
a1."ObjectId")"
"
-> Hash Join (cost=395.14..2226.83
rows=77 width=40) (actual time=2.989..5.702 rows=2197 loops=1)"
"
Hash Cond: (a2."ObjectId" =
o."ObjectId")"
"
-> Bitmap Heap Scan on
"Attribute" a2 (cost=40.68..1863.79 rows=2083 width=8) (actual
time=0.226..1.177 rows=2227 loops=1)"
"
Recheck Cond: ("MetaId" =
2983)"
"
-> Bitmap Index Scan on
ix_metaid_attribute (cost=0.00..40.16 rows=2083 width=0) (actual
time=0.175..0.175 rows=2227 loops=1)"
"
Index Cond:
("MetaId" = 2983)"
"
-> Hash (cost=346.15..346.15
rows=665 width=32) (actual time=2.756..2.756 rows=2197 loops=1)"
"
Buckets: 1024 Batches: 1
Memory Usage: 137kB"
"
-> Hash Join
(cost=235.20..346.15 rows=665 width=32) (actual time=0.980..2.335 rows=2197
loops=1)"
"
Hash Cond:
(gr."ObjectId" = o."ObjectId")"
"
-> Seq Scan on
"GeoRel" gr (cost=0.00..77.53 rows=5353 width=8) (actual time=0.005..0.357
rows=5353 loops=1)"
"
-> Hash
(cost=207.37..207.37 rows=2227 width=24) (actual time=0.966..0.966 rows=2227
loops=1)"
"
Buckets: 1024
Batches: 1 Memory Usage: 122kB"
"
-> Bitmap
Heap Scan on "Object" o (cost=45.53..207.37 rows=2227 width=24) (actual
time=0.153..0.581 rows=2227 loops=1)"
"
Recheck
Cond: ("ClassId" = 12)"
"
->
Bitmap Index Scan on ix_classid_object (cost=0.00..44.97 rows=2227 width=0)
(actual time=0.139..0.139 rows=2227 loops=1)"
"
Index Cond: ("ClassId" = 12)"
"
-> Index Scan using cover_attribute
on "Attribute" a1 (cost=0.00..6.11 rows=1 width=8) (actual time=0.003..0.003
rows=1 loops=2197)"
"
Index Cond: (("ObjectId" =
gr."ObjectId") AND ("MetaId" = 113))"
"
-> Index Scan using ix_objectid_geoobject
on "GeoObject" go (cost=0.00..5.65 rows=1 width=898) (actual time=0.002..0.002
rows=1 loops=2197)"
"
Index Cond: ("ObjectId" =
gr."GeoObjectId")"
"
-> Index Scan using "Definition_pkey" on
"Definition" d (cost=0.00..5.25 rows=1 width=17) (actual time=0.001..0.001
rows=1 loops=2197)"
"
Index Cond: (o."SubClassid" = "MetaId")"
"
-> Index Scan using ix_attributeid_attributevalue on
"AttributeValue" av1 (cost=0.00..6.23 rows=1 width=6) (actual
time=0.002..0.002 rows=1 loops=2197)"
"
Index Cond: ("AttributeId" = a1."AttributeId")"
"
-> Index Scan using ix_attributeid_attributevalue on
"AttributeValue" av2 (cost=0.00..6.25 rows=1 width=6) (actual
time=0.002..0.002 rows=1 loops=2197)"
"
Index Cond: ("AttributeId" = a2."AttributeId")"
"
-> Index Scan using cover_attribute on "Attribute" a3
(cost=0.00..6.11 rows=1 width=8) (actual time=0.002..0.002 rows=1 loops=2197)"
"
Index Cond: (("ObjectId" = gr."ObjectId") AND ("MetaId" =
2534))"
"
-> Index Scan using ix_attributeid_attributevalue on "AttributeValue" av3
(cost=0.00..6.24 rows=1 width=6) (actual time=0.002..0.002 rows=1 loops=2197)"
"
Index Cond: ("AttributeId" = a3."AttributeId")"
"
-> Index Scan using cover_attribute on "Attribute" a4 (cost=0.00..6.11 rows=1
width=8) (actual time=0.002..0.002 rows=1 loops=2197)"
"
Index Cond: (("ObjectId" = gr."ObjectId") AND ("MetaId" = 492))"
"
->
Index Scan using ix_attributeid_attributevalue on "AttributeValue" av4
(cost=0.00..6.19 rows=1 width=6) (actual time=0.001..0.002 rows=1 loops=2197)"
"
Index Cond: ("AttributeId" = a4."AttributeId")"
"
-> Index
Scan using cover_attribute on "Attribute" a5 (cost=0.00..6.11 rows=1 width=8)
(actual time=0.002..0.002 rows=1 loops=2197)"
"
Index
Cond: (("ObjectId" = gr."ObjectId") AND ("MetaId" = 111))"
"
-> Index Scan
using ix_attributeid_attributevalue on "AttributeValue" av5 (cost=0.00..6.19
rows=1 width=6) (actual time=0.001..0.002 rows=1 loops=2197)"
"
Index Cond:
("AttributeId" = a5."AttributeId")"
"
-> Index Scan using
cover_attribute on "Attribute" a6 (cost=0.00..6.11 rows=1 width=8) (actual
time=0.002..0.002 rows=1 loops=2197)"
"
Index Cond:
(("ObjectId" = gr."ObjectId") AND ("MetaId" = 2470))"
"
-> Index Scan using
ix_attributeid_attributevalue on "AttributeValue" av6 (cost=0.00..6.18 rows=1
width=6) (actual time=0.001..0.002 rows=1 loops=2197)"
"
Index Cond:
("AttributeId" = a6."AttributeId")"
"
-> Index Scan using cover_attribute
on "Attribute" a7 (cost=0.00..6.11 rows=1 width=8) (actual time=0.002..0.002
rows=1 loops=2197)"
"
Index Cond: (("ObjectId" =
gr."ObjectId") AND ("MetaId" = 2469))"
"
-> Index Scan using
ix_attributeid_attributevalue on "AttributeValue" av7 (cost=0.00..6.21 rows=1
width=6) (actual time=0.001..0.002 rows=1 loops=2197)"
"
Index Cond: ("AttributeId" =
a7."AttributeId")"
"
-> Index Scan using cover_attribute on
"Attribute" a8 (cost=0.00..6.11 rows=1 width=8) (actual time=0.002..0.002
rows=1 loops=2197)"
"
Index Cond: (("ObjectId" = gr."ObjectId")
AND ("MetaId" = 2982))"
"
-> Index Scan using ix_attributeid_attributevalue on
"AttributeValue" av8 (cost=0.00..6.22 rows=1 width=6) (actual
time=0.001..0.002 rows=1 loops=2197)"
"
Index Cond: ("AttributeId" = a8."AttributeId")"
"
-> Index Scan using cover_attribute on "Attribute" a9
(cost=0.00..6.11 rows=1 width=8) (actual time=0.002..0.002 rows=1 loops=2197)"
"
Index Cond: (("ObjectId" = gr."ObjectId") AND
("MetaId" = 2961))"
"
-> Index Scan using ix_attributeid_attributevalue on
"AttributeValue" av9 (cost=0.00..6.23 rows=1 width=6) (actual
time=0.001..0.002 rows=1 loops=2197)"
"
Index Cond: ("AttributeId" = a9."AttributeId")"
"
-> Index Scan using cover_attribute on "Attribute" a10
(cost=0.00..6.11 rows=1 width=8) (actual time=0.002..0.002 rows=1 loops=2197)"
"
Index Cond: (("ObjectId" = gr."ObjectId") AND ("MetaId" = 2965))"
"
-> Index Scan using ix_attributeid_attributevalue on "AttributeValue" av10
(cost=0.00..6.25 rows=1 width=6) (actual time=0.001..0.002 rows=1 loops=2197)"
"
Index Cond: ("AttributeId" = a10."AttributeId")"
" ->
Index Scan using cover_attribute on "Attribute" a11 (cost=0.00..6.11 rows=1
width=8) (actual time=0.002..0.002 rows=1 loops=2197)"
"
Index Cond: (("ObjectId" = gr."ObjectId") AND ("MetaId" = 2970))"
" -> Index
Scan using ix_attributeid_attributevalue on "AttributeValue" av11
(cost=0.00..6.24 rows=1 width=6) (actual time=0.001..0.002 rows=1 loops=2197)"
"
Index Cond: ("AttributeId" = a11."AttributeId")"
" -> Index Scan
using cover_attribute on "Attribute" a12 (cost=0.00..6.11 rows=1 width=8)
(actual time=0.002..0.002 rows=1 loops=2197)"
" Index
Cond: (("ObjectId" = gr."ObjectId") AND ("MetaId" = 115))"
" -> Index Scan using
ix_attributeid_attributevalue on "AttributeValue" av12 (cost=0.00..6.22 rows=1
width=6) (actual time=0.001..0.002 rows=1 loops=2197)"
" Index Cond:
("AttributeId" = a12."AttributeId")"
" -> Index Scan using
cover_attribute on "Attribute" a13 (cost=0.00..6.11 rows=1 width=8) (actual
time=0.002..0.002 rows=1 loops=2197)"
" Index Cond:
(("ObjectId" = gr."ObjectId") AND ("MetaId" = 171))"
" -> Index Scan using
ix_attributeid_attributevalue on "AttributeValue" av13 (cost=0.00..6.22 rows=1
width=6) (actual time=0.001..0.002 rows=1 loops=2197)"
" Index Cond: ("AttributeId" =
a13."AttributeId")"
" -> Index Scan using cover_attribute on
"Attribute" a14 (cost=0.00..6.11 rows=1 width=8) (actual time=0.002..0.002
rows=1 loops=2197)"
" Index Cond: (("ObjectId" =
gr."ObjectId") AND ("MetaId" = 172))"
" -> Index Scan using
ix_attributeid_attributevalue on "AttributeValue" av14 (cost=0.00..6.25 rows=1
width=6) (actual time=0.001..0.002 rows=1 loops=2197)"
" Index Cond: ("AttributeId" =
a14."AttributeId")"
" -> Index Scan using cover_attribute on "Attribute"
a15 (cost=0.00..6.11 rows=1 width=8) (actual time=0.002..0.002 rows=1
loops=2197)"
" Index Cond: (("ObjectId" = gr."ObjectId") AND
("MetaId" = 2987))"
" -> Index Scan using ix_attributeid_attributevalue on
"AttributeValue" av15 (cost=0.00..6.22 rows=1 width=6) (actual
time=0.001..0.002 rows=1 loops=2171)"
" Index Cond: ("AttributeId" = a15."AttributeId")"
" -> Index Scan using cover_attribute on "Attribute" a16
(cost=0.00..6.11 rows=1 width=8) (actual time=0.002..0.002 rows=1 loops=2171)"
" Index Cond: (("ObjectId" = gr."ObjectId") AND ("MetaId" =
1590))"
" -> Index Scan using ix_attributeid_attributevalue on "AttributeValue"
av16 (cost=0.00..6.24 rows=1 width=6) (actual time=0.001..0.002 rows=1
loops=2171)"
" Index Cond: ("AttributeId" = a16."AttributeId")"
"Total runtime: 192.953 ms"
Regards
/Daniel Hedén
-----Original Message-----
From: Craig Ringer [mailto:ring...@ringerc.id.au]
Sent: den 16 oktober 2012 04:31
To: Hedén Daniel
Cc: pgsql-bugs@postgresql.org
Subject: Re: [BUGS] BUG #7602: Select with many joins against the same table is
very slow compared to 9.2.0.
On 10/15/2012 06:55 PM, daniel.he...@sweco.se wrote:
> The following bug has been logged on the website:
>
> Bug reference: 7602
> Logged by: Daniel Hedén
> Email address: daniel.he...@sweco.se
> PostgreSQL version: 9.2.1
> Operating system: Windows 7 / Vista 64-Bit
> Description:
>
> Select with many joins against the same table is very slow compared to
> 9.2.0.
> In my case 16 times, this query takes a second max on 9.2.0 but on
> 9.2.1 it takes more than 30 minutes.
Could you have accidentally reset `join_collapse_limit` to its default value?
Show `EXPLAIN ANALYZE` output for both old and new cases, if possible.
At least for the new one.
(Please reply to the mailing list, not to me).
--
Craig Ringer
--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs
