On Tue, Oct 20, 2009 at 2:34 AM, Luca Ferrari <fluca1978@infinito.it> wrote:
> Hi all,
> I'm testing a proprietary driver that connects my old applications to a
> postgresql database. The problem is that I've got very strange issues about
> execution times. For instance, the following query:
>
> cogedb=> explain analyze SELECT * FROM GMMOVART WHERE DATA >= '01/01/2006'
> AND DATA <= '31/12/2006' ORDER BY DATA, CONTATORE, RIGA;
> QUERY PLAN
>
------------------------------------------------------------------------------------------------------------------------------------------------
> Sort (cost=152440.12..152937.79 rows=199069 width=340) (actual
> time=1734.550..1827.006 rows=214730 loops=1)
> Sort Key: data, contatore, riga
> -> Bitmap Heap Scan on gmmovart (cost=6425.18..134919.15 rows=199069
> width=340) (actual time=135.161..721.679 rows=214730 loops=1)
> Recheck Cond: ((data >= '2006-01-01'::date) AND (data <=
> '2006-12-31'::date))
> -> Bitmap Index Scan on gmmovart_index03 (cost=0.00..6375.42
> rows=199069 width=0) (actual time=128.400..128.400 rows=214730 loops=1)
> Index Cond: ((data >= '2006-01-01'::date) AND (data <=
> '2006-12-31'::date))
> Total runtime: 1893.026 ms
> (7 rows)
>
>
> Executes in 1,8 seconds. Now, the same query launched thru the driver produces
> a log with the following entry:
>
> cogedb LOG: duration: 5265.103 ms statement: SELECT * FROM GMMOVART WHERE
> DATA >= '01/01/2006' AND DATA <= '31/12/2006' ORDER BY DATA, CONTATORE, RIGA
>
> with a duration of 5,2 seconds, that is 3+ times longer than the query run in
> the psql prompt! Please note that the query is always executed locally.
Two things. 1: Actually running the query and receiving the results
isn't the same as just running it and throwing them away (what explain
analyze does) and 2: The query may be getting cached in psql if you're
running it more than once, but it may not run often enough on that
data set to get the same caching each time.