8.2.4 serious slowdown
| От | Sim Zacks |
|---|---|
| Тема | 8.2.4 serious slowdown |
| Дата | |
| Msg-id | fm5asf$1q0v$1@news.hub.org обсуждение исходный текст |
| Ответы |
Re: 8.2.4 serious slowdown
(Clodoaldo <clodoaldo.pinto.neto@gmail.com>)
Re: 8.2.4 serious slowdown (Sim Zacks <sim@compulab.co.il>) Re: 8.2.4 serious slowdown ("Isak Hansen" <isak.hansen@gmail.com>) Re: 8.2.4 serious slowdown (Bricklen Anderson <banderson@presinet.com>) Re: 8.2.4 serious slowdown (Tom Lane <tgl@sss.pgh.pa.us>) |
| Список | pgsql-general |
I just upgraded my database server from 8.0.1 to 8.2.4
Most things went very well, but I have a couple of queries that really slowed down with the new server.
On 8.0.1 the query took less then 3 seconds to complete. On 8.2.4 the same query
(I vacuumed the database before running the query) takes 60 seconds (10 minutes with Explain Analyze).
The data is exactly the same on the 2 servers.
To test for hardware differences, I loaded 8.0.11 onto a test server restored the database and ran the query.
It took about 3 seconds. I then uninstalled postgresql and installed version 8.2.4 and restored the database
and the query took about 60 seconds.
On the 8.2.4 the CPU usage (as seen from top) goes up to about 97% for most of the 60 seconds of query.
On 8.0.1, it didn't.
I have the explain from both databases, if someone could help me walk through this, I would much appreciate it.
----------------------------------------------------------------------------------------------------------------------
Explain 8.0.1 Fast query
Subquery Scan assemblycanbuild (cost=8495.27..8509.34 rows=13 width=36) (actual time=3585.026..3753.339 rows=83
loops=1)
-> GroupAggregate (cost=8495.27..8509.21 rows=13 width=32) (actual time=3585.015..3752.729 rows=83 loops=1)
-> Subquery Scan assembliesstockbatchpriorexpected (cost=8495.27..8508.30 rows=13 width=32) (actual
time=3584.912..3729.404rows=3684 loops=1)
-> GroupAggregate (cost=8495.27..8508.17 rows=13 width=112) (actual time=3584.900..3699.779 rows=3684
loops=1)
-> Sort (cost=8495.27..8496.23 rows=382 width=112) (actual time=3584.836..3613.432 rows=7400
loops=1)
Sort Key: a.assembliesbatchid, a.duedate, a.assemblyid, a.assemblyname, a.ownerid, a.partid,
a.quantity,a.stock, a.prioruse, a.units, a.qtyperunit
-> Hash Left Join (cost=8220.13..8478.89 rows=382 width=112) (actual
time=2902.740..3407.342rows=7400 loops=1)
Hash Cond: ("outer".partid = "inner".partid)
-> Subquery Scan a (cost=6877.75..6920.40 rows=125 width=88) (actual
time=2700.471..3140.321rows=3684 loops=1)
-> GroupAggregate (cost=6877.75..6919.15 rows=125 width=85) (actual
time=2700.456..3106.694rows=3684 loops=1)
-> Sort (cost=6877.75..6880.86 rows=1245 width=85) (actual
time=2700.414..2839.777rows=36876 loops=1)
Sort Key: a.assembliesbatchid, a.duedate, a.assemblyid,
a.assemblyname,a.ownerid, a.partid, a.quantity, a.stock, a.units, a.qtyperunit, a.leadfree
-> Hash Left Join (cost=6582.30..6813.74 rows=1245 width=85)
(actualtime=1458.482..1887.078 rows=36876 loops=1)
Hash Cond: (("outer".partid = "inner".partid) AND
("outer".leadfree= "inner".leadfree))
Join Filter: ((COALESCE("outer".ownerid, 1) = 1) AND
(("outer".duedate> "inner".duedate) OR (("outer".duedate = "inner".duedate) AND ("outer".assembliesbatchid >
"inner".assembliesbatchid))))
-> Subquery Scan a (cost=6012.11..6068.13 rows=1245
width=81)(actual time=1252.814..1340.992 rows=3684 loops=1)
-> GroupAggregate (cost=6012.11..6055.68 rows=1245
width=82)(actual time=1252.799..1307.969 rows=3684 loops=1)
-> Sort (cost=6012.11..6015.22 rows=1245
width=82)(actual time=1252.759..1265.317 rows=3685 loops=1)
Sort Key: d.assembliesbatchid, d.duedate,
a.assemblyid,a.assemblyname, c.ownerid, e.partid, COALESCE(c.stock, 0::bigint), d.units, e.quantity, a.leadfree
-> Merge Left Join (cost=5816.85..5948.10
rows=1245width=82) (actual time=1169.837..1220.895 rows=3685 loops=1)
Merge Cond: (("outer".batchid =
"inner".refid)AND ("outer".partid = "inner".partid))
Filter: (COALESCE("inner".commited,
false)= false)
-> Sort (cost=2382.11..2385.22
rows=1245width=86) (actual time=682.055..694.675 rows=3684 loops=1)
Sort Key: d.batchid, e.partid
-> Hash Left Join
(cost=737.64..2318.10rows=1245 width=86) (actual time=250.089..665.021 rows=3684 loops=1)
Hash Cond: ("outer".partid
="inner".partid)
Join Filter:
leadcompcheck_ab("outer".leadfree,"inner".leadstateid)
-> Merge Right Join
(cost=722.62..2296.73rows=1245 width=74) (actual time=169.106..506.307 rows=3684 loops=1)
Merge Cond:
(("outer".partid= "inner".partid) AND ("outer".assemblyid = "inner".assemblyid))
-> Index Scan using
idx_u_assidpartidon partsassembly b (cost=0.00..1396.01 rows=34286 width=16) (actual time=0.147..151.393 rows=34286
loops=1)
-> Sort
(cost=722.62..725.74rows=1245 width=66) (actual time=168.091..180.485 rows=3684 loops=1)
Sort Key:
e.partid,a.assemblyid
-> Hash Join
(cost=71.73..658.62rows=1245 width=66) (actual time=12.252..148.296 rows=3684 loops=1)
Hash
Cond:("outer".assemblyid = "inner".assemblyid)
-> Hash
Join (cost=54.68..622.89 rows=1245 width=32) (actual time=6.377..111.172 rows=3684 loops=1)
HashCond: ("outer".assembliesbatchid = "inner".assembliesbatchid)
->
Seq Scan on allocatedassemblies e (cost=0.00..460.93 rows=18967 width=12) (actual time=0.032..51.827 rows=11332
loops=1)
Filter: ((- quantity) <> 0)
->
Hash (cost=54.43..54.43 rows=98 width=24) (actual time=1.364..1.364 rows=0 loops=1)
-> Index Scan using fki_assembliesbatch_assembliesbatchstatus_id, fki_assembliesbatch_assembliesbatchstatus_id,
fki_assembliesbatch_assembliesbatchstatus_id,fki_assembliesbatch_assembliesbatchstatus_id on assembliesbatch d
(cost=0.00..54.43rows=98 width=24) (actual time=0.105..0.985 rows=99 loops=1)
Index Cond: ((assembliesbatchstatusid = 1) OR (assembliesbatchstatusid = 2) OR (assembliesbatchstatusid = 4) OR
(assembliesbatchstatusid= 7))
-> Hash
(cost=15.24..15.24 rows=724 width=38) (actual time=5.844..5.844 rows=0 loops=1)
->
Seq Scan on assemblies a (cost=0.00..15.24 rows=724 width=38) (actual time=0.030..3.149 rows=724 loops=1)
-> Hash
(cost=15.00..15.00rows=5 width=20) (actual time=80.500..80.500 rows=0 loops=1)
-> Function Scan on
stockperowner_lead_abc (cost=0.00..15.00 rows=5 width=20) (actual time=67.238..74.347 rows=1694 loops=1)
Filter:
(ownerid= 1)
-> Sort (cost=3434.74..3498.75
rows=25605width=9) (actual time=313.138..403.616 rows=25267 loops=1)
Sort Key: f.refid, f.partid
-> Seq Scan on stocklog f
(cost=0.00..1559.92rows=25605 width=9) (actual time=0.066..146.728 rows=25267 loops=1)
Filter: (transtypeid = 3)
-> Hash (cost=563.93..563.93 rows=1251 width=21) (actual
time=205.583..205.583rows=0 loops=1)
-> Hash Join (cost=71.73..563.93 rows=1251 width=21)
(actualtime=11.923..190.945 rows=3851 loops=1)
Hash Cond: ("outer".assemblyid =
"inner".assemblyid)
-> Hash Join (cost=54.68..528.12 rows=1251
width=24)(actual time=6.159..155.650 rows=3851 loops=1)
Hash Cond: ("outer".assembliesbatchid =
"inner".assembliesbatchid)
-> Seq Scan on allocatedassemblies b
(cost=0.00..365.62rows=19062 width=12) (actual time=0.029..71.287 rows=19062 loops=1)
-> Hash (cost=54.43..54.43 rows=98
width=16)(actual time=1.287..1.287 rows=0 loops=1)
-> Index Scan using
fki_assembliesbatch_assembliesbatchstatus_id,fki_assembliesbatch_assembliesbatchstatus_id,
fki_assembliesbatch_assembliesbatchstatus_id,fki_assembliesbatch_assembliesbatchstatus_id on assembliesbatch c
(cost=0.00..54.43rows=98 width=16) (actual time=0.090..0.921 rows=99 loops=1)
Index Cond:
((assembliesbatchstatusid= 1) OR (assembliesbatchstatusid = 2) OR (assembliesbatchstatusid = 4) OR
(assembliesbatchstatusid= 7))
-> Hash (cost=15.24..15.24 rows=724 width=5)
(actualtime=5.733..5.733 rows=0 loops=1)
-> Seq Scan on assemblies q
(cost=0.00..15.24rows=724 width=5) (actual time=0.040..3.081 rows=724 loops=1)
-> Hash (cost=1332.57..1332.57 rows=3924 width=28) (actual time=202.198..202.198
rows=0loops=1)
-> Hash Join (cost=592.15..1332.57 rows=3924 width=28) (actual
time=66.119..199.853rows=593 loops=1)
Hash Cond: ("outer".pnid = "inner".pnid)
-> Hash Join (cost=377.64..1019.94 rows=3925 width=32) (actual
time=11.525..139.401rows=593 loops=1)
Hash Cond: ("outer".poid = "inner".poid)
-> Seq Scan on poparts e (cost=0.00..476.60 rows=16860 width=32)
(actualtime=0.037..65.660 rows=16860 loops=1)
-> Hash (cost=373.59..373.59 rows=1620 width=8) (actual
time=11.348..11.348rows=0 loops=1)
-> Seq Scan on pos f (cost=0.00..373.59 rows=1620 width=8)
(actualtime=0.124..10.621 rows=183 loops=1)
Filter: ((postatusid >= 20) AND (postatusid <= 59) AND
(isrfq= false))
-> Hash (cost=197.01..197.01 rows=7001 width=4) (actual
time=54.561..54.561rows=0 loops=1)
-> Seq Scan on manufacturerpartpn g (cost=0.00..197.01 rows=7001
width=4)(actual time=0.035..29.047 rows=7001 loops=1)
Total runtime: 3763.256 ms
---------------------------------------------------------------------------------------------------------------------
8.2.4 Slow query
GroupAggregate (cost=5944.26..5944.50 rows=1 width=32) (actual time=608067.502..608144.235 rows=83 loops=1)
-> GroupAggregate (cost=5944.26..5944.41 rows=1 width=112) (actual time=608067.439..608127.305 rows=3684 loops=1)
-> Sort (cost=5944.26..5944.27 rows=3 width=112) (actual time=608067.381..608083.775 rows=7400 loops=1)
Sort Key: a.assembliesbatchid, a.duedate, a.assemblyid, a.assemblyname, a.ownerid, a.partid, a.quantity,
a.stock,a.prioruse, a.units, a.qtyperunit
-> Nested Loop Left Join (cost=5311.54..5944.24 rows=3 width=112) (actual time=341040.765..607912.624
rows=7400loops=1)
Join Filter: (e.partid = a.partid)
-> GroupAggregate (cost=4689.90..4689.96 rows=1 width=85) (actual time=340891.895..341154.807
rows=3684loops=1)
-> Sort (cost=4689.90..4689.91 rows=1 width=85) (actual time=340891.872..340989.892
rows=36876loops=1)
Sort Key: a.assembliesbatchid, a.duedate, a.assemblyid, a.assemblyname, a.ownerid,
a.partid,a.quantity, a.stock, a.units, a.qtyperunit, a.leadfree
-> Nested Loop Left Join (cost=4224.98..4689.89 rows=1 width=85) (actual
time=22886.336..340100.378rows=36876 loops=1)
Join Filter: ((a.partid = b.partid) AND (COALESCE(a.ownerid, 1) = 1) AND
(a.leadfree= q.leadfree) AND ((a.duedate > c.duedate) OR ((a.duedate = c.duedate) AND (a.assembliesbatchid >
c.assembliesbatchid))))
-> GroupAggregate (cost=4127.29..4127.34 rows=1 width=82) (actual
time=22801.528..22859.419rows=3684 loops=1)
-> Sort (cost=4127.29..4127.30 rows=1 width=82) (actual
time=22801.498..22812.312rows=3685 loops=1)
Sort Key: d.assembliesbatchid, d.duedate, a.assemblyid,
a.assemblyname,c.ownerid, e.partid, COALESCE(c.stock, 0::bigint), d.units, e.quantity, a.leadfree
-> Nested Loop Left Join (cost=3984.15..4127.28 rows=1 width=82)
(actualtime=360.261..22766.654 rows=3685 loops=1)
-> Nested Loop Left Join (cost=3984.15..4126.99 rows=1
width=74)(actual time=360.168..22680.414 rows=3685 loops=1)
Join Filter: ((c.partid = e.partid) AND
leadcompcheck_ab(a.leadfree,c.leadstateid))
-> Nested Loop (cost=3984.15..4111.92 rows=1 width=62)
(actualtime=319.721..411.494 rows=3685 loops=1)
-> Merge Left Join (cost=3984.15..4111.60 rows=1
width=28)(actual time=319.642..348.285 rows=3685 loops=1)
Merge Cond: ((d.batchid = f.refid) AND
(e.partid= f.partid))
Filter: (NOT COALESCE(f.commited, false))
-> Sort (cost=664.36..667.47 rows=1244
width=32)(actual time=68.579..75.827 rows=3684 loops=1)
Sort Key: d.batchid, e.partid
-> Hash Join (cost=71.92..600.42
rows=1244width=32) (actual time=3.199..52.985 rows=3684 loops=1)
Hash Cond: (e.assembliesbatchid
=d.assembliesbatchid)
-> Seq Scan on
allocatedassembliese (cost=0.00..444.93 rows=18967 width=12) (actual time=0.060..25.590 rows=11332 loops=1)
Filter: ((- quantity) <>
0)
-> Hash (cost=70.70..70.70
rows=98width=24) (actual time=0.672..0.672 rows=99 loops=1)
-> Bitmap Heap Scan on
assembliesbatchd (cost=17.75..70.70 rows=98 width=24) (actual time=0.149..0.453 rows=99 loops=1)
Recheck Cond:
(assembliesbatchstatusid= ANY ('{1,2,4,7}'::integer[]))
-> Bitmap Index
Scanon fki_assembliesbatch_assembliesbatchstatus_id (cost=0.00..17.72 rows=98 width=0) (actual time=0.121..0.121
rows=99loops=1)
Index Cond:
(assembliesbatchstatusid= ANY ('{1,2,4,7}'::integer[]))
-> Sort (cost=3319.79..3382.16 rows=24951
width=9)(actual time=160.006..210.204 rows=25267 loops=1)
Sort Key: f.refid, f.partid
-> Bitmap Heap Scan on stocklog f
(cost=417.63..1497.51rows=24951 width=9) (actual time=5.599..63.420 rows=25267 loops=1)
Recheck Cond: (transtypeid = 3)
-> Bitmap Index Scan on
targetidsl (cost=0.00..411.39 rows=24951 width=0) (actual time=5.379..5.379 rows=25267 loops=1)
Index Cond: (transtypeid =
3)
-> Index Scan using assemblies_pkey on assemblies
a (cost=0.00..0.31 rows=1 width=38) (actual time=0.007..0.009 rows=1 loops=3685)
Index Cond: (d.assemblyid = a.assemblyid)
-> Function Scan on stockperowner_lead_ab c
(cost=0.00..15.00rows=5 width=20) (actual time=0.012..3.162 rows=1694 loops=3685)
Filter: (ownerid = 1)
-> Index Scan using idx_u_assidpartid on partsassembly b
(cost=0.00..0.27rows=1 width=16) (actual time=0.010..0.012 rows=1 loops=3685)
Index Cond: ((e.partid = b.partid) AND (b.assemblyid =
a.assemblyid))
-> Hash Join (cost=97.69..531.29 rows=1250 width=21) (actual
time=2.395..78.855rows=3851 loops=3684)
Hash Cond: (b.assembliesbatchid = c.assembliesbatchid)
-> Seq Scan on allocatedassemblies b (cost=0.00..349.62 rows=19062
width=12)(actual time=0.009..35.493 rows=19062 loops=3684)
-> Hash (cost=96.47..96.47 rows=98 width=13) (actual time=3.796..3.796
rows=99loops=1)
-> Hash Join (cost=42.14..96.47 rows=98 width=13) (actual
time=2.939..3.596rows=99 loops=1)
Hash Cond: (c.assemblyid = q.assemblyid)
-> Bitmap Heap Scan on assembliesbatch c (cost=17.85..70.83
rows=98width=16) (actual time=0.137..0.397 rows=99 loops=1)
Recheck Cond: ((assembliesbatchstatusid = 1) OR
(assembliesbatchstatusid= 2) OR (assembliesbatchstatusid = 4) OR (assembliesbatchstatusid = 7))
-> BitmapOr (cost=17.85..17.85 rows=99 width=0)
(actualtime=0.111..0.111 rows=0 loops=1)
-> Bitmap Index Scan on
fki_assembliesbatch_assembliesbatchstatus_id (cost=0.00..4.85 rows=80 width=0) (actual time=0.066..0.066 rows=80
loops=1)
Index Cond: (assembliesbatchstatusid = 1)
-> Bitmap Index Scan on
fki_assembliesbatch_assembliesbatchstatus_id (cost=0.00..4.26 rows=1 width=0) (actual time=0.006..0.006 rows=0 loops=1)
Index Cond: (assembliesbatchstatusid = 2)
-> Bitmap Index Scan on
fki_assembliesbatch_assembliesbatchstatus_id (cost=0.00..4.27 rows=3 width=0) (actual time=0.006..0.006 rows=3 loops=1)
Index Cond: (assembliesbatchstatusid = 4)
-> Bitmap Index Scan on
fki_assembliesbatch_assembliesbatchstatus_id (cost=0.00..4.37 rows=16 width=0) (actual time=0.022..0.022 rows=16
loops=1)
Index Cond: (assembliesbatchstatusid = 7)
-> Hash (cost=15.24..15.24 rows=724 width=5) (actual
time=2.785..2.785rows=724 loops=1)
-> Seq Scan on assemblies q (cost=0.00..15.24 rows=724
width=5)(actual time=0.011..1.356 rows=724 loops=1)
-> Hash Join (cost=621.63..1206.10 rows=3854 width=28) (actual time=0.074..71.265 rows=593
loops=3684)
Hash Cond: (e.pnid = g.pnid)
-> Hash Join (cost=337.11..839.61 rows=3860 width=32) (actual time=0.057..68.467 rows=593
loops=3684)
Hash Cond: (e.poid = f.poid)
-> Seq Scan on poparts e (cost=0.00..379.60 rows=16860 width=32) (actual
time=0.008..34.510rows=16860 loops=3684)
-> Hash (cost=317.17..317.17 rows=1595 width=8) (actual time=7.266..7.266 rows=183
loops=1)
-> Bitmap Heap Scan on pos f (cost=54.06..317.17 rows=1595 width=8) (actual
time=1.519..6.843rows=183 loops=1)
Recheck Cond: ((postatusid >= 20) AND (postatusid <= 59))
Filter: (NOT isrfq)
-> Bitmap Index Scan on postatusidpo (cost=0.00..53.66 rows=2541
width=0)(actual time=1.418..1.418 rows=2700 loops=1)
Index Cond: ((postatusid >= 20) AND (postatusid <= 59))
-> Hash (cost=197.01..197.01 rows=7001 width=4) (actual time=42.248..42.248 rows=7001
loops=1)
-> Seq Scan on manufacturerpartpn g (cost=0.00..197.01 rows=7001 width=4) (actual
time=0.030..19.935rows=7001 loops=1)
Total runtime: 608146.760 ms
В списке pgsql-general по дате отправления:
Предыдущее
От: Magnus HaganderДата:
Сообщение: Re: After Installing a Program I get this error: psql:sql/Pg-database.sql:825: ERROR: language "plpgsql" does not exist