Non-deterministic performance of query on select, from 1s to 60s on table with 1 billion rows

I’m trying to investigate why the performance of this query is so non-deterministic. It can take anywhere from 1 seconds, to 60 seconds and above. The nature of the query is to select a "time window", and get all rows from within that time window.

Here’s the query in question, running on a table of approximately 1 billion rows:

SELECT CAST(extract(EPOCH from ts)*1000000 as bigint) as ts     , ticks     , quantity     , side FROM order_book WHERE ts >= TO_TIMESTAMP(1618882633073383/1000000.0)     AND ts < TO_TIMESTAMP(1618969033073383/1000000.0)     AND zx_prod_id = 0 ORDER BY ts ASC, del desc 

The values within TO_TIMESTAMP will keep sliding forward as I walk the whole table. Here is the EXPLAIN ANALYZE output for the same query on two different time windows:

Slow Performance

Gather Merge  (cost=105996.20..177498.48 rows=586308 width=18) (actual time=45196.559..45280.769 rows=539265 loops=1)   Workers Planned: 6   Workers Launched: 6   Buffers: shared hit=116386 read=42298   ->  Sort  (cost=104996.11..105240.40 rows=97718 width=18) (actual time=45169.717..45176.775 rows=77038 loops=7)         Sort Key: (((date_part('epoch'::text, _hyper_16_214_chunk.ts) * '1000000'::double precision))::bigint), _hyper_16_214_chunk.del DESC         Sort Method: quicksort  Memory: 9327kB         Worker 0:  Sort Method: quicksort  Memory: 8967kB         Worker 1:  Sort Method: quicksort  Memory: 9121kB         Worker 2:  Sort Method: quicksort  Memory: 9098kB         Worker 3:  Sort Method: quicksort  Memory: 9075kB         Worker 4:  Sort Method: quicksort  Memory: 9019kB         Worker 5:  Sort Method: quicksort  Memory: 9031kB         Buffers: shared hit=116386 read=42298         ->  Result  (cost=0.57..96897.07 rows=97718 width=18) (actual time=7.475..45131.932 rows=77038 loops=7)               Buffers: shared hit=116296 read=42298               ->  Parallel Index Scan using _hyper_16_214_chunk_order_book_ts_idx on _hyper_16_214_chunk  (cost=0.57..95187.01 rows=97718 width=18) (actual time=7.455..45101.670 rows=77038 loops=7)                     Index Cond: ((ts >= '2021-04-22 01:34:31.357179+00'::timestamp with time zone) AND (ts < '2021-04-22 02:34:31.357179+00'::timestamp with time zone))                     Filter: (zx_prod_id = 0)                     Rows Removed by Filter: 465513                     Buffers: shared hit=116296 read=42298 Planning Time: 1.107 ms JIT:   Functions: 49   Options: Inlining false, Optimization false, Expressions true, Deforming true   Timing: Generation 9.273 ms, Inlining 0.000 ms, Optimization 2.008 ms, Emission 36.235 ms, Total 47.517 ms Execution Time: 45335.178 ms 

Fast Performance

Gather Merge  (cost=105095.94..170457.62 rows=535956 width=18) (actual time=172.723..240.628 rows=546367 loops=1)   Workers Planned: 6   Workers Launched: 6   Buffers: shared hit=158212   ->  Sort  (cost=104095.84..104319.16 rows=89326 width=18) (actual time=146.702..152.849 rows=78052 loops=7)         Sort Key: (((date_part('epoch'::text, _hyper_16_214_chunk.ts) * '1000000'::double precision))::bigint), _hyper_16_214_chunk.del DESC         Sort Method: quicksort  Memory: 11366kB         Worker 0:  Sort Method: quicksort  Memory: 8664kB         Worker 1:  Sort Method: quicksort  Memory: 8986kB         Worker 2:  Sort Method: quicksort  Memory: 9116kB         Worker 3:  Sort Method: quicksort  Memory: 8858kB         Worker 4:  Sort Method: quicksort  Memory: 9057kB         Worker 5:  Sort Method: quicksort  Memory: 6611kB         Buffers: shared hit=158212         ->  Result  (cost=0.57..96750.21 rows=89326 width=18) (actual time=6.145..127.591 rows=78052 loops=7)               Buffers: shared hit=158122               ->  Parallel Index Scan using _hyper_16_214_chunk_order_book_ts_idx on _hyper_16_214_chunk  (cost=0.57..95187.01 rows=89326 width=18) (actual time=6.124..114.023 rows=78052 loops=7)                     Index Cond: ((ts >= '2021-04-22 01:34:31.357179+00'::timestamp with time zone) AND (ts < '2021-04-22 02:34:31.357179+00'::timestamp with time zone))                     Filter: (zx_prod_id = 4)                     Rows Removed by Filter: 464498                     Buffers: shared hit=158122 Planning Time: 0.419 ms JIT:   Functions: 49   Options: Inlining false, Optimization false, Expressions true, Deforming true   Timing: Generation 10.405 ms, Inlining 0.000 ms, Optimization 2.185 ms, Emission 39.188 ms, Total 51.778 ms Execution Time: 274.413 ms 

I interpreted this output as most of the blame lying on this parallel index scan.

At first, I tried to raise work_mem to 1 GB and shared_buffers to 24 GB, thinking that maybe it couldn’t fit all the stuff it needed in RAM, but that didn’t seem to help.

Next, I tried creating an index on (zx_prod_id, ts), thinking that the filter on the parallel index scan might be taking a while, but that didn’t seem to do anything either.

I’m no database expert, and so I’ve kind of exhausted the limits of my knowledge.

Thanks in advance for any suggestions!