X-Original-To: pgsql-performance-postgresql.org@localhost.postgresql.org Received: from localhost (av.hub.org [200.46.204.144]) by svr1.postgresql.org (Postfix) with ESMTP id 4D972DAB27 for ; Sun, 23 Oct 2005 21:08:30 -0300 (ADT) Received: from svr1.postgresql.org ([200.46.204.71]) by localhost (av.hub.org [200.46.204.144]) (amavisd-new, port 10024) with ESMTP id 09509-01 for ; Mon, 24 Oct 2005 00:08:23 +0000 (GMT) Received: from cassarossa.samfundet.no (cassarossa.samfundet.no [129.241.93.19]) by svr1.postgresql.org (Postfix) with ESMTP id 548D1DAB13 for ; Sun, 23 Oct 2005 21:08:25 -0300 (ADT) Received: from sesse by cassarossa.samfundet.no with local (Exim 4.50) id 1ETpt2-000392-FS; Mon, 24 Oct 2005 02:08:24 +0200 Date: Mon, 24 Oct 2005 02:08:24 +0200 From: "Steinar H. Gunderson" To: Guillaume Smet Cc: pgsql-performance@postgresql.org Subject: Re: Problem analyzing explain analyze output Message-ID: <20051024000824.GA11800@samfundet.no> References: <435C2297.5050207@openwide.fr> Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <435C2297.5050207@openwide.fr> User-Agent: Mutt/1.5.9i X-Virus-Scanned: by amavisd-new at hub.org X-Spam-Status: No, hits=0.011 required=5 tests=[AWL=0.011] X-Spam-Level: X-Archive-Number: 200510/322 X-Sequence-Number: 15090 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/