Thread: simple join query runs very slowly

simple join query runs very slowly

From
rdnews@dahlsys.com (Roger Dahl)
Date:
Hello everyone,

I'm having trouble with a slow query and I wonder if anyone can help
me speed it up. I have read the PostgreSQL documentation and FAQ but
have been unable to find anything to help me out.

I have three tables: items, boxes and item_box_maps. The items table
holds ids and item names. The boxes table holds ids and box names. The
item_box_maps table holds box and item ids that "map" items to boxes.

To register a box as containing a specific item, I just add a record
in item_box_maps with the appropriate box name id and item name id. I
have used this approach on SQL Server many times and have always
gotten excellent performance.

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';

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.

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:

Seq Scan on boxes b  (cost=100000000.00..208235168085.56 rows=1038
width=98) (actual time=768.62..812.63 rows=7 loops=1)
   Filter: (subplan)
   SubPlan
     ->  Materialize  (cost=100257787.86..100257787.86 rows=25692
width=4) (actual time=0.35..0.36 rows=7 loops=2076)
           ->  Seq Scan on item_box_maps
(cost=100000000.00..100257787.86 rows=25692 width=4) (actual
time=626.02..723\
.87 rows=7 loops=1)
                 Filter: (subplan)
                 SubPlan
                   ->  Materialize  (cost=5.00..5.00 rows=1 width=4)
(actual time=0.00..0.00 rows=1 loops=78544)
                         ->  Index Scan using items_idx_item on items
(cost=0.00..5.00 rows=1 width=4) (actual time=0.32.\
.0.34 rows=1 loops=1)
                               Index Cond: (item = 'hammer'::text)


What seems to be wrong with this one is that it's not using the
indexes. If I break up the query and run each part separate and
manually insert the results into the next part, I get the following
results:

select id
from items
where item = 'hammer';
id
-------
10751
(1 row)

select box_id
from item_box_maps
where item_id in (10751);

box_id
-------------
12191
10537
10536
12169
12161
12151
11327
(7 rows)

select name
from boxes
where id in (12191, 10537, 10536, 12169, 12161, 12151, 11327);

name
-----
box2910
box1223
box15
box433
box1233
box95
box1003
(7 rows)


Each of these queries return instantly and the output from EXPLAIN
indicates that they use the index. For instance:

Index Scan using boxes_pkey, boxes_pkey, boxes_pkey, boxes_pkey,
boxes_pkey, boxes_pkey, boxes_p\
key on boxes  (cost=0.00..37.69 rows=7 width=98) (actual
time=0.10..0.34 rows=7 loops=1)
   Index Cond: ((id = 12191) OR (id = 10537) OR (id = 10536) OR (id =
12169) OR (id = 12161) OR (id = 12151) OR (id = 11327))
 Total runtime: 0.51 msec

Some more information:

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?

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?

Anyone?

Roger Dahl

Re: simple join query runs very slowly

From
Stephan Szabo
Date:
On Thu, 25 Mar 2004, Roger Dahl wrote:

> Hello everyone,
>
> I'm having trouble with a slow query and I wonder if anyone can help
> me speed it up. I have read the PostgreSQL documentation and FAQ but
> have been unable to find anything to help me out.
>
> I have three tables: items, boxes and item_box_maps. The items table
> holds ids and item names. The boxes table holds ids and box names. The
> item_box_maps table holds box and item ids that "map" items to boxes.
>
> To register a box as containing a specific item, I just add a record
> in item_box_maps with the appropriate box name id and item name id. I
> have used this approach on SQL Server many times and have always
> gotten excellent performance.
>
> 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
 -- is there a typo here?  I'd think it should be i.id=m.item_id
> where i.name = 'hammer';

Hmm, you didn't give a version.  On some versions the above is going
to force the boxes to item_box_maps join to be first (where it looks like
perhaps the item_box_maps to items join first would be better).  You could
try something like:

select b.name from boxes b inner join (item_box_maps m inner join items i
on i.id=m.item_id) on m.box_id=b.id where i.name='hammer'

And see what that gives you plan wise...


Re: simple join query runs very slowly

From
"scott.marlowe"
Date:
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.


Re: simple join query runs very slowly

From
Tom Lane
Date:
rdnews@dahlsys.com (Roger Dahl) writes:
> 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';

You didn't say which PG version you are running, but I bet it is one
that strictly follows the JOIN syntax order.  Try flipping the order of
the JOIN clauses:

select b.name,
from boxes b
inner join items i on m.id = m.item_id
inner join item_box_maps m on m.box_id = b.id
where i.name = 'hammer';

There is more about this in the Performance Tips section of the docs.

            regards, tom lane