As I know EXPLAIN ANALYZE runs the query. I think you are just running
the query two times. The first time you run the query it will take a
long time to be processed - after the first run the query planner will
remember the best way to run the query so your second run runs much faster.
I can reproduce this behavior for some queries under 8.0.1 - so I'm not
100% sure if it is the same behavior under 7.4.2.
I'm still wondering why you first query takes about 4107.987 ms - this
kind of query has usually have to run much much faster.
When did you vacuumed the table the last time?
Marc G. Fournier wrote:
'k, I've been wracking my brains over this today, and I'm either
mis-understanding what is being reported *or* its reporting wrong ...
According to syslog:
LOG: duration: 4107.987 ms statement: UPDATE session SET
hit_time=now() WHERE md5='8b8e7b7ff9b1b2ed5fc60218ced28d00';
But, if I do an EXPLAIN ANALYZE:
# explain analyze UPDATE session SET hit_time=now() WHERE
md5='702c6cb20d5eb254c3feb2991e7e5e31';
QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------
Index Scan using session_md5_key on "session" (cost=0.00..6.01 rows=1
width=93) (actual time=0.060..0.060 rows=0 loops=1)
Index Cond: (md5 = '702c6cb20d5eb254c3feb2991e7e5e31'::bpchar)
Total runtime: 0.171 ms
(3 rows)
And it doesn't matter what value I put for md5, I still get <1ms ...
I could see some variations, but almost 4000x slower to *really* run
the query vs an explain analyze?
This is with 7.4.2 ...
----
Marc G. Fournier Hub.Org Networking Services (http://www.hub.org)
Email: scrappy@xxxxxxx Yahoo!: yscrappy ICQ: 7615664
---------------------------(end of broadcast)---------------------------
TIP 2: Don't 'kill -9' the postmaster