Add database info to TimescaleDB background worker logs

[dnk8n]

What type of bug is this?

Configuration

What subsystems and features are affected?

Other

What happened?

I have many DBs, each with timescale installed. But logging is central, so it is very useful to include which database in the log lines. This works well using log_line_prefix and produces logs like:

2024-11-03 00:14:12.147 UTC [3375277] user_123@database_456 WARNING: there is already a transaction in progress

However this is not the case for background jobs. I miss the context of errors that might happen due to compression jobs for example.

Right now, I don't have any failures (which would be more interesting) but here is the start of a compression job for some context). I have no idea which database it applies to:

2024-11-03 00:14:09.843 UTC [3602182] DEBUG:  launching job 1000 "Compression Policy [1000]"
2024-11-03 00:14:09.853 UTC [3395848] DEBUG:  Executing policy_compression with parameters {"hypertable_id": 1, "compress_after": "3 days"}
2024-11-03 00:14:09.856 UTC [3395848] DEBUG:  rehashing catalog cache id 35 for pg_namespace; 9 tups, 4 buckets
2024-11-03 00:14:09.856 UTC [3395848] CONTEXT:  compilation of PL/pgSQL function "policy_compression" near line 1
2024-11-03 00:14:09.884 UTC [3395848] DEBUG:  rehashing catalog cache id 54 for pg_class; 257 tups, 128 buckets
2024-11-03 00:14:09.884 UTC [3395848] CONTEXT:  PL/pgSQL function _timescaledb_functions.policy_compression_execute(integer,integer,anyelement,integer,boolean,boolean,boolean) line 42 at FOR over SELECT rows
        SQL statement "CALL _timescaledb_functions.policy_compression_execute(
                job_id, htid, lag_value::INTERVAL,
                maxchunks, verbose_log, recompress_enabled, use_creation_time
              )"
        PL/pgSQL function _timescaledb_functions.policy_compression(integer,jsonb) line 60 at CALL
2024-11-03 00:14:09.887 UTC [3395848] DEBUG:  rehashing catalog cache id 55 for pg_class; 257 tups, 128 buckets

...

TimescaleDB version affected

2.13.1

PostgreSQL version used

15.4

What operating system did you use?

Ubuntu 22.04.3 LTS x64

What installation method did you use?

Deb/Apt

What platform did you run on?

Amazon Web Services (AWS)

Relevant log output and stack trace

No response

How can we reproduce the bug?

set for example: `log_line_prefix = '%m [%p] %q%u@%d '`
It applies only to application queries. Timescale background workers do not honor it.

[akuzm]

That's a general Postgres thing, %d means current database for interactive backends (ones that handle a user session). Background workers are not that, so %d for them is always empty.

We could improve the logging though by adding the DB name to the description of the job that is being started, or something like this.

[dnk8n]

Oh so @akuzm , if I understand correctly, this is not really a bug but a feature enhancement (edit: just noticed the labels edited, so that answers this question)?

Currently there is no existing way to have the database context of background tasks in logs?