Postgresql - Point in Time recovery using recovery.conf and trigger. How to minimize the time waiting for .history files

Question

Following http://www.postgresql.org/docs/9.1/static/continuous-archiving.html, I copy the WAL archives to another machine and apply them regularly. Recently due to pg server crash at my main server I tried to restore the database by pushing a trigger (an empty file, expecting smart failover) and the logs are given below.

prodrestore_error.log

WAL file not present yet. Checking for trigger file...
trigger file found: smart failover
Trigger file:         /app/recovery-prod/trigger/pgsql.trigger.5432
Waiting for WAL file: 0000000100000001000000CC
WAL file path:        /backup/prod/db_backup/archive/0000000100000001000000CC
Restoring to:         pg_xlog/RECOVERYXLOG
Sleep interval:       60 seconds
Max wait interval:    0 forever
Command for restore:  cp "/backup/prod/db_backup/archive/0000000100000001000000CC" "pg_xlog/RECOVERYXLOG"
Keep archive history: 000000000000000000000000 and later
trigger file found: smart failover
running restore:      OK

Trigger file:         /app/recovery-prod/trigger/pgsql.trigger.5432
Waiting for WAL file: 00000002.history
WAL file path:        /backup/prod/db_backup/archive/00000002.history
Restoring to:         pg_xlog/RECOVERYHISTORY
Sleep interval:       60 seconds
Max wait interval:    0 forever
Command for restore:  cp "/backup/prod/db_backup/archive/00000002.history" "pg_xlog/RECOVERYHISTORY"
Keep archive history: 000000000000000000000000 and later
running restore:      cp: cannot stat `/backup/prod/db_backup/archive/00000002.history': No such file or directory
cp: cannot stat `/backup/prod/db_backup/archive/00000002.history': No such file or directory
cp: cannot stat `/backup/prod/db_backup/archive/00000002.history': No such file or directory
cp: cannot stat `/backup/prod/db_backup/archive/00000002.history': No such file or directory
not restored
history file not found
Trigger file:         /app/recovery-prod/trigger/pgsql.trigger.5432
Waiting for WAL file: 00000001.history
WAL file path:        /backup/prod/db_backup/archive/00000001.history
Restoring to:         pg_xlog/RECOVERYHISTORY
Sleep interval:       60 seconds
Max wait interval:    0 forever
Command for restore:  cp "/backup/prod/db_backup/archive/00000001.history" "pg_xlog/RECOVERYHISTORY"
Keep archive history: 000000000000000000000000 and later
running restore:      cp: cannot stat `/backup/prod/db_backup/archive/00000001.history': No such file or directory
cp: cannot stat `/backup/prod/db_backup/archive/00000001.history': No such file or directory
cp: cannot stat `/backup/prod/db_backup/archive/00000001.history': No such file or directory
cp: cannot stat `/backup/prod/db_backup/archive/00000001.history': No such file or directory
not restored
history file not found

postgresql-9.1-main.log

2015-08-03 08:08:44 IST::@:[5542]:LOG:  restored log file "0000000100000001000000CC" from archive
2015-08-03 08:11:44 IST::@:[5542]:LOG:  could not open file "pg_xlog/0000000100000001000000CD" (log file 1, segment 205): No such file or directory
2015-08-03 08:11:44 IST::@:[5542]:LOG:  redo done at 1/CC001E10
2015-08-03 08:11:44 IST::@:[5542]:LOG:  last completed transaction was at log time 2015-08-03 07:59:58.121908+05:30
2015-08-03 08:11:44 IST::@:[5542]:LOG:  restored log file "0000000100000001000000CC" from archive
2015-08-03 08:17:44 IST::@:[5542]:LOG:  selected new timeline ID: 2
2015-08-03 08:23:45 IST::@:[5542]:LOG:  archive recovery complete
2015-08-03 08:23:51 IST::@:[6088]:LOG:  autovacuum launcher started
2015-08-03 08:23:51 IST::@:[5541]:LOG:  database system is ready to accept connections

The whole process of looking for two history files 00000002.history and 00000001.history, 4 times and finally start the database took approximately 12 minutes. Then each repeat iteration by restoring a base backup fresh took more time as it started looking for more .history files.

How I can make this as fast to look for history files and if not present proceed quickly to start database in read/write mode ? Else, not to look for history files at all.

Answer 1

That's not the fault of the history files.

Quoting from the documentation link you referenced:

Normally, recovery will proceed through all available WAL segments, thereby restoring the database to the current point in time (or as close as possible given the available WAL segments). Therefore, a normal recovery will end with a "file not found" message, the exact text of the error message depending upon your choice of restore_command. You may also see an error message at the start of recovery for a file named something like 00000001.history. This is also normal and does not indicate a problem in simple recovery situations; see Section 24.3.4 for discussion

Since it looks like you're using pg_standby, you have a few options.

1. Adjust -r maxretries and -s sleeptime.

   By default -r maxretries is 3, and since it looks like you have the -s sleeptime setting set to 60, it will wait 60 seconds on the first retry, then 120 seconds on the second retry, then 180 seconds on the third and final retry of the copy command before it gives up and brings the replica server up into standalone mode.

   So, in addition to replaying all the logs, at the end when the command is trying to copy the .history files, you're waiting a grand total of 360 seconds, or six minutes, plus the time it takes to restore all your WAL segments under smart mode.

2. Do a fast failover instead of a smart failover.

   If you're desperate to fail over quickly, and can stand the loss of any unapplied WAL segments, you can do a fast failover instead of the smart failover you're triggering, as referenced in the pg_standby documentation here.

   The merits of smart failover versus fast failover depend on how fast you want to get your replica server going and how much tolerance you have for lost transactions.

   Fast failover ignores unapplied WAL segments and as such, the transactions are lost. Smart failover replays all the WAL segments it possibly can before bringing up the replica in standalone mode. This can take a long time depending on how many WAL segments you need to replay.

Finally, since you're on 9.1, you could use streaming replication along with a restore_command in your recovery.conf to keep the server even more up to date than the standard log shipping can, by streaming individual WAL records as they are produced.

Additionally, if the replica can't keep up with the streaming load (due to network issues or any number of things), it can alternately use a restore_command to grab WAL segments from the archive you already have set up.

You can't use pg_standby for the restore_command though.

In theory, since there is little if no delay restoring WAL records if all is going well, instead of restoring full WAL segments, your replica should come up in standalone mode much faster.

An example of streaming replication plus archiving in action can be found here:

http://evol-monkey.blogspot.com/2014/09/offsite-replication-problems-and-how-to.html

It is also useful to monitor your replication lag to make sure that everything is as up to date as your requirements dictate. Examples of that are here:

http://www.keithf4.com/monitoring_streaming_slave_lag/

Hope that helps. =)