slow query performance

From: Anj Adu <fotographs(at)gmail(dot)com>
To: pgsql-performance(at)postgresql(dot)org
Subject: slow query performance
Date: 2010-06-03 17:47:55
Message-ID: AANLkTilbM1iWSrrchOB9x1_W2CKQSTzCow6BznV1DxNk@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

I cant seem to pinpoint why this query is slow . No full table scans
are being done. The hash join is taking maximum time. The table
dev4_act_action has only 3 rows.

box is a 2 cpu quad core intel 5430 with 32G RAM... Postgres 8.4.0
1G work_mem
20G effective_cache
random_page_cost=1
default_statistics_target=1000

The larget table in the inner query is dev4_act_dy_fact which is
partitioned into 3 partitions per month. Each partition has about 25
million rows.
The rest of the tables are very small (100- 1000 rows)

explain analyze
select ipconvert(srctest_num),CASE targetpt::character varying
WHEN NULL::text THEN serv.targetsrv
ELSE targetpt::character varying
END AS targetsrv, sesstype,hits as cons,bytes, srcz.srcarea as
srcz, dstz.dstarea as dstz from
(
select srctest_num, targetpt,targetsrv_id, sesstype_id, sum(total) as
hits, sum(bin) + sum(bout) as bts, sourcearea_id, destinationarea_id
from dev4_act_dy_fact a, dev4_act_action act where thedate between
'2010-05-22' and '2010-05-22'
and a.action_id = act.action_id and action in ('rejected','sess_rejected')
and guardid_id in (select guardid_id from dev4_act_guardid where
guardid like 'cust00%')
and node_id=(select node_id from dev4_act_node where node='10.90.100.2')
group by srctest_num,targetpt,targetsrv_id,sesstype_id,
sourcearea_id, destinationarea_id
order by (sum(bin) + sum(bout)) desc
limit 1000
) a left outer join dev4_act_dstarea dstz on a.destinationarea_id =
dstz.dstarea_id
left outer join dev4_act_srcarea srcz on a.sourcearea_id = srcz.srcarea_id
left outer join dev4_act_targetsrv serv on a.targetsrv_id = serv.targetsrv_id
left outer join dev4_sesstype proto on a.sesstype_id = proto.sesstype_id
order by bytes desc

"Nested Loop Left Join (cost=95392.32..95496.13 rows=20 width=510)
(actual time=164533.831..164533.831 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=95392.32..95473.43 rows=20
width=396) (actual time=164533.830..164533.830 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=95392.32..95455.83 rows=20
width=182) (actual time=164533.829..164533.829 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=95392.32..95410.17
rows=20 width=186) (actual time=164533.829..164533.829 rows=0
loops=1)"
" -> Limit (cost=95392.32..95392.37 rows=20
width=52) (actual time=164533.828..164533.828 rows=0 loops=1)"
" InitPlan 1 (returns $0)"
" -> Index Scan using dev4_act_node_uindx
on dev4_act_node (cost=0.00..2.27 rows=1 width=4) (actual
time=0.052..0.052 rows=0 loops=1)"
" Index Cond: ((node)::text =
'10.90.100.2'::text)"
" -> Sort (cost=95390.05..95390.10 rows=20
width=52) (actual time=164533.826..164533.826 rows=0 loops=1)"
" Sort Key: ((sum(a.bin) + sum(a.bout)))"
" Sort Method: quicksort Memory: 17kB"
" -> HashAggregate
(cost=95389.22..95389.62 rows=20 width=52) (actual
time=164533.796..164533.796 rows=0 loops=1)"
" -> Nested Loop Semi Join
(cost=7.37..95388.77 rows=20 width=52) (actual
time=164533.793..164533.793 rows=0 loops=1)"
" -> Hash Join
(cost=7.37..94836.75 rows=2043 width=56) (actual
time=164533.792..164533.792 rows=0 loops=1)"
" Hash Cond:
(a.action_id = act.action_id)"
" -> Append
(cost=2.80..94045.71 rows=204277 width=60) (actual
time=164533.790..164533.790 rows=0 loops=1)"
" -> Bitmap
Heap Scan on dev4_act_dy_fact a (cost=2.80..3.82 rows=1 width=60)
(actual time=0.064..0.064 rows=0 loops=1)"
" Recheck
Cond: ((node_id = $0) AND (thedate >= '2010-05-22 00:00:00'::timestamp
without time area) AND (thedate <= '2010-05-22 00:00:00'::timestamp
without time area))"
" ->
BitmapAnd (cost=2.80..2.80 rows=1 width=0) (actual time=0.062..0.062
rows=0 loops=1)"
"
-> Bitmap Index Scan on dev4_act_dy_dm_nd_indx (cost=0.00..1.27
rows=3 width=0) (actual time=0.062..0.062 rows=0 loops=1)"
"
Index Cond: (node_id = $0)"
"
-> Bitmap Index Scan on dev4_act_dy_dm_cd_indx (cost=0.00..1.28
rows=3 width=0) (never executed)"
"
Index Cond: ((thedate >= '2010-05-22 00:00:00'::timestamp without
time area) AND (thedate <= '2010-05-22 00:00:00'::timestamp without
time area))"
" -> Index
Scan using dev4_act_dy_fact_2010_05_t3_thedate on
dev4_act_dy_fact_2010_05_t3 a (cost=0.00..94041.89 rows=204276
width=60) (actual time=164533.725..164533.725 rows=0 loops=1)"
" Index
Cond: ((thedate >= '2010-05-22 00:00:00'::timestamp without time area)
AND (thedate <= '2010-05-22 00:00:00'::timestamp without time area))"
" Filter:
(node_id = $0)"
" -> Hash
(cost=4.54..4.54 rows=2 width=4) (never executed)"
" -> Bitmap
Heap Scan on dev4_act_action act (cost=2.52..4.54 rows=2 width=4)
(never executed)"
" Recheck
Cond: ((action)::text = ANY ('{rejected,sess_rejected}'::text[]))"
" ->
Bitmap Index Scan on dev4_act_action_uindx (cost=0.00..2.52 rows=2
width=0) (never executed)"
"
Index Cond: ((action)::text = ANY
('{rejected,sess_rejected}'::text[]))"
" -> Index Scan using
dev4_act_guardid_pk on dev4_act_guardid (cost=0.00..0.27 rows=1
width=4) (never executed)"
" Index Cond:
(dev4_act_guardid.guardid_id = a.guardid_id)"
" Filter:
((dev4_act_guardid.guardid)::text ~~ 'cust00%'::text)"
" -> Index Scan using sys_c006248 on dev4_sesstype
proto (cost=0.00..0.87 rows=1 width=102) (never executed)"
" Index Cond: (a.sesstype_id = proto.sesstype_id)"
" -> Index Scan using dev4_act_targetsrv_pk on
dev4_act_targetsrv serv (cost=0.00..2.27 rows=1 width=4) (never
executed)"
" Index Cond: (a.targetsrv_id = serv.targetsrv_id)"
" -> Index Scan using dev4_act_srcarea_pk on dev4_act_srcarea
srcz (cost=0.00..0.87 rows=1 width=222) (never executed)"
" Index Cond: (a.sourcearea_id = srcz.srcarea_id)"
" -> Index Scan using dev4_act_dstarea_pk on dev4_act_dstarea dstz
(cost=0.00..0.87 rows=1 width=122) (never executed)"
" Index Cond: (a.destinationarea_id = dstz.dstarea_id)"
"Total runtime: 164534.172 ms"

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Greg Smith 2010-06-03 18:18:34 Re: Weird XFS WAL problem
Previous Message Kevin Grittner 2010-06-03 17:30:59 Re: Weird XFS WAL problem