Extremely slow when query uses GIST exclusion index

[David <dchau+postgresql@xxxxxxxxxxx>]

Hi. My databases make heavy use of timestamp ranges, and they rely on GIST exclusion constraints to ensure that the ranges are disjoint. I've noticed that queries that hit the GIST indexes are EXTREMELY slow, and the queries run much faster if I make trivial changes to avoid the GIST indexes.

Here's the setup for a test case. (Timings were collected on PostgreSQL 9.5.4 on x86_64-pc-linux-gnu, Intel Xeon E5 in a VM with 3.5 GB RAM):

CREATE TABLE app (
  pk SERIAL PRIMARY KEY,
  group_id TEXT NOT NULL,
  app_time TIMESTAMPTZ NOT NULL
);

CREATE TABLE group_span (
  pk SERIAL PRIMARY KEY,
  group_id TEXT NOT NULL,
  valid_period TSTZRANGE NOT NULL,
  EXCLUDE USING GIST (group_id WITH =, valid_period WITH &&)
);

CREATE TABLE member_span (
  pk SERIAL PRIMARY KEY,
  member_id TEXT NOT NULL,
  group_id TEXT NOT NULL,
  valid_period TSTZRANGE NOT NULL,
  EXCLUDE USING GIST
    (member_id WITH =, group_id WITH =, valid_period WITH &&)
);

-- Fill tables with some random data

INSERT INTO app (group_id, app_time)
SELECT
  MD5(CONCAT(GENERATE_SERIES(1, 10000), RANDOM())),
  DATE_TRUNC('month', TIMESTAMPTZ '2000-01-01' +
             INTERVAL '3 years' * RANDOM());

-- Give groups a 1-year span, and give some groups a 2nd-year span:
INSERT INTO group_span (group_id, valid_period)
(SELECT
   group_id,
   TSTZRANGE(app_time, app_time + INTERVAL '1 year')
 FROM app)
UNION ALL
(SELECT
   group_id,
   TSTZRANGE(app_time + INTERVAL '1 year',
             app_time + INTERVAL '2 year')
 FROM app LIMIT 2000);

-- Create members with a random span within their group_span:
INSERT INTO member_span (member_id, group_id, valid_period)
SELECT
  MD5(RANDOM()::TEXT),
  group_id,
  TSTZRANGE(
    LOWER(valid_period),
    UPPER(valid_period) - DATE_TRUNC(
      'days',
      (UPPER(valid_period) - LOWER(valid_period)) * RANDOM()
    )
  )
FROM group_span;

Given this setup, here's a query that hits the GIST exclusion index on the "member_span" table. It takes 38 sec on my machine:

SELECT *

FROM app

JOIN group_span ON

  app.group_id = group_span.group_id AND

  app.app_time <@ group_span.valid_period

JOIN member_span ON

  group_span.group_id = member_span.group_id AND

  group_span.valid_period && member_span.valid_period;

Here's the query plan for that query:

Nested Loop  (cost=319.27..776.39 rows=1 width=196) (actual time=15.370..38406.466 rows=10000 loops=1)

  Join Filter: (app.group_id = member_span.group_id)

  ->  Hash Join  (cost=319.00..771.00 rows=12 width=104) (actual time=5.790..130.613 rows=10000 loops=1)

        Hash Cond: (group_span.group_id = app.group_id)

        Join Filter: (app.app_time <@ group_span.valid_period)

        Rows Removed by Join Filter: 2000

        ->  Seq Scan on group_span  (cost=0.00..257.00 rows=12000 width=59) (actual time=0.005..16.282 rows=12000 loops=1)

        ->  Hash  (cost=194.00..194.00 rows=10000 width=45) (actual time=5.758..5.758 rows=10000 loops=1)

              Buckets: 16384  Batches: 1  Memory Usage: 910kB

              ->  Seq Scan on app  (cost=0.00..194.00 rows=10000 width=45) (actual time=0.002..2.426 rows=10000 loops=1)

  ->  Index Scan using member_span_member_id_group_id_valid_period_excl on member_span  (cost=0.28..0.44 rows=1 width=92) (actual time=1.988..3.817 rows=1 loops=10000)

        Index Cond: ((group_id = group_span.group_id) AND (group_span.valid_period && valid_period))

Planning time: 0.784 ms

Execution time: 38410.227 ms

We can make a small tweak to the query to make it complicated enough that the execution planner avoids the GIST index. In this particular case, we can replace "app.app_time <@ group_span.valid_period" with the equivalent "app.app_time >= LOWER(group_span.valid_period) AND app.app_time < UPPER(group_span.valid_period)". This equivalent query is MUCH faster:

SELECT *

FROM app

JOIN group_span ON

  app.group_id = group_span.group_id AND

  app.app_time >= LOWER(group_span.valid_period) AND

  app.app_time < UPPER(group_span.valid_period)

JOIN member_span ON

  group_span.group_id = member_span.group_id AND

  group_span.valid_period && member_span.valid_period;

It only takes 86 ms, even though it's doing 3 seq scans instead of using the index:

Hash Join  (cost=953.71..1186.65 rows=8 width=196) (actual time=58.364..84.706 rows=10000 loops=1)

  Hash Cond: (app.group_id = group_span.group_id)

  Join Filter: ((app.app_time >= lower(group_span.valid_period)) AND (app.app_time < upper(group_span.valid_period)))

  Rows Removed by Join Filter: 2000

  ->  Seq Scan on app  (cost=0.00..194.00 rows=10000 width=45) (actual time=0.007..2.391 rows=10000 loops=1)

  ->  Hash  (cost=952.81..952.81 rows=72 width=151) (actual time=58.343..58.343 rows=12000 loops=1)

        Buckets: 16384 (originally 1024)  Batches: 1 (originally 1)  Memory Usage: 2285kB

        ->  Hash Join  (cost=407.00..952.81 rows=72 width=151) (actual time=15.048..44.103 rows=12000 loops=1)

              Hash Cond: (member_span.group_id = group_span.group_id)

              Join Filter: (group_span.valid_period && member_span.valid_period)

              Rows Removed by Join Filter: 4000

              ->  Seq Scan on member_span  (cost=0.00..305.00 rows=12000 width=92) (actual time=0.001..3.865 rows=12000 loops=1)

              ->  Hash  (cost=257.00..257.00 rows=12000 width=59) (actual time=15.020..15.020 rows=12000 loops=1)

                    Buckets: 16384  Batches: 1  Memory Usage: 1195kB

                    ->  Seq Scan on group_span  (cost=0.00..257.00 rows=12000 width=59) (actual time=0.003..2.863 rows=12000 loops=1)

Planning time: 0.651 ms

Execution time: 86.721 ms

For now, I can bypass the GIST index by avoiding range operators in my queries. But why is the GIST index so slow?