Message-ID: <443E5948.4080105@archonet.com>
Date: Thu, 13 Apr 2006 14:59:36 +0100
From: Richard Huxton <dev@archonet.com>
User-Agent: Thunderbird 1.5 (X11/20051201)
MIME-Version: 1.0
To: Gavin Hamill <gdh@laterooms.com>
Cc: pgsql-performance@postgresql.org
Subject: Re: Slow query - possible bug?
References: <443E3DF5.4020207@laterooms.com>
	<3c1395330604130546g6b091f75x511955817fe65dcd@mail.gmail.com>
	<443E4C9D.3090301@laterooms.com>
In-Reply-To: <443E4C9D.3090301@laterooms.com>
Content-Type: text/plain; charset=ISO-8859-1; format=flowed
Content-Transfer-Encoding: 7bit

Gavin Hamill wrote:
> chris smith wrote:
> 
>> 1.6secs isn't too bad on 4.3mill rows...
>>
>> How many entries are there for that date range?
>>  
>>
> 1.7 secs /is/ good - it typically takes 5 or 6 seconds, which isn't so 
> good. My question is 'why does the planner choose such a bizarre range 
> request when both elements of the 'between' are identical? :)'

What's bizarre about the range request, and are you sure it's searching 
doing the union of both conditions separately? It looks to me like it's 
doing a standard range-search. If it was trying to fetch 4.3 million 
rows via that index, I'd expect it to use a different index instead.

If you've got stats turned on, look in pg_stat_user_indexes/tables 
before and after the query to see. Here's an example of a similar query 
against one of my log tables. It's small, but the clause is the same, 
and I don't see any evidence of the whole table being selected.

lamp=> SELECT * FROM pg_stat_user_indexes WHERE relname LIKE 'act%';
   relid  | indexrelid | schemaname | relname |  indexrelname  | 
idx_scan | idx_tup_read | idx_tup_fetch
---------+------------+------------+---------+----------------+----------+--------------+---------------
  6124993 |    7519044 | public     | act_log | act_log_ts_idx | 
23 |           18 |            18
  6124993 |    7371115 | public     | act_log | act_log_pkey   | 
0 |            0 |             0
(2 rows)

lamp=> EXPLAIN ANALYSE SELECT * FROM act_log WHERE al_ts BETWEEN 
'2006-04-05 14:10:23+00'::timestamptz AND '2006-04-05 
14:10:23+00'::timestamptz;
 
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------
  Index Scan using act_log_ts_idx on act_log  (cost=0.00..3.02 rows=1 
width=102) (actual time=0.116..0.131 rows=1 loops=1)
    Index Cond: ((al_ts >= '2006-04-05 15:10:23+01'::timestamp with time 
zone) AND (al_ts <= '2006-04-05 15:10:23+01'::timestamp with time zone))
  Total runtime: 0.443 ms
(3 rows)

lamp=> SELECT * FROM pg_stat_user_indexes WHERE relname LIKE 'act%';
   relid  | indexrelid | schemaname | relname |  indexrelname  | 
idx_scan | idx_tup_read | idx_tup_fetch
---------+------------+------------+---------+----------------+----------+--------------+---------------
  6124993 |    7519044 | public     | act_log | act_log_ts_idx | 
24 |           19 |            19
  6124993 |    7371115 | public     | act_log | act_log_pkey   | 
0 |            0 |             0
(2 rows)


1. vacuum full verbose your table (and post the output please)
2. perhaps reindex?
3. Try the explain analyse again and see what happens.
-- 
   Richard Huxton
   Archonet Ltd