Re: Expensive where clause

From: "Keith Worthington" <keithw(at)narrowpathinc(dot)com>
To: PostgreSQL Novice <pgsql-novice(at)postgresql(dot)org>
Cc: Stephan Szabo <sszabo(at)megazone(dot)bigpanda(dot)com>
Subject: Re: Expensive where clause
Date: 2005-02-19 06:40:45
Message-ID: 20050219062932.M67102@narrowpathinc.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-novice

On Fri, 18 Feb 2005 21:55:29 -0800 (PST), Stephan Szabo wrote
> On Fri, 18 Feb 2005, Keith Worthington wrote:
>
> > I have been working on a SQL statement that contains a WHERE
> > clause of the form WHERE column1 > column2. The query runs
> > pretty quickly (285ms) without the WHERE clause but slows to
> > a relative crawl (5850ms) when it is included.
> > Any suggestions on how to improve the performance would be
> > greatly appreciated.
>
> Explain analyze output for the query with and without the clause
> would probably be useful for analysis.

Here is the explain analyze output with the WHERE
clause commented out. This one actually ran slow. Usually it is only a few
hundred ms without the WHERE clause.

The larger picture is that I have several of these queries running as
subqueries of a larger statement. The whole statement takes upwords of 5
minutes to run on a single user machine that has minimal data. If I can't
find a way to improve this query I am going to have to go back the the drawing
board and figure out a different way of tackling the problem so that
performance is acceptable.

Thanks in advance for your help.

QUERY PLAN

-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
HashAggregate (cost=646.35..646.55 rows=80 width=36) (actual
time=1291.409..1291.633 rows=162 loops=1)
-> Hash Left Join (cost=142.94..645.95 rows=80 width=36) (actual
time=1253.595..1288.857 rows=884 loops=1)
Hash Cond: (("outer".item_id)::text = ("inner".item_id)::text)
-> Subquery Scan all_shipped_items (cost=42.06..544.66 rows=80
width=36) (actual time=3.579..34.674 rows=884 loops=1)
-> Append (cost=42.06..543.86 rows=80 width=40) (actual
time=3.574..33.078 rows=884 loops=1)
-> Subquery Scan "*SELECT* 1" (cost=42.06..80.49 rows=1
width=32) (actual time=3.572..13.620 rows=376 loops=1)
-> Nested Loop (cost=42.06..80.48 rows=1
width=32) (actual time=3.568..12.854 rows=376 loops=1)
-> Hash Join (cost=42.06..74.62 rows=1
width=32) (actual time=3.529..8.179 rows=376 loops=1)
Hash Cond: (("outer".item_id)::text =
("inner".id)::text)
-> Seq Scan on tbl_line_item
(cost=0.00..27.37 rows=1037 width=32) (actual time=0.014..1.486 rows=1087 loops=1)
-> Hash (cost=42.06..42.06 rows=1
width=24) (actual time=3.453..3.453 rows=0 loops=1)
-> Index Scan using
idx_tbl_item_item_type on tbl_item (cost=0.00..42.06 rows=1 width=24) (actual
time=0.035..2.789 rows=502 loops=1)
Index Cond:
((item_type)::text = 'DIR'::text)
Filter: ((NOT inactive) AND
(item_class = 1))
-> Index Scan using tbl_detail_pkey on
tbl_detail (cost=0.00..5.84 rows=1 width=8) (actual time=0.005..0.007 rows=1
loops=376)
Index Cond: ("outer".i_number =
tbl_detail.i_number)
-> Subquery Scan "*SELECT* 2" (cost=89.47..199.26
rows=56 width=36) (actual time=6.516..10.144 rows=460 loops=1)
-> Hash Join (cost=89.47..198.70 rows=56
width=36) (actual time=6.511..9.267 rows=460 loops=1)
Hash Cond: (("outer".id)::text =
("inner".item_id)::text)
-> Seq Scan on tbl_assembly
(cost=0.00..87.30 rows=4230 width=52) (actual time=0.809..1.470 rows=587 loops=1)
-> Hash (cost=89.46..89.46 rows=3 width=56)
(actual time=5.637..5.637 rows=0 loops=1)
-> Hash Join (cost=74.64..89.46
rows=3 width=56) (actual time=4.540..5.448 rows=137 loops=1)
Hash Cond: ("outer".i_number =
"inner".i_number)
-> Seq Scan on tbl_detail
(cost=0.00..13.53 rows=253 width=8) (actual time=0.003..0.341 rows=281 loops=1)
-> Hash (cost=74.63..74.63
rows=3 width=56) (actual time=4.483..4.483 rows=0 loops=1)
-> Hash Join
(cost=42.04..74.63 rows=3 width=56) (actual time=1.540..4.278 rows=137 loops=1)
Hash Cond:
(("outer".item_id)::text = ("inner".id)::text)
-> Seq Scan on
tbl_line_item (cost=0.00..27.37 rows=1037 width=32) (actual time=0.004..1.334
rows=1087 loops=1)
-> Hash
(cost=42.03..42.03 rows=5 width=24) (actual time=1.333..1.333 rows=0 loops=1)
-> Index Scan
using idx_tbl_item_item_type on tbl_item (cost=0.00..42.03 rows=5 width=24)
(actual time=0.035..1.078 rows=205 loops=1)
Index
Cond: ((item_type)::text = 'ASY'::text)
Filter:
(NOT inactive)
-> Subquery Scan "*SELECT* 3" (cost=89.66..116.32
rows=1 width=36) (actual time=5.076..6.629 rows=48 loops=1)
-> Nested Loop (cost=89.66..116.31 rows=1
width=36) (actual time=5.071..6.534 rows=48 loops=1)
-> Hash Join (cost=89.66..104.47 rows=2
width=38) (actual time=5.013..5.695 rows=48 loops=1)
Hash Cond: ("outer".so_number =
"inner".number)
-> Seq Scan on tbl_detail
(cost=0.00..13.53 rows=253 width=12) (actual time=0.011..0.341 rows=281 loops=1)
-> Hash (cost=89.66..89.66 rows=1
width=34) (actual time=4.964..4.964 rows=0 loops=1)
-> Hash Join (cost=84.17..89.66
rows=1 width=34) (actual time=4.395..4.882 rows=60 loops=1)
Hash Cond:
(("outer".item_id)::text = ("inner".id)::text)
-> Seq Scan on
tbl_item_bom (cost=0.00..4.32 rows=232 width=34) (actual time=0.014..0.097
rows=61 loops=1)
-> Hash
(cost=84.16..84.16 rows=1 width=24) (actual time=4.351..4.351 rows=0 loops=1)
-> Index Scan using
idx_tbl_item_item_type, idx_tbl_item_item_type on tbl_item (cost=0.00..84.16
rows=1 width=24) (actual time=0.035..3.586 rows=566 loops=1)
Index Cond:
(((item_type)::text = 'DIR'::text) OR ((item_type)::text = 'NET'::text))
Filter: ((NOT
inactive) AND (item_class = 1))
-> Index Scan using tbl_line_item_pkey on
tbl_line_item (cost=0.00..5.90 rows=1 width=10) (actual time=0.008..0.010
rows=1 loops=48)
Index Cond: (("outer".i_number =
tbl_line_item.i_number) AND ("outer".line = tbl_line_item.i_line))
-> Subquery Scan "*SELECT* 4" (cost=47.54..147.80
rows=22 width=40) (actual time=1.594..1.594 rows=0 loops=1)
-> Nested Loop (cost=47.54..147.58 rows=22
width=40) (actual time=1.591..1.591 rows=0 loops=1)
-> Nested Loop (cost=47.54..74.18 rows=1
width=60) (actual time=1.589..1.589 rows=0 loops=1)
-> Hash Join (cost=47.54..62.35
rows=2 width=62) (actual time=1.587..1.587 rows=0 loops=1)
Hash Cond: ("outer".so_number =
"inner".number)
-> Seq Scan on tbl_detail
(cost=0.00..13.53 rows=253 width=12) (never executed)
-> Hash (cost=47.53..47.53
rows=1 width=58) (actual time=1.565..1.565 rows=0 loops=1)
-> Hash Join
(cost=42.04..47.53 rows=1 width=58) (actual time=1.563..1.563 rows=0 loops=1)
Hash Cond:
(("outer".item_id)::text = ("inner".id)::text)
-> Seq Scan on
tbl_item_bom (cost=0.00..4.32 rows=232 width=34) (actual time=0.004..0.071
rows=61 loops=1)
-> Hash
(cost=42.03..42.03 rows=5 width=24) (actual time=1.408..1.408 rows=0 loops=1)
-> Index Scan
using idx_tbl_item_item_type on tbl_item (cost=0.00..42.03 rows=5 width=24)
(actual time=0.022..1.135 rows=205 loops=1)
Index
Cond: ((item_type)::text = 'ASY'::text)
Filter:
(NOT inactive)
-> Index Scan using tbl_line_item_pkey
on tbl_line_item (cost=0.00..5.90 rows=1 width=10) (never executed)
Index Cond: (("outer".i_number =
tbl_line_item.i_number) AND ("outer".line = tbl_line_item.i_line))
-> Index Scan using tbl_assembly_pkey on
tbl_assembly (cost=0.00..73.01 rows=22 width=52) (never executed)
Index Cond: (("outer".id)::text =
(tbl_assembly.id)::text)
-> Hash (cost=100.87..100.87 rows=1 width=24) (actual
time=1249.985..1249.985 rows=0 loops=1)
-> Subquery Scan all_items (cost=15.05..100.87 rows=1
width=24) (actual time=5.583..1248.912 rows=566 loops=1)
-> Nested Loop Left Join (cost=15.05..100.86 rows=1
width=28) (actual time=5.581..1247.873 rows=566 loops=1)
Join Filter: (("outer".id)::text =
("inner".item_id)::text)
-> Index Scan using idx_tbl_item_item_type,
idx_tbl_item_item_type on tbl_item items (cost=0.00..84.16 rows=1 width=24)
(actual time=0.093..5.702 rows=566 loops=1)
Index Cond: (((item_type)::text =
'DIR'::text) OR ((item_type)::text = 'NET'::text))
Filter: ((NOT inactive) AND (item_class = 1))
-> Subquery Scan last_inventory
(cost=15.05..15.95 rows=60 width=28) (actual time=0.010..1.784 rows=445 loops=566)
-> Unique (cost=15.05..15.35 rows=60
width=32) (actual time=0.008..1.043 rows=445 loops=566)
-> Sort (cost=15.05..15.20 rows=60
width=32) (actual time=0.006..0.289 rows=445 loops=566)
Sort Key: tbl_data.item_id,
tbl_data.inventory_id
-> Hash Join (cost=1.30..13.28
rows=60 width=32) (actual time=0.117..1.675 rows=445 loops=1)
Hash Cond:
("outer".inventory_id = "inner".inventory_id)
-> Seq Scan on tbl_data
(cost=0.00..8.92 rows=492 width=28) (actual time=0.009..0.474 rows=445 loops=1)
-> Hash (cost=1.24..1.24
rows=24 width=8) (actual time=0.031..0.031 rows=0 loops=1)
-> Seq Scan on
tbl_detail (cost=0.00..1.24 rows=24 width=8) (actual time=0.014..0.017 rows=2
loops=1)
Total runtime: 1292.896 ms
(82 rows)

Here is the explain analyze output with the WHERE clause active.

QUERY PLAN

-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
HashAggregate (cost=646.74..646.74 rows=1 width=36) (actual
time=11422.145..11422.334 rows=147 loops=1)
-> Nested Loop (cost=57.11..646.74 rows=1 width=36) (actual
time=17.359..11420.069 rows=504 loops=1)
Join Filter: ((("outer".item_id)::text = ("inner".item_id)::text) AND
("inner".ship_date > "outer".inventory_date))
-> Subquery Scan all_items (cost=15.05..100.87 rows=1 width=28)
(actual time=5.494..1269.377 rows=566 loops=1)
-> Nested Loop Left Join (cost=15.05..100.86 rows=1 width=28)
(actual time=5.490..1267.843 rows=566 loops=1)
Join Filter: (("outer".id)::text = ("inner".item_id)::text)
-> Index Scan using idx_tbl_item_item_type,
idx_tbl_item_item_type on tbl_item items (cost=0.00..84.16 rows=1 width=24)
(actual time=0.094..6.970 rows=566 loops=1)
Index Cond: (((item_type)::text = 'DIR'::text) OR
((item_type)::text = 'NET'::text))
Filter: ((NOT inactive) AND (item_class = 1))
-> Subquery Scan last_inventory (cost=15.05..15.95
rows=60 width=28) (actual time=0.011..1.811 rows=445 loops=566)
-> Unique (cost=15.05..15.35 rows=60 width=32)
(actual time=0.008..1.052 rows=445 loops=566)
-> Sort (cost=15.05..15.20 rows=60
width=32) (actual time=0.006..0.289 rows=445 loops=566)
Sort Key: tbl_data.item_id,
tbl_data.inventory_id
-> Hash Join (cost=1.30..13.28
rows=60 width=32) (actual time=0.124..1.661 rows=445 loops=1)
Hash Cond: ("outer".inventory_id
= "inner".inventory_id)
-> Seq Scan on tbl_data
(cost=0.00..8.92 rows=492 width=28) (actual time=0.008..0.479 rows=445 loops=1)
-> Hash (cost=1.24..1.24
rows=24 width=8) (actual time=0.032..0.032 rows=0 loops=1)
-> Seq Scan on tbl_detail
(cost=0.00..1.24 rows=24 width=8) (actual time=0.015..0.018 rows=2 loops=1)
-> Subquery Scan all_shipped_items (cost=42.06..544.66 rows=80
width=40) (actual time=0.056..17.002 rows=884 loops=566)
-> Append (cost=42.06..543.86 rows=80 width=40) (actual
time=0.054..15.355 rows=884 loops=566)
-> Subquery Scan "*SELECT* 1" (cost=42.06..80.49 rows=1
width=32) (actual time=0.053..8.856 rows=376 loops=566)
-> Nested Loop (cost=42.06..80.48 rows=1
width=32) (actual time=0.050..8.131 rows=376 loops=566)
-> Hash Join (cost=42.06..74.62 rows=1
width=32) (actual time=0.034..4.011 rows=376 loops=566)
Hash Cond: (("outer".item_id)::text =
("inner".id)::text)
-> Seq Scan on tbl_line_item
(cost=0.00..27.37 rows=1037 width=32) (actual time=0.003..1.220 rows=1087
loops=566)
-> Hash (cost=42.06..42.06 rows=1
width=24) (actual time=4.029..4.029 rows=0 loops=1)
-> Index Scan using
idx_tbl_item_item_type on tbl_item (cost=0.00..42.06 rows=1 width=24) (actual
time=0.032..3.350 rows=502 loops=1)
Index Cond:
((item_type)::text = 'DIR'::text)
Filter: ((NOT inactive) AND
(item_class = 1))
-> Index Scan using tbl_detail_pkey on
tbl_detail (cost=0.00..5.84 rows=1 width=8) (actual time=0.005..0.006 rows=1
loops=212816)
Index Cond: ("outer".i_number =
tbl_detail.i_number)
-> Subquery Scan "*SELECT* 2" (cost=89.47..199.26
rows=56 width=36) (actual time=0.365..3.797 rows=460 loops=566)
-> Hash Join (cost=89.47..198.70 rows=56
width=36) (actual time=0.361..2.979 rows=460 loops=566)
Hash Cond: (("outer".id)::text =
("inner".item_id)::text)
-> Seq Scan on tbl_assembly
(cost=0.00..87.30 rows=4230 width=52) (actual time=0.335..0.931 rows=587
loops=566)
-> Hash (cost=89.46..89.46 rows=3 width=56)
(actual time=5.369..5.369 rows=0 loops=1)
-> Hash Join (cost=74.64..89.46
rows=3 width=56) (actual time=4.359..5.177 rows=137 loops=1)
Hash Cond: ("outer".i_number =
"inner".i_number)
-> Seq Scan on tbl_detail
(cost=0.00..13.53 rows=253 width=8) (actual time=0.004..0.353 rows=281 loops=1)
-> Hash (cost=74.63..74.63
rows=3 width=56) (actual time=4.307..4.307 rows=0 loops=1)
-> Hash Join
(cost=42.04..74.63 rows=3 width=56) (actual time=1.558..4.117 rows=137 loops=1)
Hash Cond:
(("outer".item_id)::text = ("inner".id)::text)
-> Seq Scan on
tbl_line_item (cost=0.00..27.37 rows=1037 width=32) (actual time=0.004..1.138
rows=1087 loops=1)
-> Hash
(cost=42.03..42.03 rows=5 width=24) (actual time=1.356..1.356 rows=0 loops=1)
-> Index Scan
using idx_tbl_item_item_type on tbl_item (cost=0.00..42.03 rows=5 width=24)
(actual time=0.034..1.089 rows=205 loops=1)
Index
Cond: ((item_type)::text = 'ASY'::text)
Filter:
(NOT inactive)
-> Subquery Scan "*SELECT* 3" (cost=89.66..116.32
rows=1 width=36) (actual time=0.052..1.441 rows=48 loops=566)
-> Nested Loop (cost=89.66..116.31 rows=1
width=36) (actual time=0.048..1.343 rows=48 loops=566)
-> Hash Join (cost=89.66..104.47 rows=2
width=38) (actual time=0.023..0.698 rows=48 loops=566)
Hash Cond: ("outer".so_number =
"inner".number)
-> Seq Scan on tbl_detail
(cost=0.00..13.53 rows=253 width=12) (actual time=0.003..0.333 rows=281 loops=566)
-> Hash (cost=89.66..89.66 rows=1
width=34) (actual time=4.781..4.781 rows=0 loops=1)
-> Hash Join (cost=84.17..89.66
rows=1 width=34) (actual time=4.281..4.695 rows=60 loops=1)
Hash Cond:
(("outer".item_id)::text = ("inner".id)::text)
-> Seq Scan on
tbl_item_bom (cost=0.00..4.32 rows=232 width=34) (actual time=0.008..0.096
rows=61 loops=1)
-> Hash
(cost=84.16..84.16 rows=1 width=24) (actual time=4.237..4.237 rows=0 loops=1)
-> Index Scan using
idx_tbl_item_item_type, idx_tbl_item_item_type on tbl_item (cost=0.00..84.16
rows=1 width=24) (actual time=0.033..3.470 rows=566 loops=1)
Index Cond:
(((item_type)::text = 'DIR'::text) OR ((item_type)::text = 'NET'::text))
Filter: ((NOT
inactive) AND (item_class = 1))
-> Index Scan using tbl_line_item_pkey on
tbl_line_item (cost=0.00..5.90 rows=1 width=10) (actual time=0.007..0.008
rows=1 loops=27168)
Index Cond: (("outer".i_number =
tbl_line_item.i_number) AND ("outer".line = tbl_line_item.i_line))
-> Subquery Scan "*SELECT* 4" (cost=47.54..147.80
rows=22 width=40) (actual time=0.166..0.166 rows=0 loops=566)
-> Nested Loop (cost=47.54..147.58 rows=22
width=40) (actual time=0.164..0.164 rows=0 loops=566)
-> Nested Loop (cost=47.54..74.18 rows=1
width=60) (actual time=0.162..0.162 rows=0 loops=566)
-> Hash Join (cost=47.54..62.35
rows=2 width=62) (actual time=0.161..0.161 rows=0 loops=566)
Hash Cond: ("outer".so_number =
"inner".number)
-> Seq Scan on tbl_detail
(cost=0.00..13.53 rows=253 width=12) (never executed)
-> Hash (cost=47.53..47.53
rows=1 width=58) (actual time=1.432..81.382 rows=0 loops=1)
-> Hash Join
(cost=42.04..47.53 rows=1 width=58) (actual time=1.430..80.405 rows=0 loops=1)
Hash Cond:
(("outer".item_id)::text = ("inner".id)::text)
-> Seq Scan on
tbl_item_bom (cost=0.00..4.32 rows=232 width=34) (actual time=0.004..39.690
rows=34526 loops=1)
-> Hash
(cost=42.03..42.03 rows=5 width=24) (actual time=1.278..1.278 rows=0 loops=1)
-> Index Scan
using idx_tbl_item_item_type on tbl_item (cost=0.00..42.03 rows=5 width=24)
(actual time=0.024..1.024 rows=205 loops=1)
Index
Cond: ((item_type)::text = 'ASY'::text)
Filter:
(NOT inactive)
-> Index Scan using tbl_line_item_pkey
on tbl_line_item (cost=0.00..5.90 rows=1 width=10) (never executed)
Index Cond: (("outer".i_number =
tbl_line_item.i_number) AND ("outer".line = tbl_line_item.i_line))
-> Index Scan using tbl_assembly_pkey on
tbl_assembly (cost=0.00..73.01 rows=22 width=52) (never executed)
Index Cond: (("outer".id)::text =
(tbl_assembly.id)::text)
Total runtime: 11423.492 ms
(81 rows)

Kind Regards,
Keith

In response to

Responses

Browse pgsql-novice by date

  From Date Subject
Next Message Stephan Szabo 2005-02-19 15:11:56 Re: Expensive where clause
Previous Message Stephan Szabo 2005-02-19 05:55:29 Re: Expensive where clause