timescale / timescaledb

An open-source time-series SQL database optimized for fast ingest and complex queries. Packaged as a PostgreSQL extension.
https://www.timescale.com/
Other
17.89k stars 882 forks source link

[Bug]: Continuous aggregations take too long to create #5700

Open YarekTyshchenko opened 1 year ago

YarekTyshchenko commented 1 year ago

What type of bug is this?

Performance issue

What subsystems and features are affected?

Continuous aggregate

What happened?

Creating the aggregate from large amount of data takes a very long time (will never complete). I'm attaching a screenshot of metrics that should make the problem plain to see. The aggregation writes get slower as they run.

2023-05-19-120512_1195x1027_scrot

Test case SQL attached to the ticket.

You may have to adjust the number of sensors for smaller test dataset

Its possible to manually remove and add a policy continuously increasing the start interval, and in that case the write speed is maintained (as long as the period is ~10 chunks), but that's too manual over the amount of data I'm working with.

I also tried to manually trigger cagg via the refresh_continuous_aggregate however, when used in a loop, it complains about a missing relation.

DO
$$
DECLARE
    refresh_interval INTERVAL = '7d'::INTERVAL;
    end_timestamp DATE = date '2020-01-01';
    start_timestamp DATE = end_timestamp - refresh_interval;
BEGIN
    WHILE start_timestamp > date '2010-01-01' LOOP
        RAISE NOTICE 'processing timestamp % -> %', start_timestamp, end_timestamp;
        CALL refresh_continuous_aggregate('metrics_15minute'::REGCLASS, start_timestamp, end_timestamp);
        end_timestamp = start_timestamp;
        start_timestamp = start_timestamp - refresh_interval;
    END LOOP;
END
$$;
NOTICE:  processing timestamp 2019-12-25 -> 2020-01-01
NOTICE:  processing timestamp 2019-12-18 -> 2019-12-25
ERROR:  relation "metrics_15minute" does not exist
LINE 1: CALL refresh_continuous_aggregate('metrics_15minute'::REGCLA...
                                          ^
QUERY:  CALL refresh_continuous_aggregate('metrics_15minute'::REGCLASS, start_timestamp, end_timestamp)
CONTEXT:  PL/pgSQL function inline_code_block line 9 at CALL

Deployment details:

PostgreSQL 14.8 (Ubuntu 14.8-1.pgdg22.04+1) on x86_64-pc-linux-gnu, compiled by gcc (Ubuntu 11.3.0-1ubuntu1~22.04) 11.3.0, 64-bit
timescaledb | 2.9.1

Deployed in Kubernetes via the official helm chart, with an Azure Managed

TimescaleDB version affected

2.9.1, 2.10.3

PostgreSQL version used

14.8

What operating system did you use?

Helm chart, docker image version: timescale/timescaledb-ha:pg14.8-ts2.10.3

What installation method did you use?

Docker, Other

What platform did you run on?

Microsoft Azure Cloud

Relevant log output and stack trace

Nothing interesting in the logs for the time period, except maybe this:

2023-05-19 10:40:12 UTC LOG:  checkpoint starting: wal
2023-05-19 10:40:54 UTC LOG:  checkpoint complete: wrote 23073 buffers (70.4%); 0 WAL file(s) added, 10 removed, 31 recycled; write=38.006 s, sync=3.370 s, total=42.477 s; sync files=261, longest=0.841 s, average=0.013 s; distance=542367 kB, estimate=542367 kB
2023-05-19 10:40:54 UTC LOG:  checkpoint starting: wal
2023-05-19 10:42:57 UTC LOG:  checkpoint complete: wrote 25626 buffers (78.2%); 0 WAL file(s) added, 11 removed, 22 recycled; write=65.620 s, sync=56.665 s, total=122.716 s; sync files=212, longest=1.347 s, average=0.268 s; distance=542081 kB, estimate=542338 kB
2023-05-19 10:42:57 UTC LOG:  checkpoint starting: wal
2023-05-19 10:47:37 UTC LOG:  checkpoint complete: wrote 18747 buffers (57.2%); 0 WAL file(s) added, 18 removed, 23 recycled; write=203.996 s, sync=74.355 s, total=279.573 s; sync files=212, longest=1.258 s, average=0.351 s; distance=681965 kB, estimate=681965 kB
2023-05-19 10:47:37 UTC LOG:  checkpoint starting: wal
2023-05-19 10:53:34 UTC LOG:  checkpoint complete: wrote 18114 buffers (55.3%); 0 WAL file(s) added, 11 removed, 29 recycled; write=269.218 s, sync=86.751 s, total=357.415 s; sync files=212, longest=1.670 s, average=0.410 s; distance=648632 kB, estimate=678631 kB
2023-05-19 10:53:34 UTC LOG:  checkpoint starting: wal time
2023-05-19 10:59:28 UTC LOG:  checkpoint complete: wrote 18466 buffers (56.4%); 0 WAL file(s) added, 0 removed, 34 recycled; write=268.936 s, sync=83.571 s, total=353.733 s; sync files=212, longest=2.397 s, average=0.395 s; distance=552269 kB, estimate=665995 kB
2023-05-19 10:59:28 UTC LOG:  checkpoint starting: time
2023-05-19 11:05:40 UTC LOG:  checkpoint complete: wrote 12999 buffers (39.7%); 0 WAL file(s) added, 0 removed, 29 recycled; write=269.353 s, sync=102.170 s, total=372.388 s; sync files=212, longest=1.792 s, average=0.482 s; distance=480290 kB, estimate=647425 kB
2023-05-19 11:05:40 UTC LOG:  checkpoint starting: time
2023-05-19 11:11:53 UTC LOG:  checkpoint complete: wrote 13580 buffers (41.4%); 0 WAL file(s) added, 0 removed, 29 recycled; write=268.692 s, sync=102.810 s, total=372.681 s; sync files=212, longest=2.191 s, average=0.485 s; distance=481745 kB, estimate=630857 kB
2023-05-19 11:11:53 UTC LOG:  checkpoint starting: time

If there's any more detailed logging that I can enable, please let me know.

How can we reproduce the bug?

CREATE TABLE metrics (
    sensor_id INTEGER NOT NULL,
    value DOUBLE PRECISION NOT NULL,
    timestamp TIMESTAMPTZ NOT NULL,
    CONSTRAINT pk_test PRIMARY KEY (sensor_id, timestamp)
);
SELECT create_hypertable('metrics', 'timestamp');

-- Insert test data
-- 1 year = 13GB (takes 11:42.242 minutes)
-- 128 GB = 10 years
-- 1 sensor = 644196352 bytes 644 MB
-- 128 GB (half disk) = ~200 sensors
INSERT INTO metrics
SELECT
    s.sensor_id,
    random()*50 + 10,
    timestamp + (INTERVAL '1 second' * random() * 30)
FROM
    generate_series(DATE '2010-01-01', DATE '2020-01-01' - INTERVAL '1 minute', INTERVAL '1 minute') AS timestamp
        CROSS JOIN (SELECT generate_series(1, 200) as sensor_id) as s;

-- Continuous aggregations
CREATE MATERIALIZED VIEW metrics_15minute WITH (timescaledb.continuous) AS SELECT
    time_bucket('15 minute', timestamp) as timestamp,
    sensor_id,
    min(value) as min,
    max(value) as max,
    sum(value) as sum,
    count(value) as count
FROM metrics GROUP BY sensor_id, time_bucket('15 minute', timestamp)
WITH NO DATA;

SELECT add_continuous_aggregate_policy(
    'metrics_15minute',
    start_offset => null,
    end_offset => INTERVAL '14 week',
    schedule_interval => INTERVAL '1 week');
YarekTyshchenko commented 1 year ago

After a chat in Slack, I was given a working function that runs the aggregations manually by looping over a period. As expected the performance was maintained, as seen in this graph (on the right):

2023-05-22-094631_1196x1029_scrot

Left is the timescale's attempt to update the aggregations via a policy. On the right is the manual day by day. after a small bump I switched it to using 4 week periods, which increased throughput and dropped the iops.

Its strange that the aggregation policies don't run in a similar fashion, I would have expected them to re-aggregate each chunk separately, given that this would be a great place to add support for updating compressed aggregated chunks (decompress, re-aggregate, then re-compress)

pdipesh02 commented 1 year ago

Hi @YarekTyshchenko , Thanks for the update.

Please let me know if you have any additional question on this.

YarekTyshchenko commented 1 year ago

@pdipesh02 I do not, I think the problem is well documented here, and looks like its also well known from the conversation I had on slack. Is there anything more I can provide to help you fix this?

phemmer commented 1 year ago

@YarekTyshchenko

I was given a working function that runs the aggregations manually by looping over a period

Would you be able to share this function? Thanks