Slow set-returning functions

From: Dean Rasheed <dean_rasheed(at)hotmail(dot)com>
To: <pgsql-performance(at)postgresql(dot)org>
Subject: Slow set-returning functions
Date: 2008-01-20 11:40:19
Message-ID: BAY113-W283034364555E644CD1765F23C0@phx.gbl
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance


Hi,

I have been having difficulty with some functions which return sets of
rows. The functions seem to run very slowly, even though the queries
they run execute very quicky if I run them directly from psgl.
Typically these queries are only returning a few hundred rows with my
real data.

I have had difficulty coming up with a simple test case, but the code
below usually shows the same problem. Sometimes I have to run the
setup code a few times before it happens - not sure why (I would
expect this to be deterministic), but perhaps there is some randomness
introduced by the sampling done by the analyse.

The function foo() which has a hard-coded LIMIT always executes
quickly (comparable to running the query directly).

However, the function foo(int) which is passed the same LIMIT as a
parameter executes around 30 times slower. The only difference is that
the LIMIT is a parameter to the function, although the LIMIT isn't
reached anyway in this case. Sometimes running this same script
generates data for which this function executes as fast as the other
one (which is always fast).

I am finding this all very puzzling. Am I just doing something silly?

Is there any way that I can see what execution plan is being used
internally by the functions?

Thanks,

Dean.

DROP FUNCTION IF EXISTS setup();
CREATE FUNCTION setup()
RETURNS void AS
$$
DECLARE
i int;
c1 int;
c2 int;
c3 int;
BEGIN
DROP TABLE IF EXISTS foo CASCADE;
CREATE TABLE foo (id int PRIMARY KEY, name text);

i := 1;
c1 := ascii('A');
WHILE c1 <= ascii('Z') LOOP
c2 := ascii('a');
WHILE c2 <= ascii('z') LOOP
c3 := ascii('a');
WHILE c3 <= ascii('z') LOOP
INSERT INTO foo VALUES(i, chr(c1)||chr(c2)||'o');
i := i+1;
c3 := c3+1;
END LOOP;
c2 := c2+1;
END LOOP;
c1 := c1+1;
END LOOP;

CREATE INDEX foo_name_idx ON foo(lower(name) text_pattern_ops);
END;
$$ LANGUAGE plpgsql;

SELECT setup();
ANALYZE foo;

DROP FUNCTION IF EXISTS foo();
CREATE FUNCTION foo() RETURNS SETOF int AS
$$
SELECT id FROM foo WHERE lower(name) LIKE 'foo' ORDER BY id OFFSET 0 LIMIT 100;
$$ LANGUAGE SQL STABLE;

DROP FUNCTION IF EXISTS foo(int);
CREATE FUNCTION foo(int) RETURNS SETOF int AS
$$
SELECT id FROM foo WHERE lower(name) LIKE 'foo' ORDER BY id OFFSET 0 LIMIT $1;
$$ LANGUAGE SQL STABLE;

EXPLAIN ANALYZE SELECT id FROM foo WHERE name ILIKE 'foo' ORDER BY id OFFSET 0 LIMIT 100;
EXPLAIN ANALYZE SELECT id FROM foo WHERE lower(name) LIKE 'foo' ORDER BY id OFFSET 0 LIMIT 100;
EXPLAIN ANALYZE SELECT * FROM foo();
EXPLAIN ANALYZE SELECT * FROM foo(100);

QUERY PLAN
---------------------------------------------------------------------------------------------------------------
Limit (cost=336.52..336.77 rows=100 width=4) (actual time=13.377..13.507 rows=26 loops=1)
-> Sort (cost=336.52..336.86 rows=136 width=4) (actual time=13.369..13.415 rows=26 loops=1)
Sort Key: id
-> Seq Scan on foo (cost=0.00..331.70 rows=136 width=4) (actual time=2.462..13.267 rows=26 loops=1)
Filter: (name ~~* 'foo'::text)
Total runtime: 13.627 ms
(6 rows)

QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------
Limit (cost=68.13..68.19 rows=26 width=4) (actual time=0.345..0.475 rows=26 loops=1)
-> Sort (cost=68.13..68.19 rows=26 width=4) (actual time=0.338..0.381 rows=26 loops=1)
Sort Key: id
-> Bitmap Heap Scan on foo (cost=4.46..67.52 rows=26 width=4) (actual time=0.164..0.257 rows=26 loops=1)
Filter: (lower(name) ~~ 'foo'::text)
-> Bitmap Index Scan on foo_name_idx (cost=0.00..4.45 rows=26 width=0) (actual time=0.109..0.109 rows=26 loops=1)
Index Cond: (lower(name) ~=~ 'foo'::text)
Total runtime: 0.597 ms
(8 rows)

QUERY PLAN
-------------------------------------------------------------------------------------------------------
Function Scan on foo (cost=0.00..12.50 rows=1000 width=4) (actual time=1.524..1.570 rows=26 loops=1)
Total runtime: 1.647 ms
(2 rows)

QUERY PLAN
---------------------------------------------------------------------------------------------------------
Function Scan on foo (cost=0.00..12.50 rows=1000 width=4) (actual time=21.496..21.545 rows=26 loops=1)
Total runtime: 21.636 ms
(2 rows)

[PostgreSQL 8.2.5, tested on SUSE Linux 10.3, 64-bit and Windows 2000]

_________________________________________________________________
Who's friends with who and co-starred in what?
http://www.searchgamesbox.com/celebrityseparation.shtml

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Heikki Linnakangas 2008-01-20 14:34:52 Re: Slow set-returning functions
Previous Message david 2008-01-19 17:31:39 Re: [OT] RAID controllers blocking one another?