Re: Problem analyzing explain analyze output

From: "Steinar H(dot) Gunderson" <sgunderson(at)bigfoot(dot)com>
To: Guillaume Smet <guillaume(dot)smet(at)openwide(dot)fr>
Cc: pgsql-performance(at)postgresql(dot)org
Subject: Re: Problem analyzing explain analyze output
Date: 2005-10-24 00:08:24
Message-ID: 20051024000824.GA11800@samfundet.no
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

On Mon, Oct 24, 2005 at 01:53:59AM +0200, Guillaume Smet wrote:
> I don't understand why I have the Nested Loop at line 19 with an actual
> time of 254.292..257.328 because I can't find anywhere the line taking
> this 254 ms.

You don't have a nested loop with that time; however, you have

> -> Nested Loop (cost=887.45..4031.09 rows=587 width=20) (actual time=254.424..280.794 rows=514 loops=1)
> -> Bitmap Heap Scan on contcrilieu ccl (cost=887.45..1668.96 rows=587 width=8) (actual time=254.292..257.328 rows=514 loops=1)
> Recheck Cond: ((dcrilieu >= (now() - '60 days'::interval)) AND ((flagcriaccepteelieu)::text = 'O'::text))
> -> Bitmap Index Scan on idx_contcrilieu_4 (cost=0.00..887.45 rows=587 width=0) (actual time=254.143..254.143 rows=514 loops=1)
> Index Cond: ((dcrilieu >= (now() - '60 days'::interval)) AND ((flagcriaccepteelieu)::text = 'O'::text))
> -> Index Scan using pk_lieu on lieu l (cost=0.00..4.01 rows=1 width=12) (actual time=0.034..0.036 rows=1 loops=514)
> Index Cond: ("outer".numlieu = l.numlieu)

which seems to make sense; you have one run of about 257ms, plus 514 runs
taking about 0.035ms each (ie. about 18ms), which should add up to become
about 275ms (which is close enough to the reality of 281ms).

/* Steinar */
--
Homepage: http://www.sesse.net/

In response to

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Karl O. Pinc 2005-10-24 00:25:09 Re: Using LIMIT 1 in plpgsql PERFORM statements
Previous Message Guillaume Smet 2005-10-23 23:53:59 Problem analyzing explain analyze output