Message-ID: <4EFC2CE0.7050001@beccati.com>
Date: Thu, 29 Dec 2011 10:03:28 +0100
From: Matteo Beccati <php@beccati.com>
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64;
	rv:8.0) Gecko/20111105 Thunderbird/8.0
MIME-Version: 1.0
To: Claudio Freire <klaussfreire@gmail.com>
CC: Tom Lane <tgl@sss.pgh.pa.us>, =?UTF-8?B?U8O2cmVuIE1leWVyLUVwcGxlcg==?=
	<soerenme@google.com>, pgsql-performance@postgresql.org
Subject: Re: PostgreSQL 9.0.4 blocking in lseek?
References: <4EA82B7C.1040008@google.com> <9398.1319761978@sss.pgh.pa.us>
	<4EFAE7F6.30603@beccati.com> <4EFB59BC.9000208@beccati.com>
	<CAGTBQpZfxmdvoLOt7V5QrU8MYdtR2zq-FWYeQ3ZaEKjYVo5w1g@mail.gmail.com>
	<4EFB62F1.2000700@beccati.com>
In-Reply-To: <4EFB62F1.2000700@beccati.com>
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 7bit

On 28/12/2011 19:41, Matteo Beccati wrote:
> On 28/12/2011 19:07, Claudio Freire wrote:
>> On Wed, Dec 28, 2011 at 3:02 PM, Matteo Beccati <php@beccati.com> wrote:
>>> The query eventually completed in more than 18h. For comparison a normal
>>> run doesn't take more than 1m for that specific step.
>>>
>>> Do you think that bad stats and suboptimal plan alone could explain such
>>> a behaviour?
>>
>> Did you get the explain analyze output?
> 
> Unfortunately I stopped it as I thought it wasn't going to return
> anything meaningful. I've restarted the import process and it will break
> right before the problematic query. Let's see if I can get any more info
> tomorrow.

So, I'm running again the EXPLAIN ANALYZE, although I don't expect it to
return anytime soon.

However I've discovered a few typos in the index creation. If we add it
to the fact that row estimates are off for this specific query, I can
understand that the chosen plan might have been way far from optimal
with some badly picked statistics.

This is the explain analyze of the query with proper indexes in place.
As you can see estimates are still off, even though run time is ~20s:

http://explain.depesz.com/s/1UY

For comparison, here is the old explain output:

http://explain.depesz.com/s/TqD

The case is closed and as Tom pointed out already the lseek-only
activity is due to the fact that the table is fully cached in the shared
buffers and a sequential scan inside a nested loop is consistent with it.

Sorry for the noise.


Cheers
-- 
Matteo Beccati

Development & Consulting - http://www.beccati.com/