Received: from localhost (unknown [200.46.204.187]) by postgresql.org (Postfix) with ESMTP id 6D0B22E35BD for ; Mon, 24 Dec 2007 10:51:45 -0400 (AST) Received: from postgresql.org ([200.46.204.71]) by localhost (mx1.hub.org [200.46.204.187]) (amavisd-maia, port 10024) with ESMTP id 86126-03 for ; Mon, 24 Dec 2007 10:51:20 -0400 (AST) Received: from ug-out-1314.google.com (ug-out-1314.google.com [66.249.92.171]) by postgresql.org (Postfix) with ESMTP id 53EF62E0294 for ; Mon, 24 Dec 2007 10:46:32 -0400 (AST) Received: by ug-out-1314.google.com with SMTP id j3so1269597ugf.49 for ; Mon, 24 Dec 2007 06:46:30 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=domainkey-signature:received:received:message-id:date:from:sender:to:subject:mime-version:content-type:x-google-sender-auth; bh=lF6J6iYJxtB0DnvQ+AS46hCgN58PaSVt5/eUKWY567I=; b=XmlRqvvYkRV6rhwjTTPnXcCDX5zB2gKeGQVGX7yHT8mDbSnlRwKUqveIb+3fq/ap+jSfJalR2rcd4WyGiCvJaB3RqLMVaT3oHSq95SXqqPU9R7JMM4qmbBHmlUKS3+PJ8hKxCEzaFs5GMB8x7PN3eJYiibL8xla2JHz7EJZeM5A= DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=message-id:date:from:sender:to:subject:mime-version:content-type:x-google-sender-auth; b=jUdka/zZulsMkJObXlutp5+pRfJqs2kdGT95sTnuqGirmnxh532qowyq/diPl7zli/eGC8ZNgmRNxrR00BiGAPDszmbtVkEwYg0RxiGlL/0Wv6CxDSeY6Si5x2HhyC61ayfZOrBTeM5nwLfoWBJomW+95eJvu4VMpUQyh/pItng= Received: by 10.67.195.14 with SMTP id x14mr3317983ugp.40.1198507590743; Mon, 24 Dec 2007 06:46:30 -0800 (PST) Received: by 10.67.28.8 with HTTP; Mon, 24 Dec 2007 06:46:30 -0800 (PST) Message-ID: <809128960712240646q422b11afi8891433279172789@mail.gmail.com> Date: Mon, 24 Dec 2007 09:46:30 -0500 From: Marc To: pgsql-sql@postgresql.org Subject: slow query - only uses indices MIME-Version: 1.0 Content-Type: multipart/alternative; boundary="----=_Part_5675_17107189.1198507590731" X-Google-Sender-Auth: 6dda7ce9ffec3f59 X-Virus-Scanned: Maia Mailguard 1.0.1 X-Archive-Number: 200712/128 X-Sequence-Number: 29820 ------=_Part_5675_17107189.1198507590731 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Content-Disposition: inline Hey Folks, This query is running really slowly. Sometimes much slower then others. I have a feeling that there may be contention on one of the indices it is using. In the explain plan, it looks like it estimates 2 rows but actually finds 228 rows? Is that really bad? Query and explain plan are below. Seems like it spend the most time doing Index Scan using i_tablea_atextfield on tablea ru (cost=0.00..2265.28rows=2 width=12) (actual time= 0.624..881.313 rows=228 loops=1) Any suggestions? SELECT z.atextfield, z.btextfield, z.abigintfield, p.achar255field, p.ptextfield, z.achar1field, u.aboolfield, z.textfield1, z.achar8field, z.achar16field FROM tablea ru INNER JOIN tableb u ON ( u.atextfield = ru.anothertextfield ) INNER JOIN tablec z ON u.atextfield = z.atextfield INNER JOIN tabled p ON p.id = z.pid LEFT JOIN tablee m ON u.atextfield = m.atextfield AND m.boolcol5 WHERE ru.atextfield = 'thelookupval' AND u.boolcol1 IS TRUE AND u.boolcol2 IS FALSE AND ru.achar1field <> 'N' AND ru.boolcol3 IS FALSE AND NOT EXISTS ( SELECT 'x' FROM tablea fru WHERE fru.atextfield = ru.anothertextfield AND fru.boolcol3 IS TRUE ) AND EXISTS ( SELECT 'x' FROM tablef s WHERE s.atextfield = ru.atextfieldAND s.boolcol4 IS TRUE ) ORDER by ru.anothertextfield asc Sort (cost=2341.96..2341.97 rows=2 width=146) (actual time= 1118.810..1119.098 rows=228 loops=1) Sort Key: ru.anothertextfield -> Nested Loop Left Join (cost=0.00..2341.95 rows=2 width=146) (actual time= 0.930..1117.258 rows=228 loops=1) -> Nested Loop (cost=0.00..2313.36 rows=2 width=131) (actual time= 0.842..914.554 rows=228 loops=1) -> Nested Loop (cost=0.00..2296.65 rows=2 width=93) (actual time= 0.765..901.916 rows=228 loops=1) -> Nested Loop (cost=0.00..2281.98 rows=2 width=72) (actual time=0.690..893.648 rows=228 loops=1) -> Index Scan using i_tablea_atextfield on tablea ru (cost= 0.00..2265.28 rows=2 width=12) (actual time=0.624..881.313rows=228 loops=1) Index Cond: (atextfield = 'thelookupval'::text) Filter: ((achar1field <> 'N'::bpchar) AND (boolcol3 IS FALSE) AND (NOT (subplan)) AND (subplan)) SubPlan -> Index Scan using tablef_pkey on tablef s (cost=0.00..8.34 rows=1 width=0) (actual time=0.016..0.016 rows=1 loops=228) Index Cond: (atextfield = $1) Filter: (boolcol4 IS TRUE) -> Bitmap Heap Scan on tablea fru (cost= 4.61..90.41 rows=1 width=0) (actual time=3.590..3.590 rows=0 loops=243) Recheck Cond: (atextfield = $0) Filter: (boolcol3 IS TRUE) -> Bitmap Index Scan on i_tablea_atextfield (cost= 0.00..4.61 rows=22 width=0) (actual time= 0.044..0.044 rows=17 loops=243) Index Cond: (atextfield = $0) -> Index Scan using tablec_pkey on tablec z (cost= 0.00..8.34 rows=1 width=60) (actual time=0.047..0.049 rows=1 loops=228) Index Cond: (z.atextfield = ru.anothertextfield) -> Index Scan using tabled_pkey on tabled p (cost= 0.00..7.32 rows=1 width=29) (actual time=0.030..0.031 rows=1 loops=228) Index Cond: (p.id = z.pid) -> Index Scan using tableb_pkey on tableb u (cost= 0.00..8.34 rows=1 width=38) (actual time=0.049..0.051 rows=1 loops=228) Index Cond: (u.atextfield = ru.anothertextfield) Filter: ((boolcol1 IS TRUE) AND (boolcol2" IS FALSE))" -> Index Scan using tablee_atextfield_idx on tablee m (cost= 0.00..14.28 rows=1 width=39) (actual time=0.883..0.883 rows=0 loops=228) Index Cond: (u.atextfield = m.atextfield) ------=_Part_5675_17107189.1198507590731 Content-Type: text/html; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Content-Disposition: inline
Hey Folks,

This query is running really slowly.  Sometimes much slower then others.  I have a feeling that there may be contention on one of the indices it is using.  In the explain plan, it looks like it estimates 2 rows but actually finds 228 rows?  Is that really bad? 


Query and explain plan are below.  Seems like it spend the most time doing
Index Scan using i_tablea_atextfield on tablea ru  (cost=0.00..2265.28 rows=2 width=12) (actual time=0.624..881.313 rows=228 loops=1)

Any suggestions?

SELECT z.atextfield,    
       z.btextfield,    
       z.abigintfield,    
       p.achar255field, p.ptextfield,    
       z.achar1field,     u.aboolfield,    
       z.textfield1,    
       z.achar8field,    
       z.achar16field  
FROM tablea ru   
INNER JOIN tableb u ON ( u.atextfield = ru.anothertextfield )   
INNER JOIN tablec z ON u.atextfield = z.atextfield   
INNER JOIN tabled p ON p.id = z.pid   
LEFT JOIN tablee m ON u.atextfield = m.atextfield  AND m.boolcol5
WHERE ru.atextfield = 'thelookupval'  
  AND u.boolcol1 IS TRUE  
  AND u.boolcol2 IS FALSE  
  AND ru.achar1field <> 'N'  
  AND ru.boolcol3 IS FALSE  
  AND NOT EXISTS ( SELECT 'x' FROM tablea fru WHERE fru.atextfield = ru.anothertextfield AND fru.boolcol3 IS TRUE )
  AND EXISTS ( SELECT 'x' FROM tablef s WHERE s.atextfield = ru.atextfield AND s.boolcol4 IS TRUE )
  ORDER by ru.anothertextfield asc



Sort  (cost=2341.96..2341.97 rows=2 width=146) (actual time=1118.810..1119.098 rows=228 loops=1)
  Sort Key: ru.anothertextfield
  ->  Nested Loop Left Join  (cost=0.00..2341.95 rows=2 width=146) (actual time= 0.930..1117.258 rows=228 loops=1)
        ->  Nested Loop  (cost=0.00..2313.36 rows=2 width=131) (actual time=0.842..914.554 rows=228 loops=1)
              ->  Nested Loop  (cost=0.00..2296.65 rows=2 width=93) (actual time= 0.765..901.916 rows=228 loops=1)
                    ->  Nested Loop  (cost=0.00..2281.98 rows=2 width=72) (actual time=0.690..893.648 rows=228 loops=1)
                          ->  Index Scan using i_tablea_atextfield on tablea ru  (cost= 0.00..2265.28 rows=2 width=12) (actual time=0.624..881.313 rows=228 loops=1)
                                Index Cond: (atextfield = 'thelookupval'::text)
                                Filter: ((achar1field <> 'N'::bpchar) AND (boolcol3 IS FALSE) AND (NOT (subplan)) AND (subplan))
                                SubPlan
                                  ->  Index Scan using tablef_pkey on tablef s  (cost=0.00..8.34 rows=1 width=0) (actual time=0.016..0.016 rows=1 loops=228)
                                        Index Cond: (atextfield = $1)
                                        Filter: (boolcol4 IS TRUE)
                                  ->  Bitmap Heap Scan on tablea fru  (cost=4.61..90.41 rows=1 width=0) (actual time=3.590..3.590 rows=0 loops=243)
                                        Recheck Cond: (atextfield = $0)
                                        Filter: (boolcol3 IS TRUE)
                                        ->  Bitmap Index Scan on i_tablea_atextfield  (cost= 0.00..4.61 rows=22 width=0) (actual time=0.044..0.044 rows=17 loops=243)
                                              Index Cond: (atextfield = $0)
                          ->  Index Scan using tablec_pkey on tablec z  (cost= 0.00..8.34 rows=1 width=60) (actual time=0.047..0.049 rows=1 loops=228)
                                Index Cond: (z.atextfield = ru.anothertextfield)
                    ->  Index Scan using tabled_pkey on tabled p  (cost= 0.00..7.32 rows=1 width=29) (actual time=0.030..0.031 rows=1 loops=228)
                          Index Cond: (p.id = z.pid)
              ->  Index Scan using tableb_pkey on tableb u  (cost= 0.00..8.34 rows=1 width=38) (actual time=0.049..0.051 rows=1 loops=228)
                    Index Cond: (u.atextfield = ru.anothertextfield)
                    Filter: ((boolcol1 IS TRUE) AND (boolcol2" IS FALSE))"
        ->  Index Scan using tablee_atextfield_idx on tablee m  (cost=0.00..14.28 rows=1 width=39) (actual time=0.883..0.883 rows=0 loops=228)
              Index Cond: (u.atextfield = m.atextfield)



------=_Part_5675_17107189.1198507590731--