public inbox for [email protected]  
help / color / mirror / Atom feed
[PATCH 1/3] bootstrap: convert Typ to a List*
14+ messages / 6 participants
[nested] [flat]

* [PATCH 1/3] bootstrap: convert Typ to a List*
@ 2020-11-20 02:48 Justin Pryzby <[email protected]>
  0 siblings, 0 replies; 14+ messages in thread

From: Justin Pryzby @ 2020-11-20 02:48 UTC (permalink / raw)

---
 src/backend/bootstrap/bootstrap.c | 69 ++++++++++++++-----------------
 1 file changed, 31 insertions(+), 38 deletions(-)

diff --git a/src/backend/bootstrap/bootstrap.c b/src/backend/bootstrap/bootstrap.c
index 6f615e6622..18eb62ca47 100644
--- a/src/backend/bootstrap/bootstrap.c
+++ b/src/backend/bootstrap/bootstrap.c
@@ -159,7 +159,7 @@ struct typmap
 	FormData_pg_type am_typ;
 };
 
-static struct typmap **Typ = NULL;
+static List *Typ = NIL; /* List of struct typmap* */
 static struct typmap *Ap = NULL;
 
 static Datum values[MAXATTR];	/* current row's attribute values */
@@ -597,7 +597,7 @@ boot_openrel(char *relname)
 	 * pg_type must be filled before any OPEN command is executed, hence we
 	 * can now populate the Typ array if we haven't yet.
 	 */
-	if (Typ == NULL)
+	if (Typ == NIL)
 		populate_typ_array();
 
 	if (boot_reldesc != NULL)
@@ -688,7 +688,7 @@ DefineAttr(char *name, char *type, int attnum, int nullness)
 
 	typeoid = gettype(type);
 
-	if (Typ != NULL)
+	if (Typ != NIL)
 	{
 		attrtypes[attnum]->atttypid = Ap->am_oid;
 		attrtypes[attnum]->attlen = Ap->am_typ.typlen;
@@ -877,36 +877,25 @@ populate_typ_array(void)
 	Relation	rel;
 	TableScanDesc scan;
 	HeapTuple	tup;
-	int			nalloc;
-	int			i;
-
-	Assert(Typ == NULL);
 
-	nalloc = 512;
-	Typ = (struct typmap **)
-		MemoryContextAlloc(TopMemoryContext, nalloc * sizeof(struct typmap *));
+	Assert(Typ == NIL);
 
 	rel = table_open(TypeRelationId, NoLock);
 	scan = table_beginscan_catalog(rel, 0, NULL);
-	i = 0;
 	while ((tup = heap_getnext(scan, ForwardScanDirection)) != NULL)
 	{
 		Form_pg_type typForm = (Form_pg_type) GETSTRUCT(tup);
+		struct typmap *newtyp;
+		MemoryContext old;
 
-		/* make sure there will be room for a trailing NULL pointer */
-		if (i >= nalloc - 1)
-		{
-			nalloc *= 2;
-			Typ = (struct typmap **)
-				repalloc(Typ, nalloc * sizeof(struct typmap *));
-		}
-		Typ[i] = (struct typmap *)
-			MemoryContextAlloc(TopMemoryContext, sizeof(struct typmap));
-		Typ[i]->am_oid = typForm->oid;
-		memcpy(&(Typ[i]->am_typ), typForm, sizeof(Typ[i]->am_typ));
-		i++;
+		old = MemoryContextSwitchTo(TopMemoryContext);
+		newtyp = (struct typmap *) palloc(sizeof(struct typmap));
+		Typ = lappend(Typ, newtyp);
+		MemoryContextSwitchTo(old);
+
+		newtyp->am_oid = typForm->oid;
+		memcpy(&newtyp->am_typ, typForm, sizeof(newtyp->am_typ));
 	}
-	Typ[i] = NULL;				/* Fill trailing NULL pointer */
 	table_endscan(scan);
 	table_close(rel, NoLock);
 }
@@ -925,16 +914,17 @@ populate_typ_array(void)
 static Oid
 gettype(char *type)
 {
-	if (Typ != NULL)
+	if (Typ != NIL)
 	{
-		struct typmap **app;
+		ListCell *lc;
 
-		for (app = Typ; *app != NULL; app++)
+		foreach (lc, Typ)
 		{
-			if (strncmp(NameStr((*app)->am_typ.typname), type, NAMEDATALEN) == 0)
+			struct typmap *app = lfirst(lc);
+			if (strncmp(NameStr(app->am_typ.typname), type, NAMEDATALEN) == 0)
 			{
-				Ap = *app;
-				return (*app)->am_oid;
+				Ap = app;
+				return app->am_oid;
 			}
 		}
 	}
@@ -980,14 +970,17 @@ boot_get_type_io_data(Oid typid,
 	if (Typ != NULL)
 	{
 		/* We have the boot-time contents of pg_type, so use it */
-		struct typmap **app;
-		struct typmap *ap;
-
-		app = Typ;
-		while (*app && (*app)->am_oid != typid)
-			++app;
-		ap = *app;
-		if (ap == NULL)
+		struct typmap *ap = NULL;
+		ListCell *lc;
+
+		foreach (lc, Typ)
+		{
+			ap = lfirst(lc);
+			if (ap->am_oid == typid)
+				break;
+		}
+
+		if (!ap || ap->am_oid != typid)
 			elog(ERROR, "type OID %u not found in Typ list", typid);
 
 		*typlen = ap->am_typ.typlen;
-- 
2.26.2


--------------76B8D0DC8AE327D516738282
Content-Type: text/x-patch; charset=UTF-8;
 name="0002-Allow-composite-types-in-bootstrap-20210108.patch"
Content-Transfer-Encoding: 7bit
Content-Disposition: attachment;
 filename="0002-Allow-composite-types-in-bootstrap-20210108.patch"



^ permalink  raw  reply  [nested|flat] 14+ messages in thread

* Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly
@ 2024-10-31 10:18 Vitaly Davydov <[email protected]>
  2024-11-20 17:24 ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
  2025-07-02 17:20 ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly vignesh C <[email protected]>
  2025-07-18 10:44 ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Alexander Korotkov <[email protected]>
  0 siblings, 3 replies; 14+ messages in thread

From: Vitaly Davydov @ 2024-10-31 10:18 UTC (permalink / raw)
  To: pgsql-hackers


Dear Hackers,
 
I'd like to discuss a problem with replication slots's restart LSN. Physical slots are saved to disk at the beginning of checkpoint. At the end of checkpoint, old WAL segments are recycled or removed from disk, if they are not kept by slot's restart_lsn values.
 
If an existing physical slot is advanced in the middle of checkpoint execution, WAL segments, which are related to saved on disk restart LSN may be removed. It is because the calculation of the replication slot miminal LSN is occured at the end of checkpoint, prior to old WAL segments removal. If to hard stop (pg_stl -m immediate) the postgres instance right after checkpoint and to restart it, the slot's restart_lsn may point to the removed WAL segment. I believe, such behaviour is not good.
 
The doc [0] describes that restart_lsn may be set to the some past value after reload. There is a discussion [1] on pghackers where such behaviour is discussed. The main reason of not flushing physical slots on advancing is a performance reason. I'm ok with such behaviour, except of that the corresponding WAL segments should not be removed.
 
I propose to keep WAL segments by saved on disk (flushed) restart_lsn of slots. Add a new field restart_lsn_flushed into ReplicationSlot structure. Copy restart_lsn to restart_lsn_flushed in SaveSlotToPath. It doesn't change the format of storing the slot contents on disk. I attached a patch. It is not yet complete, but demonstate a way to solve the problem.
 
I reproduced the problem by the following way:
 * Add some delay in CheckPointBuffers (pg_usleep) to emulate long checkpoint execution. * Execute checkpoint and pg_replication_slot_advance right after starting of the checkpoint from another connection. * Hard restart the server right after checkpoint completion. * After restart slot's restart_lsn may point to removed WAL segment.
The proposed patch fixes it.
 
[0] https://www.postgresql.org/docs/current/logicaldecoding-explanation.html
[1] https://www.postgresql.org/message-id/flat/059cc53a-8b14-653a-a24d-5f867503b0ee%40postgrespro.ru


^ permalink  raw  reply  [nested|flat] 14+ messages in thread

* Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly
  2024-10-31 10:18 Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Vitaly Davydov <[email protected]>
@ 2024-11-20 17:24 ` Tomas Vondra <[email protected]>
  2024-11-20 22:19   ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
  2 siblings, 1 reply; 14+ messages in thread

From: Tomas Vondra @ 2024-11-20 17:24 UTC (permalink / raw)
  To: Vitaly Davydov <[email protected]>; pgsql-hackers

On 10/31/24 11:18, Vitaly Davydov wrote:
> Dear Hackers,
> 
>  
> 
> I'd like to discuss a problem with replication slots's restart LSN.
> Physical slots are saved to disk at the beginning of checkpoint. At the
> end of checkpoint, old WAL segments are recycled or removed from disk,
> if they are not kept by slot's restart_lsn values.
> 

I agree that if we can lose WAL still needed for a replication slot,
that is a bug. Retaining the WAL is the primary purpose of slots, and we
just fixed a similar issue for logical replication.

> 
> If an existing physical slot is advanced in the middle of checkpoint
> execution, WAL segments, which are related to saved on disk restart LSN
> may be removed. It is because the calculation of the replication slot
> miminal LSN is occured at the end of checkpoint, prior to old WAL
> segments removal. If to hard stop (pg_stl -m immediate) the postgres
> instance right after checkpoint and to restart it, the slot's
> restart_lsn may point to the removed WAL segment. I believe, such
> behaviour is not good.
> 

Not sure I 100% follow, but let me rephrase, just so that we're on the
same page. CreateCheckPoint() does this:

  ... something ...

  CheckPointGuts(checkPoint.redo, flags);

  ... something ...

  RemoveOldXlogFiles(_logSegNo, RedoRecPtr, recptr,
                     checkPoint.ThisTimeLineID);

The slots get synced in CheckPointGuts(), so IIUC you're saying if the
slot gets advanced shortly after the sync, the RemoveOldXlogFiles() may
remove still-needed WAL, because we happen to consider a fresh
restart_lsn when calculating the logSegNo. Is that right?

> 
> The doc [0] describes that restart_lsn may be set to the some past value
> after reload. There is a discussion [1] on pghackers where such
> behaviour is discussed. The main reason of not flushing physical slots
> on advancing is a performance reason. I'm ok with such behaviour, except
> of that the corresponding WAL segments should not be removed.
> 

I don't know which part of [0] you refer to, but I guess you're
referring to this:

    The current position of each slot is persisted only at checkpoint,
    so in the case of a crash the slot may return to an earlier LSN,
    which will then cause recent changes to be sent again when the
    server restarts. Logical decoding clients are responsible for
    avoiding ill effects from handling the same message more than once.

Yes, it's fine if we discard the new in-memory restart_lsn value, and we
do this for performance reasons - flushing the slot on every advance
would be very expensive. I haven't read [1] as it's quite long, but I
guess that's what it says.

But we must not make any "permanent" actions based on the unflushed
value, I think. Like, we should not remove WAL segments, for example.

>  
> 
> I propose to keep WAL segments by saved on disk (flushed) restart_lsn of
> slots. Add a new field restart_lsn_flushed into ReplicationSlot
> structure. Copy restart_lsn to restart_lsn_flushed in SaveSlotToPath. It
> doesn't change the format of storing the slot contents on disk. I
> attached a patch. It is not yet complete, but demonstate a way to solve
> the problem.
> 

That seems like a possible fix this, yes. And maybe it's the right one.

> 
> I reproduced the problem by the following way:
> 
>   * Add some delay in CheckPointBuffers (pg_usleep) to emulate long
>     checkpoint execution.
>   * Execute checkpoint and pg_replication_slot_advance right after
>     starting of the checkpoint from another connection.
>   * Hard restart the server right after checkpoint completion.
>   * After restart slot's restart_lsn may point to removed WAL segment.
> 
> The proposed patch fixes it.
> 

I tried to reproduce the issue using a stress test (checkpoint+restart
in a loop), but so far without success :-(

Can you clarify where exactly you added the pg_usleep(), and how long
are the waits you added? I wonder if the sleep is really needed,
considering the checkpoints are spread anyway. Also, what you mean by
"hard reset"?

What confuses me a bit is that we update the restart_lsn (and call
ReplicationSlotsComputeRequiredLSN() to recalculate the global value)
all the time. Walsender does that in PhysicalConfirmReceivedLocation for
example. So we actually see the required LSN to move during checkpoint
very often. So how come we don't see the issues much more often? Surely
I miss something important.

Another option might be that pg_replication_slot_advance() doesn't do
something it should be doing. For example, shouldn't be marking the slot
as dirty?


regards

-- 
Tomas Vondra







^ permalink  raw  reply  [nested|flat] 14+ messages in thread

* Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly
  2024-10-31 10:18 Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Vitaly Davydov <[email protected]>
  2024-11-20 17:24 ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
@ 2024-11-20 22:19   ` Tomas Vondra <[email protected]>
  2024-11-21 13:59     ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
  0 siblings, 1 reply; 14+ messages in thread

From: Tomas Vondra @ 2024-11-20 22:19 UTC (permalink / raw)
  To: [email protected]

On 11/20/24 18:24, Tomas Vondra wrote:
>
> ...
>
> What confuses me a bit is that we update the restart_lsn (and call
> ReplicationSlotsComputeRequiredLSN() to recalculate the global value)
> all the time. Walsender does that in PhysicalConfirmReceivedLocation for
> example. So we actually see the required LSN to move during checkpoint
> very often. So how come we don't see the issues much more often? Surely
> I miss something important.
> 

This question "How come we don't see this more often?" kept bugging me,
and the answer is actually pretty simple.

The restart_lsn can move backwards after a hard restart (for the reasons
explained), but physical replication does not actually rely on that. The
replica keeps track of the LSN it received (well, it uses the same LSN),
and on reconnect it sends the startpoint to the primary. And the primary
just proceeds use that instead of the (stale) restart LSN for the slot.
And the startpoint is guaranteed (I think) to be at least restart_lsn.

AFAICS this would work for pg_replication_slot_advance() too, that is if
you remember the last LSN the slot advanced to, it should be possible to
advance to it just fine. Of course, it requires a way to remember that
LSN, which for a replica is not an issue. But this just highlights we
can't rely on restart_lsn for this purpose.


(Apologies if this repeats something obvious, or something you already
said, Vitaly.)

regards

-- 
Tomas Vondra







^ permalink  raw  reply  [nested|flat] 14+ messages in thread

* Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly
  2024-10-31 10:18 Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Vitaly Davydov <[email protected]>
  2024-11-20 17:24 ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
  2024-11-20 22:19   ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
@ 2024-11-21 13:59     ` Tomas Vondra <[email protected]>
  2024-11-21 23:05       ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
  0 siblings, 1 reply; 14+ messages in thread

From: Tomas Vondra @ 2024-11-21 13:59 UTC (permalink / raw)
  To: [email protected]



On 11/20/24 23:19, Tomas Vondra wrote:
> On 11/20/24 18:24, Tomas Vondra wrote:
>>
>> ...
>>
>> What confuses me a bit is that we update the restart_lsn (and call
>> ReplicationSlotsComputeRequiredLSN() to recalculate the global value)
>> all the time. Walsender does that in PhysicalConfirmReceivedLocation for
>> example. So we actually see the required LSN to move during checkpoint
>> very often. So how come we don't see the issues much more often? Surely
>> I miss something important.
>>
> 
> This question "How come we don't see this more often?" kept bugging me,
> and the answer is actually pretty simple.
> 
> The restart_lsn can move backwards after a hard restart (for the reasons
> explained), but physical replication does not actually rely on that. The
> replica keeps track of the LSN it received (well, it uses the same LSN),
> and on reconnect it sends the startpoint to the primary. And the primary
> just proceeds use that instead of the (stale) restart LSN for the slot.
> And the startpoint is guaranteed (I think) to be at least restart_lsn.
> 
> AFAICS this would work for pg_replication_slot_advance() too, that is if
> you remember the last LSN the slot advanced to, it should be possible to
> advance to it just fine. Of course, it requires a way to remember that
> LSN, which for a replica is not an issue. But this just highlights we
> can't rely on restart_lsn for this purpose.
> 

I kept thinking about this (sorry it's this incremental), particularly
if this applies to logical replication too. And AFAICS it does not, or
at least not to this extent.

For streaming, the subscriber sends the startpoint (just like physical
replication), so it should be protected too.

But then there's the SQL API - pg_logical_slot_get_changes(). And it
turns out it ends up syncing the slot to disk pretty often, because for
RUNNING_XACTS we call LogicalDecodingProcessRecord() + standby_decode(),
which ends up calling SaveSlotToDisk(). And at the end we call
LogicalConfirmReceivedLocation() for good measure, which saves the slot
too, just to be sure.

FWIW I suspect this still is not perfectly safe, because we may still
crash / restart before the updated data.restart_lsn makes it to disk,
but after it was already used to remove old WAL, although that's
probably harder to hit. With streaming the subscriber will still send us
the new startpoint, so that should not fail I think. But with the SQL
API we probably can get into the "segment already removed" issues.

I haven't tried reproducing this yet, I guess it should be possible
using the injection points. Not sure when I get to this, though.


In any case, doesn't this suggest SaveSlotToDisk() really is not that
expensive, if we do it pretty often for logical replication? Which was
presented as the main reason why pg_replication_slot_advance() doesn't
do that. Maybe it should?

If the advance is substantial I don't think it really matters, because
there simply can't be that many of large advances. It amortizes, in a
way. But even with smaller advances it should be fine, I think - if the
goal is to not remove WAL prematurely, it's enough to flush when we move
to the next segment.


regards

-- 
Tomas Vondra







^ permalink  raw  reply  [nested|flat] 14+ messages in thread

* Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly
  2024-10-31 10:18 Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Vitaly Davydov <[email protected]>
  2024-11-20 17:24 ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
  2024-11-20 22:19   ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
  2024-11-21 13:59     ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
@ 2024-11-21 23:05       ` Tomas Vondra <[email protected]>
  2024-12-13 14:34         ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Vitaly Davydov <[email protected]>
  0 siblings, 1 reply; 14+ messages in thread

From: Tomas Vondra @ 2024-11-21 23:05 UTC (permalink / raw)
  To: [email protected]

On 11/21/24 14:59, Tomas Vondra wrote:
> 
> ...
>
> But then there's the SQL API - pg_logical_slot_get_changes(). And it
> turns out it ends up syncing the slot to disk pretty often, because for
> RUNNING_XACTS we call LogicalDecodingProcessRecord() + standby_decode(),
> which ends up calling SaveSlotToDisk(). And at the end we call
> LogicalConfirmReceivedLocation() for good measure, which saves the slot
> too, just to be sure.
> 
> FWIW I suspect this still is not perfectly safe, because we may still
> crash / restart before the updated data.restart_lsn makes it to disk,
> but after it was already used to remove old WAL, although that's
> probably harder to hit. With streaming the subscriber will still send us
> the new startpoint, so that should not fail I think. But with the SQL
> API we probably can get into the "segment already removed" issues.
> 
> I haven't tried reproducing this yet, I guess it should be possible
> using the injection points. Not sure when I get to this, though.
> 
I kept pulling on this loose thread, and the deeper I look the more I'm
concvinced ReplicationSlotsComputeRequiredLSN() is fundamentally unsafe.
I may be missing something, of course, in which case I'd be grateful if
someone could correct me.

I believe the main problem is that ReplicationSlotsComputeRequiredLSN()
operates on data that may not be on-disk yet. It just iterates over
slots in shared memory, looks at the data.restart_lsn, and rolls with
that. So some of the data may be lost after a crash or "immediate"
restart, which for restart_lsn means it can move backwards by some
unknown amount.

Unfortunately, some of the callers use the value as if it was durable,
and do irreversible actions based on it. This whole thread is about
checkpointer using the value to discard WAL supposedly not required by
any slot, only to find out we're missing WAL.

That seems like a rather fundamental problem, and the only reason why we
don't see this causing trouble more often is that (a) abrupt restarts
are not very common, (b) most slots are likely not lagging very much,
and thus not in danger of actually losing WAL, and (c) the streaming
replication tracks startpoint, which masks the issue.

But with the SQL API it's quite simple to cause issues with the right
timing, as I'll show in a bit.

There's an interesting difference in how different places update the
slot. For example LogicalConfirmReceivedLocation() does this:

1) update slot->data.restart_lsn
2) mark slot dirty: ReplicationSlotMarkDirty()
3) save slot to disk: ReplicationSlotSave()
4) recalculate required LSN: ReplicationSlotsComputeRequiredLSN()

while pg_replication_slot_advance() does only this:

1) update slot->data.restart_lsn
2) mark slot dirty: ReplicationSlotMarkDirty()
3) recalculate required LSN: ReplicationSlotsComputeRequiredLSN()

That is, it doesn't save the slot to disk. It just updates the LSN and
them proceeds to recalculate the "required LSN" for all slots. That
makes is very easy to hit the issue, as demonstrated by Vitaly.

However, it doesn't mean LogicalConfirmReceivedLocation() is safe. It
would be safe without concurrency, but it can happen that the logical
decoding does (1) and maybe (2), but before the slot gets persisted,
some other session gets to call ReplicationSlotsComputeRequiredLSN().

It might be logical decoding on another slot, or advance of a physical
slot. I haven't checked what else can trigger that.

So ultimately logical slots have exactly the same issue.

Attached are two patches, demonstrating the issue. 0001 adds injection
points into two places - before (2) in LogicalConfirmReceivedLocation,
and before removal of old WAL in a checkpoint. 0002 then adds a simple
TAP test triggering the issue in pg_logical_slot_get_changes(), leading to:

  ERROR:  requested WAL segment pg_wal/000000010000000000000001 has
          already been removed

The same issue could be demonstrated on a physical slot - it would
actually be simpler, I think.


I've been unable to cause issues for streaming replication (both
physical and logical), because the subscriber sends startpoint which
adjusts the restart_lsn to a "good" value. But I'm not sure if that's
reliable in all cases, or if the replication could break too.


It's entirely possible this behavior is common knowledge, but it was a
surprise for me. Even if the streaming replication is safe, it does seem
to make using the SQL functions less reliable (not that it doesn't have
other challenges, e.g. with Ctrl-C). But maybe it could be made safer?

I don't have a great idea how to improve this. It seems wrong for
ReplicationSlotsComputeRequiredLSN() to calculate the LSN using values
from dirty slots, so maybe it should simply retry if any slot is dirty?
Or retry on that one slot? But various places update the restart_lsn
before marking the slot as dirty, so right now this won't work.


regards

-- 
Tomas Vondra


Attachments:

  [text/x-patch] 0002-TAP-test.patch (6.5K, ../../[email protected]/2-0002-TAP-test.patch)
  download | inline diff:
From 79a045728b09237234f23130a2a710e1bdde7870 Mon Sep 17 00:00:00 2001
From: Tomas Vondra <[email protected]>
Date: Thu, 21 Nov 2024 23:07:22 +0100
Subject: [PATCH 2/2] TAP test

---
 src/test/modules/test_required_lsn/Makefile   |  18 +++
 .../modules/test_required_lsn/meson.build     |  15 +++
 .../test_required_lsn/t/001_logical_slot.pl   | 126 ++++++++++++++++++
 3 files changed, 159 insertions(+)
 create mode 100644 src/test/modules/test_required_lsn/Makefile
 create mode 100644 src/test/modules/test_required_lsn/meson.build
 create mode 100644 src/test/modules/test_required_lsn/t/001_logical_slot.pl

diff --git a/src/test/modules/test_required_lsn/Makefile b/src/test/modules/test_required_lsn/Makefile
new file mode 100644
index 00000000000..3eb2b02d38f
--- /dev/null
+++ b/src/test/modules/test_required_lsn/Makefile
@@ -0,0 +1,18 @@
+# src/test/modules/test_required_lsn/Makefile
+
+EXTRA_INSTALL=src/test/modules/injection_points \
+	contrib/test_decoding
+
+export enable_injection_points
+TAP_TESTS = 1
+
+ifdef USE_PGXS
+PG_CONFIG = pg_config
+PGXS := $(shell $(PG_CONFIG) --pgxs)
+include $(PGXS)
+else
+subdir = src/test/modules/test_required_lsn
+top_builddir = ../../../..
+include $(top_builddir)/src/Makefile.global
+include $(top_srcdir)/contrib/contrib-global.mk
+endif
diff --git a/src/test/modules/test_required_lsn/meson.build b/src/test/modules/test_required_lsn/meson.build
new file mode 100644
index 00000000000..99ef3a60a4e
--- /dev/null
+++ b/src/test/modules/test_required_lsn/meson.build
@@ -0,0 +1,15 @@
+# Copyright (c) 2022-2024, PostgreSQL Global Development Group
+
+tests += {
+  'name': 'test_required_lsn',
+  'sd': meson.current_source_dir(),
+  'bd': meson.current_build_dir(),
+  'tap': {
+    'env': {
+       'enable_injection_points': get_option('injection_points') ? 'yes' : 'no',
+    },
+    'tests': [
+      't/001_logical_replication.pl'
+    ],
+  },
+}
diff --git a/src/test/modules/test_required_lsn/t/001_logical_slot.pl b/src/test/modules/test_required_lsn/t/001_logical_slot.pl
new file mode 100644
index 00000000000..41261f4aa6b
--- /dev/null
+++ b/src/test/modules/test_required_lsn/t/001_logical_slot.pl
@@ -0,0 +1,126 @@
+# Copyright (c) 2024, PostgreSQL Global Development Group
+
+# This test verifies edge case of reading a multixact:
+# when we have multixact that is followed by exactly one another multixact,
+# and another multixact have no offset yet, we must wait until this offset
+# becomes observable. Previously we used to wait for 1ms in a loop in this
+# case, but now we use CV for this. This test is exercising such a sleep.
+
+use strict;
+use warnings FATAL => 'all';
+
+use PostgreSQL::Test::Cluster;
+use PostgreSQL::Test::Utils;
+
+use Test::More;
+
+if ($ENV{enable_injection_points} ne 'yes')
+{
+	plan skip_all => 'Injection points not supported by this build';
+}
+
+my ($node, $result);
+
+$node = PostgreSQL::Test::Cluster->new('mike');
+$node->init;
+$node->append_conf('postgresql.conf',
+	"shared_preload_libraries = 'injection_points'");
+$node->append_conf('postgresql.conf',
+	"wal_level = 'logical'");
+$node->start;
+$node->safe_psql('postgres', q(CREATE EXTENSION injection_points));
+
+# create a simple table to generate data into
+$node->safe_psql('postgres',
+	q{create table t (id serial primary key, b text)});
+
+# create the two slots we'll need
+$node->safe_psql('postgres',
+	q{select pg_create_logical_replication_slot('slot_logical', 'test_decoding')});
+$node->safe_psql('postgres',
+	q{select pg_create_physical_replication_slot('slot_physical', true)});
+
+# advance both to current position, just to have everything "valid"
+$node->safe_psql('postgres',
+	q{select count(*) from pg_logical_slot_get_changes('slot_logical', null, null)});
+$node->safe_psql('postgres',
+	q{select pg_replication_slot_advance('slot_physical', pg_current_wal_lsn())});
+
+# run checkpoint, to flush current state to disk and set a baseline
+$node->safe_psql('postgres', q{checkpoint});
+
+# generate transactions to get RUNNING_XACTS
+my $xacts = $node->background_psql('postgres');
+$xacts->query_until(qr/run_xacts/,
+q(\echo run_xacts
+SELECT 1 \watch 0.1
+\q
+));
+
+# insert 2M rows, that's about 260MB (~20 segments) worth of WAL
+$node->safe_psql('postgres',
+	q{insert into t (b) select md5(i::text) from generate_series(1,1000000) s(i)});
+
+# run another checkpoint, to set a new restore LSN
+$node->safe_psql('postgres', q{checkpoint});
+
+# another 2M rows, that's about 260MB (~20 segments) worth of WAL
+$node->safe_psql('postgres',
+	q{insert into t (b) select md5(i::text) from generate_series(1,1000000) s(i)});
+
+# run another checkpoint, this time in the background, and make it wait
+# on the injection point), so that the checkpoint stops right before
+# removing old WAL segments
+print('starting checkpoint\n');
+
+my $checkpoint = $node->background_psql('postgres');
+$checkpoint->query_safe(q(select injection_points_attach('checkpoint-before-old-wal-removal','wait')));
+$checkpoint->query_until(qr/starting_checkpoint/,
+q(\echo starting_checkpoint
+checkpoint;
+\q
+));
+
+print('waiting for injection_point\n');
+# wait until the checkpoint stops right before removing WAL segments
+$node->wait_for_event('checkpointer', 'checkpoint-before-old-wal-removal');
+
+
+# try to advance the logical slot, but make it stop when it moves to the
+# next WAL segment (has to happen in the background too)
+my $logical = $node->background_psql('postgres');
+$logical->query_safe(q{select injection_points_attach('logical-replication-slot-advance-segment','wait');});
+$logical->query_until(qr/get_changes/,
+q(
+\echo get_changes
+select count(*) from pg_logical_slot_get_changes('slot_logical', null, null) \watch 1
+\q
+));
+
+
+# wait until the checkpoint stops right before removing WAL segments
+$node->wait_for_event('client backend', 'logical-replication-slot-advance-segment');
+
+
+# OK, we're in the right situation,  time to advance the physical slot,
+# which recalculates the required LSN, and then unblock the checkpoint,
+# which removes the WAL still needed by the logical slot
+$node->safe_psql('postgres',
+	q{select pg_replication_slot_advance('slot_physical', pg_current_wal_lsn())});
+
+$node->safe_psql('postgres',
+	q{select injection_points_wakeup('checkpoint-before-old-wal-removal')});
+
+# abruptly stop the server (1 second should be enough for the checkpoint
+# to finish, would be better )
+$node->stop('immediate');
+
+$node->start;
+
+$node->safe_psql('postgres', q{select count(*) from pg_logical_slot_get_changes('slot_logical', null, null);});
+
+$node->stop;
+
+# If we reached this point - everything is OK.
+ok(1);
+done_testing();
-- 
2.47.0



  [text/x-patch] 0001-injection-points.patch (2.6K, ../../[email protected]/3-0001-injection-points.patch)
  download | inline diff:
From eef5f02a5c22ccc520c20623d70eaf093a039f09 Mon Sep 17 00:00:00 2001
From: Tomas Vondra <[email protected]>
Date: Thu, 21 Nov 2024 20:37:00 +0100
Subject: [PATCH 1/2] injection points

---
 src/backend/access/transam/xlog.c         |  4 ++++
 src/backend/replication/logical/logical.c | 18 ++++++++++++++++++
 2 files changed, 22 insertions(+)

diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index 6f58412bcab..8f9629866c3 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -7310,6 +7310,10 @@ CreateCheckPoint(int flags)
 	if (PriorRedoPtr != InvalidXLogRecPtr)
 		UpdateCheckPointDistanceEstimate(RedoRecPtr - PriorRedoPtr);
 
+#ifdef USE_INJECTION_POINTS
+	INJECTION_POINT("checkpoint-before-old-wal-removal");
+#endif
+
 	/*
 	 * Delete old log files, those no longer needed for last checkpoint to
 	 * prevent the disk holding the xlog from growing full.
diff --git a/src/backend/replication/logical/logical.c b/src/backend/replication/logical/logical.c
index e941bb491d8..569c1925ecc 100644
--- a/src/backend/replication/logical/logical.c
+++ b/src/backend/replication/logical/logical.c
@@ -30,6 +30,7 @@
 
 #include "access/xact.h"
 #include "access/xlogutils.h"
+#include "access/xlog_internal.h"
 #include "fmgr.h"
 #include "miscadmin.h"
 #include "pgstat.h"
@@ -41,6 +42,7 @@
 #include "storage/proc.h"
 #include "storage/procarray.h"
 #include "utils/builtins.h"
+#include "utils/injection_point.h"
 #include "utils/inval.h"
 #include "utils/memutils.h"
 
@@ -1844,9 +1846,13 @@ LogicalConfirmReceivedLocation(XLogRecPtr lsn)
 	{
 		bool		updated_xmin = false;
 		bool		updated_restart = false;
+		XLogRecPtr	restart_lsn;
 
 		SpinLockAcquire(&MyReplicationSlot->mutex);
 
+		/* remember the old restart lsn */
+		restart_lsn = MyReplicationSlot->data.restart_lsn;
+
 		MyReplicationSlot->data.confirmed_flush = lsn;
 
 		/* if we're past the location required for bumping xmin, do so */
@@ -1888,6 +1894,18 @@ LogicalConfirmReceivedLocation(XLogRecPtr lsn)
 		/* first write new xmin to disk, so we know what's up after a crash */
 		if (updated_xmin || updated_restart)
 		{
+#ifdef USE_INJECTION_POINTS
+			XLogSegNo	seg1,
+						seg2;
+
+			XLByteToSeg(restart_lsn, seg1, wal_segment_size);
+			XLByteToSeg(MyReplicationSlot->data.restart_lsn, seg2, wal_segment_size);
+
+			/* trigger injection point, but only if segment changes */
+			if (seg1 != seg2)
+				INJECTION_POINT("logical-replication-slot-advance-segment");
+#endif
+
 			ReplicationSlotMarkDirty();
 			ReplicationSlotSave();
 			elog(DEBUG1, "updated xmin: %u restart: %u", updated_xmin, updated_restart);
-- 
2.47.0



^ permalink  raw  reply  [nested|flat] 14+ messages in thread

* Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly
  2024-10-31 10:18 Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Vitaly Davydov <[email protected]>
  2024-11-20 17:24 ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
  2024-11-20 22:19   ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
  2024-11-21 13:59     ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
  2024-11-21 23:05       ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
@ 2024-12-13 14:34         ` Vitaly Davydov <[email protected]>
  2025-03-03 15:12           ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Vitaly Davydov <[email protected]>
  0 siblings, 1 reply; 14+ messages in thread

From: Vitaly Davydov @ 2024-12-13 14:34 UTC (permalink / raw)
  To: [email protected]

> On 11/21/24 14:59, Tomas Vondra wrote:
>
> I don't have a great idea how to improve this. It seems wrong for
> ReplicationSlotsComputeRequiredLSN() to calculate the LSN using values
> from dirty slots, so maybe it should simply retry if any slot is dirty?
> Or retry on that one slot? But various places update the restart_lsn
> before marking the slot as dirty, so right now this won't work.

To ping the topic, I would like to propose a new version of my patch. All the check-world tests seems to pass ok. 

The idea of the patch is pretty simple - keep flushed restart_lsn in memory and use this value to calculate required lsn in ReplicationSlotsComputeRequiredLSN().

One note - if restart_lsn_flushed is invalid, the restart_lsn value will be used. If we take invalid restart_lsn_flushed instead of valid restart_lsn the slot will be skipped. At the moment I have no other ideas how to deal with invalid restart_lsn_flushed.

With best regards,
Vitaly


Attachments:

  [text/x-patch] 0001-Keep-WAL-segments-by-slot-s-flushed-restart-LSN.patch (6.3K, ../../135e8-675c4600-21-304d7f40@228322535/2-0001-Keep-WAL-segments-by-slot-s-flushed-restart-LSN.patch)
  download | inline diff:
From a6fb33969213e5f5dd994853ac052df64372b85f Mon Sep 17 00:00:00 2001
From: Vitaly Davydov <[email protected]>
Date: Thu, 31 Oct 2024 12:29:12 +0300
Subject: [PATCH 1/2] Keep WAL segments by slot's flushed restart LSN

---
 src/backend/replication/slot.c      | 37 +++++++++++++++++++++++++++++
 src/backend/replication/walsender.c | 13 ++++++++++
 src/include/replication/slot.h      |  4 ++++
 3 files changed, 54 insertions(+)

diff --git a/src/backend/replication/slot.c b/src/backend/replication/slot.c
index 4a206f9527..c3c44fe9f8 100644
--- a/src/backend/replication/slot.c
+++ b/src/backend/replication/slot.c
@@ -409,6 +409,7 @@ ReplicationSlotCreate(const char *name, bool db_specific,
 	slot->candidate_restart_valid = InvalidXLogRecPtr;
 	slot->candidate_restart_lsn = InvalidXLogRecPtr;
 	slot->last_saved_confirmed_flush = InvalidXLogRecPtr;
+	slot->restart_lsn_flushed = InvalidXLogRecPtr;
 	slot->inactive_since = 0;
 
 	/*
@@ -1142,20 +1143,34 @@ ReplicationSlotsComputeRequiredLSN(void)
 	{
 		ReplicationSlot *s = &ReplicationSlotCtl->replication_slots[i];
 		XLogRecPtr	restart_lsn;
+		XLogRecPtr	restart_lsn_flushed;
 		bool		invalidated;
+		ReplicationSlotPersistency persistency;
 
 		if (!s->in_use)
 			continue;
 
 		SpinLockAcquire(&s->mutex);
+		persistency = s->data.persistency;
 		restart_lsn = s->data.restart_lsn;
 		invalidated = s->data.invalidated != RS_INVAL_NONE;
+		restart_lsn_flushed = s->restart_lsn_flushed;
 		SpinLockRelease(&s->mutex);
 
 		/* invalidated slots need not apply */
 		if (invalidated)
 			continue;
 
+		/* truncate WAL for persistent slots by flushed restart_lsn */
+		if (persistency == RS_PERSISTENT)
+		{
+			if (restart_lsn_flushed != InvalidXLogRecPtr &&
+				restart_lsn > restart_lsn_flushed)
+			{
+				restart_lsn = restart_lsn_flushed;
+			}
+		}
+
 		if (restart_lsn != InvalidXLogRecPtr &&
 			(min_required == InvalidXLogRecPtr ||
 			 restart_lsn < min_required))
@@ -1193,7 +1208,9 @@ ReplicationSlotsComputeLogicalRestartLSN(void)
 	{
 		ReplicationSlot *s;
 		XLogRecPtr	restart_lsn;
+		XLogRecPtr	restart_lsn_flushed;
 		bool		invalidated;
+		ReplicationSlotPersistency persistency;
 
 		s = &ReplicationSlotCtl->replication_slots[i];
 
@@ -1207,14 +1224,26 @@ ReplicationSlotsComputeLogicalRestartLSN(void)
 
 		/* read once, it's ok if it increases while we're checking */
 		SpinLockAcquire(&s->mutex);
+		persistency = s->data.persistency;
 		restart_lsn = s->data.restart_lsn;
 		invalidated = s->data.invalidated != RS_INVAL_NONE;
+		restart_lsn_flushed = s->restart_lsn_flushed;
 		SpinLockRelease(&s->mutex);
 
 		/* invalidated slots need not apply */
 		if (invalidated)
 			continue;
 
+		/* truncate WAL for persistent slots by flushed restart_lsn */
+		if (persistency == RS_PERSISTENT)
+		{
+			if (restart_lsn_flushed != InvalidXLogRecPtr &&
+				restart_lsn > restart_lsn_flushed)
+			{
+				restart_lsn = restart_lsn_flushed;
+			}
+		}
+
 		if (restart_lsn == InvalidXLogRecPtr)
 			continue;
 
@@ -1432,6 +1461,7 @@ ReplicationSlotReserveWal(void)
 
 	Assert(slot != NULL);
 	Assert(slot->data.restart_lsn == InvalidXLogRecPtr);
+	Assert(slot->restart_lsn_flushed == InvalidXLogRecPtr);
 
 	/*
 	 * The replication slot mechanism is used to prevent removal of required
@@ -1607,6 +1637,8 @@ InvalidatePossiblyObsoleteSlot(ReplicationSlotInvalidationCause cause,
 		 */
 		SpinLockAcquire(&s->mutex);
 
+		Assert(s->data.restart_lsn >= s->restart_lsn_flushed);
+
 		restart_lsn = s->data.restart_lsn;
 
 		/* we do nothing if the slot is already invalid */
@@ -1691,7 +1723,10 @@ InvalidatePossiblyObsoleteSlot(ReplicationSlotInvalidationCause cause,
 			 * just rely on .invalidated.
 			 */
 			if (invalidation_cause == RS_INVAL_WAL_REMOVED)
+			{
 				s->data.restart_lsn = InvalidXLogRecPtr;
+				s->restart_lsn_flushed = InvalidXLogRecPtr;
+			}
 
 			/* Let caller know */
 			*invalidated = true;
@@ -2189,6 +2224,7 @@ SaveSlotToPath(ReplicationSlot *slot, const char *dir, int elevel)
 	if (!slot->just_dirtied)
 		slot->dirty = false;
 	slot->last_saved_confirmed_flush = cp.slotdata.confirmed_flush;
+	slot->restart_lsn_flushed = cp.slotdata.restart_lsn;
 	SpinLockRelease(&slot->mutex);
 
 	LWLockRelease(&slot->io_in_progress_lock);
@@ -2386,6 +2422,7 @@ RestoreSlotFromDisk(const char *name)
 		slot->effective_xmin = cp.slotdata.xmin;
 		slot->effective_catalog_xmin = cp.slotdata.catalog_xmin;
 		slot->last_saved_confirmed_flush = cp.slotdata.confirmed_flush;
+		slot->restart_lsn_flushed = cp.slotdata.restart_lsn;
 
 		slot->candidate_catalog_xmin = InvalidTransactionId;
 		slot->candidate_xmin_lsn = InvalidXLogRecPtr;
diff --git a/src/backend/replication/walsender.c b/src/backend/replication/walsender.c
index 371eef3ddd..03cdce23f0 100644
--- a/src/backend/replication/walsender.c
+++ b/src/backend/replication/walsender.c
@@ -2329,6 +2329,7 @@ static void
 PhysicalConfirmReceivedLocation(XLogRecPtr lsn)
 {
 	bool		changed = false;
+	XLogRecPtr	restart_lsn_flushed;
 	ReplicationSlot *slot = MyReplicationSlot;
 
 	Assert(lsn != InvalidXLogRecPtr);
@@ -2336,6 +2337,7 @@ PhysicalConfirmReceivedLocation(XLogRecPtr lsn)
 	if (slot->data.restart_lsn != lsn)
 	{
 		changed = true;
+		restart_lsn_flushed = slot->restart_lsn_flushed;
 		slot->data.restart_lsn = lsn;
 	}
 	SpinLockRelease(&slot->mutex);
@@ -2343,6 +2345,17 @@ PhysicalConfirmReceivedLocation(XLogRecPtr lsn)
 	if (changed)
 	{
 		ReplicationSlotMarkDirty();
+
+		/* Save the replication slot on disk in case of its flushed restart_lsn
+		 * is invalid. Slots with invalid restart lsn are ignored when
+		 * calculating required LSN. Once we started to keep the WAL by flushed
+		 * restart LSN, we should save to disk an initial valid value.
+		 */
+		if (slot->data.persistency == RS_PERSISTENT) {
+			if (restart_lsn_flushed == InvalidXLogRecPtr && lsn != InvalidXLogRecPtr)
+				ReplicationSlotSave();
+		}
+
 		ReplicationSlotsComputeRequiredLSN();
 		PhysicalWakeupLogicalWalSnd();
 	}
diff --git a/src/include/replication/slot.h b/src/include/replication/slot.h
index d2cf786fd5..e66248b82d 100644
--- a/src/include/replication/slot.h
+++ b/src/include/replication/slot.h
@@ -211,6 +211,10 @@ typedef struct ReplicationSlot
 	 * recently stopped.
 	 */
 	TimestampTz inactive_since;
+
+	/* Latest restart LSN that was flushed to disk */
+	XLogRecPtr restart_lsn_flushed;
+
 } ReplicationSlot;
 
 #define SlotIsPhysical(slot) ((slot)->data.database == InvalidOid)
-- 
2.34.1



  [text/x-patch] 0002-Fix-src-recovery-t-001_stream_rep.pl-after-changes-i.patch (999B, ../../135e8-675c4600-21-304d7f40@228322535/3-0002-Fix-src-recovery-t-001_stream_rep.pl-after-changes-i.patch)
  download | inline diff:
From f950bb109563ce407a5972abbd2fc931ef18dbeb Mon Sep 17 00:00:00 2001
From: Vitaly Davydov <[email protected]>
Date: Fri, 13 Dec 2024 16:02:14 +0300
Subject: [PATCH 2/2] Fix src/recovery/t/001_stream_rep.pl after changes in
 restart lsn

---
 src/test/recovery/t/001_stream_rep.pl | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/src/test/recovery/t/001_stream_rep.pl b/src/test/recovery/t/001_stream_rep.pl
index f3ea45ac4a..95f61cabfc 100644
--- a/src/test/recovery/t/001_stream_rep.pl
+++ b/src/test/recovery/t/001_stream_rep.pl
@@ -553,6 +553,9 @@ chomp($phys_restart_lsn_post);
 ok( ($phys_restart_lsn_pre cmp $phys_restart_lsn_post) == 0,
 	"physical slot advance persists across restarts");
 
+# Cleanup unused WAL segments
+$node_primary->safe_psql('postgres', "CHECKPOINT;");
+
 # Check if the previous segment gets correctly recycled after the
 # server stopped cleanly, causing a shutdown checkpoint to be generated.
 my $primary_data = $node_primary->data_dir;
-- 
2.34.1



^ permalink  raw  reply  [nested|flat] 14+ messages in thread

* Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly
  2024-10-31 10:18 Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Vitaly Davydov <[email protected]>
  2024-11-20 17:24 ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
  2024-11-20 22:19   ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
  2024-11-21 13:59     ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
  2024-11-21 23:05       ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
  2024-12-13 14:34         ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Vitaly Davydov <[email protected]>
@ 2025-03-03 15:12           ` Vitaly Davydov <[email protected]>
  2025-04-04 03:22             ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Alexander Korotkov <[email protected]>
  0 siblings, 1 reply; 14+ messages in thread

From: Vitaly Davydov @ 2025-03-03 15:12 UTC (permalink / raw)
  To: pgsql-hackers

Dear Hackers,

Let me please introduce a new version of the patch.

Patch description:

The slot data is flushed to the disk at the beginning of checkpoint. If
an existing slot is advanced in the middle of checkpoint execution, its
advanced restart LSN is taken to calculate the oldest LSN for WAL
segments removal at the end of checkpoint. If the node is restarted just
after the checkpoint, the slots data will be read from the disk at
recovery with the oldest restart LSN which can refer to removed WAL
segments.
    
The patch introduces a new in-memory state for slots -
flushed_restart_lsn which is used to calculate the oldest LSN for WAL
segments removal. This state is updated every time with the current
restart_lsn at the moment, when the slot is saving to disk.

With best regards,
Vitaly


Attachments:

  [text/x-patch] 0001-Keep-WAL-segments-by-slot-s-flushed-restart-LSN.patch (5.9K, ../../1538a2-67c5c700-7-77ec5a80@179382871/2-0001-Keep-WAL-segments-by-slot-s-flushed-restart-LSN.patch)
  download | inline diff:
From 480ab108499d95c8befd95911524c4d77cec6e2e Mon Sep 17 00:00:00 2001
From: Vitaly Davydov <[email protected]>
Date: Mon, 3 Mar 2025 17:02:15 +0300
Subject: [PATCH 1/2] Keep WAL segments by slot's flushed restart LSN

The slot data is flushed to the disk at the beginning of checkpoint. If
an existing slot is advanced in the middle of checkpoint execution, its
advanced restart LSN is taken to calculate the oldest LSN for WAL
segments removal at the end of checkpoint. If the node is restarted just
after the checkpoint, the slots data will be read from the disk at
recovery with the oldest restart LSN which can refer to removed WAL
segments.

The patch introduces a new in-memory state for slots -
flushed_restart_lsn which is used to calculate the oldest LSN for WAL
segments removal. This state is updated every time with the current
restart_lsn at the moment, when the slot is saving to disk.
---
 src/backend/replication/slot.c | 41 ++++++++++++++++++++++++++++++++++
 src/include/replication/slot.h |  7 ++++++
 2 files changed, 48 insertions(+)

diff --git a/src/backend/replication/slot.c b/src/backend/replication/slot.c
index 719e531eb90..294418df217 100644
--- a/src/backend/replication/slot.c
+++ b/src/backend/replication/slot.c
@@ -424,6 +424,7 @@ ReplicationSlotCreate(const char *name, bool db_specific,
 	slot->candidate_restart_valid = InvalidXLogRecPtr;
 	slot->candidate_restart_lsn = InvalidXLogRecPtr;
 	slot->last_saved_confirmed_flush = InvalidXLogRecPtr;
+	slot->restart_lsn_flushed = InvalidXLogRecPtr;
 	slot->inactive_since = 0;
 
 	/*
@@ -1165,20 +1166,36 @@ ReplicationSlotsComputeRequiredLSN(void)
 	{
 		ReplicationSlot *s = &ReplicationSlotCtl->replication_slots[i];
 		XLogRecPtr	restart_lsn;
+		XLogRecPtr	restart_lsn_flushed;
 		bool		invalidated;
+		ReplicationSlotPersistency persistency;
 
 		if (!s->in_use)
 			continue;
 
 		SpinLockAcquire(&s->mutex);
+		persistency = s->data.persistency;
 		restart_lsn = s->data.restart_lsn;
 		invalidated = s->data.invalidated != RS_INVAL_NONE;
+		restart_lsn_flushed = s->restart_lsn_flushed;
 		SpinLockRelease(&s->mutex);
 
 		/* invalidated slots need not apply */
 		if (invalidated)
 			continue;
 
+		/* Get the flushed restart_lsn for the persistent slot to compute
+		 * the oldest LSN for WAL segments removals.
+		 */
+		if (persistency == RS_PERSISTENT)
+		{
+			if (restart_lsn_flushed != InvalidXLogRecPtr &&
+				restart_lsn > restart_lsn_flushed)
+			{
+				restart_lsn = restart_lsn_flushed;
+			}
+		}
+
 		if (restart_lsn != InvalidXLogRecPtr &&
 			(min_required == InvalidXLogRecPtr ||
 			 restart_lsn < min_required))
@@ -1216,7 +1233,9 @@ ReplicationSlotsComputeLogicalRestartLSN(void)
 	{
 		ReplicationSlot *s;
 		XLogRecPtr	restart_lsn;
+		XLogRecPtr	restart_lsn_flushed;
 		bool		invalidated;
+		ReplicationSlotPersistency persistency;
 
 		s = &ReplicationSlotCtl->replication_slots[i];
 
@@ -1230,14 +1249,28 @@ ReplicationSlotsComputeLogicalRestartLSN(void)
 
 		/* read once, it's ok if it increases while we're checking */
 		SpinLockAcquire(&s->mutex);
+		persistency = s->data.persistency;
 		restart_lsn = s->data.restart_lsn;
 		invalidated = s->data.invalidated != RS_INVAL_NONE;
+		restart_lsn_flushed = s->restart_lsn_flushed;
 		SpinLockRelease(&s->mutex);
 
 		/* invalidated slots need not apply */
 		if (invalidated)
 			continue;
 
+		/* Get the flushed restart_lsn for the persistent slot to compute
+		 * the oldest LSN for WAL segments removals.
+		 */
+		if (persistency == RS_PERSISTENT)
+		{
+			if (restart_lsn_flushed != InvalidXLogRecPtr &&
+				restart_lsn > restart_lsn_flushed)
+			{
+				restart_lsn = restart_lsn_flushed;
+			}
+		}
+
 		if (restart_lsn == InvalidXLogRecPtr)
 			continue;
 
@@ -1455,6 +1488,7 @@ ReplicationSlotReserveWal(void)
 
 	Assert(slot != NULL);
 	Assert(slot->data.restart_lsn == InvalidXLogRecPtr);
+	Assert(slot->restart_lsn_flushed == InvalidXLogRecPtr);
 
 	/*
 	 * The replication slot mechanism is used to prevent removal of required
@@ -1766,6 +1800,8 @@ InvalidatePossiblyObsoleteSlot(uint32 possible_causes,
 		 */
 		SpinLockAcquire(&s->mutex);
 
+		Assert(s->data.restart_lsn >= s->restart_lsn_flushed);
+
 		restart_lsn = s->data.restart_lsn;
 
 		/* we do nothing if the slot is already invalid */
@@ -1835,7 +1871,10 @@ InvalidatePossiblyObsoleteSlot(uint32 possible_causes,
 			 * just rely on .invalidated.
 			 */
 			if (invalidation_cause == RS_INVAL_WAL_REMOVED)
+			{
 				s->data.restart_lsn = InvalidXLogRecPtr;
+				s->restart_lsn_flushed = InvalidXLogRecPtr;
+			}
 
 			/* Let caller know */
 			*invalidated = true;
@@ -2354,6 +2393,7 @@ SaveSlotToPath(ReplicationSlot *slot, const char *dir, int elevel)
 	if (!slot->just_dirtied)
 		slot->dirty = false;
 	slot->last_saved_confirmed_flush = cp.slotdata.confirmed_flush;
+	slot->restart_lsn_flushed = cp.slotdata.restart_lsn;
 	SpinLockRelease(&slot->mutex);
 
 	LWLockRelease(&slot->io_in_progress_lock);
@@ -2569,6 +2609,7 @@ RestoreSlotFromDisk(const char *name)
 		slot->effective_xmin = cp.slotdata.xmin;
 		slot->effective_catalog_xmin = cp.slotdata.catalog_xmin;
 		slot->last_saved_confirmed_flush = cp.slotdata.confirmed_flush;
+		slot->restart_lsn_flushed = cp.slotdata.restart_lsn;
 
 		slot->candidate_catalog_xmin = InvalidTransactionId;
 		slot->candidate_xmin_lsn = InvalidXLogRecPtr;
diff --git a/src/include/replication/slot.h b/src/include/replication/slot.h
index f5a24ccfbf2..b04d2401d6e 100644
--- a/src/include/replication/slot.h
+++ b/src/include/replication/slot.h
@@ -215,6 +215,13 @@ typedef struct ReplicationSlot
 	 * recently stopped.
 	 */
 	TimestampTz inactive_since;
+
+	/* Latest restart_lsn that has been flushed to disk. For persistent slots
+	 * the flushed LSN should be taken into account when calculating the oldest
+	 * LSN for WAL segments removal.
+	 */
+	XLogRecPtr restart_lsn_flushed;
+
 } ReplicationSlot;
 
 #define SlotIsPhysical(slot) ((slot)->data.database == InvalidOid)
-- 
2.34.1



  [text/x-patch] 0002-Fix-src-recovery-t-001_stream_rep.pl.patch (971B, ../../1538a2-67c5c700-7-77ec5a80@179382871/3-0002-Fix-src-recovery-t-001_stream_rep.pl.patch)
  download | inline diff:
From 2413ab4468b94280d19316b203848912ed6d713f Mon Sep 17 00:00:00 2001
From: Vitaly Davydov <[email protected]>
Date: Fri, 13 Dec 2024 16:02:14 +0300
Subject: [PATCH 2/2] Fix src/recovery/t/001_stream_rep.pl

---
 src/test/recovery/t/001_stream_rep.pl | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/src/test/recovery/t/001_stream_rep.pl b/src/test/recovery/t/001_stream_rep.pl
index ee57d234c86..eae9d00b9b4 100644
--- a/src/test/recovery/t/001_stream_rep.pl
+++ b/src/test/recovery/t/001_stream_rep.pl
@@ -553,6 +553,9 @@ chomp($phys_restart_lsn_post);
 ok( ($phys_restart_lsn_pre cmp $phys_restart_lsn_post) == 0,
 	"physical slot advance persists across restarts");
 
+# Cleanup unused WAL segments
+$node_primary->safe_psql('postgres', "CHECKPOINT;");
+
 # Check if the previous segment gets correctly recycled after the
 # server stopped cleanly, causing a shutdown checkpoint to be generated.
 my $primary_data = $node_primary->data_dir;
-- 
2.34.1



^ permalink  raw  reply  [nested|flat] 14+ messages in thread

* Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly
  2024-10-31 10:18 Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Vitaly Davydov <[email protected]>
  2024-11-20 17:24 ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
  2024-11-20 22:19   ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
  2024-11-21 13:59     ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
  2024-11-21 23:05       ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
  2024-12-13 14:34         ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Vitaly Davydov <[email protected]>
  2025-03-03 15:12           ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Vitaly Davydov <[email protected]>
@ 2025-04-04 03:22             ` Alexander Korotkov <[email protected]>
  0 siblings, 0 replies; 14+ messages in thread

From: Alexander Korotkov @ 2025-04-04 03:22 UTC (permalink / raw)
  To: Vitaly Davydov <[email protected]>; +Cc: pgsql-hackers

Hi, Vitaly!

On Mon, Mar 3, 2025 at 5:12 PM Vitaly Davydov <[email protected]> wrote:
> The slot data is flushed to the disk at the beginning of checkpoint. If
> an existing slot is advanced in the middle of checkpoint execution, its
> advanced restart LSN is taken to calculate the oldest LSN for WAL
> segments removal at the end of checkpoint. If the node is restarted just
> after the checkpoint, the slots data will be read from the disk at
> recovery with the oldest restart LSN which can refer to removed WAL
> segments.
>
> The patch introduces a new in-memory state for slots -
> flushed_restart_lsn which is used to calculate the oldest LSN for WAL
> segments removal. This state is updated every time with the current
> restart_lsn at the moment, when the slot is saving to disk.

Thank you for your work on this subject.   I think generally your
approach is correct.  When we're truncating the WAL log, we need to
reply on the position that would be used in the case of server crush.
That is the position flushed to the disk.

While your patch is generality looks good, I'd like make following notes:

1) As ReplicationSlotsComputeRequiredLSN() is called each time we need
to advance the position of WAL needed by replication slots, the usage
pattern probably could be changed.  Thus, we probably need to call
ReplicationSlotsComputeRequiredLSN() somewhere after change of
restart_lsn_flushed while restart_lsn is not changed.  And probably
can skip ReplicationSlotsComputeRequiredLSN() in some cases when only
restart_lsn is changed.
2) I think it's essential to include into the patch test caches which
fail without patch.  You could start from integrating [1] test into
your patch, and then add more similar tests for different situations.

Links.
1.  https://www.postgresql.org/message-id/e3ac0535-e7a2-4a96-9b36-9f765e9cfec5%40vondra.me

------
Regards,
Alexander Korotkov
Supabase





^ permalink  raw  reply  [nested|flat] 14+ messages in thread

* Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly
  2024-10-31 10:18 Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Vitaly Davydov <[email protected]>
@ 2025-07-02 17:20 ` vignesh C <[email protected]>
  2025-07-18 10:43   ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Alexander Korotkov <[email protected]>
  2 siblings, 1 reply; 14+ messages in thread

From: vignesh C @ 2025-07-02 17:20 UTC (permalink / raw)
  To: Hayato Kuroda (Fujitsu) <[email protected]>; +Cc: Amit Kapila <[email protected]>; Alexander Korotkov <[email protected]>; Vitaly Davydov <[email protected]>; Tom Lane <[email protected]>; Alexander Lakhin <[email protected]>; pgsql-hackers; Masahiko Sawada <[email protected]>; [email protected] <[email protected]>

On Sun, 29 Jun 2025 at 11:52, Hayato Kuroda (Fujitsu)
<[email protected]> wrote:
>
> Dear hackers,
>
> Thanks everyone who are working on the bug. IIUC the remained task is
> to add code comments for avoiding the same mistake again described here:
>
> > Sounds reasonable. As per analysis till now, it seems removal of new
> > assert is correct and we just need to figure out the reason in all
> > failure cases as to why the physical slot's restart_lsn goes backward,
> > and then add a comment somewhere to ensure that we don't repeat a
> > similar mistake in the future.
>
> I've wrote a draft for that. How do you think?

I analyzed a scenario involving physical replication where the
restart_lsn appears to go backward by fewer files:
In my case, current restart_lsn = 0/A721E68, which corresponds to a
WAL record in the file 00000001000000000000000A. However, the recovery
process is progressing slowly and is currently at 0/3058078.
Now when the primary_conninfo is changed the walsender/walreceiver
process will be restarted. As a result, the standby starts requesting
WAL streaming from 0/3058078 the last applied wal lsn, which is in the
file 000000010000000000000003.

Since this WAL segment (000000010000000000000003) has already been
removed due to the restart_lsn being far ahead, the primary throws an
error saying WAL segment is removed. Even though the apply pointer is
at 0/3058078 (the record currently being applied), the standby already
has WAL segments up to 0/A721E68 written and available locally. So,
despite the walsender process failing to start due to missing
segments, the recovery process on the standby continues applying WAL
up to 0/A721E68 using the locally available files (including
00000001000000000000000A). Once all local WAL has been applied, the
standby will attempt to start streaming again—this time using the
latest WAL record (in my case, 0/A74000). Since this record still
exists on the primary, the walsender process starts successfully, and
physical replication resumes normally.

This confirms that even in physical replication, a backward-moving
restart_lsn does not cause issues as the standby retains the necessary
WAL locally and can catch up without requiring removed segments from
the primary.

I was able to reproduce this scenario using the
physical_replication_restart_lsn_backward patch attached, here I have
changed to increase the checkpoint to happen frequently and slowed the
recovery process to apply the wal records with delays. For me I was
able to reproduce this on every run. The logs for the same are
attached in the logs.zip file and test used to reproduce this is
available at test_restart_lsn_backward.zip file:

Important log information from the attached logs:
Restart_lsn has moved to 0/A6E8000 in the primary node:
2025-07-02 22:34:44.563 IST walsender[330205] standby1 LOG:
PhysicalConfirmReceivedLocation replication slot "sb1_slot" set
restart_lsn to 0/A6E8000
2025-07-02 22:34:44.563 IST walsender[330205] standby1 STATEMENT:
START_REPLICATION SLOT "sb1_slot" 0/3000000 TIMELINE 1

When the walsender is restarted, it will request a older WAL which has
been removed and throw an error:
2025-07-02 22:34:44.577 IST walsender[330428] standby1 STATEMENT:
START_REPLICATION SLOT "sb1_slot" 0/3000000 TIMELINE 1
2025-07-02 22:34:44.577 IST walsender[330428] standby1 ERROR:
requested WAL segment 000000010000000000000003 has already been
removed

Standby node has written WAL upto 0/A6E8000:
2025-07-02 22:34:44.563 IST walreceiver[330204] LOG:  XLogWalRcvFlush
LogstreamResult.Flush initialized to 0/A6E8000
2025-07-02 22:34:44.563 IST walreceiver[330204] LOG:  sending write
0/A6E8000 flush 0/A6E8000 apply 0/

Walreceiver process terminated:
2025-07-02 22:34:44.564 IST walreceiver[330204] FATAL:  terminating
walreceiver process due to administrator command

Walreceiver requests wal from 000000010000000000000003 WAL file which
is removed:
2025-07-02 22:34:44.577 IST walreceiver[330427] LOG:  started
streaming WAL from primary at 0/3000000 on timeline 1
2025-07-02 22:34:44.577 IST walreceiver[330427] LOG:  WalReceiverMain
LogstreamResult.Flush initialized to 0/3047958
2025-07-02 22:34:44.577 IST walreceiver[330427] LOG:  sending write
0/3047958 flush 0/3047958 apply 0/3047958
2025-07-02 22:34:44.577 IST walreceiver[330427] FATAL:  could not
receive data from WAL stream: ERROR:  requested WAL segment
000000010000000000000003 has already been removed

Even though the WAL file is removed there is no issue, recovery
process applies the WAL from locally available WAL file:
2025-07-02 22:34:44.578 IST startup[330195] LOG:  Applied wal record
end rec 0/3047990, read rec 0/3047958
2025-07-02 22:34:44.580 IST checkpointer[330193] LOG:  recovery
restart point at 0/3047938

Once all the available WAL's are applied the walsender is started
again and replication proceeds smoothly:
2025-07-02 22:35:15.002 IST walsender[330922] standby1 LOG:  received
replication command: START_REPLICATION SLOT "sb1_slot" 0/A000000
TIMELINE 1
2025-07-02 22:35:15.002 IST walsender[330922] standby1 STATEMENT:
START_REPLICATION SLOT "sb1_slot" 0/A000000 TIMELINE 1

I'm ok with adding the comments.

Regards,
Vignesh


Attachments:

  [application/octet-stream] physical_replication_restart_lsn_backward.patch (7.3K, ../../CALDaNm1u=QV1a7w48BWgkg6GnK20eE_y+raL43D46_R9Wnt8wg@mail.gmail.com/2-physical_replication_restart_lsn_backward.patch)
  download | inline diff:
diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index 47ffc0a2307..6e325db45d4 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -6836,6 +6836,7 @@ ShutdownXLOG(int code, Datum arg)
 static void
 LogCheckpointStart(int flags, bool restartpoint)
 {
+	#if 0
 	if (restartpoint)
 		ereport(LOG,
 		/* translator: the placeholders show checkpoint options */
@@ -6860,6 +6861,7 @@ LogCheckpointStart(int flags, bool restartpoint)
 						(flags & CHECKPOINT_CAUSE_XLOG) ? " wal" : "",
 						(flags & CHECKPOINT_CAUSE_TIME) ? " time" : "",
 						(flags & CHECKPOINT_FLUSH_ALL) ? " flush-all" : "")));
+	#endif
 }
 
 /*
@@ -6909,6 +6911,7 @@ LogCheckpointEnd(bool restartpoint)
 			CheckpointStats.ckpt_sync_rels;
 	average_msecs = (long) ((average_sync_time + 999) / 1000);
 
+	#if 0
 	/*
 	 * ControlFileLock is not required to see ControlFile->checkPoint and
 	 * ->checkPointCopy here as we are the only updator of those variables at
@@ -6962,6 +6965,7 @@ LogCheckpointEnd(bool restartpoint)
 						(int) (CheckPointDistanceEstimate / 1024.0),
 						LSN_FORMAT_ARGS(ControlFile->checkPoint),
 						LSN_FORMAT_ARGS(ControlFile->checkPointCopy.redo))));
+	#endif
 }
 
 /*
@@ -7160,6 +7164,7 @@ CreateCheckPoint(int flags)
 	if ((flags & (CHECKPOINT_IS_SHUTDOWN | CHECKPOINT_END_OF_RECOVERY |
 				  CHECKPOINT_FORCE)) == 0)
 	{
+		#if 0
 		if (last_important_lsn == ControlFile->checkPoint)
 		{
 			END_CRIT_SECTION();
@@ -7167,6 +7172,7 @@ CreateCheckPoint(int flags)
 					(errmsg_internal("checkpoint skipped because system is idle")));
 			return false;
 		}
+		#endif
 	}
 
 	/*
diff --git a/src/backend/access/transam/xlogrecovery.c b/src/backend/access/transam/xlogrecovery.c
index 6ce979f2d8b..f09f53df4c5 100644
--- a/src/backend/access/transam/xlogrecovery.c
+++ b/src/backend/access/transam/xlogrecovery.c
@@ -1918,6 +1918,8 @@ ApplyWalRecord(XLogReaderState *xlogreader, XLogRecord *record, TimeLineID *repl
 {
 	ErrorContextCallback errcallback;
 	bool		switchedTLI = false;
+	static int count = 0;
+	count++;
 
 	/* Setup error traceback support for ereport() */
 	errcallback.callback = rm_redo_error_callback;
@@ -2009,7 +2011,13 @@ ApplyWalRecord(XLogReaderState *xlogreader, XLogRecord *record, TimeLineID *repl
 
 	/* Pop the error context stack */
 	error_context_stack = errcallback.previous;
-
+	pg_usleep(1000L);
+	if (count > 1000)
+	pg_usleep(1000L);
+		
+	elog(LOG, "Applied wal record end rec %X/%X, read rec %X/%X",
+			LSN_FORMAT_ARGS(xlogreader->EndRecPtr),
+			LSN_FORMAT_ARGS(xlogreader->ReadRecPtr));
 	/*
 	 * Update lastReplayedEndRecPtr after this record has been successfully
 	 * replayed.
@@ -3640,6 +3648,7 @@ WaitForWALToBecomeAvailable(XLogRecPtr RecPtr, bool randAccess,
 					if (StandbyMode && CheckForStandbyTrigger())
 					{
 						XLogShutdownWalRcv();
+						elog(LOG, "returning fail vignesh1");
 						return XLREAD_FAIL;
 					}
 
@@ -3648,7 +3657,10 @@ WaitForWALToBecomeAvailable(XLogRecPtr RecPtr, bool randAccess,
 					 * and pg_wal.
 					 */
 					if (!StandbyMode)
+					{
+						elog(LOG, "returning fail vignesh2");
 						return XLREAD_FAIL;
+					}
 
 					/*
 					 * Move to XLOG_FROM_STREAM state, and set to start a
@@ -3870,6 +3882,8 @@ WaitForWALToBecomeAvailable(XLogRecPtr RecPtr, bool randAccess,
 						}
 						curFileTLI = tli;
 						SetInstallXLogFileSegmentActive();
+						elog(LOG, "vignesh request to start streaming from primary at %X/%X on timeline %u",
+							 LSN_FORMAT_ARGS(ptr), curFileTLI);
 						RequestXLogStreaming(tli, ptr, PrimaryConnInfo,
 											 PrimarySlotName,
 											 wal_receiver_create_temp_slot);
diff --git a/src/backend/postmaster/checkpointer.c b/src/backend/postmaster/checkpointer.c
index fda91ffd1ce..885d17ebde7 100644
--- a/src/backend/postmaster/checkpointer.c
+++ b/src/backend/postmaster/checkpointer.c
@@ -345,7 +345,7 @@ CheckpointerMain(const void *startup_data, size_t startup_data_len)
 	 */
 	for (;;)
 	{
-		bool		do_checkpoint = false;
+		bool		do_checkpoint = true;
 		int			flags = 0;
 		pg_time_t	now;
 		int			elapsed_secs;
@@ -573,11 +573,14 @@ CheckpointerMain(const void *startup_data, size_t startup_data_len)
 				continue;		/* no sleep for us ... */
 			cur_timeout = Min(cur_timeout, XLogArchiveTimeout - elapsed_secs);
 		}
+		pg_usleep(1000L);
 
+		#if 0
 		(void) WaitLatch(MyLatch,
 						 WL_LATCH_SET | WL_TIMEOUT | WL_EXIT_ON_PM_DEATH,
 						 cur_timeout * 1000L /* convert to ms */ ,
 						 WAIT_EVENT_CHECKPOINTER_MAIN);
+		#endif
 	}
 
 	/*
diff --git a/src/backend/replication/walreceiver.c b/src/backend/replication/walreceiver.c
index 8c4d0fd9aed..ea9168071f0 100644
--- a/src/backend/replication/walreceiver.c
+++ b/src/backend/replication/walreceiver.c
@@ -396,6 +396,9 @@ WalReceiverMain(const void *startup_data, size_t startup_data_len)
 
 			/* Initialize LogstreamResult and buffers for processing messages */
 			LogstreamResult.Write = LogstreamResult.Flush = GetXLogReplayRecPtr(NULL);
+			elog(LOG, "WalReceiverMain LogstreamResult.Flush initialized to %X/%X",
+				 LSN_FORMAT_ARGS(LogstreamResult.Flush));
+
 			initStringInfo(&reply_message);
 
 			/* Initialize nap wakeup times. */
@@ -848,6 +851,8 @@ XLogWalRcvProcessMsg(unsigned char type, char *buf, Size len, TimeLineID tli)
 				buf += hdrlen;
 				len -= hdrlen;
 				XLogWalRcvWrite(buf, len, dataStart, tli);
+				elog(LOG, "XLogWalRcvProcessMsg: wrote %zu bytes of WAL at %X/%X",
+					 len, LSN_FORMAT_ARGS(dataStart));
 				break;
 			}
 		case 'k':				/* Keepalive */
@@ -960,6 +965,8 @@ XLogWalRcvWrite(char *buf, Size nbytes, XLogRecPtr recptr, TimeLineID tli)
 		buf += byteswritten;
 
 		LogstreamResult.Write = recptr;
+		elog(LOG, "XLogWalRcvFlush LogstreamResult.Write set to %X/%X",
+			 LSN_FORMAT_ARGS(LogstreamResult.Write));
 	}
 
 	/* Update shared-memory status */
@@ -994,6 +1001,9 @@ XLogWalRcvFlush(bool dying, TimeLineID tli)
 
 		LogstreamResult.Flush = LogstreamResult.Write;
 
+		elog(LOG, "XLogWalRcvFlush LogstreamResult.Flush initialized to %X/%X",
+			 LSN_FORMAT_ARGS(LogstreamResult.Flush));
+
 		/* Update shared-memory status */
 		SpinLockAcquire(&walrcv->mutex);
 		if (walrcv->flushedUpto < LogstreamResult.Flush)
@@ -1138,7 +1148,7 @@ XLogWalRcvSendReply(bool force, bool requestReply)
 	pq_sendbyte(&reply_message, requestReply ? 1 : 0);
 
 	/* Send it */
-	elog(DEBUG2, "sending write %X/%X flush %X/%X apply %X/%X%s",
+	elog(LOG, "sending write %X/%X flush %X/%X apply %X/%X%s",
 		 LSN_FORMAT_ARGS(writePtr),
 		 LSN_FORMAT_ARGS(flushPtr),
 		 LSN_FORMAT_ARGS(applyPtr),
diff --git a/src/backend/replication/walsender.c b/src/backend/replication/walsender.c
index f2c33250e8b..3192581cb4c 100644
--- a/src/backend/replication/walsender.c
+++ b/src/backend/replication/walsender.c
@@ -2377,7 +2377,14 @@ PhysicalConfirmReceivedLocation(XLogRecPtr lsn)
 	if (slot->data.restart_lsn != lsn)
 	{
 		changed = true;
+
+		if (lsn < slot->data.restart_lsn)
+			elog(LOG, "crash scenario - slot %s, cannot confirm a restart LSN (%X/%X) that is older than the current one (%X/%X)",
+				 NameStr(slot->data.name), LSN_FORMAT_ARGS(lsn), LSN_FORMAT_ARGS(slot->data.restart_lsn));
+
 		slot->data.restart_lsn = lsn;
+		elog(LOG, "PhysicalConfirmReceivedLocation replication slot \"%s\" set restart_lsn to %X/%X",
+			 NameStr(slot->data.name), LSN_FORMAT_ARGS(slot->data.restart_lsn));
 	}
 	SpinLockRelease(&slot->mutex);
 


  [application/x-zip-compressed] test_restart_lsn_backward.zip (1.2K, ../../CALDaNm1u=QV1a7w48BWgkg6GnK20eE_y+raL43D46_R9Wnt8wg@mail.gmail.com/3-test_restart_lsn_backward.zip)
  download

  [application/x-zip-compressed] logs.zip (320.3K, ../../CALDaNm1u=QV1a7w48BWgkg6GnK20eE_y+raL43D46_R9Wnt8wg@mail.gmail.com/4-logs.zip)
  download

^ permalink  raw  reply  [nested|flat] 14+ messages in thread

* Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly
  2024-10-31 10:18 Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Vitaly Davydov <[email protected]>
  2025-07-02 17:20 ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly vignesh C <[email protected]>
@ 2025-07-18 10:43   ` Alexander Korotkov <[email protected]>
  0 siblings, 0 replies; 14+ messages in thread

From: Alexander Korotkov @ 2025-07-18 10:43 UTC (permalink / raw)
  To: vignesh C <[email protected]>; +Cc: Hayato Kuroda (Fujitsu) <[email protected]>; Amit Kapila <[email protected]>; Vitaly Davydov <[email protected]>; Tom Lane <[email protected]>; Alexander Lakhin <[email protected]>; pgsql-hackers; Masahiko Sawada <[email protected]>; [email protected] <[email protected]>

On Wed, Jul 2, 2025 at 8:20 PM vignesh C <[email protected]> wrote:
> On Sun, 29 Jun 2025 at 11:52, Hayato Kuroda (Fujitsu)
> <[email protected]> wrote:
> >
> > Dear hackers,
> >
> > Thanks everyone who are working on the bug. IIUC the remained task is
> > to add code comments for avoiding the same mistake again described here:
> >
> > > Sounds reasonable. As per analysis till now, it seems removal of new
> > > assert is correct and we just need to figure out the reason in all
> > > failure cases as to why the physical slot's restart_lsn goes backward,
> > > and then add a comment somewhere to ensure that we don't repeat a
> > > similar mistake in the future.
> >
> > I've wrote a draft for that. How do you think?
>
> I analyzed a scenario involving physical replication where the
> restart_lsn appears to go backward by fewer files:

This is indeed an interesting case.  But does restart_lsn go so much
backwards in this case?  I've checked the logs.  It looks like standby
requested a position several segments back, but restart_lsn keeps
increasing.

> I'm ok with adding the comments.

Thank you for your feedback!

------
Regards,
Alexander Korotkov
Supabase





^ permalink  raw  reply  [nested|flat] 14+ messages in thread

* Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly
  2024-10-31 10:18 Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Vitaly Davydov <[email protected]>
@ 2025-07-18 10:44 ` Alexander Korotkov <[email protected]>
  2025-07-18 10:48   ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Amit Kapila <[email protected]>
  2 siblings, 1 reply; 14+ messages in thread

From: Alexander Korotkov @ 2025-07-18 10:44 UTC (permalink / raw)
  To: Hayato Kuroda (Fujitsu) <[email protected]>; +Cc: Amit Kapila <[email protected]>; Vitaly Davydov <[email protected]>; vignesh C <[email protected]>; Tom Lane <[email protected]>; Alexander Lakhin <[email protected]>; pgsql-hackers; Masahiko Sawada <[email protected]>; [email protected] <[email protected]>

On Sun, Jun 29, 2025 at 9:22 AM Hayato Kuroda (Fujitsu)
<[email protected]> wrote:
> Thanks everyone who are working on the bug. IIUC the remained task is
> to add code comments for avoiding the same mistake again described here:
>
> > Sounds reasonable. As per analysis till now, it seems removal of new
> > assert is correct and we just need to figure out the reason in all
> > failure cases as to why the physical slot's restart_lsn goes backward,
> > and then add a comment somewhere to ensure that we don't repeat a
> > similar mistake in the future.
>
> I've wrote a draft for that. How do you think?

Looks good to me.  I'm going to push this if no objections.

------
Regards,
Alexander Korotkov
Supabase





^ permalink  raw  reply  [nested|flat] 14+ messages in thread

* Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly
  2024-10-31 10:18 Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Vitaly Davydov <[email protected]>
  2025-07-18 10:44 ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Alexander Korotkov <[email protected]>
@ 2025-07-18 10:48   ` Amit Kapila <[email protected]>
  2025-07-18 11:41     ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Alexander Korotkov <[email protected]>
  0 siblings, 1 reply; 14+ messages in thread

From: Amit Kapila @ 2025-07-18 10:48 UTC (permalink / raw)
  To: Alexander Korotkov <[email protected]>; +Cc: Hayato Kuroda (Fujitsu) <[email protected]>; Vitaly Davydov <[email protected]>; vignesh C <[email protected]>; Tom Lane <[email protected]>; Alexander Lakhin <[email protected]>; pgsql-hackers; Masahiko Sawada <[email protected]>; [email protected] <[email protected]>

On Fri, Jul 18, 2025 at 4:15 PM Alexander Korotkov <[email protected]> wrote:
>
> On Sun, Jun 29, 2025 at 9:22 AM Hayato Kuroda (Fujitsu)
> <[email protected]> wrote:
> > Thanks everyone who are working on the bug. IIUC the remained task is
> > to add code comments for avoiding the same mistake again described here:
> >
> > > Sounds reasonable. As per analysis till now, it seems removal of new
> > > assert is correct and we just need to figure out the reason in all
> > > failure cases as to why the physical slot's restart_lsn goes backward,
> > > and then add a comment somewhere to ensure that we don't repeat a
> > > similar mistake in the future.
> >
> > I've wrote a draft for that. How do you think?
>
> Looks good to me.  I'm going to push this if no objections.
>

As discussed earlier, it is a good idea to add comments in this area.
But as this is for pre-existing cases, won't it be better to start a
new thread explaining the cases and a patch? We may get feedback from
others as well.

-- 
With Regards,
Amit Kapila.





^ permalink  raw  reply  [nested|flat] 14+ messages in thread

* Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly
  2024-10-31 10:18 Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Vitaly Davydov <[email protected]>
  2025-07-18 10:44 ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Alexander Korotkov <[email protected]>
  2025-07-18 10:48   ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Amit Kapila <[email protected]>
@ 2025-07-18 11:41     ` Alexander Korotkov <[email protected]>
  0 siblings, 0 replies; 14+ messages in thread

From: Alexander Korotkov @ 2025-07-18 11:41 UTC (permalink / raw)
  To: Amit Kapila <[email protected]>; +Cc: Hayato Kuroda (Fujitsu) <[email protected]>; Vitaly Davydov <[email protected]>; vignesh C <[email protected]>; Tom Lane <[email protected]>; Alexander Lakhin <[email protected]>; pgsql-hackers; Masahiko Sawada <[email protected]>; [email protected] <[email protected]>

On Fri, Jul 18, 2025 at 1:48 PM Amit Kapila <[email protected]> wrote:
> On Fri, Jul 18, 2025 at 4:15 PM Alexander Korotkov <[email protected]> wrote:
> >
> > On Sun, Jun 29, 2025 at 9:22 AM Hayato Kuroda (Fujitsu)
> > <[email protected]> wrote:
> > > Thanks everyone who are working on the bug. IIUC the remained task is
> > > to add code comments for avoiding the same mistake again described here:
> > >
> > > > Sounds reasonable. As per analysis till now, it seems removal of new
> > > > assert is correct and we just need to figure out the reason in all
> > > > failure cases as to why the physical slot's restart_lsn goes backward,
> > > > and then add a comment somewhere to ensure that we don't repeat a
> > > > similar mistake in the future.
> > >
> > > I've wrote a draft for that. How do you think?
> >
> > Looks good to me.  I'm going to push this if no objections.
> >
>
> As discussed earlier, it is a good idea to add comments in this area.
> But as this is for pre-existing cases, won't it be better to start a
> new thread explaining the cases and a patch? We may get feedback from
> others as well.

OK, done.

https://www.postgresql.org/message-id/CAPpHfdvuyMrUg0Vs5jPfwLOo1M9B-GP5j_My9URnBX0B%3DnrHKw%40mail.g...

------
Regards,
Alexander Korotkov
Supabase





^ permalink  raw  reply  [nested|flat] 14+ messages in thread


end of thread, other threads:[~2025-07-18 11:41 UTC | newest]

Thread overview: 14+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2020-11-20 02:48 [PATCH 1/3] bootstrap: convert Typ to a List* Justin Pryzby <[email protected]>
2024-10-31 10:18 Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Vitaly Davydov <[email protected]>
2024-11-20 17:24 ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
2024-11-20 22:19   ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
2024-11-21 13:59     ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
2024-11-21 23:05       ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Tomas Vondra <[email protected]>
2024-12-13 14:34         ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Vitaly Davydov <[email protected]>
2025-03-03 15:12           ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Vitaly Davydov <[email protected]>
2025-04-04 03:22             ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Alexander Korotkov <[email protected]>
2025-07-02 17:20 ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly vignesh C <[email protected]>
2025-07-18 10:43   ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Alexander Korotkov <[email protected]>
2025-07-18 10:44 ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Alexander Korotkov <[email protected]>
2025-07-18 10:48   ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Amit Kapila <[email protected]>
2025-07-18 11:41     ` Re: Slot's restart_lsn may point to removed WAL segment after hard restart unexpectedly Alexander Korotkov <[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