Hi there
We are runing Postgres 8.3.7 on a
We have a problem with Explain Analyze that we haven't seen before.
we run an Explain Analyze on a query.
Nested Loop (cost=1256.32..2097.31 rows=198 width=1120) (actual time=12.958..20.846 rows=494 loops=1)
-> HashAggregate (cost=1256.32..1256.92 rows=198 width=4) (actual time=12.936..13.720 rows=494 loops=1)
-> Limit (cost=1255.53..1255.63 rows=198 width=20) (actual time=9.841..11.901 rows=500 loops=1)
-> Sort (cost=1255.53..1255.63 rows=198 width=20) (actual time=9.838..10.588 rows=500 loops=1)
Sort Key: ((abs((ri_metadata.latitude -
44.0247062::double precision)) + abs((ri_metadata.longitude -
(-88.5426136)::double precision))))
Sort Method: quicksort Memory: 52kB
-> Bitmap Heap Scan on ri_metadata
(cost=385.54..1254.02 rows=198 width=20) (actual time=4.638..8.558
rows=595 loops=1)
Recheck Cond: ((latitude >
43.6687062::double precision) AND (latitude < 44.3807062::double
precision) AND (longitude > (-88.8986136)::double precision) AND
(longitude < (-88.1866136)::double precision))
Filter: (category_id = ANY
('{3,274,4,1,2,275,7,278,8,277,5,280,6,279,11,9,10,15,285,16,14,19,18,17,24,23,21,266,25,32,31,30,29,40,34,48,41,44,313,54,53,55,50,52,62,61,63,302,58,57,59,71,341,69,67,338,68,337,65,66,339,79,352,77,78,74,85,83,324,81,334,335,336,372,376,373,374,363,122,368,127,128,356,355,360,359,118,358,357,140,139,138,137,143,142,141,132,130,129,135,134,191,185,186,187,188,183,202,200,193,219}'::integer[]))
-> Bitmap Index Scan on
ri_metadata_latitude_longitude_category_id_idx (cost=0.00..385.53
rows=462 width=0) (actual time=4.533..4.533 rows=1316 loops=1)
Index Cond: ((latitude >
43.6687062::double precision) AND (latitude < 44.3807062::double
precision) AND (longitude > (-88.8986136)::double precision) AND
(longitude < (-88.1866136)::double precision))
-> Index Scan using ri_result_result_id_idx on ri_result
(cost=0.00..4.24 rows=1 width=1120) (actual time=0.006..0.008 rows=1
loops=494)
Index Cond: (ri_result.result_id = ri_metadata.result_id)
Total runtime: 21.658 ms
(14 rows)
It takes only *21* ms. Then we run the same query on psql (on localhost) with timing on
select * from ri_result where result_id in
(select result_id from ri_metadata
WHERE category_id IN
(3,274,4,1,2,275,7,278,8,277,5,280,6,279,11,9,10,15,285,16,14,19,18,17,24,23,21,266,25,32,31,30,29,40,34,48,41,44,313,54,53
,55,50,52,62,61,63,302,58,57,59,71,341,69,67,338,68,337,65,66,339,79,352,77,78,74,85,83,324,81,334,335,336,372,376,373,374,363,122,368,127,
128,356,355,360,359,118,358,357,140,139,138,137,143,142,141,132,130,129,135,134,191,185,186,187,188,183,202,200,193,219)
AND latitude >43.668706199999995 AND latitude <44.3807062 AND
longitude>-88.89861359999999 AND longitude<-88.1866136
order by abs(latitude - 44.0247062)+abs(longitude - -88.5426136) limit 500)
;
Time: 2611.491 ms
The longer runtime from psql console is corroborated when we do same queries via JDBC
How can explain-analyze return significantly much faster than other
means? (I understand that some data is returned from the query to
either client end on psql or to a resultset in jdbc as opposed to a
small chunk of data in the form of a plan but still..,)
By the way, I run the explain analyze first and then run the query to avoid any caching.
Our system : Ubuntu Ubuntu 8.04.3 64 bit, 8GB RAM ,2 GHz single core, running a vm on an esx server. the database is read-only.
ri_metadata has 1473864 rows, 200MB,
Table "public.ri_metadata"
Column | Type | Modifiers
----------------+-----------------------------+----------------------------------------------------------------------
ri_metadata_id | integer | not null default nextval('ri_metadata_ri_metadata_id_seq'::regclass)
result_id | integer | not null
start_time | timestamp without time zone | not null
end_time | timestamp without time zone | not null
category_id | integer | not null
category_name | text | not null
location_id | integer |
longitude | double precision |
latitude | double precision |
city | text |
state | text |
zip | text |
street_address | text |
Indexes:
"ri_metadata_pkey" PRIMARY KEY, btree (ri_metadata_id)
"ri_metadata_category_id_idx" btree (category_id)
"ri_metadata_category_id_state" btree (category_id, state)
"ri_metadata_end_time_idx" btree (end_time)
"ri_metadata_latitude_idx" btree (latitude)
"ri_metadata_latitude_longitude_category_id_idx" btree (latitude, longitude, category_id)
"ri_metadata_location_id_idx" btree (location_id)
"ri_metadata_longitude_idx" btree (longitude)
"ri_metadata_result_id_idx" btree (result_id)
"ri_metadata_start_time_idx" btree (start_time)
"ri_metadata_state_idx" btree (state)
ri_result has 1323061 rows, 3.3GB total size
Table "public.ri_result"
Column | Type | Modifiers
--------------+------------------+------------------------------------------------------------------
ri_result_id | integer | not null default nextval('ri_result_ri_result_id_seq'::regclass)
result_id | integer | not null
facets | bytea | not null
props | bytea | not null
random | double precision |
Indexes:
"ri_result_pkey" PRIMARY KEY, btree (ri_result_id)
"ri_result_random_idx" btree (random)
"ri_result_result_id_idx" btree (result_id)
