public inbox for [email protected]
help / color / mirror / Atom feedFrom: Bharath Rupireddy <[email protected]>
To: Amit Kapila <[email protected]>
Cc: Peter Smith <[email protected]>
Cc: Alvaro Herrera <[email protected]>
Cc: Greg Stark <[email protected]>
Cc: Euler Taveira <[email protected]>
Cc: Kyotaro Horiguchi <[email protected]>
Cc: PostgreSQL Hackers <[email protected]>
Subject: Re: add log messages when replication slots become active and inactive (was Re: Is it worth adding ReplicationSlot active_pid to ReplicationSlotPersistentData?)
Date: Mon, 13 Nov 2023 17:43:13 +0530
Message-ID: <CALj2ACXCCfi_UhFfvDtQbGqyjpf8X+3sBbz0_BsUp0rANuh8Eg@mail.gmail.com> (raw)
In-Reply-To: <CAA4eK1LPe=7Rb0kR8BGuLye2urNfWs=3idmbU3OfV8VTJU9KCg@mail.gmail.com>
References: <CAM-w4HORsLbxwv8KVUHWu1PxKQLuCN1JjAnXknP8pFNSQfbh3A@mail.gmail.com>
<[email protected]>
<CALj2ACVdPMRBKCLd+XXGg+O9y5g1=0CtWs4bp39dX-J=oe=TTg@mail.gmail.com>
<CAA4eK1K=4dcBn2rcPLai76RZAVgMKmk6xAEgu0CT0p=uHa4TXw@mail.gmail.com>
<CAHut+PtP7nZT0DW6GLPi6hebJJpDx-nOr+TmcsY=gsCk1Te6kw@mail.gmail.com>
<CALj2ACWjNSA=1hz0yOcrZbZNLVffZ7A5sPqV7_mMLjtMMs_kxQ@mail.gmail.com>
<CAA4eK1LPe=7Rb0kR8BGuLye2urNfWs=3idmbU3OfV8VTJU9KCg@mail.gmail.com>
On Mon, Nov 6, 2023 at 9:09 AM Amit Kapila <[email protected]> wrote:
>
> On Sun, Nov 5, 2023 at 4:01 AM Bharath Rupireddy
> <[email protected]> wrote:
> >
> > On Thu, Nov 2, 2023 at 7:19 AM Peter Smith <[email protected]> wrote:
> > >
> > > But that's not quite compatible with what Alvaro [2] had written long
> > > back ("... the only acquisitions that would log messages are those in
> > > StartReplication and StartLogicalReplication.").
> > >
> > > In other words, ReplicationSlotAcquire/ReplicationSlotRelease is
> > > called by more places than you care to log from.
> >
> > I refreshed my thoughts for this patch and I think it's enough if
> > walsenders alone log messages when slots become active and inactive.
> > How about something like the attached v11 patch?
> >
>
> + * This function is currently used only in walsender.
> + */
> +void
> +ReplicationSlotAcquireAndLog(const char *name, bool nowait)
>
> BTW, is the reason for using it only in walsender is that it is a
> background process and it is not very apparent whether the slot is
> created, and for foreground processes, it is a bit clear when the
> command is executed.
>
> Can you please tell me the use case of this additional message?
Replication slot acquisitions and releases by backends say when
running pg_replication_slot_advance or pg_logical_slot_get_changes or
pg_drop_replication_slot or pg_create_{physical,
logical}_replication_slot are transient unlike walsenders which
comparatively hold slots for longer durations. Therefore, I've added
them only for walsenders. These messages help to know the lifetime of
a replication slot - one can know how long a streaming standby or
logical subscriber is down, IOW, how long a replication slot is
inactive in production. For instance, the time between released and
acquired slots in the below messages is the inactive replication slot
duration.
2023-11-13 11:06:34.338 UTC [470262] LOG: acquired physical
replication slot "sb_repl_slot"
2023-11-13 11:06:34.338 UTC [470262] STATEMENT: START_REPLICATION
SLOT "sb_repl_slot" 0/3000000 TIMELINE 1
2023-11-13 11:09:24.918 UTC [470262] LOG: released physical
replication slot "sb_repl_slot"
2023-11-13 12:01:40.530 UTC [470967] LOG: acquired physical
replication slot "sb_repl_slot"
2023-11-13 12:01:40.530 UTC [470967] STATEMENT: START_REPLICATION
SLOT "sb_repl_slot" 0/3000000 TIMELINE 1
> If so, the other alternative is to either use a
> parameter to the existing function or directly use am_walsender flag
> to distinguish when to print the message in acquire/release calls.
Done that way. PSA v12.
> A few other minor comments:
> 1.
> + Causes each replication command and related activity to be logged in
> + the server log.
>
> Can we be bit more specific by changing to something like: "Causes
> each replication command and slot acquisition/release to be logged in
> the server log."
Done.
> 2.
> + ereport(log_replication_commands ? LOG : DEBUG1,
> + (errmsg("walsender process with PID %d acquired %s replication slot \"%s\"",
>
> It seems PID and process name is quite unlike what we print in other
> similar messages. For example, see below messages when we start
> replication via pub/sub :
>
> We can get the PID from the log line as for other logs and I don't see
> the process name printed anywhere else.
There was a comment upthread to have PID printed, but I agree to be
consistent and changed the messages to be: acquired physical/logical
replication slot "foo" and released physical/logical replication slot
"foo".
PSA v12 patch.
--
Bharath Rupireddy
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com
Attachments:
[application/octet-stream] v12-0001-Emit-messages-when-replication-slots-become-acti.patch (3.7K, ../CALj2ACXCCfi_UhFfvDtQbGqyjpf8X+3sBbz0_BsUp0rANuh8Eg@mail.gmail.com/2-v12-0001-Emit-messages-when-replication-slots-become-acti.patch)
download | inline diff:
From cd784c50ed0fc928241f109e19f0f5c9afaa01ef Mon Sep 17 00:00:00 2001
From: Bharath Rupireddy <[email protected]>
Date: Mon, 13 Nov 2023 12:04:11 +0000
Subject: [PATCH v12] Emit messages when replication slots become active and
inactive
This commit adds log messages (at LOG level when
log_replication_commands is set, otherwise at DEBUG1 level) when
walsenders acquire and release replication slots. These messages
help to know the lifetime of a replication slot - one can know how
long a streaming standby or logical subscriber or replication slot
consumer is down. In other words, one can know how long a
replication slot is inactive - the time between released and
acquired slot messages is the inactive replication slot duration.
These messages will be extremely useful on production servers to
debug and analyze inactive replication slot issues.
Note that these messages are emitted only for walsenders when
replication slot is acquired and released, but not for backends.
This is because walsenders are the ones that typically hold
replication slots for longer durations unlike backends which hold
replication slots for executing some replication related
functions.
---
doc/src/sgml/config.sgml | 10 +++++-----
src/backend/replication/slot.c | 23 +++++++++++++++++++++++
2 files changed, 28 insertions(+), 5 deletions(-)
diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index fc35a46e5e..1dc014ce84 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -7510,11 +7510,11 @@ log_line_prefix = '%m [%p] %q%u@%d/%a '
</term>
<listitem>
<para>
- Causes each replication command to be logged in the server log.
- See <xref linkend="protocol-replication"/> for more information about
- replication command. The default value is <literal>off</literal>.
- Only superusers and users with the appropriate <literal>SET</literal>
- privilege can change this setting.
+ Causes each replication command and slot acquisition/release to be
+ logged in the server log. See <xref linkend="protocol-replication"/>
+ for more information about replication command. The default value is
+ <literal>off</literal>. Only superusers and users with the appropriate
+ <literal>SET</literal> privilege can change this setting.
</para>
</listitem>
</varlistentry>
diff --git a/src/backend/replication/slot.c b/src/backend/replication/slot.c
index 781aa43cc4..fd8b8151b6 100644
--- a/src/backend/replication/slot.c
+++ b/src/backend/replication/slot.c
@@ -537,6 +537,12 @@ retry:
*/
if (SlotIsLogical(s))
pgstat_acquire_replslot(s);
+
+ if (am_walsender)
+ ereport(log_replication_commands ? LOG : DEBUG1,
+ errmsg_internal("acquired %s replication slot \"%s\"",
+ SlotIsPhysical(MyReplicationSlot) ? "physical" : "logical",
+ NameStr(MyReplicationSlot->data.name)));
}
/*
@@ -549,9 +555,17 @@ void
ReplicationSlotRelease(void)
{
ReplicationSlot *slot = MyReplicationSlot;
+ char *slotname;
+ bool is_physical;
Assert(slot != NULL && slot->active_pid != 0);
+ if (am_walsender)
+ {
+ slotname = pstrdup(NameStr(MyReplicationSlot->data.name));
+ is_physical = SlotIsPhysical(MyReplicationSlot);
+ }
+
if (slot->data.persistency == RS_EPHEMERAL)
{
/*
@@ -596,6 +610,15 @@ ReplicationSlotRelease(void)
MyProc->statusFlags &= ~PROC_IN_LOGICAL_DECODING;
ProcGlobal->statusFlags[MyProc->pgxactoff] = MyProc->statusFlags;
LWLockRelease(ProcArrayLock);
+
+ if (am_walsender)
+ {
+ ereport(log_replication_commands ? LOG : DEBUG1,
+ errmsg_internal("released %s replication slot \"%s\"",
+ is_physical ? "physical" : "logical", slotname));
+
+ pfree(slotname);
+ }
}
/*
--
2.34.1
view thread (9+ 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], [email protected], [email protected], [email protected], [email protected], [email protected]
Subject: Re: add log messages when replication slots become active and inactive (was Re: Is it worth adding ReplicationSlot active_pid to ReplicationSlotPersistentData?)
In-Reply-To: <CALj2ACXCCfi_UhFfvDtQbGqyjpf8X+3sBbz0_BsUp0rANuh8Eg@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