Attempt to re-archive existing WAL logs after restoring from backup - Mailing list pgsql-admin

Hello.

I've been testing my DB backup and restore procedure and I've run into
something I can't figure out. After recovering from a PITR backup, when
I do another pg_start_backup PostgreSQL attempts to re-archive the last
log again, which fails because it already exists in the archive. I'm
running the Ubuntu 7.04 version of PostgreSQL 8.2.4. Here's an example
log interspersed with what I was doing in the gaps (sorry for posting
the whole thing; I'm new to PostgreSQL so I'm not sure what's
significant and what isn't):

--------
2007-05-29 02:18:33 UTC LOG:  archived transaction log file
"000000010000000000000012"
2007-05-29 02:18:34 UTC LOG:  incomplete startup packet
2007-05-29 02:18:34 UTC LOG:  received fast shutdown request
2007-05-29 02:18:34 UTC LOG:  shutting down
2007-05-29 02:18:34 UTC LOG:  database system is shut down

Deleted data directory and restored from base backup. Restarted DB:

2007-05-29 02:20:33 UTC LOG:  could not load root certificate file
"root.crt": no SSL error reported
2007-05-29 02:20:33 UTC DETAIL:  Will not verify client certificates.
2007-05-29 02:20:33 UTC LOG:  database system was interrupted at
2007-05-29 02:16:06 UTC
2007-05-29 02:20:33 UTC LOG:  starting archive recovery
2007-05-29 02:20:33 UTC LOG:  restore_command =
"/usr/local/sbin/xlogrestore %f %p"
2007-05-29 02:20:33 UTC LOG:  incomplete startup packet
2007-05-29 02:20:34 UTC LOG:  restored log file
"000000010000000000000011.000118A0.backup" from archive
2007-05-29 02:20:34 UTC FATAL:  the database system is starting up
2007-05-29 02:20:34 UTC FATAL:  the database system is starting up
2007-05-29 02:20:35 UTC LOG:  restored log file
"000000010000000000000011" from archive
2007-05-29 02:20:35 UTC LOG:  checkpoint record is at 0/110118A0
2007-05-29 02:20:35 UTC LOG:  redo record is at 0/110118A0; undo record
is at 0/0; shutdown FALSE
2007-05-29 02:20:35 UTC LOG:  next transaction ID: 0/975; next OID: 24576
2007-05-29 02:20:35 UTC LOG:  next MultiXactId: 1; next MultiXactOffset: 0
2007-05-29 02:20:35 UTC LOG:  automatic recovery in progress
2007-05-29 02:20:35 UTC LOG:  redo starts at 0/110118E8
2007-05-29 02:20:35 UTC FATAL:  the database system is starting up
2007-05-29 02:20:35 UTC LOG:  restored log file
"000000010000000000000012" from archive
2007-05-29 02:20:36 UTC FATAL:  the database system is starting up
2007-05-29 02:20:36 UTC LOG:  could not open file
"pg_xlog/000000010000000000000013" (log file 0, segment 19): No such
file or directory
2007-05-29 02:20:36 UTC LOG:  redo done at 0/120000C8
2007-05-29 02:20:36 UTC FATAL:  the database system is starting up
2007-05-29 02:20:37 UTC FATAL:  the database system is starting up
2007-05-29 02:20:37 UTC FATAL:  the database system is starting up
2007-05-29 02:20:38 UTC FATAL:  the database system is starting up
2007-05-29 02:20:38 UTC FATAL:  the database system is starting up
2007-05-29 02:20:39 UTC FATAL:  the database system is starting up
2007-05-29 02:20:39 UTC FATAL:  the database system is starting up
2007-05-29 02:20:39 UTC LOG:  incomplete startup packet
2007-05-29 02:20:39 UTC LOG:  restored log file
"000000010000000000000012" from archive
2007-05-29 02:20:39 UTC LOG:  archive recovery complete
2007-05-29 02:20:40 UTC LOG:  database system is ready

SELECT pg_switch_xlog(); (It doesn't make any difference if I do this
command or not)

2007-05-29 02:22:04 UTC LOG:  archived transaction log file
"000000010000000000000013"

SELECT pg_start_backup('testbackup');


gzip: stdout: Broken pipe
2007-05-29 02:22:46 UTC LOG:  archive command
"/usr/local/sbin/xlogarchive pg_xlog/000000010000000000000012
000000010000000000000012" failed: return code 256

gzip: stdout: Broken pipe
2007-05-29 02:22:48 UTC LOG:  archive command
"/usr/local/sbin/xlogarchive pg_xlog/000000010000000000000012
000000010000000000000012" failed: return code 256

gzip: stdout: Broken pipe
2007-05-29 02:22:50 UTC LOG:  archive command
"/usr/local/sbin/xlogarchive pg_xlog/000000010000000000000012
000000010000000000000012" failed: return code 256
2007-05-29 02:22:50 UTC WARNING:  transaction log file
"000000010000000000000012" could not be archived: too many failures
--------

Thanks for any advice.

--
Jon