Received: from localhost (unknown [200.46.204.183]) by postgresql.org (Postfix) with ESMTP id 66E8A64FC22 for ; Tue, 23 Sep 2008 21:53:54 -0300 (ADT) Received: from postgresql.org ([200.46.204.86]) by localhost (mx1.hub.org [200.46.204.183]) (amavisd-maia, port 10024) with ESMTP id 65899-01 for ; Tue, 23 Sep 2008 21:53:51 -0300 (ADT) X-Greylist: domain auto-whitelisted by SQLgrey-1.7.6 Received: from fg-out-1718.google.com (fg-out-1718.google.com [72.14.220.154]) by postgresql.org (Postfix) with ESMTP id 2642B64FC04 for ; Tue, 23 Sep 2008 21:53:50 -0300 (ADT) Received: by fg-out-1718.google.com with SMTP id 16so2063412fgg.23 for ; Tue, 23 Sep 2008 17:53:49 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=domainkey-signature:received:received:message-id:date:from:to :subject:mime-version:content-type:content-transfer-encoding :content-disposition; bh=3mJE2rJamBxFSqh3FzYb85jV2apf8BjMPXQvJPWWSxU=; b=cmgtlHb9SB6H6hD0noyKqwAXz8sialiHKGVUM2+2tfCnEqvMofFgU4CLCrKq/h+qEh R8LiHKJSK5aHf2zDJGPhCFtBeQaCEucE41a892dnI5GwNUvGUULI9DkIJbBjHLRb1mbQ jiDSaJ9SvsepU3FnfSC6QMhCV8C/mp5ldb+B8= DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=message-id:date:from:to:subject:mime-version:content-type :content-transfer-encoding:content-disposition; b=gIJuVNlLoZtPxxRr4Z9BhCDF4tg401xn3uNGGlJIdmcF0IzyZAsiIFQz+4nzOy1If0 9ydPn5PYouXawVAUEU6ii/5OUtCGmKNXWcXBwq610rNfBNikNoeJk1gwJ2b8OhwXc3iP X2UI+jSlMvcQGSC2l8qWJ1b4DK/j/7FTz3/Ic= Received: by 10.187.194.1 with SMTP id w1mr937508fap.41.1222217629306; Tue, 23 Sep 2008 17:53:49 -0700 (PDT) Received: by 10.187.245.20 with HTTP; Tue, 23 Sep 2008 17:53:49 -0700 (PDT) Message-ID: <4f8bd5c90809231753xbcdacd2xfba4d38c2eb34faf@mail.gmail.com> Date: Wed, 24 Sep 2008 03:53:49 +0300 From: Einars To: pgsql-performance@postgresql.org Subject: Chaotically weird execution plan MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 7bit Content-Disposition: inline X-Virus-Scanned: Maia Mailguard 1.0.1 X-Spam-Status: No, hits=0 tagged_above=0 required=5 tests=none X-Spam-Level: X-Archive-Number: 200809/205 X-Sequence-Number: 31518 When displaying information about information about an user in our site, I noticed an unreasonable slowdown. The culprit turned out to be a trivial select, which determines the number of comments left by an user: select count(*) from comments where created_by=80 and status=1; The comments table structure is below, and contains ~2 million records. I guess postgresql is unable to figure out exactly how to make use of the index condition? As query plan shows, it got the correct answer, 15888, very fast: the rest of the 13 seconds it's just rechecking all the comments for some weird reasons. The weird thing is, SOMETIMES, for other created_by values, it seems to work fine, as shown below as well. Is this a bug, or I'm missing something here? Thanks, Einars Lielmanis *** worse plan example: etests=> explain analyze select count(*) from comments where created_by=80 and status=1; QUERY PLAN ---------------------------------------------------------------------------------------------------------------------------------------------- Aggregate (cost=50947.51..50947.52 rows=1 width=0) (actual time=13134.360..13134.361 rows=1 loops=1) -> Bitmap Heap Scan on comments (cost=331.42..50898.41 rows=19639 width=0) (actual time=40.865..13124.116 rows=15888 loops=1) Recheck Cond: ((created_by = 80) AND (status = 1)) -> Bitmap Index Scan on comments_created_by (cost=0.00..326.51 rows=19639 width=0) (actual time=33.547..33.547 rows=15888 loops=1) Index Cond: (created_by = 80) Total runtime: 13134.688 ms *** better plan example: etests=> explain analyze select count(*) from comments where created_by=81 and status=1; QUERY PLAN ---------------------------------------------------------------------------------------------------------------------------------------- Aggregate (cost=854.10..854.11 rows=1 width=0) (actual time=0.083..0.083 rows=1 loops=1) -> Index Scan using comments_created_by on comments (cost=0.00..853.44 rows=262 width=0) (actual time=0.057..0.076 rows=3 loops=1) Index Cond: (created_by = 81) Total runtime: 0.121 ms *** structure etests=> \d comments; Table "public.comments" Column | Type | Modifiers -----------------+-----------------------------+--------------------------------------------------------------- comment_id | integer | not null default nextval('comments_comment_id_seq'::regclass) message_wiki | text | message_html | text | status | integer | post_id | integer | created | timestamp without time zone | created_by | integer | Indexes: "comments_pkey" PRIMARY KEY, btree (comment_id) "comments_created_by" btree (created_by) WHERE status = 1 "comments_for_post" btree (post_id, created) WHERE status = 1 Check constraints: "comments_status_check" CHECK (status = ANY (ARRAY[0, 1, 2])) Foreign-key constraints: "comments_created_by_fkey" FOREIGN KEY (created_by) REFERENCES members(member_id) "comments_thread_id_fkey" FOREIGN KEY (post_id) REFERENCES posts(post_id) PostgreSQL 8.3.1 on i686-pc-linux-gnu, compiled by GCC gcc (GCC) 4.2.3 (Ubuntu 4.2.3-2ubuntu7)