Re: Use of backup_label not noted in log

Hi,

On 2023-11-20 17:30:31 +0900, Michael Paquier wrote:
> On Sat, Nov 18, 2023 at 01:49:15PM -0800, Andres Freund wrote:
> > Note that the LSN in the "continuing" case is the one the backup started at,
> > not where recovery will start.
> >
> > I've wondered whether it's worth also adding an explicit message just after
> > ReachedEndOfBackup(), but it seems far less urgent due to the existing
> > "consistent recovery state reached at %X/%X" message.
>
> Upgrading the surrounding DEBUG1 to a LOG is another option, but I
> agree that I've seen less that as being an actual problem in the field
> compared to the famous I-removed-a-backup-label-and-I-m-still-up,
> until this user sees signs of corruption after recovery was finished,
> sometimes days after putting back an instance online.

"end of backup reached" could scare users, it doesn't obviously indicate
something "good". "completed backup recovery, started at %X/%X" or such would
be better imo.

> + if (ControlFile->backupStartPoint != InvalidXLogRecPtr)
> + ereport(LOG,
> + (errmsg("continuing to start from base backup with redo LSN %X/%X",
> + LSN_FORMAT_ARGS(ControlFile->backupStartPoint))));
>
> "Continuing to start" sounds a bit weird to me, though, considering
> that there are a few LOGs that say "starting" when there is a signal
> file, but I don't have a better idea on top of my mind. So that
> sounds OK here.

I didn't like it much either - but I like David's proposal in his sibling
reply:

LOG: starting backup recovery with redo LSN A/34100028, checkpoint LSN A/34100080 on timeline ID 1
LOG: restarting backup recovery with redo LSN A/34100028
and adding the message from above:
LOG: completing backup recovery with redo LSN A/34100028

Greetings,

Andres Freund