Received: from maia.hub.org (unknown [200.46.204.183]) by mail.postgresql.org (Postfix) with ESMTP id 5F339632716 for ; Mon, 15 Feb 2010 05:53:15 -0400 (AST) Received: from mail.postgresql.org ([200.46.204.86]) by maia.hub.org (mx1.hub.org [200.46.204.183]) (amavisd-maia, port 10024) with ESMTP id 54362-04 for ; Mon, 15 Feb 2010 09:53:04 +0000 (UTC) X-Greylist: from auto-whitelisted by SQLgrey-1.7.6 Received: from smtp2e.orange.fr (smtp2e.orange.fr [80.12.242.111]) by mail.postgresql.org (Postfix) with ESMTP id 60DA463261E for ; Mon, 15 Feb 2010 05:53:04 -0400 (AST) Received: from me-wanadoo.net (localhost [127.0.0.1]) by mwinf2e01.orange.fr (SMTP Server) with ESMTP id C700B800027C for ; Mon, 15 Feb 2010 10:53:01 +0100 (CET) Received: from me-wanadoo.net (localhost [127.0.0.1]) by mwinf2e01.orange.fr (SMTP Server) with ESMTP id B380D800023E for ; Mon, 15 Feb 2010 10:53:01 +0100 (CET) Received: from [192.168.10.15] (ARennes-257-1-110-118.w86-210.abo.wanadoo.fr [86.210.21.118]) by mwinf2e01.orange.fr (SMTP Server) with ESMTP id 9EDC8800027C for ; Mon, 15 Feb 2010 10:52:56 +0100 (CET) X-ME-UUID: 20100215095257650.9EDC8800027C@mwinf2e01.orange.fr Message-ID: <4B791971.6020804@boozter.com> Date: Mon, 15 Feb 2010 10:52:49 +0100 From: lionel duboeuf User-Agent: Thunderbird 2.0.0.23 (X11/20090817) MIME-Version: 1.0 To: pgsql-performance@postgresql.org Subject: Re: Almost infinite query -> Different Query Plan when changing where clause value References: <4B755913.7090004@boozter.com> <4B7519C5020000250002F242@gw.wicourts.gov> <4B75BADE.9030906@boozter.com> <4B756CE5020000250002F27C@gw.wicourts.gov> In-Reply-To: <4B756CE5020000250002F27C@gw.wicourts.gov> Content-Type: multipart/mixed; boundary="------------050608010305060505000904" X-Virus-Scanned: Maia Mailguard 1.0.1 X-Spam-Status: No, hits=-2.599 tagged_above=-10 required=5 tests=BAYES_00=-2.599 X-Spam-Level: X-Archive-Number: 201002/233 X-Sequence-Number: 37654 This is a multi-part message in MIME format. --------------050608010305060505000904 Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 8bit See as attachment the "correct" query plan for an other 'user'. I confirm by executing manual "VACUUM ANALYZE" that the problem is solved. But what i don't understand is that i would expect autovacuum to do the job. Lionel Kevin Grittner a écrit : > lionel duboeuf wrote: > >> Thanks kevin for your answer. Here is some additionnal >> informations attached as files. >> > > Could you supply an EXPLAIN ANALYZE of the fast plan as an > attachment, for comparison? > > Anyway, it looks like at least one big problem is the bad estimate > on how many rows will be generated by joining to the users5_ table: > > >> (cost=13.20..1427.83 rows=1 width=24) >> (actual time=1.374..517.662 rows=122850 loops=1) >> > > If it had expected 122850 rows to qualify for that join, it probably > would have picked a different plan. > > I just reread your original email, and I'm not sure I understand > what you meant regarding VACUUM ANALYZE. If you run that right > beforehand, do you still get the slow plan for user 10? > > -Kevin --------------050608010305060505000904 Content-Type: text/plain; name="explain_analyse_ok.txt" Content-Transfer-Encoding: 7bit Content-Disposition: inline; filename="explain_analyse_ok.txt" QUERY PLAN Nested Loop (cost=40145.11..87205.30 rows=1836 width=16) (actual time=4675.927..8731.066 rows=14 loops=1) -> Seq Scan on "user" user6_ (cost=0.00..5.89 rows=1 width=4) (actual time=0.021..0.070 rows=1 loops=1) Filter: (user_seqnum = 2) -> Nested Loop (cost=40145.11..87181.05 rows=1836 width=20) (actual time=4675.899..8730.951 rows=14 loops=1) -> Seq Scan on block block10_ (cost=0.00..1.14 rows=1 width=4) (actual time=0.005..0.013 rows=1 loops=1) Filter: (block_seqnum = 5) -> Hash Join (cost=40145.11..87161.55 rows=1836 width=24) (actual time=4675.889..8730.897 rows=14 loops=1) Hash Cond: (link0_.element_source = blocks9_.element_seqnum) -> Hash Join (cost=38355.16..84432.84 rows=81814 width=28) (actual time=1959.785..8659.972 rows=54481 loops=1) Hash Cond: (link0_.element_source = element2_.element_seqnum) -> Hash Join (cost=15293.09..59268.67 rows=100436 width=12) (actual time=213.249..6178.980 rows=357563 loops=1) Hash Cond: (link0_.element_target = element1_.element_seqnum) -> Seq Scan on link link0_ (cost=0.00..36544.07 rows=1968922 width=12) (actual time=0.017..2750.650 rows=1968833 loops=1) Filter: (link_sup_date IS NULL) -> Hash (cost=15280.27..15280.27 rows=1025 width=12) (actual time=212.858..212.858 rows=15 loops=1) -> Nested Loop (cost=2881.38..15280.27 rows=1025 width=12) (actual time=9.566..212.823 rows=15 loops=1) -> Seq Scan on "user" user4_ (cost=0.00..5.89 rows=1 width=4) (actual time=0.012..0.051 rows=1 loops=1) Filter: (user_seqnum = 2) -> Nested Loop (cost=2881.38..15264.14 rows=1025 width=16) (actual time=9.549..212.724 rows=15 loops=1) -> Seq Scan on block block8_ (cost=0.00..1.14 rows=1 width=4) (actual time=0.004..0.009 rows=1 loops=1) Filter: (block_seqnum = 5) -> Nested Loop (cost=2881.38..15252.75 rows=1025 width=20) (actual time=9.540..212.673 rows=15 loops=1) -> Hash Join (cost=2881.38..6613.08 rows=1434 width=16) (actual time=9.522..212.453 rows=15 loops=1) Hash Cond: (users3_.element_seqnum = blocks7_.element_seqnum) -> Bitmap Heap Scan on user_element users3_ (cost=1091.43..4090.04 rows=63889 width=8) (actual time=9.252..131.240 rows=60568 loops=1) Recheck Cond: (user_seqnum = 2) -> Bitmap Index Scan on fki_user_element_user (cost=0.00..1075.46 rows=63889 width=0) (actual time=9.017..9.017 rows=60568 loops=1) Index Cond: (user_seqnum = 2) -> Hash (cost=1705.72..1705.72 rows=6738 width=8) (actual time=0.079..0.079 rows=15 loops=1) -> Bitmap Heap Scan on element_block blocks7_ (cost=116.50..1705.72 rows=6738 width=8) (actual time=0.032..0.053 rows=15 loops=1) Recheck Cond: (block_seqnum = 5) -> Bitmap Index Scan on fki_element_block_block (cost=0.00..114.81 rows=6738 width=0) (actual time=0.025..0.025 rows=15 loops=1) Index Cond: (block_seqnum = 5) -> Index Scan using pk_element on element element1_ (cost=0.00..6.01 rows=1 width=4) (actual time=0.007..0.008 rows=1 loops=15) Index Cond: (element1_.element_seqnum = users3_.element_seqnum) -> Hash (cost=21951.46..21951.46 rows=63889 width=16) (actual time=1746.309..1746.309 rows=60568 loops=1) -> Hash Join (cost=15534.07..21951.46 rows=63889 width=16) (actual time=1277.246..1653.836 rows=60568 loops=1) Hash Cond: (users5_.element_seqnum = element2_.element_seqnum) -> Bitmap Heap Scan on user_element users5_ (cost=1091.43..4090.04 rows=63889 width=8) (actual time=7.775..87.724 rows=60568 loops=1) Recheck Cond: (user_seqnum = 2) -> Bitmap Index Scan on fki_user_element_user (cost=0.00..1075.46 rows=63889 width=0) (actual time=7.565..7.565 rows=60568 loops=1) Index Cond: (user_seqnum = 2) -> Hash (cost=7552.95..7552.95 rows=419895 width=8) (actual time=1269.211..1269.211 rows=419895 loops=1) -> Seq Scan on element element2_ (cost=0.00..7552.95 rows=419895 width=8) (actual time=0.031..640.484 rows=419895 loops=1) -> Hash (cost=1705.72..1705.72 rows=6738 width=8) (actual time=0.081..0.081 rows=15 loops=1) -> Bitmap Heap Scan on element_block blocks9_ (cost=116.50..1705.72 rows=6738 width=8) (actual time=0.034..0.058 rows=15 loops=1) Recheck Cond: (block_seqnum = 5) -> Bitmap Index Scan on fki_element_block_block (cost=0.00..114.81 rows=6738 width=0) (actual time=0.028..0.028 rows=15 loops=1) Index Cond: (block_seqnum = 5) Total runtime: 8731.494 ms --------------050608010305060505000904--