Re: Slow queries in PL/PGSQL function - Mailing list pgsql-general

From Gary Doades
Subject Re: Slow queries in PL/PGSQL function
Date
Msg-id t8cf30ltflun9pobqvmd2urepr0fp2il7v@4ax.com
Whole thread Raw
In response to Slow queries in PL/PGSQL function  (Jim Crate <jcrate@deepskytech.com>)
List pgsql-general
Thank for the reply.

I will move this onto the perfromance group, except that for some odd reason I cant see a
performance group on usenet. I will subscribe to the mailing list....

I will gladly upload the schema (script) or anything else that anyone wants, but it may not be
appropriate for a newsgroup or mailing list. If you want anything else please let me know where to
send it.

This is not the only query that is causing me a problem. I have about 30 stored procedures to move
from SQLServer. 15 of the 21 so far moved over to PG have similar problems. Very fast when submitted
as a complete SQL statement with constants. Very slow when used as functions.

Here is the explain for ths query using constants:

QUERY PLAN
Hash Join  (cost=629.34..213908.73 rows=34 width=151) (actual time=110.000..1518.000 rows=98
loops=1)
  Hash Cond: ("outer".staff_id = "inner".staff_id)
  Join Filter: (subplan)
  InitPlan
    ->  Seq Scan on wruserarea  (cost=1.46..3.29 rows=1 width=4) (actual time=0.000..0.000 rows=1
loops=1)
          Filter: ((uid = $4) AND (area_id = 1))
          InitPlan
            ->  Seq Scan on wruser  (cost=0.00..1.46 rows=1 width=4) (actual time=0.000..0.000
rows=1 loops=1)
                  Filter: ((username)::name = "current_user"())
  ->  Seq Scan on staff_contract sc  (cost=0.00..10.35 rows=335 width=34) (actual time=0.000..1.000
rows=335 loops=1)
  ->  Hash  (cost=625.88..625.88 rows=66 width=125) (actual time=10.000..10.000 rows=0 loops=1)
        ->  Nested Loop  (cost=56.55..625.88 rows=66 width=125) (actual time=6.000..10.000 rows=98
loops=1)
              ->  Merge Join  (cost=56.55..73.06 rows=101 width=111) (actual time=6.000..7.000
rows=98 loops=1)
                    Merge Cond: ("outer".staff_id = "inner".staff_id)
                    ->  Index Scan using staff_pkey on staff  (cost=7.74..21.90 rows=332 width=107)
(actual time=4.000..4.000 rows=332 loops=1)
                          Filter: ((hashed subplan) OR $5)
                          SubPlan
                            ->  Seq Scan on staff_area  (cost=3.16..7.52 rows=88 width=4) (actual
time=0.000..0.000 rows=18 loops=1)
                                  Filter: ((hashed subplan) OR (area_id = 1))
                                  SubPlan
                                    ->  Seq Scan on wruserarea  (cost=1.46..3.16 rows=3 width=4)
(actual time=0.000..0.000 rows=1 loops=1)
                                          Filter: (uid = $1)
                                          InitPlan
                                            ->  Seq Scan on wruser  (cost=0.00..1.46 rows=1 width=4)
(actual time=0.000..0.000 rows=1 loops=1)
                                                  Filter: ((username)::name = "current_user"())
                    ->  Sort  (cost=48.81..49.06 rows=101 width=4) (actual time=2.000..2.000 rows=98
loops=1)
                          Sort Key: sr.staff_id
                          ->  Seq Scan on search_reqt_result sr  (cost=0.00..45.45 rows=101 width=4)
(actual time=0.000..2.000 rows=98 loops=1)
                                Filter: (search_id = 143)
              ->  Index Scan using location_pkey on "location"  (cost=0.00..5.46 rows=1 width=18)
(actual time=0.000..0.000 rows=1 loops=98)
                    Index Cond: ("location".location_id = "outer".location_id)
                    Filter: ((area_id = 1) OR (subplan))
                    SubPlan
                      ->  Seq Scan on wruserarea  (cost=1.46..3.44 rows=2 width=4) (never executed)
                            Filter: ((uid = $6) AND ((area_id = 1) OR (area_id = $7)))
                            InitPlan
                              ->  Seq Scan on wruser  (cost=0.00..1.46 rows=1 width=4) (never
executed)
                                    Filter: ((username)::name = "current_user"())
  SubPlan
    ->  GroupAggregate  (cost=3.10..639.23 rows=1 width=4) (actual time=1.765..1.765 rows=1
loops=98)
          Filter: (count(contract_id) = $9)
          InitPlan
            ->  Aggregate  (cost=1.55..1.55 rows=1 width=4) (actual time=0.000..0.000 rows=1
loops=1)
                  ->  Seq Scan on search_order_reqt  (cost=0.00..1.55 rows=1 width=4) (actual
time=0.000..0.000 rows=1 loops=1)
                        Filter: (search_id = 143)
          ->  Nested Loop IN Join  (cost=1.55..637.67 rows=1 width=4) (actual time=1.439..1.765
rows=1 loops=98)
                Join Filter: ("outer".product_id = "inner".product_id)
                ->  Nested Loop  (cost=0.00..631.93 rows=186 width=8) (actual time=0.347..1.378
rows=245 loops=98)
                      ->  Index Scan using staff_contract_pkey on staff_contract c
(cost=0.00..15.77 rows=1 width=4) (actual time=0.255..0.449 rows=1 loops=98)
                            Filter: ((staff_id = $8) AND (avail_date_from <= '2003-06-12'::date) AND
(avail_date_to >= '2003-06-18'::date))
                      ->  Index Scan using staff_product_contract_id_key on staff_product p
(cost=0.00..613.80 rows=189 width=8) (actual time=0.061..0.571 rows=245 loops=98)
                            Index Cond: (p.contract_id = "outer".contract_id)
                ->  Materialize  (cost=1.55..1.56 rows=1 width=4) (actual time=0.000..0.000 rows=1
loops=23972)
                      ->  Seq Scan on search_order_reqt  (cost=0.00..1.55 rows=1 width=4) (actual
time=0.000..0.000 rows=1 loops=1)
                            Filter: (search_id = 143)
    ->  Aggregate  (cost=2252.27..2252.27 rows=1 width=2) (actual time=12.673..12.673 rows=1
loops=98)
          ->  Nested Loop  (cost=2049.93..2252.19 rows=28 width=2) (actual time=8.959..12.612
rows=13 loops=98)
                ->  Hash Join  (cost=2049.93..2167.47 rows=28 width=4) (actual time=8.908..12.337
rows=13 loops=98)
                      Hash Cond: ("outer".booking_id = "inner".booking_id)
                      ->  Index Scan using booking_plan_idx2 on booking_plan bp  (cost=0.00..98.15
rows=3822 width=4) (actual time=0.755..6.520 rows=4693 loops=98)
                            Index Cond: ((booking_date >= '2003-06-12'::date) AND (booking_date <=
'2003-06-18'::date))
                      ->  Hash  (cost=2048.37..2048.37 rows=624 width=8) (actual time=2.694..2.694
rows=0 loops=98)
                            ->  Index Scan using staff_book_idx5 on staff_booking b
(cost=0.00..2048.37 rows=624 width=8) (actual time=0.041..2.031 rows=358 loops=98)
                                  Index Cond: (contract_id = $0)
                ->  Index Scan using order_reqt_pkey on order_reqt r  (cost=0.00..3.01 rows=1
width=6) (actual time=0.014..0.014 rows=1 loops=1312)
                      Index Cond: ("outer".reqt_id = r.reqt_id)
    ->  Aggregate  (cost=3387.38..3387.38 rows=1 width=0) (actual time=0.806..0.806 rows=1 loops=98)
          ->  Nested Loop  (cost=0.00..3387.37 rows=2 width=0) (actual time=0.765..0.786 rows=3
loops=98)
                ->  Index Scan using main_order_idx on main_order  (cost=0.00..5.86 rows=2 width=4)
(actual time=0.041..0.051 rows=1 loops=98)
                      Index Cond: (client_id = 1011001947)
                ->  Index Scan using timesheet_detail_idx on timesheet_detail  (cost=0.00..1690.72
rows=3 width=4) (actual time=0.714..0.735 rows=3 loops=98)
                      Index Cond: ("outer".order_id = timesheet_detail.order_id)
                      Filter: (contract_id = $0)
Total runtime: 1530.000 ms


-------------------------------------------------------------------------------------------------------------------------------------------------

and here is the explain for the same query with parameters:


Hash Join  (cost=651.46..450445.01 rows=35 width=151) (actual time=304.000..23814.000 rows=98
loops=1)
  Hash Cond: ("outer".staff_id = "inner".staff_id)
  Join Filter: (subplan)
  InitPlan
    ->  Seq Scan on wruserarea  (cost=1.46..3.29 rows=1 width=4) (actual time=0.000..0.000 rows=1
loops=1)
          Filter: ((uid = $4) AND (area_id = 1))
          InitPlan
            ->  Seq Scan on wruser  (cost=0.00..1.46 rows=1 width=4) (actual time=0.000..0.000
rows=1 loops=1)
                  Filter: ((username)::name = "current_user"())
  ->  Seq Scan on staff_contract sc  (cost=0.00..10.35 rows=335 width=34) (actual time=0.000..1.000
rows=335 loops=1)
  ->  Hash  (cost=648.00..648.00 rows=68 width=125) (actual time=8.000..8.000 rows=0 loops=1)
        ->  Nested Loop  (cost=56.71..648.00 rows=68 width=125) (actual time=4.000..8.000 rows=98
loops=1)
              ->  Merge Join  (cost=56.71..73.28 rows=105 width=111) (actual time=3.000..6.000
rows=98 loops=1)
                    Merge Cond: ("outer".staff_id = "inner".staff_id)
                    ->  Index Scan using staff_pkey on staff  (cost=7.74..21.90 rows=332 width=107)
(actual time=1.000..2.000 rows=332 loops=1)
                          Filter: ((hashed subplan) OR $5)
                          SubPlan
                            ->  Seq Scan on staff_area  (cost=3.16..7.52 rows=88 width=4) (actual
time=0.000..0.000 rows=18 loops=1)
                                  Filter: ((hashed subplan) OR (area_id = 1))
                                  SubPlan
                                    ->  Seq Scan on wruserarea  (cost=1.46..3.16 rows=3 width=4)
(actual time=0.000..0.000 rows=1 loops=1)
                                          Filter: (uid = $1)
                                          InitPlan
                                            ->  Seq Scan on wruser  (cost=0.00..1.46 rows=1 width=4)
(actual time=0.000..0.000 rows=1 loops=1)
                                                  Filter: ((username)::name = "current_user"())
                    ->  Sort  (cost=48.97..49.24 rows=105 width=4) (actual time=2.000..2.000 rows=98
loops=1)
                          Sort Key: sr.staff_id
                          ->  Seq Scan on search_reqt_result sr  (cost=0.00..45.45 rows=105 width=4)
(actual time=0.000..2.000 rows=98 loops=1)
                                Filter: (search_id = $4)
              ->  Index Scan using location_pkey on "location"  (cost=0.00..5.46 rows=1 width=18)
(actual time=0.010..0.010 rows=1 loops=98)
                    Index Cond: ("location".location_id = "outer".location_id)
                    Filter: ((area_id = 1) OR (subplan))
                    SubPlan
                      ->  Seq Scan on wruserarea  (cost=1.46..3.44 rows=2 width=4) (never executed)
                            Filter: ((uid = $6) AND ((area_id = 1) OR (area_id = $7)))
                            InitPlan
                              ->  Seq Scan on wruser  (cost=0.00..1.46 rows=1 width=4) (never
executed)
                                    Filter: ((username)::name = "current_user"())
  SubPlan
    ->  GroupAggregate  (cost=3.10..652.99 rows=1 width=4) (actual time=1.847..1.847 rows=1
loops=98)
          Filter: (count(contract_id) = $9)
          InitPlan
            ->  Aggregate  (cost=1.55..1.55 rows=1 width=4) (actual time=0.000..0.000 rows=1
loops=1)
                  ->  Seq Scan on search_order_reqt  (cost=0.00..1.55 rows=1 width=4) (actual
time=0.000..0.000 rows=1 loops=1)
                        Filter: (search_id = $4)
          ->  Nested Loop IN Join  (cost=1.55..651.43 rows=1 width=4) (actual time=1.449..1.837
rows=1 loops=98)
                Join Filter: ("outer".product_id = "inner".product_id)
                ->  Nested Loop  (cost=0.00..645.69 rows=186 width=8) (actual time=0.429..1.306
rows=245 loops=98)
                      ->  Index Scan using staff_contract_pkey on staff_contract c
(cost=0.00..17.45 rows=1 width=4) (actual time=0.276..0.398 rows=1 loops=98)
                            Filter: ((staff_id = $8) AND ((avail_date_from)::timestamp without time
zone <= $1) AND ((avail_date_to)::timestamp without time zone >= $1))
                      ->  Index Scan using staff_product_contract_id_key on staff_product p
(cost=0.00..625.85 rows=191 width=8) (actual time=0.133..0.582 rows=245 loops=98)
                            Index Cond: (p.contract_id = "outer".contract_id)
                ->  Materialize  (cost=1.55..1.56 rows=1 width=4) (actual time=0.000..0.001 rows=1
loops=23972)
                      ->  Seq Scan on search_order_reqt  (cost=0.00..1.55 rows=1 width=4) (actual
time=0.000..0.000 rows=1 loops=1)
                            Filter: (search_id = $4)
    ->  Aggregate  (cost=8760.23..8760.24 rows=1 width=2) (actual time=236.245..236.245 rows=1
loops=98)
          ->  Nested Loop  (cost=2009.53..8760.21 rows=9 width=2) (actual time=226.378..236.194
rows=14 loops=98)
                ->  Hash Join  (cost=2009.53..8732.97 rows=9 width=4) (actual time=226.286..235.755
rows=14 loops=98)
                      Hash Cond: ("outer".booking_id = "inner".booking_id)
                      ->  Seq Scan on booking_plan bp  (cost=0.00..6716.98 rows=1274 width=4)
(actual time=209.684..229.684 rows=4704 loops=98)
                            Filter: (((booking_date)::timestamp without time zone >= $1) AND
((booking_date)::timestamp without time zone <= $2))
                      ->  Hash  (cost=2008.02..2008.02 rows=606 width=8) (actual time=3.357..3.357
rows=0 loops=98)
                            ->  Index Scan using staff_book_idx5 on staff_booking b
(cost=0.00..2008.02 rows=606 width=8) (actual time=0.163..3.061 rows=358 loops=98)
                                  Index Cond: (contract_id = $0)
                ->  Index Scan using order_reqt_pkey on order_reqt r  (cost=0.00..3.01 rows=1
width=6) (actual time=0.024..0.026 rows=1 loops=1326)
                      Index Cond: ("outer".reqt_id = r.reqt_id)
    ->  Aggregate  (cost=3443.91..3443.91 rows=1 width=0) (actual time=4.745..4.745 rows=1 loops=98)
          ->  Nested Loop  (cost=0.00..3443.90 rows=2 width=0) (actual time=4.531..4.724 rows=3
loops=98)
                ->  Index Scan using main_order_idx on main_order  (cost=0.00..5.87 rows=2 width=4)
(actual time=0.143..0.153 rows=1 loops=98)
                      Index Cond: (client_id = $3)
                ->  Index Scan using timesheet_detail_idx on timesheet_detail  (cost=0.00..1718.97
rows=3 width=4) (actual time=4.378..4.571 rows=3 loops=98)
                      Index Cond: ("outer".order_id = timesheet_detail.order_id)
                      Filter: (contract_id = $0)
Total runtime: 23853.000 ms

The only real difference I can see is the booking_plan table using a sequential scan.

Any help appreciated

Thanks,
Gary.


On Sat, 21 Feb 2004 11:15:50 -0500, tgl@sss.pgh.pa.us (Tom Lane) wrote:

>Gary Doades <gpd@cwcom.net> writes:
>> Is there someway to force the use of an index. Or at least get the
>> backend to substitue the parameters in a function before doing the
>> first query plan so it has more typical values to work with?
>
>Could we see the EXPLAIN ANALYZE output for your problem query?
>Table schemas (column data types and available indexes) are necessary
>background for this type of question as well.
>
>You might want to take the question to pgsql-performance, too ...
>it's a tad off topic for -general.
>
>            regards, tom lane
>
>---------------------------(end of broadcast)---------------------------
>TIP 9: the planner will ignore your desire to choose an index scan if your
>      joining column's datatypes do not match


pgsql-general by date:

Previous
From: Andrew Sullivan
Date:
Subject: gborg not responding?
Next
From: jack_turer@yahoo.com (jack turer)
Date:
Subject: Re: pg_dump and pg_dumpall fail when trying to backup database