bad plan - Mailing list pgsql-performance

I posted this on hackers, but I had to post it here.


===================================================================================================================================
Hi all,
running a 7.4.5 engine, I'm facing this bad plan:


empdb=# explain analyze SELECT name,url,descr,request_status,url_status,size_mb,estimated_start,request_time_stamp
empdb-#                    FROM v_sc_user_request
empdb-#                    WHERE
empdb-#                         login = 'babinow1'
empdb-#                    LIMIT 10 ;
                                                                                                    QUERY PLAN

------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=1716.38..1716.39 rows=1 width=232) (actual time=52847.239..52847.322 rows=10 loops=1)
   ->  Subquery Scan v_sc_user_request  (cost=1716.38..1716.39 rows=1 width=232) (actual time=52847.234..52847.301
rows=10loops=1) 
         ->  Sort  (cost=1716.38..1716.39 rows=1 width=201) (actual time=52847.219..52847.227 rows=10 loops=1)
               Sort Key: sr.id_sat_request
               ->  Nested Loop Left Join  (cost=1478.82..1716.37 rows=1 width=201) (actual time=3254.483..52847.064
rows=31loops=1) 
                     Join Filter: ("outer".id_package = "inner".id_package)
                     ->  Nested Loop  (cost=493.09..691.55 rows=1 width=193) (actual time=347.665..940.582 rows=31
loops=1)
                           ->  Nested Loop  (cost=493.09..688.49 rows=1 width=40) (actual time=331.446..505.628 rows=31
loops=1)
                                 Join Filter: ("inner".id_user = "outer".id_user)
                                 ->  Index Scan using user_login_login_key on user_login ul  (cost=0.00..4.00 rows=2
width=16)(actual time=12.065..12.071 rows=1 loops=1) 
                                       Index Cond: ((login)::text = 'babinow1'::text)
                                 ->  Materialize  (cost=493.09..531.37 rows=7656 width=28) (actual
time=167.654..481.813rows=8363 loops=1) 
                                       ->  Seq Scan on sat_request sr  (cost=0.00..493.09 rows=7656 width=28) (actual
time=167.644..467.344rows=8363 loops=1) 
                                             Filter: (request_time > (now() - '1 mon'::interval))
                           ->  Index Scan using url_pkey on url u  (cost=0.00..3.05 rows=1 width=161) (actual
time=13.994..14.000rows=1 loops=31) 
                                 Index Cond: ("outer".id_url = u.id_url)
                     ->  Subquery Scan vsp  (cost=985.73..1016.53 rows=1103 width=12) (actual time=25.328..1668.754
rows=493loops=31) 
                           ->  Merge Join  (cost=985.73..1011.01 rows=1103 width=130) (actual time=25.321..1666.666
rows=493loops=31) 
                                 Merge Cond: ("outer".id_program = "inner".id_program)
                                 ->  Sort  (cost=20.74..20.97 rows=93 width=19) (actual time=0.385..0.431 rows=47
loops=31)
                                       Sort Key: programs.id_program
                                       ->  Seq Scan on programs  (cost=0.00..17.70 rows=93 width=19) (actual
time=0.022..11.709rows=48 loops=1) 
                                             Filter: (id_program <> 0)
                                 ->  Sort  (cost=964.99..967.75 rows=1102 width=115) (actual time=14.592..15.218
rows=493loops=31) 
                                       Sort Key: sequences.id_program
                                       ->  Merge Join  (cost=696.16..909.31 rows=1102 width=115) (actual
time=79.717..451.495rows=493 loops=1) 
                                             Merge Cond: ("outer".id_package = "inner".id_package)
                                             ->  Merge Left Join  (cost=0.00..186.59 rows=1229 width=103) (actual
time=0.101..366.854rows=1247 loops=1) 
                                                   Merge Cond: ("outer".id_package = "inner".id_package)
                                                   ->  Index Scan using packages_pkey on packages p  (cost=0.00..131.04
rows=1229width=103) (actual time=0.048..163.503 rows=1247 loops=1) 
                                                   ->  Index Scan using package_security_id_package_key on
package_securityps  (cost=0.00..46.83 rows=855 width=4) (actual time=0.022..178.599 rows=879 loops=1) 
                                             ->  Sort  (cost=696.16..705.69 rows=3812 width=16) (actual
time=79.582..79.968rows=493 loops=1) 
                                                   Sort Key: sequences.id_package
                                                   ->  Seq Scan on sequences  (cost=0.00..469.42 rows=3812 width=16)
(actualtime=0.012..78.863 rows=493 loops=1) 
                                                         Filter: (estimated_start IS NOT NULL)
 Total runtime: 52878.516 ms
(36 rows)


Disabling the nestloop then the execution time become more affordable:

empdb=# set enable_nestloop = false;
SET
empdb=# explain analyze SELECT name,url,descr,request_status,url_status,size_mb,estimated_start,request_time_stamp
empdb-#                    FROM v_sc_user_request
empdb-#                    WHERE
empdb-#                         login = 'babinow1'
empdb-#                    LIMIT 10 ;
                                                                                                       QUERY PLAN

------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=4467.64..4467.65 rows=1 width=232) (actual time=7091.233..7091.289 rows=10 loops=1)
   ->  Subquery Scan v_sc_user_request  (cost=4467.64..4467.65 rows=1 width=232) (actual time=7091.228..7091.272
rows=10loops=1) 
         ->  Sort  (cost=4467.64..4467.64 rows=1 width=201) (actual time=7091.216..7091.221 rows=10 loops=1)
               Sort Key: sr.id_sat_request
               ->  Merge Left Join  (cost=4462.07..4467.63 rows=1 width=201) (actual time=6377.732..7091.067 rows=31
loops=1)
                     Merge Cond: ("outer".id_package = "inner".id_package)
                     ->  Sort  (cost=3389.81..3389.81 rows=1 width=193) (actual time=1338.759..1338.814 rows=31
loops=1)
                           Sort Key: sr.id_package
                           ->  Merge Join  (cost=3285.05..3389.80 rows=1 width=193) (actual time=1318.877..1338.651
rows=31loops=1) 
                                 Merge Cond: ("outer".id_url = "inner".id_url)
                                 ->  Sort  (cost=1029.26..1029.26 rows=1 width=40) (actual time=703.085..703.113
rows=31loops=1) 
                                       Sort Key: sr.id_url
                                       ->  Merge Join  (cost=991.00..1029.25 rows=1 width=40) (actual
time=702.740..702.984rows=31 loops=1) 
                                             Merge Cond: ("outer".id_user = "inner".id_user)
                                             ->  Sort  (cost=986.99..1006.13 rows=7656 width=28) (actual
time=648.559..655.302rows=8041 loops=1) 
                                                   Sort Key: sr.id_user
                                                   ->  Seq Scan on sat_request sr  (cost=0.00..493.09 rows=7656
width=28)(actual time=201.968..614.631 rows=8363 loops=1) 
                                                         Filter: (request_time > (now() - '1 mon'::interval))
                                             ->  Sort  (cost=4.01..4.02 rows=2 width=16) (actual time=35.252..35.282
rows=1loops=1) 
                                                   Sort Key: ul.id_user
                                                   ->  Index Scan using user_login_login_key on user_login ul
(cost=0.00..4.00rows=2 width=16) (actual time=35.214..35.221 rows=1 loops=1) 
                                                         Index Cond: ((login)::text = 'babinow1'::text)
                                 ->  Sort  (cost=2255.79..2308.95 rows=21264 width=161) (actual time=587.664..602.490
rows=21250loops=1) 
                                       Sort Key: u.id_url
                                       ->  Seq Scan on url u  (cost=0.00..727.32 rows=21264 width=161) (actual
time=0.026..418.586rows=21264 loops=1) 
                     ->  Sort  (cost=1072.27..1075.03 rows=1103 width=12) (actual time=5015.761..5016.092 rows=493
loops=1)
                           Sort Key: vsp.id_package
                           ->  Subquery Scan vsp  (cost=985.73..1016.53 rows=1103 width=12) (actual
time=898.876..5014.570rows=494 loops=1) 
                                 ->  Merge Join  (cost=985.73..1011.01 rows=1103 width=130) (actual
time=898.869..5011.954rows=494 loops=1) 
                                       Merge Cond: ("outer".id_program = "inner".id_program)
                                       ->  Sort  (cost=20.74..20.97 rows=93 width=19) (actual time=29.669..29.708
rows=47loops=1) 
                                             Sort Key: programs.id_program
                                             ->  Seq Scan on programs  (cost=0.00..17.70 rows=93 width=19) (actual
time=0.035..29.525rows=48 loops=1) 
                                                   Filter: (id_program <> 0)
                                       ->  Sort  (cost=964.99..967.75 rows=1102 width=115) (actual
time=868.619..869.286rows=494 loops=1) 
                                             Sort Key: sequences.id_program
                                             ->  Merge Join  (cost=696.16..909.31 rows=1102 width=115) (actual
time=44.820..867.649rows=494 loops=1) 
                                                   Merge Cond: ("outer".id_package = "inner".id_package)
                                                   ->  Merge Left Join  (cost=0.00..186.59 rows=1229 width=103) (actual
time=19.563..835.352rows=1248 loops=1) 
                                                         Merge Cond: ("outer".id_package = "inner".id_package)
                                                         ->  Index Scan using packages_pkey on packages p
(cost=0.00..131.04rows=1229 width=103) (actual time=12.796..457.520 rows=1248 loops=1) 
                                                         ->  Index Scan using package_security_id_package_key on
package_securityps  (cost=0.00..46.83 rows=855 width=4) (actual time=6.703..283.944 rows=879 loops=1) 
                                                   ->  Sort  (cost=696.16..705.69 rows=3812 width=16) (actual
time=25.222..25.705rows=494 loops=1) 
                                                         Sort Key: sequences.id_package
                                                         ->  Seq Scan on sequences  (cost=0.00..469.42 rows=3812
width=16)(actual time=0.017..24.412 rows=494 loops=1) 
                                                               Filter: (estimated_start IS NOT NULL)
 Total runtime: 7104.946 ms
(47 rows)



May I know wich parameter may I tune in order to avoid to "disable" the nested loop ?

===================================================================================================================================

I tried to reduce the runtime cost adding a new column on sat_request ( expired boolean ) in order to
have a better row extimation ( I used a partial index ) but nothing changed.


I finally was able to reduce the cost putting ( just for this query ):
set cpu_tuple_cost = 0.07

is it a resonable value ?


empdb=# set cpu_tuple_cost = 0.07;
SET
empdb=# explain analyze select *
empdb-# from v_sc_user_request
empdb-# where login = 'babinow1';
                                                                                       QUERY PLAN

----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Subquery Scan v_sc_user_request  (cost=1978.23..1978.30 rows=1 width=364) (actual time=1612.719..1613.064 rows=31
loops=1)
   ->  Sort  (cost=1978.23..1978.23 rows=1 width=201) (actual time=1612.700..1612.728 rows=31 loops=1)
         Sort Key: sr.id_sat_request
         ->  Merge Left Join  (cost=1974.05..1978.22 rows=1 width=201) (actual time=1537.343..1612.565 rows=31 loops=1)
               Merge Cond: ("outer".id_package = "inner".id_package)
               ->  Sort  (cost=887.92..887.93 rows=1 width=193) (actual time=475.924..476.020 rows=31 loops=1)
                     Sort Key: sr.id_package
                     ->  Nested Loop  (cost=4.07..887.91 rows=1 width=193) (actual time=145.782..475.851 rows=31
loops=1)
                           ->  Hash Join  (cost=4.07..884.65 rows=1 width=40) (actual time=139.816..464.678 rows=31
loops=1)
                                 Hash Cond: ("outer".id_user = "inner".id_user)
                                 ->  Index Scan using idx_sat_request_expired on sat_request sr  (cost=0.00..838.69
rows=8363width=28) (actual time=19.696..443.702 rows=8460 loops=1) 
                                       Index Cond: (expired = false)
                                 ->  Hash  (cost=4.07..4.07 rows=2 width=16) (actual time=11.779..11.779 rows=0
loops=1)
                                       ->  Index Scan using user_login_login_key on user_login ul  (cost=0.00..4.07
rows=2width=16) (actual time=11.725..11.732 rows=1 loops=1) 
                                             Index Cond: ((login)::text = 'babinow1'::text)
                           ->  Index Scan using url_pkey on url u  (cost=0.00..3.19 rows=1 width=161) (actual
time=0.345..0.347rows=1 loops=31) 
                                 Index Cond: ("outer".id_url = u.id_url)
               ->  Sort  (cost=1086.13..1088.16 rows=813 width=12) (actual time=1060.374..1060.622 rows=390 loops=1)
                     Sort Key: vsp.id_package
                     ->  Subquery Scan vsp  (cost=676.18..1046.83 rows=813 width=12) (actual time=625.645..1059.388
rows=480loops=1) 
                           ->  Hash Join  (cost=676.18..989.92 rows=813 width=131) (actual time=625.637..1057.105
rows=480loops=1) 
                                 Hash Cond: ("outer".id_package = "inner".id_package)
                                 ->  Hash Left Join  (cost=79.67..302.87 rows=1341 width=104) (actual
time=4.336..18.549rows=1342 loops=1) 
                                       Hash Cond: ("outer".id_package = "inner".id_package)
                                       ->  Seq Scan on packages p  (cost=0.00..145.87 rows=1341 width=104) (actual
time=0.007..3.357rows=1342 loops=1) 
                                       ->  Hash  (cost=77.27..77.27 rows=961 width=4) (actual time=3.685..3.685 rows=0
loops=1)
                                             ->  Seq Scan on package_security ps  (cost=0.00..77.27 rows=961 width=4)
(actualtime=0.016..2.175 rows=974 loops=1) 
                                 ->  Hash  (cost=594.48..594.48 rows=813 width=31) (actual time=620.397..620.397 rows=0
loops=1)
                                       ->  Hash Join  (cost=20.60..594.48 rows=813 width=31) (actual
time=38.307..619.406rows=480 loops=1) 
                                             Hash Cond: ("outer".id_program = "inner".id_program)
                                             ->  Seq Scan on sequences  (cost=0.00..512.82 rows=830 width=16) (actual
time=16.858..595.262rows=480 loops=1) 
                                                   Filter: (estimated_start IS NOT NULL)
                                             ->  Hash  (cost=20.48..20.48 rows=47 width=19) (actual time=21.093..21.093
rows=0loops=1) 
                                                   ->  Seq Scan on programs  (cost=0.00..20.48 rows=47 width=19)
(actualtime=9.369..20.980 rows=48 loops=1) 
                                                         Filter: (id_program <> 0)
 Total runtime: 1614.123 ms
(36 rows)



Regards
Gaetano Mendola