DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma;
	h=mime-version:in-reply-to:references:date:message-id:subject:from:to
	:cc:content-type:content-transfer-encoding;
	b=IaJKowfZTmKSuE3SoIr3AWojUnXhPWPsmJucCWhNX8vEvra7+WnGwh/SRqNSSxt8fg
	IOLURqxyTSihksNOTSq6i5TnSxR+0UzID5dKKmfpDh8dW7QSQXF0Nk/KwTt2EgzG9MjZ
	zGmvfIE9Y3G1NFeo5Y7iUYQw2bgPYYgFwTyvE=
MIME-Version: 1.0
In-Reply-To: <bd36f99e1001291949r2e769e8i7050a832b8d5a3ef@mail.gmail.com>
References: <bd36f99e1001291949r2e769e8i7050a832b8d5a3ef@mail.gmail.com>
Date: Wed, 3 Feb 2010 22:05:47 -0500
Message-ID: <603c8f071002031905w51dbea37y148284ea6546feda@mail.gmail.com>
Subject: Re: Slow query: table iteration (8.3)
From: Robert Haas <robertmhaas@gmail.com>
To: Glenn Maynard <glenn@zewt.org>
Cc: pgsql-performance@postgresql.org
Content-Type: text/plain; charset=ISO-8859-1
Content-Transfer-Encoding: quoted-printable

On Fri, Jan 29, 2010 at 10:49 PM, Glenn Maynard <glenn@zewt.org> wrote:
> Hitting a performance issues that I'm not sure how to diagnose.
>
> SELECT highscores_for_steps_and_card(s.id, 591, 1) FROM stomp_steps s;
> Seq Scan on stomp_steps s =A0(cost=3D0.00..793.52 rows=3D2902 width=3D4)
> (actual time=3D26509.919..26509.919 rows=3D0 loops=3D1)
> Total runtime: 26509.972 ms
>
> The inner function looks like this:
>
> CREATE FUNCTION highscores_for_steps_and_card(steps_id int, card_id
> int, count int) RETURNS SETOF INTEGER LANGUAGE SQL AS $$
> =A0 =A0 =A0 =A0SELECT r.id FROM stomp_round r
> =A0 =A0 =A0 =A0WHERE ($1 IS NULL OR r.steps_id =3D $1) AND ($2 IS NULL OR
> r.user_card_id =3D $2)
> =A0 =A0 =A0 =A0ORDER BY r.score DESC LIMIT $3
> $$
>
> =A0Limit =A0(cost=3D13.12..13.12 rows=3D1 width=3D8) (actual time=3D0.054=
..0.054
> rows=3D0 loops=3D1)
> =A0 -> =A0Sort =A0(cost=3D13.12..13.12 rows=3D1 width=3D8) (actual
> time=3D0.051..0.051 rows=3D0 loops=3D1)
> =A0 =A0 =A0 =A0 Sort Key: score
> =A0 =A0 =A0 =A0 Sort Method: =A0quicksort =A0Memory: 17kB
> =A0 =A0 =A0 =A0 -> =A0Bitmap Heap Scan on stomp_round r =A0(cost=3D9.09..=
13.11
> rows=3D1 width=3D8) (actual time=3D0.036..0.036 rows=3D0 loops=3D1)
> =A0 =A0 =A0 =A0 =A0 =A0 =A0 Recheck Cond: ((280 =3D steps_id) AND (user_c=
ard_id =3D 591))
> =A0 =A0 =A0 =A0 =A0 =A0 =A0 -> =A0BitmapAnd =A0(cost=3D9.09..9.09 rows=3D=
1 width=3D0) (actual
> time=3D0.032..0.032 rows=3D0 loops=3D1)
> =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 -> =A0Bitmap Index Scan on stomp_=
round_steps_id
> (cost=3D0.00..4.40 rows=3D20 width=3D0) (actual time=3D0.030..0.030 rows=
=3D0
> loops=3D1)
> =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 Index Cond: (280 =3D =
steps_id)
> =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 -> =A0Bitmap Index Scan on stomp_=
round_user_card_id
> =A0(cost=3D0.00..4.44 rows=3D25 width=3D0) (never executed)
> =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 Index Cond: (user_car=
d_id =3D 591)
> =A0Total runtime: 0.153 ms
> (12 rows)
>
> stomp_steps has about 1500 rows, so it finds 1500 high scores, one for
> each stage.
>
> I expected scalability issues from this on a regular drive, since
> it'll be doing a ton of index seeking when not working out of cache,
> so I expected to need to change to an SSD at some point (when it no
> longer easily fits in cache). =A0However, I/O doesn't seem to be the
> bottleneck yet. =A0If I run it several times, it consistently takes 26
> seconds. =A0The entire database is in OS cache (find | xargs cat:
> 250ms).
>
> I'm not sure why the full query (26s) is orders of magnitude slower
> than 1500*0.150ms (225ms). =A0It's not a very complex query, and I'd
> hope it's not being re-planned every iteration through the loop. =A0Any
> thoughts? =A0Using SELECT to iterate over a table like this is very
> useful (and I don't know any practical alternative), but it's
> difficult to profile since it doesn't play nice with EXPLAIN ANALYZE.

I believe that the time for the seq-scan node doesn't include the time
to generate the outputs, which is where all the function calls are.
As a general rule, I have found that function calls are reaaaaally
slow, and that calling a function in a loop is almost always a bad
idea.  You didn't mention what PG version you're running, but I
believe that with a sufficiently new version (8.4?) it'll actually
inline SQL functions into the invoking query, which will probably be
lots faster.  If not, you can inline it manually.

Rewriting it as a join will likely be faster still:

SELECT r.id FROM stomp_steps s, stomp_round r WHERE (s.id IS NULL OR
r.steps_id =3D s.id) AND ($1 IS NULL OR r.user_card_id =3D $1) ORDER BY
r.score DESC LIMIT $2

You might even break it into two cases:

SELECT r.id FROM stomp_steps s, stomp_round r WHERE r.steps_id =3D s.id
AND ($1 IS NULL OR r.user_card_id =3D $1)
UNION ALL
SELECT r.id FROM stomp_steps s, stomp_round r WHERE s.id IS NULL AND
($1 IS NULL OR r.user_card_id =3D $1)
ORDER BY r.score DESC LIMIT $2

Or if s.id can't really be NULL:

SELECT r.id FROM stomp_steps s, stomp_round r WHERE r.steps_id =3D s.id
AND ($1 IS NULL OR r.user_card_id =3D $1)
ORDER BY r.score DESC LIMIT $2

These kinds of rewrites allow the query planner progressively more
flexibility - to use a hash or merge join, for example, instead of a
nested loop.  And they eliminate overhead.  You'll have to play around
with it and see what works best in your particular environment, but in
general, I find it pays big dividends to avoid wrapping these kinds of
logic bits inside a function.

...Robert