Re: performance drop on 8.2.4, reverting to 8.1.4

From: "Liviu Ionescu" <ilgb(at)livius(dot)net>
To: <pgsql-performance(at)postgresql(dot)org>
Subject: Re: performance drop on 8.2.4, reverting to 8.1.4
Date: 2007-05-18 10:14:56
Message-ID: 007501c79935$63072ec0$653e10ac@ilgvaio
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

> It will probably be useful with EXPLAIN ANALYZE of your
> queries, not just the EXPLAIN.

it took 245 seconds to complete, see below.

> It looks like the planner thinks this is going to be really
> cheap -- so it's misestimating something somewhere. Have you
> ANALYZEd recently?

yes, but to be sure I did it again before issuing the request; no improvements...

regards,

Liviu

"Nested Loop Left Join (cost=32.03..2026.70 rows=1 width=125) (actual time=16.686..244822.521 rows=2026 loops=1)"
" Join Filter: (n.nodeid = public.nodeattributes.nodeid)"
" -> Nested Loop Left Join (cost=26.55..1420.57 rows=1 width=115) (actual time=13.833..176136.527 rows=2026 loops=1)"
" Join Filter: (n.nodeid = public.nodeattributes.nodeid)"
" -> Nested Loop Left Join (cost=21.06..810.90 rows=1 width=105) (actual time=10.336..95476.175 rows=2026 loops=1)"
" Join Filter: (n.nodeid = public.nodeattributes.nodeid)"
" -> Nested Loop Left Join (cost=15.55..194.15 rows=1 width=95) (actual time=6.514..11524.892 rows=2026 loops=1)"
" Join Filter: (n.nodeid = rtunodes.nodeid)"
" -> Nested Loop Left Join (cost=11.17..107.94 rows=1 width=82) (actual time=0.661..71.751 rows=2026 loops=1)"
" Filter: (templatenodes.nodeid IS NULL)"
" -> Hash Left Join (cost=11.17..99.66 rows=1 width=82) (actual time=0.643..36.053 rows=2206 loops=1)"
" Hash Cond: (n.nodeid = templates.nodeid)"
" Filter: (templates.nodeid IS NULL)"
" -> Hash Left Join (cost=8.73..88.06 rows=2270 width=82) (actual time=0.502..27.756 rows=2270 loops=1)"
" Hash Cond: (n.nodeid = rtus.nodeid)"
" -> Hash Left Join (cost=4.34..74.11 rows=2270 width=74) (actual time=0.286..20.179 rows=2270 loops=1)"
" Hash Cond: (n.nodeid = areas.nodeid)"
" -> Hash Left Join (cost=1.43..61.83 rows=2270 width=66) (actual time=0.114..13.062 rows=2270 loops=1)"
" Hash Cond: (n.nodeid = realms.nodeid)"
" -> Seq Scan on nodes n (cost=0.00..51.70 rows=2270 width=49) (actual time=0.016..4.089 rows=2270 loops=1)"
" -> Hash (cost=1.19..1.19 rows=19 width=17) (actual time=0.056..0.056 rows=19 loops=1)"
" -> Seq Scan on realms (cost=0.00..1.19 rows=19 width=17) (actual time=0.006..0.023 rows=19 loops=1)"
" -> Hash (cost=1.85..1.85 rows=85 width=8) (actual time=0.156..0.156 rows=85 loops=1)"
" -> Seq Scan on areas (cost=0.00..1.85 rows=85 width=8) (actual time=0.007..0.070 rows=85 loops=1)"
" -> Hash (cost=3.06..3.06 rows=106 width=8) (actual time=0.200..0.200 rows=106 loops=1)"
" -> Seq Scan on rtus (cost=0.00..3.06 rows=106 width=8) (actual time=0.010..0.105 rows=106 loops=1)"
" -> Hash (cost=1.64..1.64 rows=64 width=4) (actual time=0.119..0.119 rows=64 loops=1)"
" -> Seq Scan on templates (cost=0.00..1.64 rows=64 width=4) (actual time=0.006..0.059 rows=64 loops=1)"
" -> Index Scan using nodeid_pkey on templatenodes (cost=0.00..8.27 rows=1 width=4) (actual time=0.009..0.009 rows=0 loops=2206)"
" Index Cond: (n.nodeid = templatenodes.nodeid)"
" -> Hash Join (cost=4.38..63.51 rows=1816 width=13) (actual time=0.012..4.417 rows=1816 loops=2026)"
" Hash Cond: (rtunodes.rtuid = r.nodeid)"
" -> Seq Scan on rtunodes (cost=0.00..34.16 rows=1816 width=9) (actual time=0.009..1.290 rows=1816 loops=2026)"
" -> Hash (cost=3.06..3.06 rows=106 width=8) (actual time=0.194..0.194 rows=106 loops=1)"
" -> Seq Scan on rtus r (cost=0.00..3.06 rows=106 width=8) (actual time=0.005..0.091 rows=106 loops=1)"
" -> Hash Join (cost=5.51..611.90 rows=388 width=14) (actual time=0.033..39.896 rows=2079 loops=2026)"
" Hash Cond: (a.typeid = t.typeid)"
" -> Hash Join (cost=4.34..604.41 rows=647 width=18) (actual time=0.031..36.513 rows=2079 loops=2026)"
" Hash Cond: (public.nodeattributes.attributeid = a.attributeid)"
" -> Seq Scan on nodeattributes (cost=0.00..505.35 rows=23535 width=18) (actual time=0.008..16.826 rows=23535 loops=2026)"
" -> Hash (cost=4.28..4.28 rows=5 width=8) (actual time=0.077..0.077 rows=5 loops=1)"
" -> Seq Scan on attributes a (cost=0.00..4.28 rows=5 width=8) (actual time=0.033..0.067 rows=5 loops=1)"
" Filter: ((name)::text = 'iconName'::text)"
" -> Hash (cost=1.10..1.10 rows=6 width=4) (actual time=0.023..0.023 rows=6 loops=1)"
" -> Seq Scan on types t (cost=0.00..1.10 rows=6 width=4) (actual time=0.005..0.012 rows=6 loops=1)"
" Filter: isattributetype"
" -> Hash Join (cost=5.49..606.76 rows=233 width=14) (actual time=0.104..38.474 rows=1865 loops=2026)"
" Hash Cond: (a.typeid = t.typeid)"
" -> Hash Join (cost=4.31..601.80 rows=388 width=18) (actual time=0.101..35.484 rows=1865 loops=2026)"
" Hash Cond: (public.nodeattributes.attributeid = a.attributeid)"
" -> Seq Scan on nodeattributes (cost=0.00..505.35 rows=23535 width=18) (actual time=0.008..16.624 rows=23535 loops=2026)"
" -> Hash (cost=4.28..4.28 rows=3 width=8) (actual time=0.071..0.071 rows=3 loops=1)"
" -> Seq Scan on attributes a (cost=0.00..4.28 rows=3 width=8) (actual time=0.019..0.058 rows=3 loops=1)"
" Filter: ((name)::text = 'addUPItemplate'::text)"
" -> Hash (cost=1.10..1.10 rows=6 width=4) (actual time=0.025..0.025 rows=6 loops=1)"
" -> Seq Scan on types t (cost=0.00..1.10 rows=6 width=4) (actual time=0.004..0.012 rows=6 loops=1)"
" Filter: isattributetype"
" -> Hash Join (cost=5.48..604.19 rows=155 width=14) (actual time=0.794..33.783 rows=132 loops=2026)"
" Hash Cond: (a.typeid = t.typeid)"
" -> Hash Join (cost=4.30..600.50 rows=259 width=18) (actual time=0.791..33.550 rows=132 loops=2026)"
" Hash Cond: (public.nodeattributes.attributeid = a.attributeid)"
" -> Seq Scan on nodeattributes (cost=0.00..505.35 rows=23535 width=18) (actual time=0.008..16.623 rows=23535 loops=2026)"
" -> Hash (cost=4.28..4.28 rows=2 width=8) (actual time=0.060..0.060 rows=2 loops=1)"
" -> Seq Scan on attributes a (cost=0.00..4.28 rows=2 width=8) (actual time=0.015..0.054 rows=2 loops=1)"
" Filter: ((name)::text = 'addUPIsubclass'::text)"
" -> Hash (cost=1.10..1.10 rows=6 width=4) (actual time=0.022..0.022 rows=6 loops=1)"
" -> Seq Scan on types t (cost=0.00..1.10 rows=6 width=4) (actual time=0.003..0.009 rows=6 loops=1)"
" Filter: isattributetype"
"Total runtime: 244826.065 ms"

In response to

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Steinar H. Gunderson 2007-05-18 10:46:46 Re: performance drop on 8.2.4, reverting to 8.1.4
Previous Message Steinar H. Gunderson 2007-05-18 09:49:21 Re: performance drop on 8.2.4, reverting to 8.1.4