Reduce log level of some logical decoding messages to DEBUG1

Started by Fujii Masao22 days ago10 messageshackers
Jump to latest
#1Fujii Masao
masao.fujii@gmail.com

Hi,

In logical decoding, messages like the following are currently logged at
LOG level:

LOG: starting logical decoding for slot "myslot"
DETAIL: Streaming transactions committing after 0/030872C0,
reading WAL from 0/03087288.
STATEMENT: ...
LOG: logical decoding found consistent point at 0/03087288
DETAIL: There are no running transactions.
STATEMENT: ...

These can be useful for debugging, but DBAs are typically not interested in
them. They can also be emitted frequently, for example, on each call to
functions like pg_logical_slot_peek_binary_changes() or
pg_replication_slot_advance() etc. When such functions are called repeatedly,
the logs can quickly become noisy.

The slotsync worker can also generate these messages periodically. Due to
the issue discussed at [1]/messages/by-id/CAHGQGwF6zG9Z8ws1yb3hY1VqV-WT7hR0qyXCn2HdbjvZQKufDw@mail.gmail.com, this can currently happen as often as every 200ms
(which should be fixed separately). Even without that issue, these messages
would be still emitted regularly.

Given that these are mostly developer-oriented messages, logging them at
LOG level seems too verbose. I'm proposing to reduce their level to DEBUG1.
A patch is attached.

Alternatively, if we want to keep them at LOG by default, we could introduce
a GUC like trace_logical_decoding_messages, similar to
the old trace_recovery_messages, to control their verbosity independently
of log_min_messages.

Thought?

This topic came up in [1]/messages/by-id/CAHGQGwF6zG9Z8ws1yb3hY1VqV-WT7hR0qyXCn2HdbjvZQKufDw@mail.gmail.com and [2]/messages/by-id/CAHGQGwED5kJxZ_MdCh=WLa5M7ekXdnzCO1ZCQhQNCEdfaEPwFQ@mail.gmail.com, and Amit suggested discussing it separately,
so I started this thread.

Regards,

[1]: /messages/by-id/CAHGQGwF6zG9Z8ws1yb3hY1VqV-WT7hR0qyXCn2HdbjvZQKufDw@mail.gmail.com
[2]: /messages/by-id/CAHGQGwED5kJxZ_MdCh=WLa5M7ekXdnzCO1ZCQhQNCEdfaEPwFQ@mail.gmail.com

--
Fujii Masao

Attachments:

v1-0001-Reduce-log-level-of-some-logical-decoding-message.patchapplication/octet-stream; name=v1-0001-Reduce-log-level-of-some-logical-decoding-message.patchDownload+5-5
#2Bharath Rupireddy
bharath.rupireddyforpostgres@gmail.com
In reply to: Fujii Masao (#1)
Re: Reduce log level of some logical decoding messages to DEBUG1

Hi,

On Mon, Mar 23, 2026 at 1:23 AM Fujii Masao <masao.fujii@gmail.com> wrote:

In logical decoding, messages like the following are currently logged at
LOG level:

LOG: starting logical decoding for slot "myslot"
DETAIL: Streaming transactions committing after 0/030872C0,
reading WAL from 0/03087288.
STATEMENT: ...
LOG: logical decoding found consistent point at 0/03087288
DETAIL: There are no running transactions.
STATEMENT: ...

These can be useful for debugging, but DBAs are typically not interested in
them. They can also be emitted frequently, for example, on each call to
functions like pg_logical_slot_peek_binary_changes() or
pg_replication_slot_advance() etc. When such functions are called repeatedly,
the logs can quickly become noisy.

I understand the chattiness of these when the decoding is done using
functions. But they seem to be useful when decoding using walsender
and replication connection. Also, it looks to me that the errdetail
describing various cases like when there are no running transactions,
when logical decoding will begin using saved snapshot, etc., is
helpful.

The slotsync worker can also generate these messages periodically. Due to
the issue discussed at [1], this can currently happen as often as every 200ms
(which should be fixed separately). Even without that issue, these messages
would be still emitted regularly.

Given that these are mostly developer-oriented messages, logging them at
LOG level seems too verbose. I'm proposing to reduce their level to DEBUG1.
A patch is attached.

Alternatively, if we want to keep them at LOG by default, we could introduce
a GUC like trace_logical_decoding_messages, similar to
the old trace_recovery_messages, to control their verbosity independently
of log_min_messages.

Thought?

1 for another GUC IMHO. How about we find if the logical decoding is
being done using walsender (a boolean like isDecodingUsingWalSender,
default being false, set to true when in walsender) and emit them at
LOG level when set to true. Would something like this work?

--
Bharath Rupireddy
Amazon Web Services: https://aws.amazon.com

#3Fujii Masao
masao.fujii@gmail.com
In reply to: Bharath Rupireddy (#2)
Re: Reduce log level of some logical decoding messages to DEBUG1

On Mon, Mar 23, 2026 at 10:53 PM Bharath Rupireddy
<bharath.rupireddyforpostgres@gmail.com> wrote:

Hi,

On Mon, Mar 23, 2026 at 1:23 AM Fujii Masao <masao.fujii@gmail.com> wrote:

In logical decoding, messages like the following are currently logged at
LOG level:

LOG: starting logical decoding for slot "myslot"
DETAIL: Streaming transactions committing after 0/030872C0,
reading WAL from 0/03087288.
STATEMENT: ...
LOG: logical decoding found consistent point at 0/03087288
DETAIL: There are no running transactions.
STATEMENT: ...

These can be useful for debugging, but DBAs are typically not interested in
them. They can also be emitted frequently, for example, on each call to
functions like pg_logical_slot_peek_binary_changes() or
pg_replication_slot_advance() etc. When such functions are called repeatedly,
the logs can quickly become noisy.

I understand the chattiness of these when the decoding is done using
functions. But they seem to be useful when decoding using walsender
and replication connection. Also, it looks to me that the errdetail
describing various cases like when there are no running transactions,
when logical decoding will begin using saved snapshot, etc., is
helpful.

I agree those messages are useful for developers. Do you think they're also
useful for DBAs, and therefore should remain at LOG level?

The slotsync worker can also generate these messages periodically. Due to
the issue discussed at [1], this can currently happen as often as every 200ms
(which should be fixed separately). Even without that issue, these messages
would be still emitted regularly.

Given that these are mostly developer-oriented messages, logging them at
LOG level seems too verbose. I'm proposing to reduce their level to DEBUG1.
A patch is attached.

Alternatively, if we want to keep them at LOG by default, we could introduce
a GUC like trace_logical_decoding_messages, similar to
the old trace_recovery_messages, to control their verbosity independently
of log_min_messages.

Thought?

1 for another GUC IMHO. How about we find if the logical decoding is
being done using walsender (a boolean like isDecodingUsingWalSender,
default being false, set to true when in walsender) and emit them at
LOG level when set to true. Would something like this work?

If we want to see those messages when walsender is performing logical
decoding, that should still be possible even if we lower the level to DEBUG1.
With the recent extension to log_min_messages (commit 38e0190ced7),
we can enable them just for walsender
(e.g., log_min_messages = 'warning,walsender:debug1').

Regards,

--
Fujii Masao

#4Bharath Rupireddy
bharath.rupireddyforpostgres@gmail.com
In reply to: Fujii Masao (#3)
Re: Reduce log level of some logical decoding messages to DEBUG1

Hi,

On Mon, Mar 23, 2026 at 8:44 AM Fujii Masao <masao.fujii@gmail.com> wrote:

I understand the chattiness of these when the decoding is done using
functions. But they seem to be useful when decoding using walsender
and replication connection. Also, it looks to me that the errdetail
describing various cases like when there are no running transactions,
when logical decoding will begin using saved snapshot, etc., is
helpful.

I agree those messages are useful for developers. Do you think they're also
useful for DBAs, and therefore should remain at LOG level?

- 1 for another GUC IMHO. How about we find if the logical decoding is
being done using walsender (a boolean like isDecodingUsingWalSender,
default being false, set to true when in walsender) and emit them at
LOG level when set to true. Would something like this work?

If we want to see those messages when walsender is performing logical
decoding, that should still be possible even if we lower the level to DEBUG1.
With the recent extension to log_min_messages (commit 38e0190ced7),
we can enable them just for walsender
(e.g., log_min_messages = 'warning,walsender:debug1').

I agree with this. One could use the new log_min_messages feature
introduced in PG19 if wanted. Perhaps, it's a good idea to add this
recommendation to the commit message to help those wanting to enable
these logs.

I reviewed the v1 patch and it LGTM. Thanks!

--
Bharath Rupireddy
Amazon Web Services: https://aws.amazon.com

#5Fujii Masao
masao.fujii@gmail.com
In reply to: Fujii Masao (#3)
Re: Reduce log level of some logical decoding messages to DEBUG1

On Tue, Mar 24, 2026 at 12:44 AM Fujii Masao <masao.fujii@gmail.com> wrote:

Alternatively, if we want to keep them at LOG by default, we could introduce
a GUC like trace_logical_decoding_messages, similar to
the old trace_recovery_messages, to control their verbosity independently
of log_min_messages.

Just in case where many users still want to see those log messages at LOG level,
I also created a second patch (0002) that introduces a new GUC,
trace_logical_decoding_messages, to control logging of logical
decoding debug messages (e.g., "logical decoding found consistent point").

With the default setting (DEBUG1 for now), these messages are effectively
logged at LOG level. Setting it to LOG suppresses them unless permitted
by log_min_messages.

At the moment, this parameter affects only a small set of messages
(about five). We can consider extending it to cover more logical
decoding messages later.

Regards,

--
Fujii Masao

Attachments:

v2-0001-Reduce-log-level-of-some-logical-decoding-message.patchapplication/octet-stream; name=v2-0001-Reduce-log-level-of-some-logical-decoding-message.patchDownload+5-5
v2-0002-Add-trace_logical_decoding_messages-GUC-to-contro.patchapplication/octet-stream; name=v2-0002-Add-trace_logical_decoding_messages-GUC-to-contro.patchDownload+69-6
#6Fujii Masao
masao.fujii@gmail.com
In reply to: Bharath Rupireddy (#4)
Re: Reduce log level of some logical decoding messages to DEBUG1

On Wed, Mar 25, 2026 at 12:10 PM Bharath Rupireddy
<bharath.rupireddyforpostgres@gmail.com> wrote:

I agree with this. One could use the new log_min_messages feature
introduced in PG19 if wanted. Perhaps, it's a good idea to add this
recommendation to the commit message to help those wanting to enable
these logs.

OK, I will do that later.

I reviewed the v1 patch and it LGTM. Thanks!

Thanks for the review!

Regards,

--
Fujii Masao

#7Bharath Rupireddy
bharath.rupireddyforpostgres@gmail.com
In reply to: Fujii Masao (#5)
Re: Reduce log level of some logical decoding messages to DEBUG1

Hi,

On Tue, Mar 24, 2026 at 8:15 PM Fujii Masao <masao.fujii@gmail.com> wrote:

On Tue, Mar 24, 2026 at 12:44 AM Fujii Masao <masao.fujii@gmail.com> wrote:

Alternatively, if we want to keep them at LOG by default, we could introduce
a GUC like trace_logical_decoding_messages, similar to
the old trace_recovery_messages, to control their verbosity independently
of log_min_messages.

Just in case where many users still want to see those log messages at LOG level,
I also created a second patch (0002) that introduces a new GUC,
trace_logical_decoding_messages, to control logging of logical
decoding debug messages (e.g., "logical decoding found consistent point").

-1 for another GUC. If needed, we could explore using
log_replication_commands, but I'm okay with your other suggestion on
using the new feature with log_min_messages. Perhaps, we could wait
for some time to hear from others.

--
Bharath Rupireddy
Amazon Web Services: https://aws.amazon.com

#8Fujii Masao
masao.fujii@gmail.com
In reply to: Bharath Rupireddy (#7)
Re: Reduce log level of some logical decoding messages to DEBUG1

On Wed, Mar 25, 2026 at 12:28 PM Bharath Rupireddy
<bharath.rupireddyforpostgres@gmail.com> wrote:

Hi,

On Tue, Mar 24, 2026 at 8:15 PM Fujii Masao <masao.fujii@gmail.com> wrote:

On Tue, Mar 24, 2026 at 12:44 AM Fujii Masao <masao.fujii@gmail.com> wrote:

Alternatively, if we want to keep them at LOG by default, we could introduce
a GUC like trace_logical_decoding_messages, similar to
the old trace_recovery_messages, to control their verbosity independently
of log_min_messages.

Just in case where many users still want to see those log messages at LOG level,
I also created a second patch (0002) that introduces a new GUC,
trace_logical_decoding_messages, to control logging of logical
decoding debug messages (e.g., "logical decoding found consistent point").

-1 for another GUC. If needed, we could explore using
log_replication_commands, but I'm okay with your other suggestion on
using the new feature with log_min_messages.

I'd prefer this approach.

Perhaps, we could wait
for some time to hear from others.

+1.

If there are no further comments in the next few days, and given the limited
time before feature freeze, I'm inclined to at least apply the 0001 patch
(which simply lowers the log level to DEBUG1).

Regards,

--
Fujii Masao

#9Fujii Masao
masao.fujii@gmail.com
In reply to: Fujii Masao (#8)
Re: Reduce log level of some logical decoding messages to DEBUG1

On Wed, Mar 25, 2026 at 2:54 PM Fujii Masao <masao.fujii@gmail.com> wrote:

Perhaps, we could wait
for some time to hear from others.

+1.

If there are no further comments in the next few days, and given the limited
time before feature freeze, I'm inclined to at least apply the 0001 patch
(which simply lowers the log level to DEBUG1).

Since there were no objections for about a week, I've pushed the 0001
patch. Thanks!

If any issues or concerns are raised, let's consider applying the 0002 patch!

Regards,

--
Fujii Masao

#10Chao Li
li.evan.chao@gmail.com
In reply to: Fujii Masao (#9)
Re: Reduce log level of some logical decoding messages to DEBUG1

On Apr 1, 2026, at 14:48, Fujii Masao <masao.fujii@gmail.com> wrote:

On Wed, Mar 25, 2026 at 2:54 PM Fujii Masao <masao.fujii@gmail.com> wrote:

Perhaps, we could wait
for some time to hear from others.

+1.

If there are no further comments in the next few days, and given the limited
time before feature freeze, I'm inclined to at least apply the 0001 patch
(which simply lowers the log level to DEBUG1).

Since there were no objections for about a week, I've pushed the 0001
patch. Thanks!

If any issues or concerns are raised, let's consider applying the 0002 patch!

Regards,

--
Fujii Masao

TBH, I’m not quite sure what practical benefit this patch set provides.

In 0001, some messages are changed from LOG to DEBUG1. But then 0002 introduces trace_logical_decoding_messages, whose default is DEBUG1, so with the default setting those messages are effectively promoted back to LOG again. That seems to cancel out the behavior change from 0001 by default.

Also, looking at where trace_logical_decoding() is applied in 0002, all the call sites currently pass DEBUG1. So in practice, if a user sets trace_logical_decoding_messages to anything higher than DEBUG1, all of those messages disappear. That makes it feel more like an on/off switch than a mechanism for filtering messages by level.

So at least to me, the overall value of this patch is still not very clear.

Best regards,
--
Chao Li (Evan)
HighGo Software Co., Ltd.
https://www.highgo.com/