Postgres HA (based on WAL-shipping) fails

Question

Hi. I'm hoping someone can help me a WAL-shipping and warm standby issue. My standby system runs happily for weeks, then all of a sudden it starts looking for .history files that don't exist. It then craps out and I can't successfully restart it without rebuilding the standby.

Both systems are running CentOS 4.5 and postgres 8.4.1. They use NFS to store WAL files from production on the standby.

A relevant chunk of the log, with my comments:

[** Recovery is running normally **]

Trigger file            : /tmp/pgsql.trigger
Waiting for WAL file    : 00000001000000830000005B
WAL file path           : /var/tafkan_backup_from_db1/00000001000000830000005B
Restoring to            : pg_xlog/RECOVERYXLOG
Sleep interval          : 2 seconds
Max wait interval       : 0 forever
Command for restore     : cp "/var/tafkan_backup_from_db1/00000001000000830000005B" "pg_xlog/RECOVERYXLOG"
Keep archive history    : 00000001000000830000004D and later
WAL file not present yet. Checking for trigger file...
WAL file not present yet. Checking for trigger file...
WAL file not present yet. Checking for trigger file...
running restore         : OK

Trigger file            : /tmp/pgsql.trigger
Waiting for WAL file    : 00000001000000830000005B
WAL file path           : /var/tafkan_backup_from_db1/00000001000000830000005B
Restoring to            : pg_xlog/RECOVERYXLOG
Sleep interval          : 2 seconds
Max wait interval       : 0 forever
Command for restore     : cp "/var/tafkan_backup_from_db1/00000001000000830000005B" "pg_xlog/RECOVERYXLOG"
Keep archive history    : 000000000000000000000000 and later
running restore         : OK

[** All of a sudden it starts looks for .history files **]

Trigger file            : /tmp/pgsql.trigger
Waiting for WAL file    : 00000002.history
WAL file path           : /var/tafkan_backup_from_db1/00000002.history
Restoring to            : pg_xlog/RECOVERYHISTORY
Sleep interval          : 2 seconds
Max wait interval       : 0 forever
Command for restore     : cp "/var/tafkan_backup_from_db1/00000002.history" "pg_xlog/RECOVERYHISTORY"
Keep archive history    : 000000000000000000000000 and later
running restore         :cp: cannot stat `/var/tafkan_backup_from_db1/00000002.history': No such file or directory
cp: cannot stat `/var/tafkan_backup_from_db1/00000002.history': No such file or directory
cp: cannot stat `/var/tafkan_backup_from_db1/00000002.history': No such file or directory
cp: cannot stat `/var/tafkan_backup_from_db1/00000002.history': No such file or directory
not restored
history file not found
Trigger file            : /tmp/pgsql.trigger
Waiting for WAL file    : 00000001.history
WAL file path           : /var/tafkan_backup_from_db1/00000001.history
Restoring to            : pg_xlog/RECOVERYHISTORY
Sleep interval          : 2 seconds
Max wait interval       : 0 forever
Command for restore     : cp "/var/tafkan_backup_from_db1/00000001.history" "pg_xlog/RECOVERYHISTORY"
Keep archive history    : 000000000000000000000000 and later
running restore         :cp: cannot stat `/var/tafkan_backup_from_db1/00000001.history': No such file or directory
cp: cannot stat `/var/tafkan_backup_from_db1/00000001.history': No such file or directory
cp: cannot stat `/var/tafkan_backup_from_db1/00000001.history': No such file or directory
cp: cannot stat `/var/tafkan_backup_from_db1/00000001.history': No such file or directory
not restored
history file not found

[** I stopped Postgres, renamed recovery.done to recovery.conf, and restarted it. **]

Trigger file            : /tmp/pgsql.trigger
Waiting for WAL file    : 00000002.history
WAL file path           : /var/tafkan_backup_from_db1/00000002.history
Restoring to            : pg_xlog/RECOVERYHISTORY
Sleep interval          : 2 seconds
Max wait interval       : 0 forever
Command for restore     : cp "/var/tafkan_backup_from_db1/00000002.history" "pg_xlog/RECOVERYHISTORY"
Keep archive history    : 000000000000000000000000 and later
running restore         :cp: cannot stat `/var/tafkan_backup_from_db1/00000002.history': No such file or directory
cp: cannot stat `/var/tafkan_backup_from_db1/00000002.history': No such file or directory
cp: cannot stat `/var/tafkan_backup_from_db1/00000002.history': No such file or directory
cp: cannot stat `/var/tafkan_backup_from_db1/00000002.history': No such file or directory
not restored
history file not found
Trigger file            : /tmp/pgsql.trigger
Waiting for WAL file    : 0000000200000083000000A2
WAL file path           : /var/tafkan_backup_from_db1/0000000200000083000000A2
Restoring to            : pg_xlog/RECOVERYXLOG
Sleep interval          : 2 seconds
Max wait interval       : 0 forever
Command for restore     : cp "/var/tafkan_backup_from_db1/0000000200000083000000A2" "pg_xlog/RECOVERYXLOG"
Keep archive history    : 000000000000000000000000 and later
WAL file not present yet. Checking for trigger file...
WAL file not present yet. Checking for trigger file...
WAL file not present yet. Checking for trigger file...
WAL file not present yet. Checking for trigger file...

[** This file is not present. All WAL files start with 00000001. **] 

Any ideas? I don't even know what .history files are, and the (mostly excellent) documentation is not very clear on any of this.

PS. I wish I was running VMs so I could use link text and not have to worry about any of this application-level HA nonsense :-)

Update: Here are some of the logs from the standby server at about this time. It looks like something made the server stop recovering and come online, but I don't know what. I'm pretty certain that nothing could have created the trigger file.

2010-01-20 03:30:15 EST 4b3a5c63.401b LOG:  restored log file "00000001000000830000005A" from archive
2010-01-20 03:30:23 EST 4b3a5c63.401b LOG:  restored log file "00000001000000830000005B" from archive
2010-01-20 03:30:23 EST 4b3a5c63.401b LOG:  record with zero length at 83/5BFA2FF8
2010-01-20 03:30:23 EST 4b3a5c63.401b LOG:  redo done at 83/5BFA2FAC
2010-01-20 03:30:23 EST 4b3a5c63.401b LOG:  last completed transaction was at log time 2010-01-20 03:28:04.594399-05
2010-01-20 03:30:25 EST 4b3a5c63.401b LOG:  restored log file "00000001000000830000005B" from archive
2010-01-20 03:30:37 EST 4b3a5c63.401b LOG:  selected new timeline ID: 2
2010-01-20 03:30:49 EST 4b3a5c63.401b LOG:  archive recovery complete
2010-01-20 03:30:59 EST 4b3a5c62.4019 LOG:  database system is ready to accept connections

Answer 1

A totally different approach for HA might be to host the PG database on a DRBD device shared between the two machines.

Answer 2

Did you use your own recovery script/program? If yes - please don't do it. Use pg_standby from PostgreSQL contrib.

Otherwise - just ignore the .history files.

Answer 3

Your replicated copy came online at some point. "00000002.history" is looking for a history file for timeline 00000002, whereas the rest of your logs start with 00000001, which is the original timeline.

I would check your PostgreSQL logs right before it started looking for the history file to see if there's any indication the DB came online, even for a moment.