Thread: A bad plan

A bad plan

From
Gaetano Mendola
Date:
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=10 loops=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.064rows=31 loops=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.071rows=1 loops=1)                                      Index Cond: ((login)::text = 'babinow1'::text)
                             ->  Materialize  (cost=493.09..531.37 rows=7656 width=28) (actual time=167.654..481.813
rows=8363loops=1)                                      ->  Seq Scan on sat_request sr  (cost=0.00..493.09 rows=7656
width=28)(actual time=167.644..467.344 rows=8363 loops=1)                                            Filter:
(request_time> (now() - '1 mon'::interval))                          ->  Index Scan using url_pkey on url u
(cost=0.00..3.05rows=1 width=161) (actual time=13.994..14.000 rows=1 loops=31)                                Index
Cond:("outer".id_url = u.id_url)                    ->  Subquery Scan vsp  (cost=985.73..1016.53 rows=1103 width=12)
(actualtime=25.328..1668.754 rows=493 loops=31)                          ->  Merge Join  (cost=985.73..1011.01
rows=1103width=130) (actual time=25.321..1666.666 rows=493 loops=31)                                Merge Cond:
("outer".id_program= "inner".id_program)                                ->  Sort  (cost=20.74..20.97 rows=93 width=19)
(actualtime=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.709
rows=48loops=1)                                            Filter: (id_program <> 0)                                ->
Sort (cost=964.99..967.75 rows=1102 width=115) (actual time=14.592..15.218 rows=493 loops=31)
          Sort Key: sequences.id_program                                      ->  Merge Join  (cost=696.16..909.31
rows=1102width=115) (actual time=79.717..451.495 rows=493 loops=1)                                            Merge
Cond:("outer".id_package = "inner".id_package)                                            ->  Merge Left Join
(cost=0.00..186.59rows=1229 width=103) (actual time=0.101..366.854 rows=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=1229 width=103) (actual time=0.048..163.503
rows=1247loops=1)                                                  ->  Index Scan using package_security_id_package_key
onpackage_security ps  (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.968 rows=493
loops=1)                                                 Sort Key: sequences.id_package
                ->  Seq Scan on sequences  (cost=0.00..469.42 rows=3812 width=16) (actual time=0.012..78.863 rows=493
loops=1)                                                       Filter: (estimated_start IS NOT NULL)Total runtime:
52878.516ms
 
(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=10 loops=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.067rows=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=31 loops=1)                                Merge Cond: ("outer".id_url =
"inner".id_url)                               ->  Sort  (cost=1029.26..1029.26 rows=1 width=40) (actual
time=703.085..703.113rows=31 loops=1)                                      Sort Key: sr.id_url
           ->  Merge Join  (cost=991.00..1029.25 rows=1 width=40) (actual time=702.740..702.984 rows=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.302 rows=8041 loops=1)
                                  Sort Key: sr.id_user                                                  ->  Seq Scan on
sat_requestsr  (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=1 loops=1)
                            Sort Key: ul.id_user                                                  ->  Index Scan using
user_login_login_keyon user_login ul  (cost=0.00..4.00 rows=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=21250 loops=1)
                            Sort Key: u.id_url                                      ->  Seq Scan on url u
(cost=0.00..727.32rows=21264 width=161) (actual time=0.026..418.586 rows=21264 loops=1)                    ->  Sort
(cost=1072.27..1075.03rows=1103 width=12) (actual time=5015.761..5016.092 rows=493 loops=1)
SortKey: vsp.id_package                          ->  Subquery Scan vsp  (cost=985.73..1016.53 rows=1103 width=12)
(actualtime=898.876..5014.570 rows=494 loops=1)                                ->  Merge Join  (cost=985.73..1011.01
rows=1103width=130) (actual time=898.869..5011.954 rows=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=47 loops=1)                                            Sort Key:
programs.id_program                                           ->  Seq Scan on programs  (cost=0.00..17.70 rows=93
width=19)(actual time=0.035..29.525 rows=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.352 rows=1248 loops=1)                                                        Merge
Cond:("outer".id_package = "inner".id_package)                                                        ->  Index Scan
usingpackages_pkey on packages p  (cost=0.00..131.04 rows=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.705 rows=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.412rows=494 loops=1)                                                              Filter:
(estimated_startIS 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 ?



Regards
Gaetano Mendola








Re: A bad plan

From
Josh Berkus
Date:
Gaetano,

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

Please take this to the PGSQL-PERFORMANCE mailing list; that's what that list 
exists for.

Or IRC, where I know your are sometimes.  But not -Hackers.

Thanks!

-- 
Josh Berkus
Aglio Database Solutions
San Francisco


Re: A bad plan

From
Gaetano Mendola
Date:
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Josh Berkus wrote:
> Gaetano,
> 
> 
>>Hi all,
>>running a 7.4.5 engine, I'm facing this bad plan:
> 
> 
> Please take this to the PGSQL-PERFORMANCE mailing list; that's what that list 
> exists for.
> 
> Or IRC, where I know your are sometimes.  But not -Hackers.

Sorry, I was convinced to have sent this email to performances ( as I do
usually ).



Regards
Gaetano Mendola


-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.2.5 (MingW32)
Comment: Using GnuPG with Thunderbird - http://enigmail.mozdev.org

iD8DBQFCLXih7UpzwH2SGd4RApCYAKCS/1qPYFs7GABfpwAO0c51kg+daQCg/J66
vwv2Z92GtFvOwKFwa8jC838=
=BlCp
-----END PGP SIGNATURE-----