Re: PostgreSQL archiving last replayed WAL after recovery

Hello,

I'm wondering about PostgreSQL always archiving the last replayed WAL
after getting out of recovery. This does not seem to be documented
anywhere, and this part of code is quite tricky to understand.
IMHO, PostgreSQL should not try to archive again WAL files coming from
the restore_command.
Is this a wanted behaviour ?

It's quite easy to reproduce by making a pg_basebackup of a test cluster
and configuring the second cluster in recovery mode. In my example, I
didn't produce some activity to add some WAL between the hotbackup and
the recovery, but PostgreSQL is only trying to archive the last replayed
WAL. Test is done with 9.2.4.

Here's the log file of the recovered cluster :
LOG: database system was interrupted; last known up at 2013-04-22
11:17:33 CEST
LOG: creating missing WAL directory "pg_xlog/archive_status"
LOG: starting archive recovery
LOG: restored log file "000000010000000000000036" from archive
LOG: redo starts at 0/36000020
LOG: consistent recovery state reached at 0/360000E0
LOG: database system is ready to accept read only connections
cp: impossible d'?valuer
<</home/thomas/postgresql/v92/archives/000000010000000000000037>>: Aucun
fichier ou dossier de ce type
LOG: could not open file "pg_xlog/000000010000000000000037" (log file
0, segment 55): Aucun fichier ou dossier de ce type
LOG: redo done at 0/360000E0
LOG: restored log file "000000010000000000000036" from archive
cp: impossible d'?valuer
<</home/thomas/postgresql/v92/archives/00000002.history>>: Aucun fichier
ou dossier de ce type
LOG: selected new timeline ID: 2
cp: impossible d'?valuer
<</home/thomas/postgresql/v92/archives/00000001.history>>: Aucun fichier
ou dossier de ce type
LOG: archive recovery complete
LOG: checkpoint starting: end-of-recovery immediate wait
LOG: checkpoint complete: wrote 0 buffers (0.0%); 0 transaction log
file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.000 s,
total=0.329 s; sync files=0, longest=0.000 s, average=0.000 s
LOG: database system is ready to accept connections
LOG: autovacuum launcher started
-- WAL 000000010000000000000036 archived --
-- WAL 00000002.history archived --
LOG: received smart shutdown request
LOG: autovacuum launcher shutting down
LOG: shutting down
-- WAL 000000020000000000000037 archived --

Btw, my archive_command was archive_command = 'cp -i %p
/home/thomas/postgresql/v92/archives2/%f </dev/null && echo "-- WAL %f
archived --"', thus the "-- WAL ... archived --" messages.

Also, the archives2 directory contains the following files - the
directory was empty before :
thomas(at)laptop:~/postgresql/v92/archives2$ ls
000000010000000000000036 00000002.history 000000020000000000000037

Also, I wonder why the message "restored log file
"000000010000000000000036" from archive" appears two time during the
recovery. Is this WAL really replayed twice ?

Thanks,
Thomas

I'm having the same problem. In my case, and as recommended in the official
documentation, my archive command checks that the file exists first, before
archiving it:After a successful recovery, the last WAL file replayed from
the base archive is still in the pg_xlog directory, so when it tries to
archive it, it fails:Is this a expected behaviour? Or should the px_log
directory be cleaned-up again on recovery_end_command ?Cheers

--
View this message in context: http://postgresql.1045698.n5.nabble.com/PostgreSQL-archiving-last-replayed-WAL-after-recovery-tp5752831p5762234.html
Sent from the PostgreSQL - general mailing list archive at Nabble.com.