Re: how could select id=xx so slow?

[Yan Chunlu <springrider@xxxxxxxxx>]

thanks for all the help. I checked the probability and found that:

1, the size of tuple is small

2, I checked the log manually and it indeed cost that much of time,  not aggregated

the value of "log_min_messages" in postgresql.conf is error, I have changed it to "warning", so far does not received any warning, still waiting.

beside I do see some COMMIT which is relatively slow for example:

   60 2012-07-08 00:00:29 CST [19367]: [131-1] LOG:  duration: 375.851 ms  statement: COMMIT

   61 2012-07-08 00:00:30 CST [19367]: [132-1] LOG:  duration: 327.964 ms  statement: COMMIT

but only one "BEGIN" in the same one day log file, did that influence the query time too?

On Fri, Jul 6, 2012 at 9:10 PM, Albe Laurenz <laurenz.albe@xxxxxxxxxx> wrote:

Yan Chunlu wrote:
> I have grabbed one day slow query log and analyzed it by pgfouine, to
my surprise, the slowest query
> is just a simple select statement:
>
> select diggcontent_data_message.thing_id,
diggcontent_data_message.KEY,
> diggcontent_data_message.value, diggcontent_data_message.kind FROM
diggcontent_data_message WHERE
> diggcontent_data_message.thing_id = 3570882;
>
> where thing_id is the primary key,  guess how long it takes?
>
> 754.61 seconds!!
>
> I tried explain analyze it and below is the result, which is very
fast:
>
> explain analyze select diggcontent_data_message.thing_id,
diggcontent_data_message.KEY,
> diggcontent_data_message.value, diggcontent_data_message.kind FROM
diggcontent_data_message WHERE
> diggcontent_data_message.thing_id = 3570882;
>
QUERY PLAN
>
------------------------------------------------------------------------
------------------------------
> -------------------------------------------------------------
>  Index Scan using idx_thing_id_diggcontent_data_message on
diggcontent_data_message  (cost=0.00..15.34
> rows=32 width=51) (actual time=0.080..0.096 rows=8 loops=1)
>    Index Cond: (thing_id = 3570882)
>  Total runtime: 0.115 ms
> (3 rows)
>
> so I wonder could this simple select is innocent and affected badly by
other queries? how could I find
> those queries that really slow down the database?

Are these by any chance the aggregated costs in pgFouine?
Could it be that the statement just ran very often and used that time in
total?

Other than that, it could have been blocked by something that takes an
exclusive lock on the table.

There are no ON SELECT DO INSTEAD rules or similar things on the table,
right?

Yours,
Laurenz Albe