Received: from maia.hub.org (unknown [200.46.204.183]) by mail.postgresql.org (Postfix) with ESMTP id 96CB1632AE5 for ; Wed, 10 Feb 2010 23:53:03 -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 71230-09 for ; Thu, 11 Feb 2010 03:52:52 +0000 (UTC) X-Greylist: from auto-whitelisted by SQLgrey-1.7.6 Received: from sss.pgh.pa.us (sss.pgh.pa.us [66.207.139.130]) by mail.postgresql.org (Postfix) with ESMTP id 1D0136327CD for ; Wed, 10 Feb 2010 23:52:53 -0400 (AST) Received: from sss2.sss.pgh.pa.us (tgl@localhost [127.0.0.1]) by sss.pgh.pa.us (8.14.2/8.14.2) with ESMTP id o1B3qne5028371; Wed, 10 Feb 2010 22:52:49 -0500 (EST) To: Bryce Nesbitt cc: pgsql-performance@postgresql.org, Robert Haas , Pavel Stehule , "Jorge Montero" Subject: Re: Re: 512, 600ms query becomes 7500ms... but why? Postgres 8.3 query planner quirk? In-reply-to: <4B7362DC.2060301@obviously.com> References: <4B723042.7090406@obviously.com> <4B726E81.2060904@obviously.com> <603c8f071002101231k45e9161eyeacf9072219489eb@mail.gmail.com> <4B7362DC.2060301@obviously.com> Comments: In-reply-to Bryce Nesbitt message dated "Wed, 10 Feb 2010 17:52:28 -0800" Date: Wed, 10 Feb 2010 22:52:49 -0500 Message-ID: <28370.1265860369@sss.pgh.pa.us> From: Tom Lane 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/180 X-Sequence-Number: 37601 Bryce Nesbitt writes: > The query plans are now attached (sorry I did not start there: many > lists reject attachments). Or you can click on "text" at the query > planner analysis site http://explain.depesz.com/s/qYq At least some of the problem is the terrible quality of the rowcount estimates in the IN subquery, as you extracted here: > Nested Loop (cost=0.00..23393.15 rows=23 width=4) (actual time=0.077..15.637 rows=4003 loops=1) > -> Index Scan using words_word on words (cost=0.00..5.47 rows=1 width=4) (actual time=0.049..0.051 rows=1 loops=1) > Index Cond: ((word)::text = 'insider'::text) > -> Index Scan using article_words_wc on article_words (cost=0.00..23234.38 rows=12264 width=8) (actual time=0.020..7.237 rows=4003 loops=1) > Index Cond: (article_words.word_key = words.word_key) > Total runtime: 19.776 ms Given that it estimated 1 row out of "words" (quite correctly) and 12264 rows out of each scan on article_words, you'd think that the join size estimate would be 12264, which would be off by "only" a factor of 3 from the true result. Instead it's 23, off by a factor of 200 :-(. Running a roughly similar test case here, I see that 8.4 gives significantly saner estimates, which I think is because of this patch: http://archives.postgresql.org/pgsql-committers/2008-10/msg00191.php At the time I didn't want to risk back-patching it, because there were a lot of other changes in the same general area in 8.4. But it would be interesting to see what happens with your example if you patch 8.3 similarly. (Note: I think only the first diff hunk is relevant to 8.3.) regards, tom lane