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)