Обсуждение: Slow indexscan

Hello group

I have a problem with a simple index scan using the primary key of a table taking too long.

Relevant facts:
pg version 7.3.4 (yeah very old, we are upgrading asap)

postgresql.conf:
shared_buffers = 25000
random_page_cost = 2
effective_cache_size = 200000
sort_mem = 20000

Table:
db=# \d tbl_20070601
             Table "public.tbl_20070601"
      Column      |         Type          | Modifiers
------------------+-----------------------+-----------
 validtime        | bigint                | not null
 latitude         | double precision      | not null
 longitude        | double precision      | not null
.....
parname          | character varying(20) | not null
....
(table has a lot of columns but these are the most important ones)

Indexes: tbl_20060601_pkey primary key btree (validtime, latitude, longitude, ..., parname, ...)

Validtime is a timestamp for the row (not my design).

the query:
db=# explain analyze select * from tbl_20070601 where validtime between 20070602000000 and 20070602235500 and latitude=60.2744 and longitude=26.4417 and parname in ('parameter');
                                                                                       QUERY PLAN                                  
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Index Scan using tbl_20070601_pkey on tbl_20070601 t1  (cost= 0.00..365.13 rows=13 width=137) (actual time=120.83..10752.64 rows=539 loops=1)
   Index Cond: ((validtime >= 20070602000000::bigint) AND (validtime <= 20070602235500::bigint) AND (latitude = 60.2744::double precision) AND (longitude = 26.4417::double precision))
   Filter: (parname = 'temperature'::character varying)
 Total runtime: 10753.85 msec
(4 rows)

db=# select count(*) from tbl_20070601;
   count
---------
 3715565
(1 row)

the query is only returning 539 rows but it takes more than 10 seconds to execute. The table has only inserts and never deletes or updates and it has been analyzed recently.

Is there anything to tweak with the query and/or postgresql, or should the hardware be inspected? Server is 2-CPU 4GB RAM blade-server with a fibre connection to a disk subsystem. Any more information I can give about the system?


Regards

MP

"Mikko Partio" <mpartio@gmail.com> writes:

>  Index Scan using tbl_20070601_pkey on tbl_20070601 t1
> (cost=0.00..365.13rows=13 width=137) (actual time=
> 120.83..10752.64 rows=539 loops=1)
>    Index Cond: ((validtime >= 20070602000000::bigint) AND (validtime <=
> 20070602235500::bigint) AND (latitude = 60.2744::double precision) AND
> (longitude = 26.4417::double precision))
>    Filter: (parname = 'temperature'::character varying)

You do realize that's going to scan the entire index range from
20070602000000 to 20070602235500?

If this is a typical query you'd be better off putting the lat/long
columns first in the index.

            regards, tom lane

Mikko Partio wrote:
>
>
> On 6/20/07, *Tom Lane* <tgl@sss.pgh.pa.us <mailto:tgl@sss.pgh.pa.us>> wrote:
>
>     "Mikko Partio" <mpartio@gmail.com <mailto:mpartio@gmail.com>> writes:
>
>      >  Index Scan using tbl_20070601_pkey on tbl_20070601 t1
>      > (cost=0.00..365.13rows=13 width=137) (actual time=
>      > 120.83..10752.64 rows=539 loops=1)
>      >    Index Cond: ((validtime >= 20070602000000::bigint) AND
>     (validtime <=
>      > 20070602235500::bigint) AND (latitude = 60.2744::double
>     precision) AND
>      > (longitude = 26.4417::double precision))
>      >    Filter: (parname = 'temperature'::character varying)
>
>     You do realize that's going to scan the entire index range from
>     20070602000000 to 20070602235500?
>
>     If this is a typical query you'd be better off putting the lat/long
>     columns first in the index.
>
>                             regards, tom lane
>
>
>
> Thanks for the reply.
>
> Adding a new index does not speed up the query (although the planner
> decides to use the index):
>
> db=# create index tbl_20070601_latlonvalidpar_index on tbl_20070601
> (latitude,longitude,validtime,parname);
> CREATE INDEX
>
> db=# explain analyze select * from tbl_20070601 where validtime between
> 20070602000000 and 20070602235500 and latitude= 60.2744 and
> longitude=26.4417 and parname in ('temperature');
>
> QUERY PLAN
>
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

>
>  Index Scan using tbl_20070601_latlonvalidpar_index on tbl_20070601 t1
> (cost=0.00..29.18 rows=13 width=137) (actual time=3471.94..31542.90
> rows=539 loops=1)
>    Index Cond: ((latitude = 60.2744::double precision) AND (longitude =
> 26.4417::double precision) AND (validtime >= 20070602000000::bigint) AND
> (validtime <= 20070602235500::bigint) AND (parname =
> 'temperature'::character varying))
>  Total runtime: 31544.48 msec
> (3 rows)
>
>
> This is a very typical query and therefore it should be made as fast as
> possible. There are several tables like this rowcount ranging from 3
> million to 13 million. I have some possibilities to modify the queries
> as well as the tables, but the actual table structure is hard coded.
>
> Any other suggestions?

Try increasing your default_statistics_target and rerunning explain
analyze. Secondly try increasing your work_mem.

Joshua D. Drake


>
> Regards
>
> MP
>
>


--

       === The PostgreSQL Company: Command Prompt, Inc. ===
Sales/Support: +1.503.667.4564 || 24x7/Emergency: +1.800.492.2240
Providing the most comprehensive  PostgreSQL solutions since 1997
              http://www.commandprompt.com/

Donate to the PostgreSQL Project: http://www.postgresql.org/about/donate
PostgreSQL Replication: http://www.commandprompt.com/products/

"Mikko Partio" <mpartio@gmail.com> writes:
> Adding a new index does not speed up the query (although the planner decides
> to use the index):

Hm.  Lots of dead rows maybe?  What's your vacuuming policy?

            regards, tom lane

The table only gets inserts and selects, never updates or deletes so I guess vacuuming isn't necessary. Anyways:


db=# SET default_statistics_target TO 1000;
SET
db=# vacuum analyze verbose tbl_20070601;
INFO:  --Relation public.tbl_20070601--
INFO:  Index tbl_20070601_pkey: Pages 95012; Tuples 3715565: Deleted 0.
        CPU 8.63s/1.82u sec elapsed 367.57 sec.
INFO:  Index tbl_20070601_latlonvalidpar_index: Pages 27385; Tuples 3715565: Deleted 0.
        CPU 1.55s/1.22u sec elapsed 23.27 sec.
INFO:  Removed 2865 tuples in 2803 pages.
        CPU 0.30s/0.20u sec elapsed 37.91 sec.
INFO:  Pages 83950: Changed 0, Empty 0; Tup 3715565: Vac 2865, Keep 0, UnUsed 0.
        Total CPU 12.32s/3.69u sec elapsed 449.98 sec.
INFO:  Analyzing public.tbl_20070601
VACUUM
db=# set sort_mem to 50000;
SET
db=# explain analyze * from tbl_20070601 where validtime between 20070602000000 and 20070602235500 and latitude=60.2744 and longitude=26.4417 and parname in ('temperature');
                                                                                                               QUERY PLAN          
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Index Scan using tbl_20070601_latlonvalidpar on tbl_20070601 t1  (cost=0.00..28.46 rows=13 width=137) (actual time=37.81..1415.06 rows=539 loops=1)
   Index Cond: ((latitude = 60.2744::double precision) AND (longitude = 26.4417::double precision) AND (validtime >= 20070602000000::bigint) AND (validtime <= 20070602235500::bigint) AND (parname = 'temperature'::character varying))
 Total runtime: 1416.53 msec
(3 rows)


I guess the sort_mem helped, or then part of the rows are in the cache already. Should increasing sort_mem help here since there are no sorts etc?

Regards

MP

On Jun 20, 2007, at 9:02 , Mikko Partio wrote:

> Relevant facts:
> pg version 7.3.4 (yeah very old, we are upgrading asap)

There have been many performance improvements—not to mention security
and data-eating bug fixes—since then. Upgrading should be one of your
highest priorities. And it may even fix the issue at hand!

> Index Scan using tbl_20070601_pkey on tbl_20070601 t1
> (cost=0.00..365.13rows=13 width=137) (actual time=
> 120.83..10752.64 rows=539 loops=1)

Something appears a bit off with your index, or at least the
statistics Postgres is using to estimate it. It's estimating that the
query will return 13 rows, but you're actually returning 539. Maybe
there's some corruption in the index which is leading to both the
performance issue you're seeing and the statistics issues. Have you
tried REINDEX?

Michael Glaesemann
grzm seespotcode net

Mikko,

I don't follow this thread, just see familiar spherical coordinates we
work with a lot. If you need fast radial query you can use our
q3c package available from q3c.sf.net. See some details
http://www.sai.msu.su/~megera/wiki/SkyPixelization

Oleg

On Wed, 20 Jun 2007, Tom Lane wrote:

> "Mikko Partio" <mpartio@gmail.com> writes:
>
>>  Index Scan using tbl_20070601_pkey on tbl_20070601 t1
>> (cost=0.00..365.13rows=13 width=137) (actual time=
>> 120.83..10752.64 rows=539 loops=1)
>>    Index Cond: ((validtime >= 20070602000000::bigint) AND (validtime <=
>> 20070602235500::bigint) AND (latitude = 60.2744::double precision) AND
>> (longitude = 26.4417::double precision))
>>    Filter: (parname = 'temperature'::character varying)
>
> You do realize that's going to scan the entire index range from
> 20070602000000 to 20070602235500?
>
> If this is a typical query you'd be better off putting the lat/long
> columns first in the index.
>
>             regards, tom lane
>
> ---------------------------(end of broadcast)---------------------------
> TIP 4: Have you searched our list archives?
>
>               http://archives.postgresql.org
>

     Regards,
         Oleg
_____________________________________________________________
Oleg Bartunov, Research Scientist, Head of AstroNet (www.astronet.ru),
Sternberg Astronomical Institute, Moscow University, Russia
Internet: oleg@sai.msu.su, http://www.sai.msu.su/~megera/
phone: +007(495)939-16-83, +007(495)939-23-83

"Mikko Partio" <mpartio@gmail.com> writes:
> I guess the sort_mem helped, or then part of the rows are in the cache
> already. Should increasing sort_mem help here since there are no sorts etc?

No, it wouldn't --- this change has to be due to the data being already
loaded into cache.

There's no obvious reason for the previous query to be so slow, unless
you've got horrendously slow or overloaded disk hardware.  What sort of
machine is this anyway, and was it doing any other work at the time?

            regards, tom lane

"Mikko Partio" <mpartio@gmail.com> writes:
> This is already a great improvement compared to the previous 8 seconds. Our
> app developers claim though that previously the same queries have run in
> less than 1 second. The database had a mysterious crash a few months ago
> (some tables lost their content) and the performance has been bad ever
> since. I don't know the details of this crash since I just inherited the
> system recently and unfortunately no logfiles are left. Could the crash
> somehow corrupt catalog files so that the querying gets slower? I know this
> is a long shot but I don't know what else to think of.

I'd wonder more about what was done to recover from the crash.  For
instance, if they had to reload the tables, then it seems possible that
this table was previously nicely clustered on the relevant index and
is now quite disordered.  You might check to see if any pg_index entries
have pg_index.indisclustered set, and if so try a CLUSTER command to
re-order the table(s).

Another thing to try, which is at least slightly more useful than waving
a dead chicken at the DB, is to REINDEX everything in sight, including
the system catalogs.  This'd fix any remaining index corruption, and
probably expose heap corruption if there is any.

            regards, tom lane