BUG #19897: Recovery fails after "LOG: consistent recovery state reached"

From: PG Bug reporting form <noreply(at)postgresql(dot)org>
To: pgsql-bugs(at)lists(dot)postgresql(dot)org
Cc: harukat(at)sraoss(dot)co(dot)jp
Subject: BUG #19897: Recovery fails after "LOG: consistent recovery state reached"
Date: 2026-11-12 15:08:29
Message-ID: 19897-60cf65e39604f958@postgresql.org
Views: Whole Thread | Raw Message | Download mbox | Resend email
Thread:
Lists: pgsql-bugs

The following bug has been logged on the website:

Bug reference: 19897
Logged by: Haruka Takatsuka
Email address: harukat(at)sraoss(dot)co(dot)jp
PostgreSQL version: 15.0
Operating system: Linux
Description:

When using the following procedure to recover a base backup taken from a
standby,
the service would sometimes fail to start up with log messages in the
following strange sequence:

LOG: consistent recovery state reached at ...
LOG: invalid record length at ...
FATAL: recovery ended before configured recovery target was reached
LOG: database system is ready to accept read-only connections
LOG: startup process (PID 1234) exited with exit code 1

The base backup had the same result after repeated attempts.

(recovery steps)
$ rm -f data/15.5reco/log/*
$ rm data/15.5reco/standby.signal
$ touch data/15.5reco/recovery.signal
$ cat >> data/15.5reco/postgresql.conf <<EOS
recovery_target = 'immediate'
restore_command = 'false' ## mimics not to be able to get valid wal and
history
recovery_target_action = 'pause'

EOS

$ pg_ctl start -D data/15.5reco
pg_ctl: could not start server

$ cat data/15.5/reco/log/*
2026-11-10 16:16:55.811 JST [3810] LOG: starting PostgreSQL 15.5 on
x86_64-pc-linux-gnu, compiled by gcc (GCC) 14.3.1 20250617 (Red Hat
14.3.1-2), 64-bit
2026-11-10 16:16:55.812 JST [3810] LOG: listening on IPv6 address "::1",
port 5434
2026-11-10 16:16:55.812 JST [3810] LOG: listening on IPv4 address
"127.0.0.1", port 5434
2026-11-10 16:16:55.817 JST [3810] LOG: listening on Unix socket
"/tmp/.s.PGSQL.5434"
2026-11-10 16:16:55.822 JST [3814] LOG: database system was interrupted
while in recovery at log time 2026-09-24 09:40:18 JST
2026-11-10 16:16:55.822 JST [3814] HINT: If this has occurred more than
once some data might be corrupted and you might need to choose an earlier
recovery target.
2026-11-10 16:16:56.448 JST [3814] LOG: starting point-in-time recovery to
earliest consistent point
2026-11-10 16:16:56.458 JST [3814] LOG: redo starts at 0/12000028
2026-11-10 16:16:56.963 JST [3814] LOG: consistent recovery state reached
at 0/1470A6B0
2026-11-10 16:16:56.963 JST [3814] LOG: invalid record length at
0/1470A6B0: wanted 24, got 0
2026-11-10 16:16:56.963 JST [3814] LOG: redo done at 0/1470A678 system
usage: CPU: user: 0.00 s, system: 0.40 s, elapsed: 0.50 s
2026-11-10 16:16:56.963 JST [3814] LOG: last completed transaction was at
log time 2026-09-24 09:42:16.241123+09
2026-11-10 16:16:56.963 JST [3814] FATAL: recovery ended before configured
recovery target was reached
2026-11-10 16:16:56.963 JST [3810] LOG: database system is ready to accept
read-only connections
2026-11-10 16:16:56.965 JST [3810] LOG: startup process (PID 3814) exited
with exit code 1
2026-11-10 16:16:56.965 JST [3810] LOG: terminating any other active server
processes
2026-11-10 16:16:56.965 JST [3810] LOG: shutting down due to startup
process failure
2026-11-10 16:16:56.967 JST [3810] LOG: database system is shut down

When I checked the source code, I found that recoveryStopsAfter() returned
false
at the condition "if (rmid != RM_XACT_ID) return false;" before reaching
the condition "if (recoveryTarget == RECOVERY_TARGET_IMMEDIATE &&
reachedConsistency)".

After modifying the order of decisions as follows, I can now boot from the
same backup properly.
It looks like all PostgreSQL branches have the same problem.

diff --git a/src/backend/access/transam/xlogrecovery.c
b/src/backend/access/transam/xlogrecovery.c
index 52ac6d58423..796226efad4 100644
--- a/src/backend/access/transam/xlogrecovery.c
+++ b/src/backend/access/transam/xlogrecovery.c
@@ -2789,6 +2789,20 @@ recoveryStopsAfter(XLogReaderState *record)
return true;
}

+ /* Check if we should stop as soon as reaching consistency */
+ if (recoveryTarget == RECOVERY_TARGET_IMMEDIATE &&
reachedConsistency)
+ {
+ ereport(LOG,
+ (errmsg("recovery stopping after reaching
consistency")));
+
+ recoveryStopAfter = true;
+ recoveryStopXid = InvalidTransactionId;
+ recoveryStopTime = 0;
+ recoveryStopLSN = InvalidXLogRecPtr;
+ recoveryStopName[0] = '\0';
+ return true;
+ }
+
if (rmid != RM_XACT_ID)
return false;

@@ -2867,20 +2881,6 @@ recoveryStopsAfter(XLogReaderState *record)
}
}

- /* Check if we should stop as soon as reaching consistency */
- if (recoveryTarget == RECOVERY_TARGET_IMMEDIATE &&
reachedConsistency)
- {
- ereport(LOG,
- (errmsg("recovery stopping after reaching
consistency")));
-
- recoveryStopAfter = true;
- recoveryStopXid = InvalidTransactionId;
- recoveryStopTime = 0;
- recoveryStopLSN = InvalidXLogRecPtr;
- recoveryStopName[0] = '\0';
- return true;
- }
-
return false;
}

Responses

Browse pgsql-bugs by date

  From Date Subject
Next Message Tom Lane 2026-11-12 15:22:41 Re: BUG #19834: eager aggregation still evaluates volatile join clauses when the volatile function is inside a SubPl
Previous Message zengman 2026-11-12 14:50:10 Re: BUG #19625: SQL/JSON boolean DEFAULT expression silently replaced with 'false'