From: Gaetano Mendola <mendola@bigfoot.com>
Subject: Re: bad plan
Date: Tue, 08 Mar 2005 19:35:31 +0100
Organization: Hub.Org Networking Services
Lines: 96
Message-ID: <422DF073.7080307@bigfoot.com>
References: <422D7F23.7000109@bigfoot.com> <422D8F0E.8000906@archonet.com>
	<422D9904.5010904@bigfoot.com> <422DA6A5.2060908@archonet.com>
Mime-Version: 1.0
Content-Type: text/plain; charset=ISO-8859-1
Content-Transfer-Encoding: 7bit
To: Richard Huxton <dev@archonet.com>
User-Agent: Mozilla Thunderbird 1.0 (Windows/20041206)
In-Reply-To: <422DA6A5.2060908@archonet.com>
To: pgsql-performance@postgresql.org

Richard Huxton wrote:

> OK, so looking at the original EXPLAIN the order of processing seems to be:
> 1. v_sat_request is evaluated and filtered on login='...' (lines 7..15)
> This gives us 31 rows
> 2. The left-join from v_sat_request to v_sc_packages is processed (lines
> 5..6)
> This involves the subquery scan on vsp (from line 16) where it seems to
> think the best idea is a merge join of programs to sequences.

Whel basically v_sc_packages depends on other 3 views that are just a simple
interface to a plain table.


If I execute a select only on this table I get reasonable executions time:


=== cpu_tuple_cost = 0.07

# explain analyze select * from v_sc_packages where id_package = 19628;
                                                                              QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Nested Loop  (cost=0.00..15.96 rows=1 width=131) (actual time=41.450..41.494 rows=1 loops=1)
   ->  Nested Loop  (cost=0.00..11.86 rows=1 width=116) (actual time=1.022..1.055 rows=1 loops=1)
         ->  Nested Loop Left Join  (cost=0.00..7.89 rows=1 width=104) (actual time=0.330..0.345 rows=1 loops=1)
               ->  Index Scan using packages_pkey on packages p  (cost=0.00..3.90 rows=1 width=104) (actual time=0.070..0.075 rows=1 loops=1)
                     Index Cond: (id_package = 19628)
               ->  Index Scan using package_security_id_package_key on package_security ps  (cost=0.00..3.91 rows=1 width=4) (actual time=0.232..0.237 rows=1 loops=1)
                     Index Cond: ("outer".id_package = ps.id_package)
         ->  Index Scan using idx_sequences_id_package on sequences  (cost=0.00..3.90 rows=1 width=16) (actual time=0.670..0.685 rows=1 loops=1)
               Index Cond: (19628 = id_package)
               Filter: (estimated_start IS NOT NULL)
   ->  Index Scan using programs_pkey on programs  (cost=0.00..4.02 rows=1 width=19) (actual time=0.078..0.086 rows=1 loops=1)
         Index Cond: (programs.id_program = "outer".id_program)
         Filter: (id_program <> 0)
 Total runtime: 42.650 ms
(14 rows)

=== cpu_tuple_cost = 0.01

# explain analyze select * from v_sc_packages where id_package = 19628;
                                                                               QUERY PLAN
------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Nested Loop  (cost=0.00..15.54 rows=1 width=131) (actual time=25.062..69.977 rows=1 loops=1)
   ->  Nested Loop  (cost=0.00..11.56 rows=1 width=116) (actual time=5.396..50.299 rows=1 loops=1)
         ->  Nested Loop Left Join  (cost=0.00..7.71 rows=1 width=104) (actual time=5.223..32.842 rows=1 loops=1)
               ->  Index Scan using packages_pkey on packages p  (cost=0.00..3.84 rows=1 width=104) (actual time=0.815..7.235 rows=1 loops=1)
                     Index Cond: (id_package = 19628)
               ->  Index Scan using package_security_id_package_key on package_security ps  (cost=0.00..3.85 rows=1 width=4) (actual time=4.366..25.555 rows=1 loops=1)
                     Index Cond: ("outer".id_package = ps.id_package)
         ->  Index Scan using idx_sequences_id_package on sequences  (cost=0.00..3.84 rows=1 width=16) (actual time=0.147..17.422 rows=1 loops=1)
               Index Cond: (19628 = id_package)
               Filter: (estimated_start IS NOT NULL)
   ->  Index Scan using programs_pkey on programs  (cost=0.00..3.96 rows=1 width=19) (actual time=0.043..0.049 rows=1 loops=1)
         Index Cond: (programs.id_program = "outer".id_program)
         Filter: (id_program <> 0)
 Total runtime: 70.254 ms
(14 rows)


and I get the best with this:

=== cpu_tuple_cost = 0.001


# explain analyze select * from v_sc_packages where id_package = 19628;
                                                                           QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------
 Nested Loop  (cost=0.00..15.48 rows=1 width=131) (actual time=2.516..2.553 rows=1 loops=1)
   ->  Nested Loop  (cost=0.00..7.78 rows=1 width=31) (actual time=1.439..1.457 rows=1 loops=1)
         ->  Index Scan using idx_sequences_id_package on sequences  (cost=0.00..3.83 rows=1 width=16) (actual time=0.442..0.450 rows=1 loops=1)
               Index Cond: (19628 = id_package)
               Filter: (estimated_start IS NOT NULL)
         ->  Index Scan using programs_pkey on programs  (cost=0.00..3.95 rows=1 width=19) (actual time=0.972..0.978 rows=1 loops=1)
               Index Cond: (programs.id_program = "outer".id_program)
               Filter: (id_program <> 0)
   ->  Nested Loop Left Join  (cost=0.00..7.68 rows=1 width=104) (actual time=0.110..0.125 rows=1 loops=1)
         ->  Index Scan using packages_pkey on packages p  (cost=0.00..3.84 rows=1 width=104) (actual time=0.040..0.046 rows=1 loops=1)
               Index Cond: (id_package = 19628)
         ->  Index Scan using package_security_id_package_key on package_security ps  (cost=0.00..3.84 rows=1 width=4) (actual time=0.036..0.042 rows=1 loops=1)
               Index Cond: ("outer".id_package = ps.id_package)
 Total runtime: 2.878 ms
(14 rows)


but with this last setting for the original query is choosed a very bad plan.


Regards
Gaetano Mendola