Date: Tue, 28 Mar 2006 10:22:00 -0500
From: george young <gry@ll.mit.edu>
To: Simon Riggs <simon@2ndquadrant.com>
Cc: pgsql-performance@postgresql.org
Subject: Re: simple join uses indexes, very slow
Message-Id: <20060328102200.39077862.gry@ll.mit.edu>
In-Reply-To: <1143534654.3839.251.camel@localhost.localdomain>
References: <20060327134733.72422d23.gry@ll.mit.edu>
	<1143534654.3839.251.camel@localhost.localdomain>
Reply-To: gry@ll.mit.edu
Organization: MIT Lincoln Laboratory
Mime-Version: 1.0
Content-Type: text/plain; charset=US-ASCII
Content-Transfer-Encoding: 7bit

On Tue, 28 Mar 2006 09:30:54 +0100
Simon Riggs <simon@2ndquadrant.com> threw this fish to the penguins:

> On Mon, 2006-03-27 at 13:47 -0500, george young wrote:
> 
> > Table sizes: parameters has 2.1512e+07 tuples, run_opsets has 211745 tuples.
> > 
> > explain analyze SELECT ro.run, ro.opset_num, p.step_num FROM run_opsets ro, parameters p WHERE ro.run = p.run AND ro.opset_num = p.opset_num and ro.run='team9';
> >                                                                  QUERY PLAN
> > --------------------------------------------------------------------------------------------------------------------------------------------
> >  Nested Loop  (cost=2.16..7957.40 rows=6707 width=22) (actual time=14.986..70197.129 rows=43050 loops=1)
> >    ->  Index Scan using run_opsets_pkey on run_opsets ro  (cost=0.00..128.75 rows=71 width=18) (actual time=0.386..62.959 rows=263 loops=1)
> >          Index Cond: (run = 'team9'::text)
> >    ->  Bitmap Heap Scan on parameters p  (cost=2.16..109.93 rows=27 width=22) (actual time=1.591..266.211 rows=164 loops=263)
> >          Recheck Cond: (('team9'::text = p.run) AND ("outer".opset_num = p.opset_num))
> >          ->  Bitmap Index Scan on parameters_idx  (cost=0.00..2.16 rows=27 width=0) (actual time=1.153..1.153 rows=164 loops=263)
> >                Index Cond: (('team9'::text = p.run) AND ("outer".opset_num = p.opset_num))
> >  Total runtime: 70237.727 ms
> > (8 rows)
> 
> The planner appears to be underestimating the number of rows retrieved
> in both cases, then multiplying them together to make it worse.
> Multi-column indexes provide less accurate estimates (right now).
> 
> Looks like a hash join might be faster. What is your work_mem set to?
work_mem= 1024


> Can you SET enable_nestloop=off and rerun the EXPLAIN ANALYZE?
newschm3=> set enable_nestloop=off ;
SET
newschm3=> explain analyze SELECT ro.run, ro.opset_num, p.step_num FROM run_opsets ro, parameters p WHERE ro.run = p.run AND ro.opset_num = p.opset_num and ro.run='team9';
                                                                     QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------------------------
 Merge Join  (cost=34177.87..34291.36 rows=6707 width=22) (actual time=68421.681..68547.686 rows=43050 loops=1)
   Merge Cond: ("outer".opset_num = "inner".opset_num)
   ->  Sort  (cost=130.93..131.11 rows=71 width=18) (actual time=107.744..107.901 rows=263 loops=1)
         Sort Key: ro.opset_num
         ->  Index Scan using run_opsets_pkey on run_opsets ro  (cost=0.00..128.75 rows=71 width=18) (actual time=57.641..106.096 rows=263 loops=1)
               Index Cond: (run = 'team9'::text)
   ->  Sort  (cost=34046.94..34070.02 rows=9231 width=22) (actual time=68301.325..68358.087 rows=43050 loops=1)
         Sort Key: p.opset_num
         ->  Bitmap Heap Scan on parameters p  (cost=272.31..33438.97 rows=9231 width=22) (actual time=526.462..67363.577 rows=43050 loops=1)
               Recheck Cond: ('team9'::text = run)
               ->  Bitmap Index Scan on parameters_idx  (cost=0.00..272.31 rows=9231 width=0) (actual time=483.500..483.500 rows=43050 loops=1)
                     Index Cond: ('team9'::text = run)
 Total runtime: 68595.868 ms
(13 rows)

-- George Young

-- 
"Are the gods not just?"  "Oh no, child.
What would become of us if they were?" (CSL)