Re: What is syslog:duration reporting ... ?
От | Aldor |
---|---|
Тема | Re: What is syslog:duration reporting ... ? |
Дата | |
Msg-id | 430E1CCD.6000700@mediaroot.de обсуждение исходный текст |
Ответ на | Re: What is syslog:duration reporting ... ? ("Marc G. Fournier" <scrappy@postgresql.org>) |
Список | pgsql-admin |
Can you post the code you created the INDEX with - I think there is something which could explain the duration. Marc G. Fournier wrote: > On Thu, 25 Aug 2005, Aldor wrote: > >> 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. > > > That would work if I were to get really occasional high values in > syslog, but this is almost a consist thing over a very short period of > time: > > Aug 25 14:53:32 forgehouse-s1 postgres[23721]: [2-1] LOG: duration: > 567.559 ms statement: UPDATE session SET hit_time=now() WHERE > md5='7537b74eab488de54d6e0167d1919207'; > Aug 25 14:53:32 forgehouse-s1 postgres[23722]: [2-1] LOG: duration: > 565.966 ms statement: UPDATE session SET hit_time=now() WHERE > md5='d84613009a95296fb511c2cb051ad618'; > Aug 25 14:53:33 forgehouse-s1 postgres[23723]: [2-1] LOG: duration: > 1192.789 ms statement: UPDATE session SET hit_time=now() WHERE > md5='d84613009a95296fb511c2cb051ad618'; > Aug 25 14:53:53 forgehouse-s1 postgres[23727]: [2-1] LOG: duration: > 12159.162 ms statement: UPDATE session SET hit_time=now() WHERE > md5='d84613009a95296fb511c2cb051ad618'; > Aug 25 14:53:54 forgehouse-s1 postgres[23728]: [2-1] LOG: duration: > 3283.185 ms statement: UPDATE session SET hit_time=now() WHERE > md5='7537b74eab488de54d6e0167d1919207'; > Aug 25 14:53:57 forgehouse-s1 postgres[23729]: [2-1] LOG: duration: > 2116.516 ms statement: UPDATE session SET hit_time=now() WHERE > md5='7537b74eab488de54d6e0167d1919207'; > > And you will notice that the last two are the exact same md5 value ... > >> When did you vacuumed the table the last time? > > > pg_autovacuum is running to keep things up to date, and I just ran a > VACUUM FULL *and* a REINDEX, just to make sure things are clean ... > > No matter when I try it, I can't seem to get a value above 10ms for that > query above when I do it from psql ... > > > >> >> 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@hub.org Yahoo!: yscrappy ICQ: >>> 7615664 >>> >>> ---------------------------(end of broadcast)--------------------------- >>> TIP 2: Don't 'kill -9' the postmaster >>> >> > > ---- > Marc G. Fournier Hub.Org Networking Services (http://www.hub.org) > Email: scrappy@hub.org Yahoo!: yscrappy ICQ: 7615664 >
В списке pgsql-admin по дате отправления: