From: Karl Denninger <karl@denninger.net>
To: Kevin Grittner <Kevin.Grittner@wicourts.gov>
Cc: pgsql-performance@postgresql.org
Cc: pgsql-sql@postgresql.org
Subject: Re: SQL Query Performance - what gives?
Date: Tue, 18 Aug 2009 18:03:44 -0500
Message-ID: <4A8B334F.1010801@denninger.net> (raw)
In-Reply-To: <4A8ADDEA0200002500029CA3@gw.wicourts.gov>
References: <4A8B04C7.6060702@denninger.net>
<4A8AC75C0200002500029C8A@gw.wicourts.gov>
<4A8B1606.2040209@denninger.net>
<4A8ADDEA0200002500029CA3@gw.wicourts.gov>
Kevin Grittner wrote:
> Karl Denninger <karl@denninger.net> wrote:
>
>> -> Index Scan using forum_name on forum
>> (cost=0.00..250.63 rows=1 width=271) (actual time=0.013..0.408
>> rows=63 loops=1)
>> Filter: (((contrib IS NULL) OR (contrib = '
>> '::text) OR (contrib ~~ '%b%'::text)) AND ((permission & 127) =
>> permission))
>>
>
> The biggest issue, as far as I can see, is that it thinks that the
> selection criteria on forum will limit to one row, while it really
> matches 63 rows.
>
> You might be able to coerce it into a faster plan with something like
> this (untested):
>
> select *
> from (select * from post
> where invisible <> 1
> and to_tsvector('english', message)
> @@ to_tsquery('violence')
> ) p,
> forum
> where forum.name = p.forum
> and (permission & '127') = permission
> and (contrib is null or contrib = ' ' or contrib like '%b%')
> order by modified desc
> limit 100
> ;
>
> -Kevin
>
That didn't help.
The FTS alone returns 2,000 records on that table, and does so VERY quickly:
ticker=# explain analyze select count(ordinal) from post, forum where
post.forum=forum.name and invisible <> 1
and to_tsvector('english', message)
@@ to_tsquery('violence');
QUERY
PLAN
----------------------------------------------------------------------------------------------------------------------------------------
Aggregate (cost=5901.57..5901.58 rows=1 width=4) (actual
time=17.492..17.494 rows=1 loops=1)
-> Hash Join (cost=613.80..5898.04 rows=1408 width=4) (actual
time=1.436..14.620 rows=2056 loops=1)
Hash Cond: (post.forum = forum.name)
-> Bitmap Heap Scan on post (cost=370.93..5635.71 rows=1435
width=14) (actual time=1.123..7.944 rows=2056 loops=1)
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) (actual time=0.738..0.738 rows=2099 loops=1)
Index Cond: (to_tsvector('english'::text, message)
@@ to_tsquery('violence'::text))
-> Hash (cost=242.07..242.07 rows=64 width=9) (actual
time=0.300..0.300 rows=64 loops=1)
-> Index Scan using forum_name on forum
(cost=0.00..242.07 rows=64 width=9) (actual time=0.011..0.182 rows=64
loops=1)
Total runtime: 17.559 ms
(11 rows)
ticker=#
Ok, but now when we check the permission mask....
ticker=# explain analyze select count(ordinal) from post, forum where
post.forum=forum.name and invisible <> 1
and to_tsvector('english', message)
@@ to_tsquery('violence') and (permission & 4 = permission);
QUERY
PLAN
--------------------------------------------------------------------------------------------------------------------------------------------------
Aggregate (cost=1329.07..1329.08 rows=1 width=4) (actual
time=29819.293..29819.295 rows=1 loops=1)
-> Nested Loop (cost=978.97..1329.01 rows=22 width=4) (actual
time=2.575..29815.530 rows=2056 loops=1)
-> Index Scan using forum_name on forum (cost=0.00..242.39
rows=1 width=13) (actual time=0.016..0.355 rows=62 loops=1)
Filter: ((permission & 4) = permission)
-> Bitmap Heap Scan on post (cost=978.97..1086.28 rows=27
width=14) (actual time=97.997..480.746 rows=33 loops=62)
Recheck Cond: ((to_tsvector('english'::text,
post.message) @@ to_tsquery('violence'::text)) AND (post.forum =
forum.name))
Filter: (post.invisible <> 1)
-> BitmapAnd (cost=978.97..978.97 rows=27 width=0)
(actual time=91.106..91.106 rows=0 loops=62)
-> Bitmap Index Scan on idx_message
(cost=0.00..370.57 rows=1435 width=0) (actual time=0.680..0.680
rows=2099 loops=62)
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) (actual time=89.927..89.927
rows=22980 loops=62)
Index Cond: (post.forum = forum.name)
Total runtime: 29819.376 ms
(13 rows)
ticker=#
The problem appearsa to lie in the "nested loop", and I don't understand
why that's happening. Isn't a **LINEAR** check on each returned value
(since we do the aggregate first?) sufficient? Why is the query planner
creating a nested loop - the aggregate contains the tested field and it
is not subject to change once aggregated?!
Attachments:karl.vcf (text/x-vcard, 263B) download
begin:vcard
fn:Karl Denninger
n:Denninger;Karl
org:Cuda Systems LLC
adr;dom:;;314 Olde Post Road;Niceville;FL;32578
email;internet:karl@denninger.net
tel;work:850-376-9364
tel;fax:850-897-9364
x-mozilla-html:TRUE
url:http://market-ticker.org
version:2.1
end:vcard
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-sql@postgresql.org
Cc: karl@denninger.net, Kevin.Grittner@wicourts.gov, pgsql-performance@postgresql.org
Subject: Re: SQL Query Performance - what gives?
In-Reply-To: <4A8B334F.1010801@denninger.net>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox