Re: explain analyze reports that my queries are fast but they run very slowly

[Nikolas Everett <nik9000@xxxxxxxxx>]

Another other thing - the query seems to get faster after the first time we plan it.  I'm not sure that this is the case but I think it might be.

On Thu, Dec 27, 2012 at 2:28 PM, Nikolas Everett <nik9000@xxxxxxxxx> wrote:

Sorry for the confusion around the queries.  Both queries are causing trouble.  We've noticed that just EXPLAINING the very simple queries takes forever.

After more digging it looks like this table has an inordinate number of indices (10 ish).  There a whole buch of conditional indicies for other columns that we're not checking.  The particular column that is causing us trouble exists in both a regular (con_id) and a composite index (con_id, somthing_else).

We checked on locks and don't see any ungranted locks.  Would waiting on the AccessShareLock not appear in pg_locks?

Thanks!

Nik

On Thu, Dec 27, 2012 at 2:21 PM, Tom Lane <tgl@xxxxxxxxxxxxx> wrote:

Nikolas Everett <nik9000@xxxxxxxxx> writes:
> We just upgraded from 8.3 to 9.1 and we're seeing some performance
> problems.  When we EXPLAIN ANALYZE our queries the explain result claim
> that the queries are reasonably fast but the wall clock time is way way
> longer.  Does anyone know why this might happen?

> Like so:
> db=>\timing
> db=>EXPLAIN ANALYZE SELECT max(id) FROM foo WHERE blah_id = 1209123;

> The plan is sensible.  The estimates are sensible.  The actual DB time
> reads like it is very sensible.  But the wall clock time is like 11 seconds
> and the \timing report confirms it.

Seems like the extra time would have to be in parsing/planning, or in
waiting to acquire AccessShareLock on the table.  It's hard to believe
the former for such a simple query, unless the table has got thousands
of indexes or something silly like that.  Lock waits are surely possible
if there is something else contending for exclusive lock on the table,
but it's hard to see how the wait time would be so consistent.

BTW, the explain.depesz.com link you posted clearly does not correspond
to the above query (it's not doing a MAX), so another possibility is
confusion about what query is really causing trouble.  We've seen people
remove essential details before while trying to anonymize their query.

                        regards, tom lane