Duplicate trigger error in `compress_chunk()`

[JLockerman]

Relevant system information:

• OS: macos docker timescale/timescaledb:2.0.0-rc2-pg12
• PostgreSQL version: 12
• TimescaleDB version 2.0-rc2
• Installation method: Docker

Describe the bug Running compress_chunk() occasionally returns the error

ERROR:  trigger "compressed_chunk_insert_blocker" for relation "_hyper_1_1_chunk" already exists

To Reproduce Steps to reproduce the behavior:

1. git clone --branch duplicate-trigger-repro --single-branch https://github.com/timescale/promscale.git
2. cd promscale
3. go test -v -run TestSQLGoldenFiles ./pkg/pgmodel/end_to_end_tests -use-timescale2 -use-extension=false

Expected behavior Either for compress_chunk() to succeed, or for it to fail with

ERROR:  chunk "_hyper_1_1_chunk" is already compressed

Actual behavior compress_chunk() fails with

ERROR:  trigger "compressed_chunk_insert_blocker" for relation "_hyper_1_1_chunk" already exists

Additional context SQL file used to trigger the error

\set ECHO all
\set ON_ERROR_STOP 1

SELECT _prom_catalog.get_or_create_metric_table_name('cpu_usage');
SELECT _prom_catalog.get_or_create_metric_table_name('cpu_total');
CALL _prom_catalog.finalize_metric_creation();
INSERT INTO prom_data.cpu_usage
  SELECT timestamptz '2000-01-01 02:03:04'+(interval '1s' * g), 100.1 + g, _prom_catalog.get_or_create_series_id('{"__name__": "cpu_usage", "namespace":"dev", "node": "brain"}')
  FROM generate_series(1,10) g;
INSERT INTO prom_data.cpu_usage
  SELECT timestamptz '2000-01-01 02:03:04'+(interval '1s' * g), 100.1 + g, _prom_catalog.get_or_create_series_id('{"__name__": "cpu_usage", "namespace":"production", "node": "pinky", "new_tag":"foo"}')
  FROM generate_series(1,10) g;
INSERT INTO prom_data.cpu_total
  SELECT timestamptz '2000-01-01 02:03:04'+(interval '1s' * g), 100.0, _prom_catalog.get_or_create_series_id('{"__name__": "cpu_total", "namespace":"dev", "node": "brain"}')
  FROM generate_series(1,10) g;
INSERT INTO prom_data.cpu_total
  SELECT timestamptz '2000-01-01 02:03:04'+(interval '1s' * g), 100.0, _prom_catalog.get_or_create_series_id('{"__name__": "cpu_total", "namespace":"production", "node": "pinky", "new_tag_2":"bar"}')
  FROM generate_series(1,10) g;

SELECT * FROM prom_info.label ORDER BY key;

SELECT count(compress_chunk(i)) from show_chunks('prom_data.cpu_usage') i;

SELECT * FROM cpu_usage ORDER BY time, series_id LIMIT 5;
SELECT time, value, jsonb(labels), val(namespace_id) FROM cpu_usage ORDER BY time, series_id LIMIT 5;
SELECT * FROM prom_series.cpu_usage ORDER BY series_id;

Where get_or_create_metric_table_name() effectively creates a new hypertable like this, and finalize_metric_creation() creates the compression policy. get_or_create_series_id() is a JSON-to-INT mapping function, and shouldn't be relevant.

[k-rus]

@JLockerman Thank you for reporting! Am I correct that the chunk, which gets the trigger error, is compressed, i.e., the issue is in the user unfriendly error message?

[JLockerman]

@k-rus as far as I know: I believe that the chunk is being compressed in the background concurrently with foreground compression, so it should be compressed, but I've never actually checked

[svenklemm]

@JLockerman sorry not too familiar with promscale tests, where would i see that error message?

 sven  alice    ~/projects/promscale  duplicate-trigger-repro  %  go test -v -run TestSQLGoldenFiles ./pkg/pgmodel/end_to_end_tests -use-timescale2 -use-extension=false
2020/11/03 15:19:50 Starting container id: c3ba5b01cf10 image: quay.io/testcontainers/ryuk:0.2.3
2020/11/03 15:19:51 Waiting for container id c3ba5b01cf10 image: quay.io/testcontainers/ryuk:0.2.3
2020/11/03 15:19:51 Container is ready id: c3ba5b01cf10 image: quay.io/testcontainers/ryuk:0.2.3
2020/11/03 15:19:51 Starting container id: 69397702fd5b image: timescale/timescaledb:2.0.0-rc2-pg12
2020/11/03 15:19:52 Waiting for container id 69397702fd5b image: timescale/timescaledb:2.0.0-rc2-pg12
2020/11/03 15:19:54 Container is ready id: 69397702fd5b image: timescale/timescaledb:2.0.0-rc2-pg12
2020/11/03 15:19:54 Starting container id: 0586a3dd7689 image: prom/prometheus
2020/11/03 15:19:54 Waiting for container id 0586a3dd7689 image: prom/prometheus
2020/11/03 15:19:55 Container is ready id: 0586a3dd7689 image: prom/prometheus
=== RUN   TestSQLGoldenFiles
level=warn ts=2020-11-03T14:19:55.960Z caller=migrate.go:128 msg="could not install promscale: the extension is not available. continuing without extension"
    golden_files_test.go:94: Golden file does not match result: diff ../testdata/expected/info_view-timescaledb.out /tmp/testdata100281429/out/info_view.out
--- FAIL: TestSQLGoldenFiles (2.30s)
FAIL
FAIL    github.com/timescale/promscale/pkg/pgmodel/end_to_end_tests     7.375s
FAIL
 sven  alice    ~/projects/promscale  duplicate-trigger-repro  ERROR  %  cat /tmp/testdata100281429/out/info_view.out
\set ON_ERROR_STOP 1
SELECT _prom_catalog.get_or_create_metric_table_name('cpu_usage');
 get_or_create_metric_table_name
---------------------------------
 (1,cpu_usage,t)
(1 row)

SELECT _prom_catalog.get_or_create_metric_table_name('cpu_total');
 get_or_create_metric_table_name
---------------------------------
 (2,cpu_total,t)
(1 row)

CALL _prom_catalog.finalize_metric_creation();
CALL
INSERT INTO prom_data.cpu_usage
  SELECT timestamptz '2000-01-01 02:03:04'+(interval '1s' * g), 100.1 + g, _prom_catalog.get_or_create_series_id('{"__name__": "cpu_usage", "namespace":"dev", "node": "brain"}')
  FROM generate_series(1,10) g;
INSERT 0 10
INSERT INTO prom_data.cpu_usage
  SELECT timestamptz '2000-01-01 02:03:04'+(interval '1s' * g), 100.1 + g, _prom_catalog.get_or_create_series_id('{"__name__": "cpu_usage", "namespace":"production", "node": "pinky", "new_tag":"foo"}')
  FROM generate_series(1,10) g;
INSERT 0 10
INSERT INTO prom_data.cpu_total
  SELECT timestamptz '2000-01-01 02:03:04'+(interval '1s' * g), 100.0, _prom_catalog.get_or_create_series_id('{"__name__": "cpu_total", "namespace":"dev", "node": "brain"}')
  FROM generate_series(1,10) g;
INSERT 0 10
INSERT INTO prom_data.cpu_total
  SELECT timestamptz '2000-01-01 02:03:04'+(interval '1s' * g), 100.0, _prom_catalog.get_or_create_series_id('{"__name__": "cpu_total", "namespace":"production", "node": "pinky", "new_tag_2":"bar"}')
  FROM generate_series(1,10) g;
INSERT 0 10
SELECT id , metric_name , table_name, retention_period, chunk_interval > interval '7 hour', label_keys, size , compression_ratio, total_chunks, compressed_chunks FROM prom_info.metric ORDER BY id;
 id | metric_name | table_name | retention_period | ?column? |             label_keys              | size  | compression_ratio | total_chunks | compressed_chunks
----+-------------+------------+------------------+----------+-------------------------------------+-------+-------------------+--------------+-------------------
  1 | cpu_usage   | cpu_usage  | 90 days          | t        | {__name__,namespace,new_tag,node}   | 40 kB |                   |            1 |                 0
  2 | cpu_total   | cpu_total  | 90 days          | t        | {__name__,namespace,new_tag_2,node} | 24 kB |                   |            1 |                 0
(2 rows)

SELECT * FROM prom_info.label ORDER BY key;
    key    | value_column_name | id_column_name |        values
-----------+-------------------+----------------+-----------------------
 __name__  | __name__          | __name___id    | {cpu_total,cpu_usage}
 namespace | namespace         | namespace_id   | {dev,production}
 new_tag   | new_tag           | new_tag_id     | {foo}
 new_tag_2 | new_tag_2         | new_tag_2_id   | {bar}
 node      | node              | node_id        | {brain,pinky}
(5 rows)

[JLockerman]

@svenklemm in the output for views.out I'm not sure why it's outputting info_views first, I suspect it's random. (also if you haven't already, you should re-pull the duplicate-trigger-repro it briefly desynchronized.

[NunoFilipeSantos]

@JLockerman do you know if this was fixed int he meantime?

[JLockerman]

@NunoFilipeSantos I haven't heard anything. @cevian Have you guys seen the bug recently, or did we work around it on the promscale end?

[JLockerman]

(the promscale duplicate-trigger-repro branch is still up so the reproduction steps in the original post should still trigger the bug, if it still exists)

[nuljon]

i just received the error trying to make a new continuous aggregation:

ERROR: trigger "ts_cagg_invalidation_trigger" for relation "_hyper_15_14_chunk" already exists SQL state: 42710