Interesting incosistent query timing - Mailing list pgsql-general

Hi,

I am researching some interesting inconsistent query timing and hope some
of the gurus hanging out here might help me shed a light on this...

The table:
 Column |           Type           |                     Modifiers

--------+--------------------------+----------------------------------------
------------
 rid    | integer                  | not null default
nextval('rv2_mdata_id_seq'::text)
 pid    | integer                  |
 owid   | integer                  |
 ioid   | integer                  |
 dcid   | character varying        |
 dsid   | character varying        |
 drid   | integer                  |
 usg    | integer                  |
 idx    | character varying        |
 env    | integer                  |
 nxid   | integer                  |
 ci     | integer                  |
 cd     | numeric(21,6)            |
 cr     | real                     |
 cts    | timestamp with time zone |
 cst    | character varying        |
 ctx    | text                     |
 cbl    | oid                      |
 acl    | text                     |
Indexes: id_mdata_dictid,
         id_mdata_dictid_dec,
         id_mdata_dictid_int,
         id_mdata_dictid_real,
         id_mdata_dictid_string,
         id_mdata_dictid_text,
         id_mdata_dictid_timestamp,
         id_mdata_dowid,
         id_mdata_ioid,
         id_mdata_owid
Primary key: rv2_mdata_pkey

Index "id_mdata_dictid_string"
 Column |       Type
--------+-------------------
 dcid   | character varying
 dsid   | character varying
 drid   | integer
 nxid   | integer
 cst    | character varying
btree
Index predicate: ((usg & 16) = 16)



The query:
explain analyze verbose
select distinct t1.owid
        from rv2_mdata t1
        where t1.dcid='ADDR' and t1.dsid='AUXDICT' and t1.drid=110 and
t1.usg & 16 = 16
        and t1.nxid = 0
        and t1.cst ilike '%redist%'
        and t1.owid > 10
;

For the first time run it executes in 1.5 - 2 seconds. From the second
time, only 10 msec are needed for the same result:

Unique  (cost=3.84..3.84 rows=1 width=4) (actual time=1569.36..1569.39
rows=11 loops=1)
  ->  Sort  (cost=3.84..3.84 rows=1 width=4) (actual time=1569.36..1569.37
rows=11 loops=1)
        ->  Index Scan using id_mdata_dictid_string on rv2_mdata t1
(cost=0.00..3.83 rows=1 width=4) (actual time=17.02..1569.22 rows=11 loops=1)
Total runtime: 1569.50 msec


Unique  (cost=3.84..3.84 rows=1 width=4) (actual time=10.51..10.53 rows=11
loops=1)
  ->  Sort  (cost=3.84..3.84 rows=1 width=4) (actual time=10.51..10.51
rows=11 loops=1)
        ->  Index Scan using id_mdata_dictid_string on rv2_mdata t1
(cost=0.00..3.83 rows=1 width=4) (actual time=0.60..10.43 rows=11 loops=1)
Total runtime: 10.64 msec

If any of the "dcid", "dsid", or "drid" constraint values are altered, the
query starts again at 1.5 - 2 secs, then drops to 10.5 msec again.

Even after restarting PostgreSQL, the number is lower (~50 msec) than when
running for the first time.

I really would like to get a consistent timing here (the lower the better
of course) since these queries will happen quite often within our
application, and I need a consistent and predictable timing (this being a
core component).

This is postgresql 7.2.1 on RH72.

Any clues? Thanks for insights,


--
   >O     Ernest E. Vogelsinger
   (\)    ICQ #13394035
    ^     http://www.vogelsinger.at/