SQL Query Performance - what gives?

From: Karl Denninger <karl(at)denninger(dot)net>
To: pgsql-sql(at)postgresql(dot)org, pgsql-performance(at)postgresql(dot)org
Subject: SQL Query Performance - what gives?
Date: 2009-08-18 19:45:11
Message-ID: 4A8B04C7.6060702@denninger.net
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance pgsql-sql


Let's take the following EXPLAIN results:

ticker=# explain select * from post, forum where forum.name = post.forum
and invisible <> 1 and to_tsvector('english', message) @@
to_tsquery('violence') order by modified desc limit
100;

QUERY PLAN
---------------------------------------------------------------------------------------------------------------
Limit (cost=5951.85..5952.10 rows=100 width=706)
-> Sort (cost=5951.85..5955.37 rows=1408 width=706)
Sort Key: post.modified
-> Hash Join (cost=613.80..5898.04 rows=1408 width=706)
Hash Cond: (post.forum = forum.name)
-> Bitmap Heap Scan on post (cost=370.93..5635.71
rows=1435 width=435)
Recheck Cond: (to_tsvector('english'::text,
message) @@ to_tsquery('violence'::text))
Filter: (invisible <> 1)
-> Bitmap Index Scan on idx_message
(cost=0.00..370.57 rows=1435 width=0)
Index Cond: (to_tsvector('english'::text,
message) @@ to_tsquery('violence'::text))
-> Hash (cost=242.07..242.07 rows=64 width=271)
-> Index Scan using forum_name on forum
(cost=0.00..242.07 rows=64 width=271)
(12 rows)

ticker=#

And

ticker=# explain select * from post, forum where forum.name = post.forum
and invisible <> 1 and ((permission & '127') = permission) and (contrib
is null or contrib = ' ' or contrib like '%b%') and
to_tsvector('english', message) @@ to_tsquery('violence') order by
modified desc limit 100;

QUERY
PLAN
------------------------------------------------------------------------------------------------------------------------------------------------
Limit (cost=1329.81..1329.87 rows=22 width=706)
-> Sort (cost=1329.81..1329.87 rows=22 width=706)
Sort Key: post.modified
-> Nested Loop (cost=978.96..1329.32 rows=22 width=706)
-> Index Scan using forum_name on forum
(cost=0.00..242.71 rows=1 width=271)
Filter: (((contrib IS NULL) OR (contrib = '
'::text) OR (contrib ~~ '%b%'::text)) AND ((permission & 127) = permission))
-> Bitmap Heap Scan on post (cost=978.96..1086.28
rows=27 width=435)
Recheck Cond: ((to_tsvector('english'::text,
post.message) @@ to_tsquery('violence'::text)) AND (post.forum =
forum.name))
Filter: (post.invisible <> 1)
-> BitmapAnd (cost=978.96..978.96 rows=27 width=0)
-> Bitmap Index Scan on idx_message
(cost=0.00..370.57 rows=1435 width=0)
Index Cond:
(to_tsvector('english'::text, post.message) @@ to_tsquery('violence'::text))
-> Bitmap Index Scan on post_forum
(cost=0.00..607.78 rows=26575 width=0)
Index Cond: (post.forum = forum.name)
(14 rows)

ticker=#

The difference in these two queries is that the second qualifies the
returned search to check two permission blocks - one related to the
user's permission bit mask, and the second a mask of single-character
"flags" (the user's classification must be in the list of permitted
classifications)

Ok. Notice that the top-line cost of the first query is HIGHER.

The first query runs almost instantly - average execution latency is
frequently in the few-hundred millisecond range.

The second query can take upward of 30 seconds (!) to run.

Neither hits the disk, the machine in question has scads of free RAM
available, and while busy is not particularly constrained. Other
simultaneous users on the database are getting queries back immediately
(no unreasonable delays).

If I remove parts of the permission tests it does not matter. If ANY of
those tests qualifies the returned values the performance goes in the
toilet. If I re-order when the permission tests appear (e.g. at the end
of the search command) it makes no difference in the response time
either (it does, however, change the EXPLAIN output somewhat, and
thereby appears to change the query plan.

What's going on here? I can usually figure out what's causing bad
performance and fix it with the judicious addition of an index or other
similar thing - this one has me completely mystified.

-- Karl

Attachment Content-Type Size
karl.vcf text/x-vcard 265 bytes

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Kevin Grittner 2009-08-18 20:23:08 Re: SQL Query Performance - what gives?
Previous Message Tom Lane 2009-08-18 19:09:52 Re: Weird index or sort behaviour

Browse pgsql-sql by date

  From Date Subject
Next Message Kevin Grittner 2009-08-18 20:23:08 Re: SQL Query Performance - what gives?
Previous Message Jasen Betts 2009-08-18 11:18:10 Re: operator contains in older Pgsql