Skip to content

Commit

Permalink
Use more reasonable log level when logging compression progress
Browse files Browse the repository at this point in the history 
Don't use LOG log level when printing out non-actionable progress
information regarding compression.

Fixes #7280
  • Loading branch information
@svenklemm
svenklemm committed Oct 9, 2024
1 parent 7b2b44b commit 8775c84
Show file tree
Hide file tree
Showing 8 changed files with 150 additions and 185 deletions.
2 changes: 2 additions & 0 deletions .unreleased/pr_7335
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,2 @@
Fixes: #7335 Change log level used in compression
Thanks: @gmilamjr for reporting an issue with the log level of compression messages
18 changes: 9 additions & 9 deletions tsl/src/compression/api.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -398,7 +398,7 @@ compress_chunk_impl(Oid hypertable_relid, Oid chunk_relid)
compresschunkcxt_init(&cxt, hcache, hypertable_relid, chunk_relid);

/* acquire locks on src and compress hypertable and src chunk */
ereport(LOG,
ereport(DEBUG1,
(errmsg("acquiring locks for compressing \"%s.%s\"",
get_namespace_name(get_rel_namespace(chunk_relid)),
get_rel_name(chunk_relid))));
Expand All @@ -408,7 +408,7 @@ compress_chunk_impl(Oid hypertable_relid, Oid chunk_relid)

/* acquire locks on catalog tables to keep till end of txn */
LockRelationOid(catalog_get_table_id(ts_catalog_get(), CHUNK), RowExclusiveLock);
ereport(LOG,
ereport(DEBUG1,
(errmsg("locks acquired for compressing \"%s.%s\"",
get_namespace_name(get_rel_namespace(chunk_relid)),
get_rel_name(chunk_relid))));
Expand Down Expand Up @@ -441,7 +441,7 @@ compress_chunk_impl(Oid hypertable_relid, Oid chunk_relid)
/* create compressed chunk and a new table */
compress_ht_chunk = create_compress_chunk(cxt.compress_ht, cxt.srcht_chunk, InvalidOid);
new_compressed_chunk = true;
ereport(LOG,
ereport(DEBUG1,
(errmsg("new compressed chunk \"%s.%s\" created",
NameStr(compress_ht_chunk->fd.schema_name),
NameStr(compress_ht_chunk->fd.table_name))));
Expand All @@ -452,7 +452,7 @@ compress_chunk_impl(Oid hypertable_relid, Oid chunk_relid)
/* use an existing compressed chunk to compress into */
compress_ht_chunk = ts_chunk_get_by_id(mergable_chunk->fd.compressed_chunk_id, true);
result_chunk_id = mergable_chunk->table_id;
ereport(LOG,
ereport(DEBUG1,
(errmsg("merge into existing compressed chunk \"%s.%s\"",
NameStr(compress_ht_chunk->fd.schema_name),
NameStr(compress_ht_chunk->fd.table_name))));
Expand Down Expand Up @@ -590,7 +590,7 @@ decompress_chunk_impl(Chunk *uncompressed_chunk, bool if_compressed)
ts_chunk_validate_chunk_status_for_operation(uncompressed_chunk, CHUNK_DECOMPRESS, true);
compressed_chunk = ts_chunk_get_by_id(uncompressed_chunk->fd.compressed_chunk_id, true);

ereport(LOG,
ereport(DEBUG1,
(errmsg("acquiring locks for decompressing \"%s.%s\"",
NameStr(uncompressed_chunk->fd.schema_name),
NameStr(uncompressed_chunk->fd.table_name))));
Expand All @@ -617,7 +617,7 @@ decompress_chunk_impl(Chunk *uncompressed_chunk, bool if_compressed)

/* acquire locks on catalog tables to keep till end of txn */
LockRelationOid(catalog_get_table_id(ts_catalog_get(), CHUNK), RowExclusiveLock);
ereport(LOG,
ereport(DEBUG1,
(errmsg("locks acquired for decompressing \"%s.%s\"",
NameStr(uncompressed_chunk->fd.schema_name),
NameStr(uncompressed_chunk->fd.table_name))));
Expand Down Expand Up @@ -1152,12 +1152,12 @@ recompress_chunk_segmentwise_impl(Chunk *uncompressed_chunk)
*/
if (ts_chunk_clear_status(uncompressed_chunk,
CHUNK_STATUS_COMPRESSED_UNORDERED | CHUNK_STATUS_COMPRESSED_PARTIAL))
ereport(LOG,
ereport(DEBUG1,
(errmsg("cleared chunk status for recompression: \"%s.%s\"",
NameStr(uncompressed_chunk->fd.schema_name),
NameStr(uncompressed_chunk->fd.table_name))));

ereport(LOG,
ereport(DEBUG1,
(errmsg("acquiring locks for recompression: \"%s.%s\"",
NameStr(uncompressed_chunk->fd.schema_name),
NameStr(uncompressed_chunk->fd.table_name))));
Expand Down Expand Up @@ -1279,7 +1279,7 @@ recompress_chunk_segmentwise_impl(Chunk *uncompressed_chunk)

/* Index scan */
Relation index_rel = index_open(row_compressor.index_oid, ExclusiveLock);
ereport(LOG,
ereport(DEBUG1,
(errmsg("locks acquired for recompression: \"%s.%s\"",
NameStr(uncompressed_chunk->fd.schema_name),
NameStr(uncompressed_chunk->fd.table_name))));
Expand Down
36 changes: 8 additions & 28 deletions tsl/src/compression/compression.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -442,18 +442,7 @@ compress_chunk(Oid in_table, Oid out_table, int insert_options)
{
int64 nrows_processed = 0;

/*
* even though we log the information below, this debug info
* is still used for INFO messages to clients and our tests.
*/
if (ts_guc_debug_compression_path_info)
{
elog(INFO,
"compress_chunk_indexscan_start matched index \"%s\"",
get_rel_name(matched_index_rel->rd_id));
}

elog(LOG,
elog(ts_guc_debug_compression_path_info ? INFO : DEBUG1,
"using index \"%s\" to scan rows for compression",
get_rel_name(matched_index_rel->rd_id));

Expand All @@ -465,7 +454,7 @@ compress_chunk(Oid in_table, Oid out_table, int insert_options)
{
row_compressor_process_ordered_slot(&row_compressor, slot, mycid);
if ((++nrows_processed % report_reltuples) == 0)
elog(LOG,
elog(DEBUG2,
"compressed " INT64_FORMAT " rows from \"%s\"",
nrows_processed,
RelationGetRelationName(in_rel));
Expand All @@ -474,7 +463,7 @@ compress_chunk(Oid in_table, Oid out_table, int insert_options)
if (row_compressor.rows_compressed_into_current_value > 0)
row_compressor_flush(&row_compressor, mycid, true);

elog(LOG,
elog(DEBUG1,
"finished compressing " INT64_FORMAT " rows from \"%s\"",
nrows_processed,
RelationGetRelationName(in_rel));
Expand All @@ -485,16 +474,7 @@ compress_chunk(Oid in_table, Oid out_table, int insert_options)
}
else
{
/*
* even though we log the information below, this debug info
* is still used for INFO messages to clients and our tests.
*/
if (ts_guc_debug_compression_path_info)
{
elog(INFO, "compress_chunk_tuplesort_start");
}

elog(LOG,
elog(ts_guc_debug_compression_path_info ? INFO : DEBUG1,
"using tuplesort to scan rows from \"%s\" for compression",
RelationGetRelationName(in_rel));

Expand Down Expand Up @@ -862,15 +842,15 @@ row_compressor_append_sorted_rows(RowCompressor *row_compressor, Tuplesortstate
{
row_compressor_process_ordered_slot(row_compressor, slot, mycid);
if ((++nrows_processed % report_reltuples) == 0)
elog(LOG,
elog(DEBUG2,
"compressed " INT64_FORMAT " rows from \"%s\"",
nrows_processed,
RelationGetRelationName(in_rel));
}

if (row_compressor->rows_compressed_into_current_value > 0)
row_compressor_flush(row_compressor, mycid, true);
elog(LOG,
elog(DEBUG1,
"finished compressing " INT64_FORMAT " rows from \"%s\"",
nrows_processed,
RelationGetRelationName(in_rel));
Expand Down Expand Up @@ -1330,13 +1310,13 @@ decompress_chunk(Oid in_table, Oid out_table)
row_decompressor_decompress_row_to_table(&decompressor);

if ((++nrows_processed % report_reltuples) == 0)
elog(LOG,
elog(DEBUG2,
"decompressed " INT64_FORMAT " rows from \"%s\"",
nrows_processed,
RelationGetRelationName(in_rel));
}

elog(LOG,
elog(DEBUG1,
"finished decompressing " INT64_FORMAT " rows from \"%s\"",
nrows_processed,
RelationGetRelationName(in_rel));
Expand Down
5 changes: 0 additions & 5 deletions tsl/test/expected/compression_bgw.out
View file
Original file line number Diff line number Diff line change
Expand Up @@ -351,11 +351,6 @@ SELECT alter_job(id,config:=jsonb_set(config,'{verbose_log}', 'true'))
set client_min_messages TO LOG;
CALL run_job(:job_id);
LOG: statement: CALL run_job(1004);
LOG: acquiring locks for compressing "_timescaledb_internal._hyper_11_40_chunk"
LOG: locks acquired for compressing "_timescaledb_internal._hyper_11_40_chunk"
LOG: new compressed chunk "_timescaledb_internal.compress_hyper_13_61_chunk" created
LOG: using tuplesort to scan rows from "_hyper_11_40_chunk" for compression
LOG: finished compressing 144 rows from "_hyper_11_40_chunk"
LOG: job 1004 completed processing chunk _timescaledb_internal._hyper_11_40_chunk
set client_min_messages TO NOTICE;
LOG: statement: set client_min_messages TO NOTICE;
Expand Down
14 changes: 7 additions & 7 deletions tsl/test/expected/compression_conflicts.out
View file
Original file line number Diff line number Diff line change
Expand Up @@ -37,7 +37,7 @@ INSERT INTO comp_conflicts_1 VALUES
ROLLBACK;
SELECT compress_chunk(c) AS "CHUNK" FROM show_chunks('comp_conflicts_1') c
\gset
INFO: compress_chunk_tuplesort_start
INFO: using tuplesort to scan rows from "_hyper_1_1_chunk" for compression
-- after compression no data should be in uncompressed chunk
SELECT count(*) FROM ONLY :CHUNK;
count
Expand Down Expand Up @@ -123,7 +123,7 @@ INSERT INTO comp_conflicts_2 VALUES ('2020-01-01','d1',0.1);
INSERT INTO comp_conflicts_2 VALUES ('2020-01-01','d2',0.2);
SELECT compress_chunk(c) AS "CHUNK" FROM show_chunks('comp_conflicts_2') c
\gset
INFO: compress_chunk_tuplesort_start
INFO: using tuplesort to scan rows from "_hyper_3_3_chunk" for compression
-- after compression no data should be in uncompressed chunk
SELECT count(*) FROM ONLY :CHUNK;
count
Expand Down Expand Up @@ -212,7 +212,7 @@ INSERT INTO comp_conflicts_3 VALUES ('2020-01-01','d2', 'label', 0.2);
INSERT INTO comp_conflicts_3 VALUES ('2020-01-01',NULL, 'label', 0.3);
SELECT compress_chunk(c) AS "CHUNK" FROM show_chunks('comp_conflicts_3') c
\gset
INFO: compress_chunk_tuplesort_start
INFO: using tuplesort to scan rows from "_hyper_5_5_chunk" for compression
-- after compression no data should be in uncompressed chunk
SELECT count(*) FROM ONLY :CHUNK;
count
Expand Down Expand Up @@ -465,7 +465,7 @@ INSERT INTO comp_conflicts_4 VALUES ('2020-01-01','d2',0.2);
INSERT INTO comp_conflicts_4 VALUES ('2020-01-01',NULL,0.3);
SELECT compress_chunk(c) AS "CHUNK" FROM show_chunks('comp_conflicts_4') c
\gset
INFO: compress_chunk_tuplesort_start
INFO: using tuplesort to scan rows from "_hyper_7_7_chunk" for compression
-- after compression no data should be in uncompressed chunk
SELECT count(*) FROM ONLY :CHUNK;
count
Expand Down Expand Up @@ -611,9 +611,9 @@ ALTER TABLE compressed_ht SET (
);
NOTICE: default order by for hypertable "compressed_ht" is set to ""time" DESC"
SELECT COMPRESS_CHUNK(SHOW_CHUNKS('compressed_ht'));
INFO: compress_chunk_tuplesort_start
INFO: compress_chunk_tuplesort_start
INFO: compress_chunk_tuplesort_start
INFO: using tuplesort to scan rows from "_hyper_9_9_chunk" for compression
INFO: using tuplesort to scan rows from "_hyper_9_10_chunk" for compression
INFO: using tuplesort to scan rows from "_hyper_9_11_chunk" for compression
compress_chunk
-----------------------------------------
_timescaledb_internal._hyper_9_9_chunk
Expand Down
Loading

0 comments on commit 8775c84

Please sign in to comment.