problems after restoring from a pg_basebackup

On Fri, 2012-04-27 at 16:25 -0700, Lonni J Friedman wrote:

Greetings,
I'm running postgresql-9.1.3 on a Linux-x86_64 (Fedora16, if it
matters) system. I noticed the existence of pg_basebackup starting in
9.1, and figured I'd try it out and see if it would simplify our
backup & management processes.

$ pg_basebackup -P -v -D /tmp/backup -x -Ft -z -U postgres
xlog start point: C6/64000020
135733616/135733616 kB (100%), 1/1 tablespace
xlog end point: C6/640000A0
pg_basebackup: base backup completed

So after running through this, I tried to use (restore) the backup
that was generated. While everything appears to be working ok from a
functional perspective, in the server log I saw the following:
######
LOG: creating missing WAL directory "pg_xlog/archive_status"
LOG: database system was not properly shut down; automatic recovery in progress
LOG: redo starts at C6/66000078
LOG: could not open file "pg_xlog/00000001000000C600000067" (log file
198, segment 103): No such file or directory
LOG: redo done at C6/660000A0
FATAL: the database system is starting up
LOG: autovacuum launcher started
LOG: database system is ready to accept connections
#####

Just to be clear, here's what I did after pg_basebackup had completed
successfully:
0) shutdown postgresql gracefully, and verified that it was fully shutdown
1) moved $PGDATA to $PGDATA.old
2) created $PGDATA as postgres user
3) extracted the basebackup tarball as postgres user
cd $PGDATA && tar xzvpf /tmp/backup/base.tar.gz
4) started postgresql up

I would have expected that I wouldn't have gotten the 'not properly
shutdown' warning, or the 'could not open file' warning by following
this process. Am I doing something wrong?

No, I think you did right. The first error message is right: you didn't
stop PostgreSQL. You were right not to stop it, but PostgreSQL is right
to say that it wasn't stopped, and that it has to replay some logs (if
there was some activity during the backup). The second error message
says that this specific wal file is not available and thus it has
nothing more to replay. Seems good to me.

--
Guillaume
http://blog.guillaume.lelarge.info
http://www.dalibo.com

Lonni J Friedman wrote:

I'm running postgresql-9.1.3 on a Linux-x86_64 (Fedora16, if it
matters) system. I noticed the existence of pg_basebackup starting in
9.1, and figured I'd try it out and see if it would simplify our
backup & management processes.

$ pg_basebackup -P -v -D /tmp/backup -x -Ft -z -U postgres
xlog start point: C6/64000020
135733616/135733616 kB (100%), 1/1 tablespace
xlog end point: C6/640000A0
pg_basebackup: base backup completed

So after running through this, I tried to use (restore) the backup
that was generated. While everything appears to be working ok from a
functional perspective, in the server log I saw the following:
######
LOG: creating missing WAL directory "pg_xlog/archive_status"
LOG: database system was not properly shut down; automatic recovery in progress
LOG: redo starts at C6/66000078
LOG: could not open file "pg_xlog/00000001000000C600000067" (log file
198, segment 103): No such file or directory
LOG: redo done at C6/660000A0
FATAL: the database system is starting up
LOG: autovacuum launcher started
LOG: database system is ready to accept connections
#####

Just to be clear, here's what I did after pg_basebackup had completed
successfully:
0) shutdown postgresql gracefully, and verified that it was fully shutdown
1) moved $PGDATA to $PGDATA.old
2) created $PGDATA as postgres user
3) extracted the basebackup tarball as postgres user
cd $PGDATA && tar xzvpf /tmp/backup/base.tar.gz
4) started postgresql up

I would have expected that I wouldn't have gotten the 'not properly
shutdown' warning, or the 'could not open file' warning by following
this process. Am I doing something wrong?

From what you quote it looks like everything went well and as expected.

An online backup is not a consistent state of the database, so WAL
files will have to be applied to recover the database. See
http://www.postgresql.org/docs/current/static/continuous-archiving.html#BACKUP-PITR-RECOVERY

Your method worked because you used the -x flag to copy WAL files
along with the backup. You were lucky because all the necessary WAL
files were still there (see the note in pg_basebackup's
documentation).

If there is activity on the database while you take your backup and
wal_keep_segments is not high enough, you method will not work.
In general, you should also copy the archived WAL files and follow
the procedure in the above link to restore the database.

Yours,
Laurenz Albe