Message-ID: <467C4C07.1090700@g2switchworks.com>
Date: Fri, 22 Jun 2007 17:24:07 -0500
From: Scott Marlowe <smarlowe@g2switchworks.com>
User-Agent: Thunderbird 1.5.0.4 (X11/20060516)
MIME-Version: 1.0
To: Tom Tamulewicz <tomjt7@hotmail.com>
CC: grzm@seespotcode.net,  pgsql-performance@postgresql.org
Subject: Re: Slow join query
References: <BAY140-F37C384351E25AC87580FA290170@phx.gbl>
In-Reply-To: <BAY140-F37C384351E25AC87580FA290170@phx.gbl>
Content-Type: text/plain; charset=ISO-8859-1; format=flowed
Content-Transfer-Encoding: 7bit

Tom Tamulewicz wrote:
>
>  
>
>         ------------------------------------------------------------------------
>
>     SELECT p.party_id, p.first_name, p.last_name, pli.address1,
>     pli.city, pli.state FROM customer as p JOIN address as pli ON (
>     p.party_id = pli.party_id ) WHERE ( p.void_flag IS NULL OR
>     p.void_flag = false )  AND  (first_name like 'B%') AND (last_name
>     like 'S%') AND (pli.state like 'M%') AND (pli.city like 'AL%')
>     ORDER BY last_name, first_name LIMIT 51  
>
>                                                                                                         
>     QUERY PLAN                                       
>     ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>      Limit  (cost=0.00..96.48 rows=1 width=2450) (actual
>     time=13459.814..13459.814 rows=0 loops=1)
>        ->  Nested Loop  (cost=0.00..96.48 rows=1 width=2450) (actual
>     time=13459.804..13459.804 rows=0 loops=1)
>              ->  Index Scan using idx_last_name on customer p 
>     (cost=0.00..50.22 rows=1 width=1209) (actual
>     time=57.812..13048.524 rows=2474 loops=1)
>                    Index Cond: (((last_name)::text >= 'S'::character
>     varying) AND ((last_name)::text < 'T'::character varying) AND
>     ((first_name)::text >= 'B'::character varying) AND
>     ((first_name)::text < 'C'::character varying))
>                    Filter: (((void_flag IS NULL) OR (void_flag =
>     false)) AND ((first_name)::text ~~ 'B%'::text) AND
>     ((last_name)::text ~~ 'S%'::text))
>              ->  Index Scan using address_pkey on address pli 
>     (cost=0.00..46.23 rows=1 width=1257) (actual time=0.149..0.149
>     rows=0 loops=2474)
>                    Index Cond: (("outer".party_id = pli.party_id))
>                    Filter: (((state)::text ~~ 'M%'::text) AND
>     ((city)::text ~~ 'AL%'::text))
>      Total runtime: 13460.292 ms
>

The problem here is this bit:

->  Index Scan using idx_last_name on customer p  (cost=0.00..50.22 
rows=1 width=1209) (actual time=57.812..13048.524 rows=2474 loops=1)
               Index Cond: (((last_name)::text >= 'S'::character 
varying) AND ((last_name)::text < 'T'::character varying) AND 
((first_name)::text >= 'B'::character varying) AND ((first_name)::text < 
'C'::character varying))
               Filter: (((void_flag IS NULL) OR (void_flag = false)) AND 
((first_name)::text ~~ 'B%'::text) AND ((last_name)::text ~~ 'S%'::text))

Note that you're getting back 2474 rows, but the planner expects 1.  Not 
the actual time going from 57 to 13048, it's spending all it's time 
looking up each tuple in the index, then in the table.  Using a seq scan 
would be much faster.

Have you analyzed this table?  If so, you might need to up the stats 
target on last_name and see if that helps.