Обсуждение: Re: pgsql: Reduce log level of some logical decoding messages from LOG to D
On Wed, Apr 1, 2026 at 2:44 AM Fujii Masao <fujii@postgresql.org> wrote: > Reduce log level of some logical decoding messages from LOG to DEBUG1 Hi, Apologies for not having noticed this thread before the patch was committed, but I have some reservations about this change. I agree that if someone is calling pg_logical_slot_get_changes() regularly, it isn't good to write a LOG message every time. However, I am concerned that this may make problems with regular logical decoding much harder to debug. I see that there was some discussion of adding a GUC to raise the level back up to LOG, but I feel like that wouldn't help much. If something goes wrong, enabling the messages for the future won't tell you what went wrong in the past. I am wondering whether a better approach might be to set the LOG level based on context -- that is, if it's actually logical decoding, log this at LOG, but if it's just someone peeking at a slot or similar, reduce the log level to DEBUG1 or, really, probably more like DEBUG3. Thoughts? -- Robert Haas EDB: http://www.enterprisedb.com
On Fri, Apr 3, 2026 at 4:56 AM Robert Haas <robertmhaas@gmail.com> wrote: > > On Wed, Apr 1, 2026 at 2:44 AM Fujii Masao <fujii@postgresql.org> wrote: > > Reduce log level of some logical decoding messages from LOG to DEBUG1 > > Hi, > > Apologies for not having noticed this thread before the patch was > committed, but I have some reservations about this change. Thanks for sharing your thoughts! > I agree > that if someone is calling pg_logical_slot_get_changes() regularly, it > isn't good to write a LOG message every time. However, I am concerned > that this may make problems with regular logical decoding much harder > to debug. I see that there was some discussion of adding a GUC to > raise the level back up to LOG, but I feel like that wouldn't help > much. Yes, I'm proposing a new GUC, trace_logical_decoding_messages, as discussed in [1]. I was thinking this GUC would be sufficient for this purpose. With this GUC, the messages changed to DEBUG1 by this commit could be output at LOG by default, preserving previous behavior. On the other hand, users who want less noise could then adjust the setting to suppress those messages. This way, it would cover both use cases: those who want LOG-level messages for debugging, and those who prefer to suppress them. But maybe I'm missing something. It would be helpful to understand what issues you see with this approach. > If something goes wrong, enabling the messages for the future > won't tell you what went wrong in the past. I am wondering whether a > better approach might be to set the LOG level based on context -- that > is, if it's actually logical decoding, log this at LOG, but if it's > just someone peeking at a slot or similar, reduce the log level to > DEBUG1 or, really, probably more like DEBUG3. You are suggesting something like that logical walsender and pg_logical_slot_get_changes() should log at LOG, while the slotsync worker should use DEBUG? Sorry, I may be misunderstanding, since the slotsync worker can also use logical decoding mechanism internally. Could you clarify what you have in mind by "peeking at a slot or similar"? Regards, [1] https://postgr.es/m/CAHGQGwFB+hC97SHDpn1vOHHOq9uM5OZZmt50j7v6Z1JUNtH5zQ@mail.gmail.com -- Fujii Masao
On Thu, Apr 2, 2026 at 8:45 PM Fujii Masao <masao.fujii@gmail.com> wrote: > > If something goes wrong, enabling the messages for the future > > won't tell you what went wrong in the past. I am wondering whether a > > better approach might be to set the LOG level based on context -- that > > is, if it's actually logical decoding, log this at LOG, but if it's > > just someone peeking at a slot or similar, reduce the log level to > > DEBUG1 or, really, probably more like DEBUG3. > > You are suggesting something like that logical walsender and > pg_logical_slot_get_changes() should log at LOG, while the slotsync worker > should use DEBUG? Sorry, I may be misunderstanding, since the slotsync worker > can also use logical decoding mechanism internally. Could you clarify what you > have in mind by "peeking at a slot or similar"? No, what I mean is that if someone runs an SQL function from the foreground, they probably don't want that to result in a LOG message, but if background activity results in such a message, the LOG message is probably a good idea. The reasons are: 1. Somebody might run many foreground queries that rely on the logical decoding infrastructure, so logging something every time such a query is executed could produce a lot of log spam. But there shouldn't be so much background logical decoding for this to be an issue. 2. If logical replication is not working, that may be a major issue for the DBA. A problem running pg_logical_slot_get_changes() is likely not as critical (and if it is, they can always lower client_min_messages or log_min_messages for that session only). -- Robert Haas EDB: http://www.enterprisedb.com
On Mon, Apr 6, 2026 at 11:55 PM Robert Haas <robertmhaas@gmail.com> wrote: > > On Thu, Apr 2, 2026 at 8:45 PM Fujii Masao <masao.fujii@gmail.com> wrote: > > > If something goes wrong, enabling the messages for the future > > > won't tell you what went wrong in the past. I am wondering whether a > > > better approach might be to set the LOG level based on context -- that > > > is, if it's actually logical decoding, log this at LOG, but if it's > > > just someone peeking at a slot or similar, reduce the log level to > > > DEBUG1 or, really, probably more like DEBUG3. > > > > You are suggesting something like that logical walsender and > > pg_logical_slot_get_changes() should log at LOG, while the slotsync worker > > should use DEBUG? Sorry, I may be misunderstanding, since the slotsync worker > > can also use logical decoding mechanism internally. Could you clarify what you > > have in mind by "peeking at a slot or similar"? > > No, what I mean is that if someone runs an SQL function from the > foreground, they probably don't want that to result in a LOG message, > but if background activity results in such a message, the LOG message > is probably a good idea. The reasons are: > > 1. Somebody might run many foreground queries that rely on the logical > decoding infrastructure, so logging something every time such a query > is executed could produce a lot of log spam. But there shouldn't be so > much background logical decoding for this to be an issue. > > 2. If logical replication is not working, that may be a major issue > for the DBA. A problem running pg_logical_slot_get_changes() is likely > not as critical (and if it is, they can always lower > client_min_messages or log_min_messages for that session only). This seems similar to Bharath's suggestion in [1]. You can already do this by setting log_min_messages = 'warning,walsender:debug1'. With that setting, DEBUG1 logical decoding messages from walsender are logged at LOG, while backends follow log_min_messages=warning, so logical decoding SQL functions don't emit those DEBUG1 messages. But probably are you suggesting making this behavior the default? If yes, one straightforward approach to implement that would be to log these messages at LOG when AmWalSenderProcess() or AmLogicalSlotSyncWorkerProcess() is true, and at DEBUG1 otherwise. The downside of this approach is that it becomes harder to suppress these messages for walsender or slotsync worker if some users want to do that. For example, raising log_min_messages to FATAL or PANIC would suppress them, but would also hide ERROR messages, which isn't desirable in production. Regards, [1] https://postgr.es/m/CALj2ACX_SSJYKt5od1C2874yeotTO9JewfRY9B=3DYx2daUAMw@mail.gmail.com -- Fujii Masao
On Mon, Apr 6, 2026 at 11:57 AM Fujii Masao <masao.fujii@gmail.com> wrote: > This seems similar to Bharath's suggestion in [1]. Yes, I think it's the same idea. > You can already do this by > setting log_min_messages = 'warning,walsender:debug1'. With that setting, > DEBUG1 logical decoding messages from walsender are logged at LOG, while > backends follow log_min_messages=warning, so logical decoding SQL functions > don't emit those DEBUG1 messages. > > But probably are you suggesting making this behavior the default? If yes, > one straightforward approach to implement that would be to log these messages > at LOG when AmWalSenderProcess() or AmLogicalSlotSyncWorkerProcess() is true, > and at DEBUG1 otherwise. Yeah. > The downside of this approach is that it becomes harder to suppress these > messages for walsender or slotsync worker if some users want to do that. > For example, raising log_min_messages to FATAL or PANIC would suppress them, > but would also hide ERROR messages, which isn't desirable in production. I honestly don't know why anyone would want to do that. If these messages are showing up from background workers often enough to cause a problem, isn't something terribly wrong? It probably means your logical replication connections are constantly getting broken and having to be reestablished. The premise stated in the commit message is that these messages are simply too noisy, and that seems fair to me, because of the possibility of triggering them from SQL. But the idea that these aren't useful to a DBA when troubleshooting actual problems with logical replication seems quite incorrect to me. -- Robert Haas EDB: http://www.enterprisedb.com
On Tue, Apr 7, 2026 at 1:16 AM Robert Haas <robertmhaas@gmail.com> wrote: > > But probably are you suggesting making this behavior the default? If yes, > > one straightforward approach to implement that would be to log these messages > > at LOG when AmWalSenderProcess() or AmLogicalSlotSyncWorkerProcess() is true, > > and at DEBUG1 otherwise. > > Yeah. OK, I've prepared a patch to implement this. Patch attached. It introduces a LogicalDecodingLogLevel() macro to choose the log level based on context, but the name may not be ideal, so suggestions are welcome. > > The downside of this approach is that it becomes harder to suppress these > > messages for walsender or slotsync worker if some users want to do that. > > For example, raising log_min_messages to FATAL or PANIC would suppress them, > > but would also hide ERROR messages, which isn't desirable in production. > > I honestly don't know why anyone would want to do that. If these > messages are showing up from background workers often enough to cause > a problem, isn't something terribly wrong? It probably means your > logical replication connections are constantly getting broken and > having to be reestablished. The premise stated in the commit message > is that these messages are simply too noisy, and that seems fair to > me, because of the possibility of triggering them from SQL. But the > idea that these aren't useful to a DBA when troubleshooting actual > problems with logical replication seems quite incorrect to me. Maybe. One such case is that, due to the issue discussed in [1], the slotsync worker can generate those messages as frequently as every 200 ms. But once that is fixed, it emits them only once per sync cycle, with intervals ranging from MIN_SLOTSYNC_WORKER_NAPTIME_MS (200 ms) to MAX_SLOTSYNC_WORKER_NAPTIME_MS (30 s), which might not generate excessive log volume. At that point, it might be OK if messages from background activity are not easily suppressible. Regards, [1] https://postgr.es/m/CAHGQGwF6zG9Z8ws1yb3hY1VqV-WT7hR0qyXCn2HdbjvZQKufDw@mail.gmail.com -- Fujii Masao
Вложения
On Tue, Apr 7, 2026 at 8:34 AM Fujii Masao <masao.fujii@gmail.com> wrote: > > On Tue, Apr 7, 2026 at 1:16 AM Robert Haas <robertmhaas@gmail.com> wrote: > > > But probably are you suggesting making this behavior the default? If yes, > > > one straightforward approach to implement that would be to log these messages > > > at LOG when AmWalSenderProcess() or AmLogicalSlotSyncWorkerProcess() is true, > > > and at DEBUG1 otherwise. > > > > Yeah. > > OK, I've prepared a patch to implement this. Patch attached. > It introduces a LogicalDecodingLogLevel() macro to choose the log level > based on context, but the name may not be ideal, so suggestions are welcome. > How about adding repack_worker to that check as well? See 28d534e2ae. > > > > The downside of this approach is that it becomes harder to suppress these > > > messages for walsender or slotsync worker if some users want to do that. > > > For example, raising log_min_messages to FATAL or PANIC would suppress them, > > > but would also hide ERROR messages, which isn't desirable in production. > > > > I honestly don't know why anyone would want to do that. If these > > messages are showing up from background workers often enough to cause > > a problem, isn't something terribly wrong? It probably means your > > logical replication connections are constantly getting broken and > > having to be reestablished. The premise stated in the commit message > > is that these messages are simply too noisy, and that seems fair to > > me, because of the possibility of triggering them from SQL. But the > > idea that these aren't useful to a DBA when troubleshooting actual > > problems with logical replication seems quite incorrect to me. > > Maybe. One such case is that, due to the issue discussed in [1], the slotsync > worker can generate those messages as frequently as every 200 ms. But once > that is fixed, it emits them only once per sync cycle, with intervals ranging > from MIN_SLOTSYNC_WORKER_NAPTIME_MS (200 ms) to > MAX_SLOTSYNC_WORKER_NAPTIME_MS (30 s), which might not generate > excessive log volume. At that point, it might be OK if messages from > background activity are not easily suppressible. > Yeah, we need to fix that issue. With Regards, Amit Kapila.
On Tue, Apr 7, 2026 at 8:48 AM Amit Kapila <amit.kapila16@gmail.com> wrote: > > On Tue, Apr 7, 2026 at 8:34 AM Fujii Masao <masao.fujii@gmail.com> wrote: > > > > On Tue, Apr 7, 2026 at 1:16 AM Robert Haas <robertmhaas@gmail.com> wrote: > > > > But probably are you suggesting making this behavior the default? If yes, > > > > one straightforward approach to implement that would be to log these messages > > > > at LOG when AmWalSenderProcess() or AmLogicalSlotSyncWorkerProcess() is true, > > > > and at DEBUG1 otherwise. > > > > > > Yeah. > > > > OK, I've prepared a patch to implement this. Patch attached. > > It introduces a LogicalDecodingLogLevel() macro to choose the log level > > based on context, but the name may not be ideal, so suggestions are welcome. > > > > How about adding repack_worker to that check as well? See 28d534e2ae. > The other possibility is to use AmRegularBackendProcess() to decide the log_level in this case. -- With Regards, Amit Kapila.
On Tue, Apr 7, 2026 at 12:18 PM Amit Kapila <amit.kapila16@gmail.com> wrote: > > On Tue, Apr 7, 2026 at 8:34 AM Fujii Masao <masao.fujii@gmail.com> wrote: > > > > On Tue, Apr 7, 2026 at 1:16 AM Robert Haas <robertmhaas@gmail.com> wrote: > > > > But probably are you suggesting making this behavior the default? If yes, > > > > one straightforward approach to implement that would be to log these messages > > > > at LOG when AmWalSenderProcess() or AmLogicalSlotSyncWorkerProcess() is true, > > > > and at DEBUG1 otherwise. > > > > > > Yeah. > > > > OK, I've prepared a patch to implement this. Patch attached. > > It introduces a LogicalDecodingLogLevel() macro to choose the log level > > based on context, but the name may not be ideal, so suggestions are welcome. > > > > How about adding repack_worker to that check as well? See 28d534e2ae. Thanks for the info! It may be better to use DEBUG1 when AmRegularBackendProcess() is true and LOG otherwise, rather than checking AmWalSenderProcess() or AmLogicalSlotSyncWorkerProcess(). This would also cover any future background processes that use logical decoding. Regards, -- Fujii Masao
On Tue, Apr 7, 2026 at 12:33 PM Amit Kapila <amit.kapila16@gmail.com> wrote: > The other possibility is to use AmRegularBackendProcess() to decide > the log_level in this case. Yes, that makes sense. (I replied the same idea before seeing this message, sorry for the duplication.) Regards, -- Fujii Masao
On Tue, Apr 7, 2026 at 12:54 PM Fujii Masao <masao.fujii@gmail.com> wrote: > > On Tue, Apr 7, 2026 at 12:33 PM Amit Kapila <amit.kapila16@gmail.com> wrote: > > The other possibility is to use AmRegularBackendProcess() to decide > > the log_level in this case. > > Yes, that makes sense. I've updated the patch to use AmRegularBackendProcess(). Patch attached. Regards, -- Fujii Masao
Вложения
On Tue, Apr 7, 2026 at 11:39 AM Fujii Masao <masao.fujii@gmail.com> wrote: > > On Tue, Apr 7, 2026 at 12:54 PM Fujii Masao <masao.fujii@gmail.com> wrote: > > > > On Tue, Apr 7, 2026 at 12:33 PM Amit Kapila <amit.kapila16@gmail.com> wrote: > > > The other possibility is to use AmRegularBackendProcess() to decide > > > the log_level in this case. > > > > Yes, that makes sense. > > I've updated the patch to use AmRegularBackendProcess(). Patch attached. > LGTM. -- With Regards, Amit Kapila.
On Fri, Apr 10, 2026 at 6:55 PM Amit Kapila <amit.kapila16@gmail.com> wrote: > LGTM. Thanks for the review! I've pushed the patch. Regards, -- Fujii Masao
Fujii Masao <masao.fujii@gmail.com> writes:
> Thanks for the review! I've pushed the patch.
de74d1e9a has had a surprising consequence. Coverity has started to
whine like this about each use of ereport(LogicalDecodingLogLevel():
>>> CID 1691470: Integer handling issues (CONSTANT_EXPRESSION_RESULT)
>>> "((MyBackendType == B_BACKEND) ? 14 : 15) >= 21" is always false regardless of the values of its operands. This
occursas the logical second operand of "&&".
1975 ereport(LogicalDecodingLogLevel(),
1976 errmsg("logical decoding found consistent point at %X/%08X",
1977 LSN_FORMAT_ARGS(lsn)),
1978 errdetail("Logical decoding will begin using saved snapshot."));
It's right of course: neither log level is >= ERROR. I don't see
why that would constitute a bug, so this is just useless nannyism
from Coverity. We could dismiss these complaints as false positives,
but the prospect of having to do that repeatedly in future isn't
attractive. I wonder if anyone sees a way to rewrite to dodge
this complaint. The only thing I can think of is to turn
LogicalDecodingLogLevel() into an out-of-line function, which I
think would silence it ... but I might be wrong, and anyway that's
not a very attractive solution either. Anybody have a better idea?
regards, tom lane