Slow performance in query on continuous aggregates

I’m seeing very slow performance on a simple query, with a limited dataset.
This should be what timescaledb is intended for, so I must be missing something obvious.

query on an aggregated view.

SELECT
      time_bucket('1 day', time, 'UTC') AS mtime,
      sensor,
      first(ELECTRICITY_USED_TARIFF_1, time) as value
from meters_day
      -- using a time range, way before my 'live'-data. 
      where time > (CURRENT_TIMESTAMP - INTERVAL '7 days') and time < (CURRENT_TIMESTAMP - INTERVAL '3 days')
      and sensor = '337891'
group by mtime, sensor
order by mtime desc
limit 3;

This query takes hundreds of milliseconds!!, which does not make any sense

2023-11-16 21:29:36.025 UTC [37] LOG:  duration: 398.794 ms  statement: 

I’d expect this to complete in the ms range (maybe up to 10ms).
Anyone an idea what is causing this?

EXPLAIN OUTPUT

"Limit  (cost=40536.41..40536.49 rows=3 width=23)"
"  ->  GroupAggregate  (cost=40536.41..40541.46 rows=200 width=23)"
"        Group Key: (time_bucket('1 day'::interval, ""*SELECT* 1"".""time"", 'UTC'::text, NULL::timestamp with time zone, NULL::interval)), ""*SELECT* 1"".sensor"
"        ->  Sort  (cost=40536.41..40536.93 rows=205 width=31)"
"              Sort Key: (time_bucket('1 day'::interval, ""*SELECT* 1"".""time"", 'UTC'::text, NULL::timestamp with time zone, NULL::interval)) DESC"
"              ->  Result  (cost=0.17..40528.54 rows=205 width=31)"
"                    ->  Append  (cost=0.17..40525.98 rows=205 width=23)"
"                          ->  Subquery Scan on ""*SELECT* 1""  (cost=0.17..11.98 rows=5 width=38)"
"                                ->  Custom Scan (ChunkAppend) on _materialized_hypertable_21  (cost=0.17..11.93 rows=5 width=70)"
"                                      Chunks excluded during startup: 4"
"                                      ->  Index Scan using _hyper_21_155_chunk__materialized_hypertable_21_sensor_time_idx on _hyper_21_155_chunk  (cost=0.17..2.39 rows=1 width=48)"
"                                            Index Cond: ((sensor = '337891'::text) AND (""time"" < COALESCE(_timescaledb_internal.to_timestamp(_timescaledb_internal.cagg_watermark(21)), '-infinity'::timestamp with time zone)) AND (""time"" > (CURRENT_TIMESTAMP - '7 days'::interval)) AND (""time"" < (CURRENT_TIMESTAMP - '3 days'::interval)))"
"                          ->  Subquery Scan on ""*SELECT* 2""  (cost=40430.98..40512.98 rows=200 width=23)"
"                                ->  Finalize GroupAggregate  (cost=40430.98..40510.98 rows=200 width=55)"
"                                      Group Key: (time_bucket('1 day'::interval, p1_values.""time"", 'Europe/Amsterdam'::text, NULL::timestamp with time zone, NULL::interval)), p1_values.sensor"
"                                      ->  Gather Merge  (cost=40430.98..40501.98 rows=600 width=47)"
"                                            Workers Planned: 3"
"                                            ->  Sort  (cost=39430.94..39431.44 rows=200 width=47)"
"                                                  Sort Key: (time_bucket('1 day'::interval, p1_values.""time"", 'Europe/Amsterdam'::text, NULL::timestamp with time zone, NULL::interval))"
"                                                  ->  Partial HashAggregate  (cost=39420.29..39423.29 rows=200 width=47)"
"                                                        Group Key: time_bucket('1 day'::interval, p1_values.""time"", 'Europe/Amsterdam'::text, NULL::timestamp with time zone, NULL::interval), p1_values.sensor"
"                                                        ->  Parallel Custom Scan (ChunkAppend) on p1_values  (cost=0.43..12966.24 rows=3527207 width=31)"
"                                                              Chunks excluded during startup: 14"
"                                                              ->  Parallel Index Scan Backward using _hyper_7_140_chunk_p1_values_time_idx on _hyper_7_140_chunk  (cost=0.43..53.84 rows=2 width=23)"
"                                                                    Index Cond: (""time"" >= COALESCE(_timescaledb_internal.to_timestamp(_timescaledb_internal.cagg_watermark(21)), '-infinity'::timestamp with time zone))"
"                                                                    Filter: ((sensor = '337891'::text) AND (time_bucket('1 day'::interval, ""time"", 'Europe/Amsterdam'::text, NULL::timestamp with time zone, NULL::interval) > (CURRENT_TIMESTAMP - '7 days'::interval)) AND (time_bucket('1 day'::interval, ""time"", 'Europe/Amsterdam'::text, NULL::timestamp with time zone, NULL::interval) < (CURRENT_TIMESTAMP - '3 days'::interval)))"
"                                                              ->  Parallel Seq Scan on _hyper_7_160_chunk  (cost=0.00..3615.75 rows=204 width=23)"
"                                                                    Filter: ((sensor = '337891'::text) AND (""time"" >= COALESCE(_timescaledb_internal.to_timestamp(_timescaledb_internal.cagg_watermark(21)), '-infinity'::timestamp with time zone)) AND (time_bucket('1 day'::interval, ""time"", 'Europe/Amsterdam'::text, NULL::timestamp with time zone, NULL::interval) > (CURRENT_TIMESTAMP - '7 days'::interval)) AND (time_bucket('1 day'::interval, ""time"", 'Europe/Amsterdam'::text, NULL::timestamp with time zone, NULL::interval) < (CURRENT_TIMESTAMP - '3 days'::interval)))"

While measuring the performance, there are no other read queries beeing executed, and insert rate is at about one per second.

There are actually just 4 rows of data in this time range, see:

energy=# select count (*)
energy-# from meters_day
energy-#      where time > (CURRENT_TIMESTAMP - INTERVAL '7 days') and time < (CURRENT_TIMESTAMP - INTERVAL '3 days')
energy-#      and sensor = '337891';
 count 
-------
     4

Other queries

More queries are slow, even the ‘count’ above takes hundreds of milliseconds

2023-11-16 21:47:59.123 UTC [37] LOG:  duration: 347.943 ms  statement: select count (*)
	from meters_day
		    where time > (CURRENT_TIMESTAMP - INTERVAL '7 days') and time < (CURRENT_TIMESTAMP - INTERVAL '3 days')
	        and sensor = '337891

(result of count is 4 !)

Tables

hypertable: p1_values
2 materialized views meters_day and meters_hour, meters_hour has downsampled data one sample per hour, meters_day has one sample per day

CREATE TABLE if not EXISTS p1_values (
    time TIMESTAMPTZ NOT NULL,

    sensor TEXT NOT NULL,
    CURRENT_ELECTRICITY_DELIVERY             DOUBLE PRECISION NULL,
    CURRENT_ELECTRICITY_USAGE                DOUBLE PRECISION NULL,
    ELECTRICITY_DELIVERED_TARIFF_1           DOUBLE PRECISION NULL,
    ELECTRICITY_DELIVERED_TARIFF_2           DOUBLE PRECISION NULL,
    ELECTRICITY_USED_TARIFF_1                DOUBLE PRECISION NULL,
    ELECTRICITY_USED_TARIFF_2                DOUBLE PRECISION NULL,
    HOURLY_GAS_METER_READING                 DOUBLE PRECISION NULL,
    INSTANTANEOUS_ACTIVE_POWER_L1_NEGATIVE   DOUBLE PRECISION NULL,
    INSTANTANEOUS_ACTIVE_POWER_L1_POSITIVE   DOUBLE PRECISION NULL,
    INSTANTANEOUS_ACTIVE_POWER_L2_NEGATIVE   DOUBLE PRECISION NULL,
    INSTANTANEOUS_ACTIVE_POWER_L2_POSITIVE   DOUBLE PRECISION NULL,
    INSTANTANEOUS_ACTIVE_POWER_L3_NEGATIVE   DOUBLE PRECISION NULL,
    INSTANTANEOUS_ACTIVE_POWER_L3_POSITIVE   DOUBLE PRECISION NULL,
    INSTANTANEOUS_CURRENT_L1                 DOUBLE PRECISION NULL,
    INSTANTANEOUS_CURRENT_L2                 DOUBLE PRECISION NULL,
    INSTANTANEOUS_CURRENT_L3                 DOUBLE PRECISION NULL,
    INSTANTANEOUS_VOLTAGE_L1                 DOUBLE PRECISION NULL,
    INSTANTANEOUS_VOLTAGE_L2                 DOUBLE PRECISION NULL,
    INSTANTANEOUS_VOLTAGE_L3                 DOUBLE PRECISION NULL,
    LONG_POWER_FAILURE_COUNT                 INT NULL,
    SHORT_POWER_FAILURE_COUNT                INT NULL,
    VOLTAGE_SAG_L1_COUNT                     INT NULL,
    VOLTAGE_SAG_L2_COUNT                     INT NULL,
    VOLTAGE_SAG_L3_COUNT                     INT NULL,
    VOLTAGE_SWELL_L1_COUNT                   INT NULL,
    VOLTAGE_SWELL_L2_COUNT                   INT NULL,
    VOLTAGE_SWELL_L3_COUNT                   INT NULL
);

CREATE unique INDEX if not EXISTS sensor_time ON p1_values (sensor, time DESC);


SELECT create_hypertable('p1_values','time', if_not_exists => TRUE);
CREATE MATERIALIZED VIEW if not EXISTS meters_day
WITH (timescaledb.continuous) AS
SELECT
  time_bucket('1 day', "time", 'Europe/Amsterdam') AS time,
  sensor,
  first(ELECTRICITY_DELIVERED_TARIFF_1, time) FILTER (WHERE ELECTRICITY_DELIVERED_TARIFF_1 IS NOT NULL) AS ELECTRICITY_DELIVERED_TARIFF_1,
  first(ELECTRICITY_DELIVERED_TARIFF_2, time) FILTER (WHERE ELECTRICITY_DELIVERED_TARIFF_2 IS NOT NULL) AS ELECTRICITY_DELIVERED_TARIFF_2,
  first(ELECTRICITY_USED_TARIFF_1, time) FILTER (WHERE ELECTRICITY_USED_TARIFF_1 IS NOT NULL) AS ELECTRICITY_USED_TARIFF_1,
  first(ELECTRICITY_USED_TARIFF_2, time) FILTER (WHERE ELECTRICITY_USED_TARIFF_2 IS NOT NULL) AS ELECTRICITY_USED_TARIFF_2,
  first(HOURLY_GAS_METER_READING, time) FILTER (WHERE HOURLY_GAS_METER_READING IS NOT NULL) AS HOURLY_GAS_METER_READING
FROM p1_values
GROUP BY time_bucket('1 day', "time", 'Europe/Amsterdam'), sensor
WITH NO DATA;

SELECT add_continuous_aggregate_policy('meters_day',
  start_offset => INTERVAL '5 days',
  end_offset => INTERVAL '1 hour',
  schedule_interval => INTERVAL '1 days',
  if_not_exists => true
);

Indexes

"public"	"p1_values"	"sensor_time"		"CREATE UNIQUE INDEX sensor_time ON public.p1_values USING btree (sensor, ""time"" DESC)"
"public"	"p1_values"	"p1_values_time_idx"		"CREATE INDEX p1_values_time_idx ON public.p1_values USING btree (""time"" DESC)"

Data size

There is roughly 1,5 GB on data (including indexes)
The data volume of the docker instance gives:

energy_postgres_data   1         1.363GB

Version

timescale/timescaledb:latest-pg14 in docker on Ubuntu 20.04.6 LTS

On a VPS with 2GB RAM

  • not swapping, about 50% memory free (unused).
  • typically around 5% cpu usage (when only doing inserts)
  • not much IO going on. IO: writes ~ 10-20 iops, reads < iops.

shared_buffers = 512MB

explain analyze output

"Limit  (cost=42293.78..42293.86 rows=3 width=23) (actual time=312.238..314.802 rows=3 loops=1)"
"  ->  GroupAggregate  (cost=42293.78..42298.83 rows=200 width=23) (actual time=312.237..314.796 rows=3 loops=1)"
"        Group Key: (time_bucket('1 day'::interval, ""*SELECT* 1"".""time"", 'UTC'::text, NULL::timestamp with time zone, NULL::interval)), ""*SELECT* 1"".sensor"
"        ->  Sort  (cost=42293.78..42294.29 rows=205 width=31) (actual time=312.214..314.769 rows=4 loops=1)"
"              Sort Key: (time_bucket('1 day'::interval, ""*SELECT* 1"".""time"", 'UTC'::text, NULL::timestamp with time zone, NULL::interval)) DESC"
"              Sort Method: quicksort  Memory: 25kB"
"              ->  Result  (cost=0.17..42285.91 rows=205 width=31) (actual time=0.034..314.744 rows=4 loops=1)"
"                    ->  Append  (cost=0.17..42283.35 rows=205 width=23) (actual time=0.031..314.739 rows=4 loops=1)"
"                          ->  Subquery Scan on ""*SELECT* 1""  (cost=0.17..11.98 rows=5 width=38) (actual time=0.030..0.035 rows=4 loops=1)"
"                                ->  Custom Scan (ChunkAppend) on _materialized_hypertable_21  (cost=0.17..11.93 rows=5 width=70) (actual time=0.029..0.033 rows=4 loops=1)"
"                                      Chunks excluded during startup: 4"
"                                      ->  Index Scan using _hyper_21_155_chunk__materialized_hypertable_21_sensor_time_idx on _hyper_21_155_chunk  (cost=0.17..2.39 rows=1 width=48) (actual time=0.028..0.030 rows=4 loops=1)"
"                                            Index Cond: ((sensor = '337891'::text) AND (""time"" < COALESCE(_timescaledb_internal.to_timestamp(_timescaledb_internal.cagg_watermark(21)), '-infinity'::timestamp with time zone)) AND (""time"" > (CURRENT_TIMESTAMP - '7 days'::interval)) AND (""time"" < (CURRENT_TIMESTAMP - '3 days'::interval)))"
"                          ->  Subquery Scan on ""*SELECT* 2""  (cost=42188.34..42270.34 rows=200 width=23) (actual time=312.148..314.701 rows=0 loops=1)"
"                                ->  Finalize GroupAggregate  (cost=42188.34..42268.34 rows=200 width=55) (actual time=312.148..314.700 rows=0 loops=1)"
"                                      Group Key: (time_bucket('1 day'::interval, p1_values.""time"", 'Europe/Amsterdam'::text, NULL::timestamp with time zone, NULL::interval)), p1_values.sensor"
"                                      ->  Gather Merge  (cost=42188.34..42259.34 rows=600 width=47) (actual time=312.147..314.698 rows=0 loops=1)"
"                                            Workers Planned: 3"
"                                            Workers Launched: 3"
"                                            ->  Sort  (cost=41188.30..41188.80 rows=200 width=47) (actual time=217.329..217.333 rows=0 loops=4)"
"                                                  Sort Key: (time_bucket('1 day'::interval, p1_values.""time"", 'Europe/Amsterdam'::text, NULL::timestamp with time zone, NULL::interval))"
"                                                  Sort Method: quicksort  Memory: 25kB"
"                                                  Worker 0:  Sort Method: quicksort  Memory: 25kB"
"                                                  Worker 1:  Sort Method: quicksort  Memory: 25kB"
"                                                  Worker 2:  Sort Method: quicksort  Memory: 25kB"
"                                                  ->  Partial HashAggregate  (cost=41177.66..41180.66 rows=200 width=47) (actual time=217.286..217.290 rows=0 loops=4)"
"                                                        Group Key: time_bucket('1 day'::interval, p1_values.""time"", 'Europe/Amsterdam'::text, NULL::timestamp with time zone, NULL::interval), p1_values.sensor"
"                                                        Batches: 1  Memory Usage: 40kB"
"                                                        Worker 0:  Batches: 1  Memory Usage: 40kB"
"                                                        Worker 1:  Batches: 1  Memory Usage: 40kB"
"                                                        Worker 2:  Batches: 1  Memory Usage: 40kB"
"                                                        ->  Parallel Custom Scan (ChunkAppend) on p1_values  (cost=0.43..14722.85 rows=3527307 width=31) (actual time=217.276..217.280 rows=0 loops=4)"
"                                                              Chunks excluded during startup: 14"
"                                                              ->  Parallel Index Scan Backward using _hyper_7_140_chunk_p1_values_time_idx on _hyper_7_140_chunk  (cost=0.43..53.84 rows=2 width=23) (actual time=12.625..12.625 rows=0 loops=1)"
"                                                                    Index Cond: (""time"" >= COALESCE(_timescaledb_internal.to_timestamp(_timescaledb_internal.cagg_watermark(21)), '-infinity'::timestamp with time zone))"
"                                                                    Filter: ((sensor = '337891'::text) AND (time_bucket('1 day'::interval, ""time"", 'Europe/Amsterdam'::text, NULL::timestamp with time zone, NULL::interval) > (CURRENT_TIMESTAMP - '7 days'::interval)) AND (time_bucket('1 day'::interval, ""time"", 'Europe/Amsterdam'::text, NULL::timestamp with time zone, NULL::interval) < (CURRENT_TIMESTAMP - '3 days'::interval)))"
"                                                                    Rows Removed by Filter: 2672"
"                                                              ->  Parallel Seq Scan on _hyper_7_160_chunk  (cost=0.00..5372.12 rows=304 width=23) (actual time=214.117..214.118 rows=0 loops=4)"
"                                                                    Filter: ((sensor = '337891'::text) AND (""time"" >= COALESCE(_timescaledb_internal.to_timestamp(_timescaledb_internal.cagg_watermark(21)), '-infinity'::timestamp with time zone)) AND (time_bucket('1 day'::interval, ""time"", 'Europe/Amsterdam'::text, NULL::timestamp with time zone, NULL::interval) > (CURRENT_TIMESTAMP - '7 days'::interval)) AND (time_bucket('1 day'::interval, ""time"", 'Europe/Amsterdam'::text, NULL::timestamp with time zone, NULL::interval) < (CURRENT_TIMESTAMP - '3 days'::interval)))"
"                                                                    Rows Removed by Filter: 25776"
"Planning Time: 11.084 ms"
"Execution Time: 315.544 ms"

The Rows Removed by Filter: 25776" looks not ok, that should all have been skipped.

I found the cause of my abysmal performance. Somehow the continuous aggregates where not working. There was a problem with the background workers.

When issuing a:

SELECT _timescaledb_internal.start_background_workers();

Then all queries where below 1ms again, (as expected).

Found info at Timescale Documentation | Troubleshooting continuous aggregates