I'm hoping that someone on the list can help me understand an apparent
discrepancy in the performance information that I'm collecting on a
particularly troublesome query.
The configuration: pg-8.2.4 on RHEL4. log_min_duration_statement = 1m.
In my syslog output, I see entries indicating that the
JDBC-driver-originated query on a table named 'city_summary' are taking
upwards of 300 seconds:
Oct 1 18:27:47 srv3 postgres-8.2[1625]: [12-1]
LOG: duration: 307077.037 ms execute S_42: select * from city_summary
where state = $1 and city_master_id = $2 and res_type =
'single_family' and date = $3
and range = 90 and zip = $4 and quartile = '__ALL'
DETAIL: parameters: $1 = 'CA', $2 = '291', $3 = '2007-09-28', $4 = '__ALL'
However, if I run the same query on the same host at the same time that
the Java application is running, but from the psql command line, it
takes only 0.37 seconds:
> time /opt/postgres-8.2.4/bin/psql --port 54824 -U postgres -d
altos_research -c 'select fact_id from city_summary where state =
\'CA\' and city_master_id = 291 and zip = \'__ALL\' and quartile =
\'__ALL\' and res_type = \'single_family\' and range = \'90\' and date =
\'2007-09-28\';'
fact_id
----------
46624925
(1 row)
0.00user 0.00system 0:00.37elapsed 0%CPU (0avgtext+0avgdata 0maxresident)k
0inputs+0outputs (0major+285minor)pagefaults 0swaps
The output of 'explain' seems to indicate that the right index is being
used:
QUERY PLAN
Index Scan using city_summary_pkey on city_summary (cost=0.00..12.27
rows=1 width=2721)
Index Cond: ((date = '2007-09-28'::text) AND
(state = 'CA'::text) AND
(city_master_id = 334::bigint) AND
(quartile = '__ALL'::text) AND
(range = '90'::text))
Filter: ((zip = '__ALL'::text) AND ((res_type)::text =
'single_family'::text))
(3 rows)
The index looks like this:
# \d city_summary_pkey
Index "public.city_summary_pkey"
Column | Type
--------------------+---------
date | text
state | text
city_master_id | bigint
zip_master_id | integer
res_type_master_id | bigint
quartile | text
range | text
primary key, btree, for table "public.city_summary"
Any ideas on why I am seeing such a big difference between the two
measurements (JDBC/syslog vs. command line)?
Thanks,
Jason