public inbox for [email protected]
help / color / mirror / Atom feedFrom: Fujii Masao <[email protected]>
To: Robert Haas <[email protected]>
Cc: PostgreSQL Hackers <[email protected]>
Subject: Re: pgsql: Reduce log level of some logical decoding messages from LOG to D
Date: Tue, 7 Apr 2026 12:04:12 +0900
Message-ID: <CAHGQGwFf+cpgw3T=NsGF8cxm4zx74AMCdajDda2Z7OXq9YM1mQ@mail.gmail.com> (raw)
In-Reply-To: <CA+TgmoZ2+HQess2QSuZp1si17CDHw165PQROaFq0skcKJS20-g@mail.gmail.com>
References: <[email protected]>
<CA+TgmoYsu2+YAo9eLGkDp5VP-pfQ-jOoX382vS4THKHeRTNgew@mail.gmail.com>
<CAHGQGwEhtaT6qe5fN--t6HhTwBvBoZUukx-NVPpEMG9uFWHHvw@mail.gmail.com>
<CA+TgmoYwebE37qZwcNE9MKT4rt3ymP2s1M6KyRK_MGkxCYZMeg@mail.gmail.com>
<CAHGQGwFARNb_2J1Skvw5RQSsyhqUqWQgQJNDhP+v-7fzinLfOw@mail.gmail.com>
<CA+TgmoZ2+HQess2QSuZp1si17CDHw165PQROaFq0skcKJS20-g@mail.gmail.com>
On Tue, Apr 7, 2026 at 1:16 AM Robert Haas <[email protected]> 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
Attachments:
[application/octet-stream] v1-0001-Adjust-log-level-of-logical-decoding-messages-by-.patch (4.8K, 2-v1-0001-Adjust-log-level-of-logical-decoding-messages-by-.patch)
download | inline diff:
From fbcad31a5d187cb044b46e1b00b24b69adf6e5e5 Mon Sep 17 00:00:00 2001
From: Fujii Masao <[email protected]>
Date: Tue, 7 Apr 2026 10:11:22 +0900
Subject: [PATCH v1] Adjust log level of logical decoding messages by context
Commit 21b018e7eab lowered some logical decoding messages from LOG to DEBUG1.
However, per discussion on pgsql-hackers, messages from background activity
(walsender or slotsync worker) should remain at LOG, as they are less frequent
and more likely to indicate issues that DBAs should notice.
For foreground SQL functions (e.g., pg_logical_slot_peek_binary_changes()),
keep these messages at DEBUG1 to avoid excessive log noise. They can still be
enabled by lowering client_min_messages or log_min_messages for the session.
This commit updates logical decoding to log these messages at LOG for
background activity and at DEBUG1 for foreground execution.
---
src/backend/replication/logical/logical.c | 2 +-
src/backend/replication/logical/snapbuild.c | 6 +++---
src/include/replication/logical.h | 18 ++++++++++++++++++
.../t/038_save_logical_slots_shutdown.pl | 1 -
4 files changed, 22 insertions(+), 5 deletions(-)
diff --git a/src/backend/replication/logical/logical.c b/src/backend/replication/logical/logical.c
index f20d0c542f3..5c92fba2f53 100644
--- a/src/backend/replication/logical/logical.c
+++ b/src/backend/replication/logical/logical.c
@@ -598,7 +598,7 @@ CreateDecodingContext(XLogRecPtr start_lsn,
ctx->reorder->output_rewrites = ctx->options.receive_rewrites;
- ereport(DEBUG1,
+ ereport(LogicalDecodingLogLevel(),
(errmsg("starting logical decoding for slot \"%s\"",
NameStr(slot->data.name)),
errdetail("Streaming transactions committing after %X/%08X, reading WAL from %X/%08X.",
diff --git a/src/backend/replication/logical/snapbuild.c b/src/backend/replication/logical/snapbuild.c
index b4269a3b102..192b1560369 100644
--- a/src/backend/replication/logical/snapbuild.c
+++ b/src/backend/replication/logical/snapbuild.c
@@ -1312,7 +1312,7 @@ SnapBuildFindSnapshot(SnapBuild *builder, XLogRecPtr lsn, xl_running_xacts *runn
builder->state = SNAPBUILD_CONSISTENT;
builder->next_phase_at = InvalidTransactionId;
- ereport(DEBUG1,
+ ereport(LogicalDecodingLogLevel(),
errmsg("logical decoding found consistent point at %X/%08X",
LSN_FORMAT_ARGS(lsn)),
errdetail("There are no running transactions."));
@@ -1409,7 +1409,7 @@ SnapBuildFindSnapshot(SnapBuild *builder, XLogRecPtr lsn, xl_running_xacts *runn
builder->state = SNAPBUILD_CONSISTENT;
builder->next_phase_at = InvalidTransactionId;
- ereport(DEBUG1,
+ ereport(LogicalDecodingLogLevel(),
errmsg("logical decoding found consistent point at %X/%08X",
LSN_FORMAT_ARGS(lsn)),
errdetail("There are no old transactions anymore."));
@@ -1915,7 +1915,7 @@ SnapBuildRestore(SnapBuild *builder, XLogRecPtr lsn)
Assert(builder->state == SNAPBUILD_CONSISTENT);
- ereport(DEBUG1,
+ ereport(LogicalDecodingLogLevel(),
errmsg("logical decoding found consistent point at %X/%08X",
LSN_FORMAT_ARGS(lsn)),
errdetail("Logical decoding will begin using saved snapshot."));
diff --git a/src/include/replication/logical.h b/src/include/replication/logical.h
index bc9d4ece672..abf64bdc9d4 100644
--- a/src/include/replication/logical.h
+++ b/src/include/replication/logical.h
@@ -153,4 +153,22 @@ extern XLogRecPtr LogicalReplicationSlotCheckPendingWal(XLogRecPtr end_of_wal,
extern XLogRecPtr LogicalSlotAdvanceAndCheckSnapState(XLogRecPtr moveto,
bool *found_consistent_snapshot);
+
+/*
+ * This macro determines the log level for messages about starting logical
+ * decoding and finding a consistent point.
+ *
+ * When logical decoding is triggered by a foreground SQL function (e.g.,
+ * pg_logical_slot_peek_binary_changes()), these messages are logged at DEBUG1
+ * to avoid excessive log noise. This is acceptable since such issues are
+ * typically less critical, and the messages can still be enabled by lowering
+ * client_min_messages or log_min_messages for the session.
+ *
+ * When the messages originate from background activity (walsender or
+ * slotsync worker), they are logged at LOG, as these events are less frequent
+ * and more likely to indicate issues that DBAs should notice by default.
+ */
+#define LogicalDecodingLogLevel() \
+ ((AmWalSenderProcess() || AmLogicalSlotSyncWorkerProcess()) ? LOG : DEBUG1)
+
#endif
diff --git a/src/test/recovery/t/038_save_logical_slots_shutdown.pl b/src/test/recovery/t/038_save_logical_slots_shutdown.pl
index 05aa78b4bc7..c0392d50460 100644
--- a/src/test/recovery/t/038_save_logical_slots_shutdown.pl
+++ b/src/test/recovery/t/038_save_logical_slots_shutdown.pl
@@ -48,7 +48,6 @@ $node_publisher->append_conf(
'postgresql.conf', q{
checkpoint_timeout = 1h
autovacuum = off
-log_min_messages = 'debug1'
});
$node_publisher->start;
--
2.51.2
view thread (15+ messages) latest in thread
reply
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: [email protected]
Cc: [email protected], [email protected], [email protected]
Subject: Re: pgsql: Reduce log level of some logical decoding messages from LOG to D
In-Reply-To: <CAHGQGwFf+cpgw3T=NsGF8cxm4zx74AMCdajDda2Z7OXq9YM1mQ@mail.gmail.com>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox