Re: strange query behavior

The tables for theses queries are vacuumed and analyzed regularly. I
just did an analyze to be sure and here are the results

explain analyze select * from battery join observationresults on
battery.batteryidentifier = observationresults.batteryidentifier left
outer join observationcomment on
observationresults.observationidentifier =
observationcomment.observationidentifier left outer join batterycomment
on battery.batteryidentifier=batterycomment.batteryidentifier where
battery.batteryidentifier in (1177470, 1177469);

QUERY PLAN

------------------------------------------------------------------------
------------------------------------------------------------------------
---------------
Nested Loop Left Join (cost=5.03..12553.00 rows=13 width=248) (actual
time=0.362..1.345 rows=30 loops=1)
-> Nested Loop Left Join (cost=4.01..12424.13 rows=13 width=208)
(actual time=0.307..0.927 rows=30 loops=1)
-> Nested Loop (cost=4.01..9410.49 rows=13 width=145) (actual
time=0.227..0.416 rows=30 loops=1)
-> Bitmap Heap Scan on battery (cost=4.01..11.64 rows=2
width=69) (actual time=0.135..0.138 rows=2 loops=1)
Recheck Cond: ((batteryidentifier = 1177470) OR
(batteryidentifier = 1177469))
-> BitmapOr (cost=4.01..4.01 rows=2 width=0)
(actual time=0.106..0.106 rows=0 loops=1)
-> Bitmap Index Scan on ix_battery_id
(cost=0.00..2.00 rows=1 width=0) (actual time=0.091..0.091 rows=1
loops=1)
Index Cond: (batteryidentifier =
1177470)
-> Bitmap Index Scan on ix_battery_id
(cost=0.00..2.00 rows=1 width=0) (actual time=0.011..0.011 rows=1
loops=1)
Index Cond: (batteryidentifier =
1177469)
-> Index Scan using ix_obresults_bat on
observationresults (cost=0.00..4682.40 rows=1362 width=76) (actual
time=0.047..0.091 rows=15 loops=2)
Index Cond: ("outer".batteryidentifier =
observationresults.batteryidentifier)
-> Index Scan using ix_obcomment_obid on observationcomment
(cost=0.00..227.73 rows=327 width=63) (actual time=0.013..0.013 rows=0
loops=30)
Index Cond: ("outer".observationidentifier =
observationcomment.observationidentifier)
-> Bitmap Heap Scan on batterycomment (cost=1.02..9.84 rows=6
width=40) (actual time=0.007..0.007 rows=0 loops=30)
Recheck Cond: ("outer".batteryidentifier =
batterycomment.batteryidentifier)
-> Bitmap Index Scan on ix_batcomment (cost=0.00..1.02 rows=6
width=0) (actual time=0.005..0.005 rows=0 loops=30)
Index Cond: ("outer".batteryidentifier =
batterycomment.batteryidentifier)
Total runtime: 1.585 ms

explain analyze select * from battery join observationresults on
battery.batteryidentifier = observationresults.batteryidentifier left
outer join observationcomment on
observationresults.observationidentifier =
observationcomment.observationidentifier left outer join batterycomment
on battery.batteryidentifier=batterycomment.batteryidentifier where
battery.batteryidentifier = 1177470;

QUERY PLAN

------------------------------------------------------------------------
------------------------------------------------------------------------
------------------------
Hash Left Join (cost=4733.62..269304.43 rows=1348 width=248) (actual
time=19275.506..19275.568 rows=9 loops=1)
Hash Cond: ("outer".batteryidentifier = "inner".batteryidentifier)
-> Merge Right Join (cost=4723.75..269287.81 rows=1348 width=208)
(actual time=19275.432..19275.473 rows=9 loops=1)
Merge Cond: ("outer".observationidentifier =
"inner".observationidentifier)
-> Index Scan using ix_obcomment_obid on observationcomment
(cost=0.00..245841.14 rows=7484253 width=63) (actual
time=0.094..13403.300 rows=4361601 loops=1)
-> Sort (cost=4723.75..4727.12 rows=1348 width=145) (actual
time=0.270..0.278 rows=9 loops=1)
Sort Key: observationresults.observationidentifier
-> Nested Loop (cost=0.00..4653.67 rows=1348 width=145)
(actual time=0.166..0.215 rows=9 loops=1)
-> Index Scan using ix_battery_id on battery
(cost=0.00..5.81 rows=1 width=69) (actual time=0.079..0.082 rows=1
loops=1)
Index Cond: (batteryidentifier = 1177470)
-> Index Scan using ix_obresults_bat on
observationresults (cost=0.00..4634.38 rows=1348 width=76) (actual
time=0.079..0.102 rows=9 loops=1)
Index Cond: (1177470 = batteryidentifier)
-> Hash (cost=9.85..9.85 rows=6 width=40) (actual time=0.039..0.039
rows=0 loops=1)
-> Bitmap Heap Scan on batterycomment (cost=1.02..9.85 rows=6
width=40) (actual time=0.037..0.037 rows=0 loops=1)
Recheck Cond: (batteryidentifier = 1177470)
-> Bitmap Index Scan on ix_batcomment (cost=0.00..1.02
rows=6 width=0) (actual time=0.032..0.032 rows=0 loops=1)
Index Cond: (batteryidentifier = 1177470)
Total runtime: 19275.838 ms
(18 rows)

Tim Jones
Healthcare Project Manager
Optio Software, Inc.
(770) 576-3555
-----Original Message-----
From: Tom Lane [mailto:tgl(at)sss(dot)pgh(dot)pa(dot)us]
Sent: Wednesday, December 13, 2006 2:17 PM
To: Tim Jones
Cc: pgsql-performance(at)postgresql(dot)org
Subject: Re: [PERFORM] strange query behavior

"Tim Jones" <TJones(at)optio(dot)com> writes:
> I have a query that uses an IN clause and it seems in perform great
> when there is more than two values in it but if there is only one it
> is really slow. Also if I change the query to use an = instead of IN
> in the case of only one value it is still slow.

Please provide EXPLAIN ANALYZE output for both cases.

> Possibly I need to reindex this
> particular index?

More likely you need to ANALYZE the table so that the planner has
up-to-date stats ...

regards, tom lane