Thread: excessive disk access during query

excessive disk access during query

From
Toby Sargeant
Date:
Hi,

I have a pretty trivial query that seems to take an excessive amount of time
to run, and while doing so is only consuming 5-10% of CPU. It looks like the
rest of the time is spent doing disk access (the hd is certainly grinding
away a lot).

I'm not sure whether this is able to be improved, and if it is, what to
tweak.

Admittedly the tables are pretty large, but a test using dd shows that
I'm getting something like 30M/sec off disk (without hitting cache), and
while the query is running the kernel has ~1.7G worth of cache available.

The tables and indices in question appear to be around 200M each, which
I would have thought would fit in cache quite nicely.

The machine itself is a 3GHz P4 w/ 2G memory. I don't have root on it, so
I haven't been able to play with hdparm too much, but I have requested that
it be set up with hdparm -u1 -d1 -m16 (which is my default guess for disk
tuning parameters).

Thanks,

Toby.

The relevant data (sorry about the long lines) is:

postgres config:

shared_buffers = 32768
max_fsm_relations = 100
max_fsm_pages = 50000
sort_mem = 16384
vacuum_mem = 65536
effective_cache_size = 163840

table sizes:

sargeant=> select relname, relpages from pg_class where relname like 'seq_text%' order by relpages desc;
           relname           | relpages
-----------------------------+----------
 seq_text                    |    55764
 seq_text_text_index         |    30343
 seq_text_text_lindex        |    30343
 seq_text_map                |    28992
 seq_text_map_seq_index      |    22977
 seq_text_pkey               |     7528
 seq_text_map_seq_text_index |     6478
 seq_text_id_seq             |        1
(8 rows)

query:

sargeant=> explain analyze select seq_md5sum, seq_alphabet from seq_text_map, seq_text where lower(text) like '%porin%'
andseq_text.id = seq_text_map.seq_text_id; 
                                                                              QUERY PLAN

----------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Merge Join  (cost=0.00..448139.41 rows=14786 width=52) (actual time=1582.24..125624.92 rows=2140 loops=1)
   Merge Cond: ("outer".seq_text_id = "inner".id)
   ->  Index Scan using seq_text_map_seq_text_index on seq_text_map  (cost=0.00..154974.74 rows=2957158 width=48)
(actualtime=23.04..110877.65 rows=2956147 loops=1) 
   ->  Index Scan using seq_text_pkey on seq_text  (cost=0.00..285540.03 rows=17174 width=4) (actual
time=71.51..12260.38rows=3077 loops=1) 
         Filter: (lower(text) ~~ '%porin%'::text)
 Total runtime: 125627.45 msec
(6 rows)



Attachment

Re: excessive disk access during query

From
Tom Lane
Date:
Toby Sargeant <sargeant@wehi.edu.au> writes:
>  Merge Join  (cost=0.00..448139.41 rows=14786 width=52) (actual time=1582.24..125624.92 rows=2140 loops=1)
>    Merge Cond: ("outer".seq_text_id = "inner".id)
>    ->  Index Scan using seq_text_map_seq_text_index on seq_text_map  (cost=0.00..154974.74 rows=2957158 width=48)
(actualtime=23.04..110877.65 rows=2956147 loops=1) 
>    ->  Index Scan using seq_text_pkey on seq_text  (cost=0.00..285540.03 rows=17174 width=4) (actual
time=71.51..12260.38rows=3077 loops=1) 
>          Filter: (lower(text) ~~ '%porin%'::text)
>  Total runtime: 125627.45 msec

I'm surprised it doesn't try to use a hash join instead.  Are the
datatypes of seq_text_id and id different (if so, can you make them the
same?)  What sorts of plans and timings do you get if you flip
enable_mergejoin and/or enable_indexscan?

            regards, tom lane