Re: simple join query runs very slowly

From: "scott(dot)marlowe" <scott(dot)marlowe(at)ihs(dot)com>
To: Roger Dahl <rdnews(at)dahlsys(dot)com>
Cc: <pgsql-general(at)postgresql(dot)org>
Subject: Re: simple join query runs very slowly
Date: 2004-03-26 21:39:13
Message-ID: Pine.LNX.4.33.0403261431140.8192-100000@css120.ihs.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-general

On 25 Mar 2004, Roger Dahl wrote:

> To find out which boxes contain a specific item, I would write a query
> like this:
>
> select b.name,
> from boxes b
> inner join item_box_maps m on m.box_id = b.id
> inner join items i on m.id = m.item_id
> where i.name = 'hammer';

Is this the actual query? You're not joining items to anything. I'm
guessing it should really be:

inner join items i on i.id = m.item_id

Looking at the explain, I'm assuming it's just a typo, as it shows the
query using an index on i something or other.

> I've set up a PostgreSQL database with around 2000 boxes, 2000 items
> and 80.000 mappings. The query above will typically return 40 records
> (names of boxes) for a given item name. I'm used to this query running
> "instantaneously" but on my PostgreSQL server this query takes over
> one second.
>
> I have btree indexes on everything and have vacuum analyze'ed
> everything. EXPLAIN gives me the following output on the query above:
>
> Hash Join (cost=5.00..3608.36 rows=14 width=114) (actual
> time=572.76..1043.98 rows=7 loops=1)
> Hash Cond: ("outer".item_id = "inner".id)
> -> Merge Join (cost=0.00..3371.16 rows=30938 width=110) (actual
> time=472.93..969.62 rows=27978 loops=1)
> Merge Cond: ("outer".id = "inner".box_id)
> -> Index Scan using boxes_pkey on boxes b
> (cost=0.00..1621.40 rows=2076 width=102) (actual time=2.95..26.0\
> 8 rows=2076 loops=1)
> -> Index Scan using item_box_maps_idx_box_id on
> item_box_maps m (cost=0.00..1233.31 rows=51384 wi\
> dth=8) (actual time=24.17..580.09 rows=78544 loops=1)
> -> Hash (cost=5.00..5.00 rows=1 width=4) (actual time=0.38..0.38
> rows=0 loops=1)
> -> Index Scan using items_idx_item on items i
> (cost=0.00..5.00 rows=1 width=4) (actual time=0.35..0.37 rows=1 l\
> oops=1)
> Index Cond: (item = 'hammer'::text)
> Total runtime: 1044.35 msec
>
> I don't have any experience interpreting these, but to my untrained
> eye, everything looks fine.

No major issues with row count estimates bein way off. But, maybe hash
join isn't the best here. You can try disabling it and see what you get:

set enable_hashjoin = off;

and try it again.

> I then tried rewriting the query to use subqueries:
>
> select b.name
> from boxes b
> where b.id in (
> select box_id
> from item_box_maps
> where item_id in (
> select id
> from items
> where item = 'hammer'
> )
> );
>
> This one runs only slightly faster at around 800ms and gives the
> following EXPLAIN output:

Now it's important which version you're running. In clauses are much sped
up in 7.4.

> Seq Scan on boxes b (cost=100000000.00..208235168085.56 rows=1038

This tells me that set enable_seqscan=off was done. Was it?

Forcing an index isn't always fastest.

> SELECT relname, relkind, reltuples, relpages FROM pg_class WHERE
> relname LIKE 'items%';
>
> relname | relkind | reltuples | relpages
> ------------------------+---------+-----------+----------
> items_id_seq | S | 1 | 1
> items_pkey | i | 2124 | 38
> items_type | c | 0 | 0
> items | r | 2124 | 81
> items_idx_item | i | 2124 | 9
> (5 rows)
>
> SELECT relname, relkind, reltuples, relpages FROM pg_class WHERE
> relname LIKE 'boxes%';
>
> relname | relkind | reltuples | relpages
> --------------------------+---------+-----------+----------
> boxes_id_seq | S | 1 | 1
> boxes_pkey | i | 2076 | 67
> boxes_type | c | 0 | 0
> boxes | r | 2076 | 456
> boxes_idx_name | i | 2076 | 12
> (5 rows)
>
> SELECT relname, relkind, reltuples, relpages FROM pg_class WHERE
> relname LIKE 'item_box_maps%';
>
> relname | relkind | reltuples | relpages
> ----------------------------------+---------+-----------+----------
> item_box_maps_id_seq | S | 1 | 1
> item_box_maps_pkey | i | 78544 | 246
> item_box_maps | r | 51384 | 435
> item_box_maps_idx_item_id | i | 78544 | 232
> item_box_maps_idx_box_id | i | 78544 | 248
> item_box_maps_idx_item_id_box_id | i | 78544 | 296
> (6 rows)
>
> SELECT attname, n_distinct, most_common_vals FROM pg_stats WHERE
> tablename = 'item_box_maps';
>
> attname | n_distinct | most_common_vals
> ----------+------------+----------------------------------------------------------
> id | -1 |
> item_id | 2271 | {1,771,33,11104,81,677,4915,2,46,11853}
> box_id | 3448 |
> {10720,10600,10701,9329,9346,10611,10734,2960,5270,9332}
> (3 rows)
>
> The only thing I notice in here is that the indexes for the mapping
> table are huge -- over half the size of the table. Is that correct?

Yep. does dropping and recreating them make them smaller?

If not, then that's how big they have to be. In which case, a seq scan
may be faster for many situations. Have you done anything to disable
them?

> Other than that, I have run out of ideas. SQL Server would run the
> query instantaneously and it should be possible to have PostgreSQL run
> it in much less than a second, but how?

Have you read the performance tuning doc on varlena?

http://www.varlena.com/varlena/GeneralBits/Tidbits/perf.html

Keep us informed of your progress... I'd like to know what all you need
to do to get it to run well.

In response to

Browse pgsql-general by date

  From Date Subject
Next Message Bruno Wolff III 2004-03-26 21:46:07 Re: Native Win32 port - PLEASE!
Previous Message Rick Gigger 2004-03-26 21:26:37 Re: Native Win32 port - PLEASE!