Re: how could select id=xx so slow?

From: Yan Chunlu <springrider(at)gmail(dot)com>
To: Albe Laurenz <laurenz(dot)albe(at)wien(dot)gv(dot)at>
Cc: pgsql-performance(at)postgresql(dot)org
Subject: Re: how could select id=xx so slow?
Date: 2012-07-09 09:20:56
Message-ID: CAOA66tF8dAzAS9wG381bhp+AiC2LrzcF7MDmOxvgW0p07rMNtw@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

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(dot)albe(at)wien(dot)gv(dot)at>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
>

In response to

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Gregg Jaskiewicz 2012-07-09 11:55:33 Re: Paged Query
Previous Message Sylvain CAILLET 2012-07-09 06:49:36 Re: Create tables performance