Re: Slow Query- Simple taking

On Tue, Oct 19, 2010 at 2:21 PM, Ozer, Pam <pozer@automotive.com> wrote:
> I have the following query running on 8.4, which takes 3516 ms.  It is very
> straight forward.  It brings back 116412 records.  The explain only takes
> 1348ms
>
> select VehicleUsed.VehicleUsedId as VehicleUsedId ,
>
> VehicleUsed.VehicleUsedDisplayPriority as VehicleUsedDisplayPriority ,
>
> VehicleUsed.VehicleYear as VehicleYear ,
>
> VehicleUsed.VehicleUsedDisplayPriority as VehicleUsedDisplayPriority ,
>
> VehicleUsed.HasVehicleUsedThumbnail as HasVehicleUsedThumbnail ,
>
> VehicleUsed.HasVehicleUsedPrice as HasVehicleUsedPrice ,
>
> VehicleUsed.VehicleUsedPrice as VehicleUsedPrice ,
>
> VehicleUsed.HasVehicleUsedMileage as HasVehicleUsedMileage ,
>
> VehicleUsed.VehicleUsedMileage as VehicleUsedMileage ,
>
> VehicleUsed.IsCPO as IsCPO , VehicleUsed.IsMTCA as IsMTCA
>
> from VehicleUsed
>
> where ( VehicleUsed.VehicleMakeId = 28 )
>
> order by VehicleUsed.VehicleUsedDisplayPriority , VehicleUsed.VehicleYear
> desc , VehicleUsed.HasVehicleUsedThumbnail desc ,
> VehicleUsed.HasVehicleUsedPrice desc , VehicleUsed.VehicleUsedPrice ,
> VehicleUsed.HasVehicleUsedMileage desc , VehicleUsed.VehicleUsedMileage ,
>
> VehicleUsed.IsCPO desc , VehicleUsed.IsMTCA desc
>
>
>
>
>
> The explain is also very straight forward
>
>
>
> "Sort  (cost=104491.48..105656.24 rows=116476 width=41) (actual
> time=1288.413..1325.457 rows=116412 loops=1)"
>
> "  Sort Key: vehicleuseddisplaypriority, vehicleyear,
> hasvehicleusedthumbnail, hasvehicleusedprice, vehicleusedprice,
> hasvehicleusedmileage, vehicleusedmileage, iscpo, ismtca"
>
> "  Sort Method:  quicksort  Memory: 19443kB"
>
> "  ->  Bitmap Heap Scan on vehicleused  (cost=7458.06..65286.42 rows=116476
> width=41) (actual time=34.982..402.164 rows=116412 loops=1)"
>
> "        Recheck Cond: (vehiclemakeid = 28)"
>
> "        ->  Bitmap Index Scan on vehicleused_i08  (cost=0.00..7341.59
> rows=116476 width=0) (actual time=22.854..22.854 rows=116412 loops=1)"
>
> "              Index Cond: (vehiclemakeid = 28)"
>
> "Total runtime: 1348.487 ms"
>
>
>
> Can someone tell me why after it runs the index scan it hen runs a bitmap
> heap scan?  It should not take this long to run should it?  If I limit the
> results it comes back in 300ms.

It doesn't.  The EXPLAIN output shows it running the bitmap index scan
first and then bitmap heap scan.  The bitmap index scan is taking 22
ms, and the bitmap index and bitmap heap scans combined are taking 402
ms.  The sort is then taking another 800+ ms for a total of 1325 ms.
Any additional time is spent returning rows to the client.

--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company