[Bug]: Potential costing / planning issue: skipscan not chosen with time quals

[davidkohn88]

What type of bug is this?

Performance issue

What subsystems and features are affected?

Query planner, SkipScan

What happened?

Working with a table like the one in the getting started demo:

CREATE TABLE stocks_real_time (
    time timestamp with time zone NOT NULL,
    symbol text NOT NULL,
    price double precision,
    day_volume integer
);

CREATE INDEX stocks_real_time_symbol_time_idx ON stocks_real_time(symbol text_ops,time timestamptz_ops);
CREATE INDEX stocks_real_time_time_idx ON stocks_real_time(time timestamptz_ops DESC);
SELECT create_hypertable('stocks_real_time','time', create_default_indexes=>false);

If I run a DISTINCT query on the whole data set, I get a very fast skipscan, ie about 3ms for:

SELECT DISTINCT SYMBOL FROM stocks_real_time;

But if I add a time qual on that, which is a pretty common use case (ie I want the distinct symbols in the last day) I no longer get a skipscan and it takes ~200-1000x longer than the query over the whole table, which is exactly the opposite of what I'd expect, that when I limit the time, it would be faster (or at least the same) not slower! So this query, for a day takes a few hundred ms once the data is in buffer cache:

I suspect it's something about the second column (time) in the index and either not being able to do a check on the value in the index, or not costing that check correctly (or perhaps it's doing it correctly and it's actually much more expensive than I think, but that seems unlikely given the large difference I'm seeing and the fact that you can do an index only scan until you reach the time qual at least).

A where clause on symbol only works fine and still gives me a skipscan, so it's probably something to do with it being the non-leading index column?

I tried create index on stocks_real_time(time, symbol); but still couldn't trigger a skipscan, though this index seems like it would actually be worse for it, I thought I'd give it a shot.

TimescaleDB version affected

2.7.1

PostgreSQL version used

14.4

What operating system did you use?

Cloud

What installation method did you use?

Not applicable

What platform did you run on?

Timescale Cloud

Relevant log output and stack trace

EXPLAIN (ANALYZE, BUFFERS) SELECT DISTINCT SYMBOL FROM stocks_real_time;
Unique  (cost=2.19..467.04 rows=200 width=4) (actual time=0.050..2.934 rows=52 loops=1)
  Buffers: shared hit=956
  ->  Merge Append  (cost=2.19..464.54 rows=1000 width=4) (actual time=0.049..2.897 rows=260 loops=1)
        Sort Key: _hyper_10_14_chunk.symbol
        Buffers: shared hit=956
        ->  Custom Scan (SkipScan) on _hyper_10_14_chunk  (cost=0.43..89.73 rows=200 width=4) (actual time=0.015..0.791 rows=52 loops=1)
              Buffers: shared hit=191
              ->  Index Only Scan using _hyper_10_14_chunk_stocks_real_time_symbol_time_idx on _hyper_10_14_chunk  (cost=0.43..28246.29 rows=1334231 width=4) (actual time=0.014..0.779 rows=52 loops=1)
                    Index Cond: (symbol > NULL::text)
                    Heap Fetches: 0
                    Buffers: shared hit=191
        ->  Custom Scan (SkipScan) on _hyper_10_15_chunk  (cost=0.43..90.15 rows=200 width=4) (actual time=0.008..0.533 rows=52 loops=1)
              Buffers: shared hit=189
              ->  Index Only Scan using _hyper_10_15_chunk_stocks_real_time_symbol_time_idx on _hyper_10_15_chunk  (cost=0.43..46014.19 rows=2219337 width=4) (actual time=0.008..0.522 rows=52 loops=1)
                    Index Cond: (symbol > NULL::text)
                    Heap Fetches: 0
                    Buffers: shared hit=189
        ->  Custom Scan (SkipScan) on _hyper_10_16_chunk  (cost=0.43..89.65 rows=200 width=4) (actual time=0.008..0.508 rows=52 loops=1)
              Buffers: shared hit=194
              ->  Index Only Scan using _hyper_10_16_chunk_stocks_real_time_symbol_time_idx on _hyper_10_16_chunk  (cost=0.43..32269.48 rows=1556097 width=4) (actual time=0.008..0.498 rows=52 loops=1)
                    Index Cond: (symbol > NULL::text)
                    Heap Fetches: 0
                    Buffers: shared hit=194
        ->  Custom Scan (SkipScan) on _hyper_10_17_chunk  (cost=0.43..89.67 rows=200 width=4) (actual time=0.007..0.493 rows=52 loops=1)
              Buffers: shared hit=188
              ->  Index Only Scan using _hyper_10_17_chunk_stocks_real_time_symbol_time_idx on _hyper_10_17_chunk  (cost=0.43..37500.83 rows=1797787 width=4) (actual time=0.007..0.483 rows=52 loops=1)
                    Index Cond: (symbol > NULL::text)
                    Heap Fetches: 0
                    Buffers: shared hit=188
        ->  Custom Scan (SkipScan) on _hyper_10_18_chunk  (cost=0.42..88.67 rows=200 width=4) (actual time=0.009..0.515 rows=52 loops=1)
              Buffers: shared hit=194
              ->  Index Only Scan using _hyper_10_18_chunk_stocks_real_time_symbol_time_idx on _hyper_10_18_chunk  (cost=0.42..9766.77 rows=467903 width=4) (actual time=0.009..0.505 rows=52 loops=1)
                    Index Cond: (symbol > NULL::text)
                    Heap Fetches: 0
                    Buffers: shared hit=194
Planning:
  Buffers: shared hit=54
Planning Time: 0.282 ms
Execution Time: 2.976 ms

--vs 
EXPLAIN (ANALYZE, BUFFERS) SELECT DISTINCT SYMBOL FROM stocks_real_time WHERE time >='2022-04-06 23:59:17+00' and time <'2022-04-09 23:59:17+00';

HashAggregate  (cost=31083.87..31085.87 rows=200 width=4) (actual time=638.563..638.571 rows=52 loops=1)
  Group Key: _hyper_10_14_chunk.symbol
  Batches: 1  Memory Usage: 40kB
  Buffers: shared hit=94148
  ->  Append  (cost=0.43..28978.61 rows=842106 width=4) (actual time=0.007..313.362 rows=840227 loops=1)
        Buffers: shared hit=94148
        ->  Index Scan using _hyper_10_14_chunk_stocks_real_time_time_idx on _hyper_10_14_chunk  (cost=0.43..3.37 rows=37 width=4) (actual time=0.007..0.024 rows=100 loops=1)
              Index Cond: (("time" >= '2022-04-06 23:59:17+00'::timestamp with time zone) AND ("time" < '2022-04-09 23:59:17+00'::timestamp with time zone))
              Buffers: shared hit=4
        ->  Index Scan using _hyper_10_15_chunk_stocks_real_time_time_idx on _hyper_10_15_chunk  (cost=0.43..24764.71 rows=842069 width=4) (actual time=0.010..258.017 rows=840127 loops=1)
              Index Cond: (("time" >= '2022-04-06 23:59:17+00'::timestamp with time zone) AND ("time" < '2022-04-09 23:59:17+00'::timestamp with time zone))
              Buffers: shared hit=94144
Planning:
  Buffers: shared hit=36
Planning Time: 0.445 ms
Execution Time: 638.606 ms

How can we reproduce the bug?

Setup for the table is above and is the same as the getting started tutorial, so can grab data here: https://docs.timescale.com/getting-started/latest/add-data/#ingest-the-dataset

[nikkhils]

@davidkohn88

it seems to be working just fine for me with latest TS sources and latest data from our website. I did invoke ANALYZE manually on the table before running the queries.

postgres=# EXPLAIN SELECT DISTINCT SYMBOL FROM stocks_real_time WHERE time >='2022-08-16 23:59:17+00' and time <'2022-08-19 23:59:17+00';
                                                                                          QUERY PLAN                                                                                          
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Unique  (cost=0.86..63.86 rows=51 width=4)
   ->  Merge Append  (cost=0.86..63.61 rows=102 width=4)
         Sort Key: _hyper_3_10_chunk.symbol
         ->  Custom Scan (SkipScan) on _hyper_3_10_chunk  (cost=0.43..37.38 rows=51 width=4)
               ->  Index Only Scan using _hyper_3_10_chunk_stocks_real_time_symbol_time_idx on _hyper_3_10_chunk  (cost=0.43..30738.71 rows=100650 width=4)
                     Index Cond: ((symbol > NULL::text) AND ("time" >= '2022-08-16 16:59:17-07'::timestamp with time zone) AND ("time" < '2022-08-19 16:59:17-07'::timestamp with time zone))
         ->  Custom Scan (SkipScan) on _hyper_3_11_chunk  (cost=0.43..25.20 rows=51 width=4)
               ->  Index Only Scan using _hyper_3_11_chunk_stocks_real_time_symbol_time_idx on _hyper_3_11_chunk  (cost=0.43..53950.93 rows=810078 width=4)
                     Index Cond: ((symbol > NULL::text) AND ("time" >= '2022-08-16 16:59:17-07'::timestamp with time zone) AND ("time" < '2022-08-19 16:59:17-07'::timestamp with time zone))
(9 rows)

[svenklemm]

@davidkohn88 this works for me, seeing that you are explicit about the operator classes did you by any chance use text_pattern_ops in your symbol index? text_pattern_ops indexes don't fulfill the requirements for skipscan.