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@sss.pgh.pa.us]
Sent: Wednesday, December 13, 2006 2:17 PM
To: Tim Jones
Cc: pgsql-performance@postgresql.org
Subject: Re: [PERFORM] strange query behavior

"Tim Jones" <TJones@optio.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