Re: PG 9.3 Switch streaming to wal shipping

On 09/29/2014 05:16 PM, Adrian Klaver wrote:
> On 09/29/2014 02:17 PM, Andy Colson wrote:
>> Crap! Is this a problem?!
>>
>> I switched back to cp, all was going well, here are some logs:
>>
>> Sep 29 16:07:10 webserv postgres[17735]: [590-1] ,,2014-09-29
>> 16:07:10.888 CDT,: LOG: restored log file "00000002000000B900000023"
>> from archive
>> Sep 29 16:07:13 webserv postgres[17734]: [3-1] ,,2014-09-29 16:07:13.971
>> CDT,: LOG: received fast shutdown request
>> Sep 29 16:07:13 webserv postgres[17734]: [4-1] ,,2014-09-29 16:07:13.971
>> CDT,: LOG: aborting any active transactions
>> Sep 29 16:07:13 webserv postgres[17739]: [2-1] ,,2014-09-29 16:07:13.995
>> CDT,: LOG: shutting down
>> Sep 29 16:07:13 webserv postgres[17739]: [3-1] ,,2014-09-29 16:07:13.995
>> CDT,: LOG: database system is shut down
>>
>> So it was at 00000002000000B900000023.
>>
>> I switched recovery.conf to:
>>
>> restore_command = '/usr/local/pg93/bin/pg_standby -d /pub/archive %f %p
>> 2>>/tmp/standby.log'
>>
>> and restart PG. PG log shows:
>> Sep 29 16:08:56 webserv postgres[19054]: [2-1] ,,2014-09-29 16:08:56.002
>> CDT,: LOG: database system was shut down in recovery at 2014-09-29
>> 16:07:13 CDT
>> Sep 29 16:08:56 webserv postgres[19054]: [3-1] ,,2014-09-29 16:08:56.002
>> CDT,: LOG: entering standby mode
>> Sep 29 16:08:56 webserv postgres[19054]: [4-1] ,,2014-09-29 16:08:56.017
>> CDT,: LOG: restored log file "00000002.history" from archive
>> Sep 29 16:08:56 webserv postgres[19054]: [5-1] ,,2014-09-29 16:08:56.042
>> CDT,: LOG: restored log file "00000002000000B900000015" from archive
>>
>> I was at 23! Did it really replay 15? How bad is that?
>> /tmp/standby.log makes no sense at all:
>>
>> Trigger file: <not set>
>> Waiting for WAL file: 00000002.history
>> WAL file path: /pub/archive/00000002.history
>> Restoring to: pg_xlog/RECOVERYHISTORY
>> Sleep interval: 5 seconds
>> Max wait interval: 0 forever
>> Command for restore: cp "/pub/archive/00000002.history"
>> "pg_xlog/RECOVERYHISTORY"
>> Keep archive history: no cleanup required
>> running restore: OK
>> Trigger file: <not set>
>> Waiting for WAL file: 00000002000000B900000015
>> WAL file path: /pub/archive/00000002000000B900000015
>> Restoring to: pg_xlog/RECOVERYXLOG
>> Sleep interval: 5 seconds
>> Max wait interval: 0 forever
>> Command for restore: cp "/pub/archive/00000002000000B900000015"
>> "pg_xlog/RECOVERYXLOG"
>> Keep archive history: no cleanup required
>> running restore: OK
>> Trigger file: <not set>
>> Waiting for WAL file: 00000002000000B900000006
>> WAL file path: /pub/archive/00000002000000B900000006
>> Restoring to: pg_xlog/RECOVERYXLOG
>> Sleep interval: 5 seconds
>> Max wait interval: 0 forever
>> Command for restore: cp "/pub/archive/00000002000000B900000006"
>> "pg_xlog/RECOVERYXLOG"
>> Keep archive history: no cleanup required
>> WAL file not present yet.
>> WAL file not present yet.
>> WAL file not present yet.
>>
>>
>> Why did it jump from 15 back to 6? Why did it even start at 15? Am I
>> hosed at this point? I really don't want to make another base backup.
>
> Not sure. Some observations:
>
> In the above you have a .history file which seems to indicate you have wandered into timelines:
>
> http://www.postgresql.org/docs/9.3/static/continuous-archiving.html
>
> 24.3.5. Timelines
>
> You might want to look at the pg_xlog directory on the master and the archive directory to see if the WAL file numbers match what you are seeing.
>
>>
>> -Andy
>>
>>
>>
>>
>
>

Yes, the timeline is correct. A while back I had to promote a slave as a new master, so this should be my 2nd timeline. (I almost feel like a time lord)

And yes, the master pg_xlog is full of 00000002000000B90* files.

-Andy