Strange discrepancy in query performance...

From: "Jason L(dot) Buberel" <jason(at)buberel(dot)org>
To: pgsql-general(at)postgresql(dot)org
Subject: Strange discrepancy in query performance...
Date: 2007-10-01 23:47:55
Message-ID: 4701872B.4050403@buberel.org
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-general

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

Responses

Browse pgsql-general by date

  From Date Subject
Next Message Tom Lane 2007-10-02 00:01:42 Re: Strange discrepancy in query performance...
Previous Message Nasby Jim 2007-10-01 23:33:58 pgcrypto digest_exists replacement?