Re: Slow queries in PL/PGSQL function

From: Gary Doades <gpd(at)cwcom(dot)net>
To: pgsql-general(at)postgresql(dot)org
Subject: Re: Slow queries in PL/PGSQL function
Date: 2004-02-21 19:39:45
Message-ID: t8cf30ltflun9pobqvmd2urepr0fp2il7v@4ax.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: 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(at)sss(dot)pgh(dot)pa(dot)us (Tom Lane) wrote:

>Gary Doades <gpd(at)cwcom(dot)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

In response to

Browse pgsql-general by date

  From Date Subject
Next Message Simon Windsor 2004-02-21 20:16:54 md5 calls
Previous Message Franco Bruno Borghesi 2004-02-21 19:14:38 Re: Post gresql commands