public inbox for [email protected]
help / color / mirror / Atom feedRe: add log messages when replication slots become active and inactive (was Re: Is it worth adding ReplicationSlot active_pid to ReplicationSlotPersistentData?)
3+ messages / 3 participants
[nested] [flat]
* Re: add log messages when replication slots become active and inactive (was Re: Is it worth adding ReplicationSlot active_pid to ReplicationSlotPersistentData?)
@ 2023-03-24 03:25 Bharath Rupireddy <[email protected]>
2023-03-24 03:52 ` Re: add log messages when replication slots become active and inactive (was Re: Is it worth adding ReplicationSlot active_pid to ReplicationSlotPersistentData?) Greg Stark <[email protected]>
0 siblings, 1 reply; 3+ messages in thread
From: Bharath Rupireddy @ 2023-03-24 03:25 UTC (permalink / raw)
To: Euler Taveira <[email protected]>; +Cc: Alvaro Herrera <[email protected]>; Amit Kapila <[email protected]>; Kyotaro Horiguchi <[email protected]>; PostgreSQL Hackers <[email protected]>
On Fri, Mar 24, 2023 at 3:11 AM Euler Taveira <[email protected]> wrote:
>
> If you are adding separate functions as suggested, you should add a comment at
> the top of ReplicationSlotAcquire() and ReplicationSlotRelease() functions
> saying that LogReplicationSlotAquired() and LogReplicationSlotReleased()
> functions should be called respectively after it.
Done.
> My suggestion is that the functions should have the same name with a "Log"
> prefix. On of them has a typo "Aquired" in its name. Hence,
> LogReplicationSlotAcquire() and LogReplicationSlotRelease() as names. It is
> easier to find if someone is grepping by the origin function.
Done.
> I prefer a sentence that includes a verb.
>
> physical replication slot \"%s\" is acquired
> logical replication slot \"%s\" is released
Hm, changed for now. But I'll leave it to the committer's discretion.
> Isn't the PID important for this use case? If so, of course, you can rely on
> log_line_prefix (%p) but if the PID is crucial for an investigation then it
> should also be included in the message.
On Fri, Mar 24, 2023 at 3:10 AM Peter Smith <[email protected]> wrote:
>
> Patch v8 applied OK, and builds/renders the HTML docs OK, and passes
> the regression and subscription TAP tests OK.
>
> Here are some minor comments:
>
> 1.
> + ereport(log_replication_commands ? LOG : DEBUG3,
> + (errmsg("acquired physical replication slot \"%s\"",
> + slotname)));
>
> AFAIK those extra parentheses wrapping the "errmsg" part are not necessary.
Done
> 2.
> extern void LogReplicationSlotAquired(bool is_physical, char *slotname);
> extern void LogReplicationSlotReleased(bool is_physical, char *slotname);
>
> The "char *slotname" params of those helper functions should probably
> be declared and defined as "const char *slotname".
Done.
> Otherwise, from a code review perspective the patch v8 LGTM.
Thanks. Please have a look at the v9 patch.
--
Bharath Rupireddy
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com
Attachments:
[application/octet-stream] v9-0001-Add-LOG-messages-when-replication-slots-become-ac.patch (7.0K, ../../CALj2ACWHvzq05mZ25M0Rk9p0c5YpcrvkdVXHAoQaqRtFiDGS3A@mail.gmail.com/2-v9-0001-Add-LOG-messages-when-replication-slots-become-ac.patch)
download | inline diff:
From 44d6a8528e22e5882319d1308c74946b95922bfd Mon Sep 17 00:00:00 2001
From: Bharath Rupireddy <[email protected]>
Date: Fri, 24 Mar 2023 03:23:15 +0000
Subject: [PATCH v9] Add LOG messages when replication slots become active and
inactive
These logs will be extremely useful on production servers to debug
and analyze inactive replication slot issues.
---
doc/src/sgml/config.sgml | 7 +++--
src/backend/replication/slot.c | 49 +++++++++++++++++++++++++++++
src/backend/replication/walsender.c | 15 +++++++++
src/backend/utils/misc/guc_tables.c | 2 +-
src/include/replication/slot.h | 2 ++
5 files changed, 71 insertions(+), 4 deletions(-)
diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index 481f93cea1..f9b0d3c9a9 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -7593,9 +7593,10 @@ 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>.
+ Causes each replication command and related activity 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>
diff --git a/src/backend/replication/slot.c b/src/backend/replication/slot.c
index 2293c0c6fc..3e363eaad8 100644
--- a/src/backend/replication/slot.c
+++ b/src/backend/replication/slot.c
@@ -180,7 +180,14 @@ ReplicationSlotShmemExit(int code, Datum arg)
{
/* Make sure active replication slots are released */
if (MyReplicationSlot != NULL)
+ {
+ char *slotname;
+
+ slotname = pstrdup(NameStr(MyReplicationSlot->data.name));
ReplicationSlotRelease();
+ LogReplicationSlotRelease(SlotIsPhysical(MyReplicationSlot), slotname);
+ pfree(slotname);
+ }
/* Also cleanup all the temporary slots. */
ReplicationSlotCleanup();
@@ -445,6 +452,9 @@ ReplicationSlotName(int index, Name name)
*
* An error is raised if nowait is true and the slot is currently in use. If
* nowait is false, we sleep until the slot is released by the owning process.
+ *
+ * Note: use LogReplicationSlotAcquire() if needed, to log a message after
+ * acquiring the replication slot.
*/
void
ReplicationSlotAcquire(const char *name, bool nowait)
@@ -542,6 +552,9 @@ retry:
*
* This or another backend can re-acquire the slot later.
* Resources this slot requires will be preserved.
+ *
+ * Note: use LogReplicationSlotRelease() if needed, to log a message after
+ * releasing the replication slot.
*/
void
ReplicationSlotRelease(void)
@@ -596,6 +609,42 @@ ReplicationSlotRelease(void)
LWLockRelease(ProcArrayLock);
}
+/*
+ * Helper function to log a message after replication slot acquisition.
+ */
+void
+LogReplicationSlotAcquire(bool is_physical, const char *slotname)
+{
+ Assert(MyReplicationSlot != NULL);
+
+ if (is_physical)
+ ereport(log_replication_commands ? LOG : DEBUG3,
+ errmsg("physical replication slot \"%s\" is acquired",
+ slotname));
+ else
+ ereport(log_replication_commands ? LOG : DEBUG3,
+ errmsg("logical replication slot \"%s\" is acquired",
+ slotname));
+}
+
+/*
+ * Helper function to log a message after replication slot release.
+ */
+void
+LogReplicationSlotRelease(bool is_physical, const char *slotname)
+{
+ Assert(MyReplicationSlot == NULL);
+
+ if (is_physical)
+ ereport(log_replication_commands ? LOG : DEBUG3,
+ errmsg("physical replication slot \"%s\" is released",
+ slotname));
+ else
+ ereport(log_replication_commands ? LOG : DEBUG3,
+ errmsg("logical replication slot \"%s\" is released",
+ slotname));
+}
+
/*
* Cleanup all temporary slots created in current session.
*/
diff --git a/src/backend/replication/walsender.c b/src/backend/replication/walsender.c
index 75e8363e24..97ecb0b7d5 100644
--- a/src/backend/replication/walsender.c
+++ b/src/backend/replication/walsender.c
@@ -322,7 +322,14 @@ WalSndErrorCleanup(void)
wal_segment_close(xlogreader);
if (MyReplicationSlot != NULL)
+ {
+ char *slotname;
+
+ slotname = pstrdup(NameStr(MyReplicationSlot->data.name));
ReplicationSlotRelease();
+ LogReplicationSlotRelease(SlotIsPhysical(MyReplicationSlot), slotname);
+ pfree(slotname);
+ }
ReplicationSlotCleanup();
@@ -703,6 +710,8 @@ StartReplication(StartReplicationCmd *cmd)
(errcode(ERRCODE_OBJECT_NOT_IN_PREREQUISITE_STATE),
errmsg("cannot use a logical replication slot for physical replication")));
+ LogReplicationSlotAcquire(true, cmd->slotname);
+
/*
* We don't need to verify the slot's restart_lsn here; instead we
* rely on the caller requesting the starting point to use. If the
@@ -843,7 +852,10 @@ StartReplication(StartReplicationCmd *cmd)
}
if (cmd->slotname)
+ {
ReplicationSlotRelease();
+ LogReplicationSlotRelease(true, cmd->slotname);
+ }
/*
* Copy is finished now. Send a single-row result set indicating the next
@@ -1260,6 +1272,8 @@ StartLogicalReplication(StartReplicationCmd *cmd)
cmd->slotname),
errdetail("This slot has been invalidated because it exceeded the maximum reserved size.")));
+ LogReplicationSlotAcquire(false, cmd->slotname);
+
/*
* Force a disconnect, so that the decoding code doesn't need to care
* about an eventual switch from running in recovery, to running in a
@@ -1321,6 +1335,7 @@ StartLogicalReplication(StartReplicationCmd *cmd)
FreeDecodingContext(logical_decoding_ctx);
ReplicationSlotRelease();
+ LogReplicationSlotRelease(false, cmd->slotname);
replication_active = false;
if (got_STOPPING)
diff --git a/src/backend/utils/misc/guc_tables.c b/src/backend/utils/misc/guc_tables.c
index 1c0583fe26..ea41ccc7e2 100644
--- a/src/backend/utils/misc/guc_tables.c
+++ b/src/backend/utils/misc/guc_tables.c
@@ -1203,7 +1203,7 @@ struct config_bool ConfigureNamesBool[] =
},
{
{"log_replication_commands", PGC_SUSET, LOGGING_WHAT,
- gettext_noop("Logs each replication command."),
+ gettext_noop("Logs each replication command and related activity."),
NULL
},
&log_replication_commands,
diff --git a/src/include/replication/slot.h b/src/include/replication/slot.h
index 8872c80cdf..d5faf89368 100644
--- a/src/include/replication/slot.h
+++ b/src/include/replication/slot.h
@@ -202,6 +202,8 @@ extern void ReplicationSlotDrop(const char *name, bool nowait);
extern void ReplicationSlotAcquire(const char *name, bool nowait);
extern void ReplicationSlotRelease(void);
+extern void LogReplicationSlotAcquire(bool is_physical, const char *slotname);
+extern void LogReplicationSlotRelease(bool is_physical, const char *slotname);
extern void ReplicationSlotCleanup(void);
extern void ReplicationSlotSave(void);
extern void ReplicationSlotMarkDirty(void);
--
2.34.1
^ permalink raw reply [nested|flat] 3+ messages in thread
* Re: add log messages when replication slots become active and inactive (was Re: Is it worth adding ReplicationSlot active_pid to ReplicationSlotPersistentData?)
2023-03-24 03:25 Re: add log messages when replication slots become active and inactive (was Re: Is it worth adding ReplicationSlot active_pid to ReplicationSlotPersistentData?) Bharath Rupireddy <[email protected]>
@ 2023-03-24 03:52 ` Greg Stark <[email protected]>
0 siblings, 0 replies; 3+ messages in thread
From: Greg Stark @ 2023-03-24 03:52 UTC (permalink / raw)
To: Bharath Rupireddy <[email protected]>; +Cc: Euler Taveira <[email protected]>; Alvaro Herrera <[email protected]>; Amit Kapila <[email protected]>; Kyotaro Horiguchi <[email protected]>; PostgreSQL Hackers <[email protected]>
On Thu, 23 Mar 2023 at 23:30, Bharath Rupireddy
<[email protected]> wrote:
>
> > + ereport(log_replication_commands ? LOG : DEBUG3,
> > + (errmsg("acquired physical replication slot \"%s\"",
> > + slotname)));
So this is just a bit of bike-shedding but I don't feel like these log
messages really meet the standard we set for our logging. Like what
did the acquiring? What does "acquired" actually mean for a
replication slot? Is there not any meta information about the
acquisition that can give more context to the reader to make this
message more meaningful?
I would expect a log message like this to say, I dunno, something like
"physical replication slot \"%s\" acquired by streaming TCP connection
to 192.168.0.1:999 at LSN ... with xxxMB of logs to read"
I even would be wondering if the other end shouldn't also be logging a
corresponding log and we shouldn't be going out of our way to ensure
there's enough information to match them up and presenting them in a
way that makes that easy.
--
greg
^ permalink raw reply [nested|flat] 3+ messages in thread
* [PATCH v49 4/7] Fix a few problems in index build progress reporting.
@ 2026-03-27 15:50 Álvaro Herrera <[email protected]>
0 siblings, 0 replies; 3+ messages in thread
From: Álvaro Herrera @ 2026-03-27 15:50 UTC (permalink / raw)
First, index_build() should not update the progress when being driven by
REPACK, because the progress reporting infractructure cannot handle status of
two commands at the same time. So far, REPACK with the CONCURRENTLY option
neglected this problem altogether, but even the existing REPACK wasn't
consistent enough: even if the 'progress' variable in repack_index() was
false, it didn't pass the value to index_build().
Second, REPACK (CONCURRENTLY) should not set PROGRESS_REPACK_PHASE to
PROGRESS_REPACK_PHASE_FINAL_CLEANUP in rebuild_relation() because it calls
finish_heap_swap() anyway (via rebuild_relation_finish_concurrent()), which
does the same thing.
---
src/backend/bootstrap/bootstrap.c | 2 +-
src/backend/catalog/heap.c | 3 ++-
src/backend/catalog/index.c | 22 ++++++++++++++++++----
src/backend/catalog/toasting.c | 3 ++-
src/backend/commands/indexcmds.c | 1 +
src/include/catalog/index.h | 4 +++-
6 files changed, 27 insertions(+), 8 deletions(-)
diff --git a/src/backend/bootstrap/bootstrap.c b/src/backend/bootstrap/bootstrap.c
index 38ef683d4c7..60fb7051830 100644
--- a/src/backend/bootstrap/bootstrap.c
+++ b/src/backend/bootstrap/bootstrap.c
@@ -1183,7 +1183,7 @@ build_indices(void)
heap = table_open(ILHead->il_heap, NoLock);
ind = index_open(ILHead->il_ind, NoLock);
- index_build(heap, ind, ILHead->il_info, false, false);
+ index_build(heap, ind, ILHead->il_info, false, false, false);
index_close(ind, NoLock);
table_close(heap, NoLock);
diff --git a/src/backend/catalog/heap.c b/src/backend/catalog/heap.c
index 5748aa9a1a9..ae6b7cda3dd 100644
--- a/src/backend/catalog/heap.c
+++ b/src/backend/catalog/heap.c
@@ -3570,7 +3570,8 @@ RelationTruncateIndexes(Relation heapRelation)
/* Initialize the index and rebuild */
/* Note: we do not need to re-establish pkey setting */
- index_build(heapRelation, currentIndex, indexInfo, true, false);
+ index_build(heapRelation, currentIndex, indexInfo, true, false,
+ true);
/* We're done with this index */
index_close(currentIndex, NoLock);
diff --git a/src/backend/catalog/index.c b/src/backend/catalog/index.c
index b86ad73c626..bac8d527ae5 100644
--- a/src/backend/catalog/index.c
+++ b/src/backend/catalog/index.c
@@ -715,6 +715,9 @@ UpdateIndexRelation(Oid indexoid,
* already exists.
* INDEX_CREATE_PARTITIONED:
* create a partitioned index (table must be partitioned)
+ * INDEX_CREATE_REPORT_PROGRESS:
+ * update the backend's progress information during index build.
+
* constr_flags: flags passed to index_constraint_create
* (only if INDEX_CREATE_ADD_CONSTRAINT is set)
* allow_system_table_mods: allow table to be a system catalog
@@ -760,6 +763,7 @@ index_create(Relation heapRelation,
bool invalid = (flags & INDEX_CREATE_INVALID) != 0;
bool concurrent = (flags & INDEX_CREATE_CONCURRENT) != 0;
bool partitioned = (flags & INDEX_CREATE_PARTITIONED) != 0;
+ bool progress = (flags & INDEX_CREATE_REPORT_PROGRESS) != 0;
char relkind;
TransactionId relfrozenxid;
MultiXactId relminmxid;
@@ -1276,7 +1280,8 @@ index_create(Relation heapRelation,
}
else
{
- index_build(heapRelation, indexRelation, indexInfo, false, true);
+ index_build(heapRelation, indexRelation, indexInfo, false, true,
+ progress);
}
/*
@@ -1438,6 +1443,12 @@ index_create_copy(Relation heapRelation, bool concurrently,
stattargets[i].isnull = isnull;
}
+ /*
+ * Note: The current callers do not need INDEX_CREATE_REPORT_PROGRESS. If
+ * 'concurrently' is true, there is no build at all. Otherwise the index
+ * build is a sub-command of REPACK. The current infrastructure does not
+ * allow two commands to report their progress at the same time.
+ */
if (concurrently)
flags = INDEX_CREATE_SKIP_BUILD | INDEX_CREATE_CONCURRENT;
@@ -1528,7 +1539,7 @@ index_concurrently_build(Oid heapRelationId,
indexInfo->ii_BrokenHotChain = false;
/* Now build the index */
- index_build(heapRel, indexRelation, indexInfo, false, true);
+ index_build(heapRel, indexRelation, indexInfo, false, true, true);
/* Roll back any GUC changes executed by index functions */
AtEOXact_GUC(false, save_nestlevel);
@@ -3001,6 +3012,7 @@ index_update_stats(Relation rel,
*
* isreindex indicates we are recreating a previously-existing index.
* parallel indicates if parallelism may be useful.
+ * progress indicates if the backend should update its progress info.
*
* Note: before Postgres 8.2, the passed-in heap and index Relations
* were automatically closed by this routine. This is no longer the case.
@@ -3011,7 +3023,8 @@ index_build(Relation heapRelation,
Relation indexRelation,
IndexInfo *indexInfo,
bool isreindex,
- bool parallel)
+ bool parallel,
+ bool progress)
{
IndexBuildResult *stats;
Oid save_userid;
@@ -3062,6 +3075,7 @@ index_build(Relation heapRelation,
RestrictSearchPath();
/* Set up initial progress report status */
+ if (progress)
{
const int progress_index[] = {
PROGRESS_CREATEIDX_PHASE,
@@ -3819,7 +3833,7 @@ reindex_index(const ReindexStmt *stmt, Oid indexId,
/* Initialize the index and rebuild */
/* Note: we do not need to re-establish pkey setting */
- index_build(heapRelation, iRel, indexInfo, true, true);
+ index_build(heapRelation, iRel, indexInfo, true, true, progress);
/* Re-allow use of target index */
ResetReindexProcessing();
diff --git a/src/backend/catalog/toasting.c b/src/backend/catalog/toasting.c
index 4aa52a4bd25..51b27a8c71c 100644
--- a/src/backend/catalog/toasting.c
+++ b/src/backend/catalog/toasting.c
@@ -332,7 +332,8 @@ create_toast_table(Relation rel, Oid toastOid, Oid toastIndexOid,
BTREE_AM_OID,
rel->rd_rel->reltablespace,
collationIds, opclassIds, NULL, coloptions, NULL, (Datum) 0,
- INDEX_CREATE_IS_PRIMARY, 0, true, true, NULL);
+ INDEX_CREATE_IS_PRIMARY | INDEX_CREATE_REPORT_PROGRESS, 0,
+ true, true, NULL);
table_close(toast_rel, NoLock);
diff --git a/src/backend/commands/indexcmds.c b/src/backend/commands/indexcmds.c
index 4a2d21915b1..25e8c1945c5 100644
--- a/src/backend/commands/indexcmds.c
+++ b/src/backend/commands/indexcmds.c
@@ -1233,6 +1233,7 @@ DefineIndex(ParseState *pstate,
flags |= INDEX_CREATE_PARTITIONED;
if (stmt->primary)
flags |= INDEX_CREATE_IS_PRIMARY;
+ flags |= INDEX_CREATE_REPORT_PROGRESS;
/*
* If the table is partitioned, and recursion was declined but partitions
diff --git a/src/include/catalog/index.h b/src/include/catalog/index.h
index ed9e4c37d27..7ebe4f0bd87 100644
--- a/src/include/catalog/index.h
+++ b/src/include/catalog/index.h
@@ -71,6 +71,7 @@ extern void index_check_primary_key(Relation heapRel,
#define INDEX_CREATE_IF_NOT_EXISTS (1 << 4)
#define INDEX_CREATE_PARTITIONED (1 << 5)
#define INDEX_CREATE_INVALID (1 << 6)
+#define INDEX_CREATE_REPORT_PROGRESS (1 << 7)
extern Oid index_create(Relation heapRelation,
const char *indexRelationName,
@@ -148,7 +149,8 @@ extern void index_build(Relation heapRelation,
Relation indexRelation,
IndexInfo *indexInfo,
bool isreindex,
- bool parallel);
+ bool parallel,
+ bool progress);
extern void validate_index(Oid heapId, Oid indexId, Snapshot snapshot);
--
2.47.3
--3n3vqr5y2jhknrqj
Content-Type: text/x-diff; charset=utf-8
Content-Disposition: attachment;
filename="v49-0005-Error-out-any-process-that-would-block-at-REPACK.patch"
^ permalink raw reply [nested|flat] 3+ messages in thread
end of thread, other threads:[~2026-03-27 15:50 UTC | newest]
Thread overview: 3+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2023-03-24 03:25 Re: add log messages when replication slots become active and inactive (was Re: Is it worth adding ReplicationSlot active_pid to ReplicationSlotPersistentData?) Bharath Rupireddy <[email protected]>
2023-03-24 03:52 ` Greg Stark <[email protected]>
2026-03-27 15:50 [PATCH v49 4/7] Fix a few problems in index build progress reporting. Álvaro Herrera <[email protected]>
This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox