Re: 512,600ms query becomes 7500ms... but why? Postgres 8.3 query planner quirk?

From: Bryce Nesbitt <bryce2(at)obviously(dot)com>
To: pgsql-performance(at)postgresql(dot)org
Cc: Kevin Grittner <Kevin(dot)Grittner(at)wicourts(dot)gov>
Subject: Re: 512,600ms query becomes 7500ms... but why? Postgres 8.3 query planner quirk?
Date: 2010-02-13 07:45:23
Message-ID: 4B765893.9080600@obviously.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

EXPLAIN ANALYZE
SELECT contexts.context_key
FROM contexts
JOIN articles ON (articles.context_key = contexts.context_key)
JOIN matview_82034 ON (matview_82034.context_key =
contexts.context_key)
WHERE EXISTS
(
SELECT *
FROM article_words
JOIN words using (word_key)
WHERE context_key = contexts.context_key
AND word = 'insider'
)
AND EXISTS
(
SELECT *
FROM article_words
JOIN words using (word_key)
WHERE context_key = contexts.context_key
AND word = 'trading'
)
AND EXISTS
(
SELECT *
FROM virtual_ancestors a
JOIN bp_categories ON (bp_categories.context_key =
a.ancestor_key)
WHERE a.context_key = contexts.context_key
AND lower(bp_categories.category) = 'law'
)
AND articles.indexed
;

------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Nested Loop (cost=13511.95..13662023.05 rows=19282 width=4) (actual time=3070.834..225973.159 rows=622 loops=1)
-> Hash Join (cost=13511.95..356938.38 rows=177937 width=8) (actual time=1106.242..7520.756 rows=351337 loops=1)
Hash Cond: (articles.context_key = matview_82034.context_key)
-> Seq Scan on articles (cost=0.00..334502.90 rows=386266 width=4) (actual time=0.030..4031.203 rows=355626 loops=1)
Filter: indexed
-> Hash (cost=6322.20..6322.20 rows=438220 width=4) (actual time=1105.663..1105.663 rows=438220 loops=1)
-> Seq Scan on matview_82034 (cost=0.00..6322.20 rows=438220 width=4) (actual time=7.105..544.072 rows=438220 loops=1)
-> Index Scan using contexts_pkey on contexts (cost=0.00..74.76 rows=1 width=4) (actual time=0.619..0.619 rows=0 loops=351337)
Index Cond: (contexts.context_key = articles.context_key)
Filter: ((subplan) AND (subplan) AND (subplan))
SubPlan
-> Nested Loop (cost=0.00..30.54 rows=1 width=17) (actual time=6.119..6.119 rows=1 loops=983)
-> Index Scan using words_word on words (cost=0.00..5.50 rows=1 width=13) (actual time=0.028..0.029 rows=1 loops=983)
Index Cond: ((word)::text = 'trading'::text)
-> Index Scan using article_words_cw on article_words (cost=0.00..25.02 rows=1 width=8) (actual time=6.082..6.082 rows=1 loops=983)
Index Cond: ((public.article_words.context_key = $0) AND (public.article_words.word_key = public.words.word_key))
-> Nested Loop (cost=0.00..30.54 rows=1 width=17) (actual time=6.196..6.196 rows=0 loops=26494)
-> Index Scan using words_word on words (cost=0.00..5.50 rows=1 width=13) (actual time=0.022..0.024 rows=1 loops=26494)
Index Cond: ((word)::text = 'insider'::text)
-> Index Scan using article_words_cw on article_words (cost=0.00..25.02 rows=1 width=8) (actual time=6.165..6.165 rows=0 loops=26494)
Index Cond: ((public.article_words.context_key = $0) AND (public.article_words.word_key = public.words.word_key))
-> Nested Loop (cost=0.00..38.38 rows=3 width=29) (actual time=0.122..0.122 rows=0 loops=351337)
-> Index Scan using virtual_context_key_idx on virtual_ancestors a (cost=0.00..7.35 rows=5 width=10) (actual time=0.074..0.085 rows=5 loops=351337)
Index Cond: (context_key = $0)
-> Index Scan using bp_categories_context_key_idx on bp_categories (cost=0.00..6.19 rows=1 width=19) (actual time=0.004..0.004 rows=0 loops=1740050)
Index Cond: (bp_categories.context_key = a.ancestor_key)
Filter: (lower(bp_categories.category) = 'law'::text)
Total runtime: 225976.046 ms
(28 rows)

# select * from version();
PostgreSQL 8.3.4 on x86_64-pc-linux-gnu, compiled by GCC cc (GCC) 4.1.2 20061115 (prerelease) (Debian 4.1.1-21)
(1 row)

Attachment Content-Type Size
unknown_filename text/html 1.9 KB
Grittner_qplan.txt text/plain 4.1 KB

In response to

Browse pgsql-performance by date

  From Date Subject
Next Message Bryce Nesbitt 2010-02-13 07:55:07 Re: Re: 512,600ms query becomes 7500ms... but why? Postgres 8.3 query planner quirk?
Previous Message Greg Smith 2010-02-13 07:05:41 Re: Dell PERC H700/H800