Обсуждение: 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@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:
View this message in context: Re: PostgreSQL archiving last replayed WAL after recovery
Sent from the PostgreSQL - general mailing list archive at Nabble.com.
archive_command = 'test ! -f /ORA/dbs02/PGTEST/archive/%f && cp %p /ORA/dbs02/PGTEST/archive/%f'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:
LOG: database system was interrupted; last known up at 2013-07-02 14:53:37 CEST LOG: creating missing WAL directory "pg_xlog/archive_status" LOG: starting point-in-time recovery to 2013-07-02 15:20:12+02 LOG: restored log file "000000010000000000000002" from archive LOG: redo starts at 0/2000020 LOG: consistent recovery state reached at 0/20023D0 LOG: restored log file "000000010000000000000003" from archive LOG: recovery stopping before commit of transaction 4063, time 2013-07-02 15:20:12.211559+02 LOG: redo done at 0/306D8B8 LOG: last completed transaction was at log time 2013-07-02 15:20:11.189978+02 cp: cannot stat `/ORA/dbs02/PGTEST/archive/00000002.history': No such file or directory LOG: selected new timeline ID: 2 cp: cannot stat `/ORA/dbs02/PGTEST/archive/00000001.history': No such file or directory LOG: archive recovery complete LOG: autovacuum launcher started LOG: database system is ready to accept connections LOG: archive command failed with exit code 1 DETAIL: The failed archive command was: test ! -f /ORA/dbs02/PGTEST/archive/000000010000000000000003 && cp pg_xlog/000000010000000000000003 /ORA/dbs02/PGTEST/archive/000000010000000000000003 LOG: archive command failed with exit code 1 DETAIL: The failed archive command was: test ! -f /ORA/dbs02/PGTEST/archive/000000010000000000000003 && cp pg_xlog/000000010000000000000003 /ORA/dbs02/PGTEST/archive/000000010000000000000003 LOG: archive command failed with exit code 1 DETAIL: The failed archive command was: test ! -f /ORA/dbs02/PGTEST/archive/000000010000000000000003 && cp pg_xlog/000000010000000000000003 /ORA/dbs02/PGTEST/archive/000000010000000000000003 WARNING: transaction log file "000000010000000000000003" could not be archived: too many failuresIs this a expected behaviour? Or should the px_log directory be cleaned-up again on recovery_end_command ? Cheers
View this message in context: Re: PostgreSQL archiving last replayed WAL after recovery
Sent from the PostgreSQL - general mailing list archive at Nabble.com.