Hi,
I have been trying to fix a performance issue that we have which I have
tracked down to index scans being done on a particular table (or set of
tables):
The following query:
explain analyze select *
FROM inbound.event_20090526 e
LEFT OUTER JOIN inbound.internal_host i ON (e.mta_host_id = i.id)
LEFT OUTER JOIN inbound.internal_host iaa ON (e.aamta_host_id = iaa.id)
LEFT OUTER JOIN inbound.event_status es ON (e.event_status_id = es.id)
LEFT OUTER JOIN inbound.threat t ON (e.threat_id = t.id), inbound.domain
d, inbound.event_type et
WHERE e.domain_id = d.id
AND e.event_type_id = et.id
AND d.name IN (
'testdomain.com'
);
Does this:
QUERY
PLAN
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Nested Loop Left Join (cost=0.00..10887.03 rows=8 width=2021) (actual
time=50.352..14378.603 rows=3453 loops=1)
-> Nested Loop Left Join (cost=0.00..10882.23 rows=8 width=1985)
(actual time=50.346..14372.820 rows=3453 loops=1)
-> Nested Loop Left Join (cost=0.00..10877.43 rows=8
width=1949) (actual time=50.336..14358.101 rows=3453 loops=1)
-> Nested Loop Left Join (cost=0.00..10872.63 rows=8
width=1801) (actual time=50.321..14344.603 rows=3453 loops=1)
-> Nested Loop (cost=0.00..10867.83 rows=8
width=1764) (actual time=50.315..14336.979 rows=3453 loops=1)
-> Nested Loop (cost=0.00..10863.03 rows=8
width=1728) (actual time=50.288..14308.368 rows=3453 loops=1)
-> Index Scan using domain_name_idx on
domain d (cost=0.00..6.63 rows=1 width=452) (actual time=0.049..0.080
rows=1 loops=1)
Index Cond: ((name)::text =
'testdomain.com'::text)
-> Index Scan using
event_20090526_domain_idx on event_20090526 e (cost=0.00..10694.13
rows=3606 width=1276) (actual time=50.233..14305.211 rows=3453 loops=1)
Index Cond: (e.domain_id = d.id)
-> Index Scan using event_type_pkey on
event_type et (cost=0.00..0.56 rows=1 width=36) (actual
time=0.006..0.006 rows=1 loops=3453)
Index Cond: (et.id = e.event_type_id)
-> Index Scan using threat_pkey on threat t
(cost=0.00..0.56 rows=1 width=37) (actual time=0.000..0.000 rows=0
loops=3453)
Index Cond: (e.threat_id = t.id)
-> Index Scan using event_status_pkey on event_status
es (cost=0.00..0.56 rows=1 width=148) (actual time=0.002..0.002 rows=1
loops=3453)
Index Cond: (e.event_status_id = es.id)
-> Index Scan using internal_host_pkey on internal_host iaa
(cost=0.00..0.56 rows=1 width=36) (actual time=0.002..0.003 rows=1
loops=3453)
Index Cond: (e.aamta_host_id = iaa.id)
-> Index Scan using internal_host_pkey on internal_host i
(cost=0.00..0.56 rows=1 width=36) (actual time=0.000..0.000 rows=0
loops=3453)
Index Cond: (e.mta_host_id = i.id)
Total runtime: 14380.000 ms
If the same query is done straight away again we get:
QUERY
PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Nested Loop Left Join (cost=0.00..10887.03 rows=8 width=2021) (actual
time=0.165..67.388 rows=3453 loops=1)
-> Nested Loop Left Join (cost=0.00..10882.23 rows=8 width=1985)
(actual time=0.162..61.973 rows=3453 loops=1)
-> Nested Loop Left Join (cost=0.00..10877.43 rows=8
width=1949) (actual time=0.156..49.756 rows=3453 loops=1)
-> Nested Loop Left Join (cost=0.00..10872.63 rows=8
width=1801) (actual time=0.148..37.522 rows=3453 loops=1)
-> Nested Loop (cost=0.00..10867.83 rows=8
width=1764) (actual time=0.146..31.920 rows=3453 loops=1)
-> Nested Loop (cost=0.00..10863.03 rows=8
width=1728) (actual time=0.129..10.325 rows=3453 loops=1)
-> Index Scan using domain_name_idx on
domain d (cost=0.00..6.63 rows=1 width=452) (actual time=0.099..0.139
rows=1 loops=1)
Index Cond: ((name)::text =
'rhe.com.au'::text)
-> Index Scan using
event_20090526_domain_idx on event_20090526 e (cost=0.00..10694.13
rows=3606 width=1276) (actual time=0.027..7.510 rows=3453 loops=1)
Index Cond: (e.domain_id = d.id)
-> Index Scan using event_type_pkey on
event_type et (cost=0.00..0.56 rows=1 width=36) (actual
time=0.004..0.005 rows=1 loops=3453)
Index Cond: (et.id = e.event_type_id)
-> Index Scan using threat_pkey on threat t
(cost=0.00..0.56 rows=1 width=37) (actual time=0.000..0.000 rows=0
loops=3453)
Index Cond: (e.threat_id = t.id)
-> Index Scan using event_status_pkey on event_status
es (cost=0.00..0.56 rows=1 width=148) (actual time=0.002..0.002 rows=1
loops=3453)
Index Cond: (e.event_status_id = es.id)
-> Index Scan using internal_host_pkey on internal_host iaa
(cost=0.00..0.56 rows=1 width=36) (actual time=0.002..0.002 rows=1
loops=3453)
Index Cond: (e.aamta_host_id = iaa.id)
-> Index Scan using internal_host_pkey on internal_host i
(cost=0.00..0.56 rows=1 width=36) (actual time=0.000..0.000 rows=0
loops=3453)
Index Cond: (e.mta_host_id = i.id)
Total runtime: 68.475 ms
Which suggests to me that it takes the remainder of the 14300ms in the
first query to read the event_20090526_domain_idx index in from disk.
The table has 2 million records in it, and the index has a physical size
on disk of 44MB. The box this is running on is rather powerful having 8
cores, 16GB ram, and stripped disks.
What I am wondering is is there any reason why this would be taking so
long? Or what can be done to fix this / track down the issue more?
Cheers
Bryce
--
Sent via pgsql-performance mailing list (pgsql-performance@xxxxxxxxxxxxxx)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
