Bad planner results - Mailing list pgsql-general

From Greg Stark
Subject Bad planner results
Date
Msg-id 87u0ut0yr1.fsf@stark.xeocode.com
Whole thread Raw
Responses Re: Bad planner results
List pgsql-general
I think this is just a bad case of "nested loops are costed wrong". But it's a
really really bad case. Like, even without any overlap in records looked up in
the nested loop I cannot imagine it ever being the wrong plan for these stats.
And Postgres is insistent on avoiding it, I have to disable both merge and
hash joins to get the 5ms nested loop join.



db=> EXPLAIN ANALYZE
 SELECT distinct foo
   FROM t1 join t1_t2 using (t1_id) join t2 using (t2_id)
  WHERE bar = 232
;

                                                                                  QUERY PLAN
                                                     

----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Unique  (cost=13036.55..13056.98 rows=33 width=4) (actual time=1040.238..1040.368 rows=11 loops=1)
   ->  Sort  (cost=13036.55..13046.76 rows=4087 width=4) (actual time=1040.234..1040.291 rows=93 loops=1)
         Sort Key: t1.foo
         ->  Hash Join  (cost=267.80..12791.39 rows=4087 width=4) (actual time=12.511..1040.084 rows=93 loops=1)
               Hash Cond: ("outer".t1_id = "inner".t1_id)
               ->  Hash Join  (cost=125.43..12587.72 rows=4087 width=4) (actual time=1.344..1028.681 rows=93 loops=1)
                     Hash Cond: ("outer".t2_id = "inner".t2_id)
                     ->  Seq Scan on t1_t2  (cost=0.00..9507.28 rows=582828 width=8) (actual time=0.003..572.865
rows=582828loops=1) 
                     ->  Hash  (cost=125.14..125.14 rows=117 width=4) (actual time=0.463..0.463 rows=0 loops=1)
                           ->  Index Scan using idx_t2_bar on t2  (cost=0.00..125.14 rows=117 width=4) (actual
time=0.028..0.331rows=95 loops=1) 
                                 Index Cond: (bar = 232)
               ->  Hash  (cost=133.89..133.89 rows=3389 width=8) (actual time=10.537..10.537 rows=0 loops=1)
                     ->  Seq Scan on t1  (cost=0.00..133.89 rows=3389 width=8) (actual time=0.018..6.422 rows=3389
loops=1)
 Total runtime: 1040.752 ms
(14 rows)



db=> set enable_hashjoin = false;

                                                                                        QUERY PLAN
                                                                  

-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Unique  (cost=15715.48..15735.92 rows=33 width=4) (actual time=98.095..98.230 rows=11 loops=1)
   ->  Sort  (cost=15715.48..15725.70 rows=4087 width=4) (actual time=98.091..98.151 rows=93 loops=1)
         Sort Key: t1.foo
         ->  Merge Join  (cost=15233.28..15470.33 rows=4087 width=4) (actual time=85.827..97.943 rows=93 loops=1)
               Merge Cond: ("outer".t1_id = "inner".t1_id)
               ->  Index Scan using t1_pkey on t1  (cost=0.00..167.27 rows=3389 width=8) (actual time=0.025..10.374
rows=3291loops=1) 
               ->  Sort  (cost=15233.28..15243.50 rows=4087 width=4) (actual time=83.872..83.936 rows=93 loops=1)
                     Sort Key: t1_t2.t1_id
                     ->  Merge Join  (cost=129.16..14988.13 rows=4087 width=4) (actual time=13.992..83.729 rows=93
loops=1)
                           Merge Cond: ("outer".t2_id = "inner".t2_id)
                           ->  Index Scan using t1_t2_all on t1_t2  (cost=0.00..13600.12 rows=582828 width=8) (actual
time=0.016..58.722rows=24533 loops=1) 
                           ->  Sort  (cost=129.16..129.45 rows=117 width=4) (actual time=0.866..0.974 rows=163 loops=1)
                                 Sort Key: t2.t2_id
                                 ->  Index Scan using idx_t2_bar on t2  (cost=0.00..125.14 rows=117 width=4) (actual
time=0.024..0.648rows=95 loops=1) 
                                       Index Cond: (bar = 232)
 Total runtime: 98.406 ms
(16 rows)

db=> set enable_hashjoin = false;
SET
db=> set enable_mergejoin = false;
SET

                                                                                 QUERY PLAN
                                                    

---------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Unique  (cost=42624.09..42644.53 rows=33 width=4) (actual time=4.257..4.390 rows=11 loops=1)
   ->  Sort  (cost=42624.09..42634.31 rows=4087 width=4) (actual time=4.255..4.310 rows=93 loops=1)
         Sort Key: t1.foo
         ->  Nested Loop  (cost=0.00..42378.94 rows=4087 width=4) (actual time=0.249..4.095 rows=93 loops=1)
               ->  Nested Loop  (cost=0.00..29219.05 rows=4087 width=4) (actual time=0.220..2.247 rows=93 loops=1)
                     ->  Index Scan using idx_t2_bar on t2  (cost=0.00..125.14 rows=117 width=4) (actual
time=0.029..0.372rows=95 loops=1) 
                           Index Cond: (bar = 232)
                     ->  Index Scan using t1_t2_code on t1_t2  (cost=0.00..245.63 rows=243 width=8) (actual
time=0.012..0.015rows=1 loops=95) 
                           Index Cond: (t1_t2.t2_id = "outer".t2_id)
               ->  Index Scan using t1_pkey on t1  (cost=0.00..3.21 rows=1 width=8) (actual time=0.012..0.015 rows=1
loops=93)
                     Index Cond: (t1.t1_id = "outer".t1_id)
 Total runtime: 4.564 ms
(12 rows)



--
greg

pgsql-general by date:

Previous
From: Secrétariat
Date:
Subject: Re: Connection to a PG 8.0 Beta 1 win32 server
Next
From: "Magnus Hagander"
Date:
Subject: Re: Connection to a PG 8.0 Beta 1 win32 server