есть postgresql 9.4

Master - Slave , включена WAL async репликация и в общем каталоге archive logs

делаю fast -m у master

None - Slave

делаю promote для slave

None - Master

и включаю бывший master как slave

Slave - Master


Но периодически, не всегда, а иногда, бывший master не хочет становится slave, и пишет вот такое в логи:








< 2015-07-03 12:32:05.632 MSK >DEBUG: write 0/D0002B0 flush 0/D0002B0 apply 0/D0002B0
< 2015-07-03 12:32:06.223 MSK >DEBUG: forked new backend, pid=42899 socket=10
< 2015-07-03 12:32:06.228 MSK >LOG: statement: select pg_is_in_recovery()
< 2015-07-03 12:32:06.231 MSK >DEBUG: server process (PID 42899) exited with exit code 0
< 2015-07-03 12:32:06.299 MSK >DEBUG: forked new backend, pid=42920 socket=10
< 2015-07-03 12:32:06.303 MSK >LOG: statement: select application_name,upper(state),upper(sync_state) from pg_stat_replication
< 2015-07-03 12:32:06.307 MSK >DEBUG: server process (PID 42920) exited with exit code 0
< 2015-07-03 12:32:07.350 MSK >DEBUG: hot standby feedback xmin 2002 epoch 0
< 2015-07-03 12:32:07.653 MSK >DEBUG: write 0/D0002B0 flush 0/D0002B0 apply 0/D0002B0
< 2015-07-03 12:32:09.370 MSK >DEBUG: hot standby feedback xmin 2002 epoch 0
< 2015-07-03 12:32:09.673 MSK >DEBUG: write 0/D0002B0 flush 0/D0002B0 apply 0/D0002B0
< 2015-07-03 12:32:11.129 MSK >DEBUG: forked new backend, pid=43319 socket=10
< 2015-07-03 12:32:11.134 MSK >LOG: statement: select pg_is_in_recovery()
< 2015-07-03 12:32:11.137 MSK >DEBUG: forked new backend, pid=43321 socket=10
< 2015-07-03 12:32:11.138 MSK >DEBUG: server process (PID 43319) exited with exit code 0
< 2015-07-03 12:32:11.139 MSK >LOG: incomplete startup packet
< 2015-07-03 12:32:11.140 MSK >DEBUG: server process (PID 43321) exited with exit code 0
< 2015-07-03 12:32:11.149 MSK >DEBUG: forked new backend, pid=43325 socket=10
< 2015-07-03 12:32:11.154 MSK >LOG: statement: select pg_is_in_recovery()
< 2015-07-03 12:32:11.157 MSK >DEBUG: server process (PID 43325) exited with exit code 0
< 2015-07-03 12:32:11.235 MSK >DEBUG: postmaster received signal 2
< 2015-07-03 12:32:11.235 MSK >LOG: received fast shutdown request
< 2015-07-03 12:32:11.235 MSK >LOG: aborting any active transactions
< 2015-07-03 12:32:11.235 MSK >LOG: autovacuum launcher shutting down
< 2015-07-03 12:32:11.238 MSK >LOG: shutting down
< 2015-07-03 12:32:11.332 MSK >DEBUG: performing replication slot checkpoint
< 2015-07-03 12:32:11.374 MSK >DEBUG: creating and filling new WAL file
< 2015-07-03 12:32:11.463 MSK >DEBUG: archived transaction log file "00000002000000000000000D"
< 2015-07-03 12:32:11.498 MSK >DEBUG: done creating and filling new WAL file
< 2015-07-03 12:32:11.501 MSK >DEBUG: attempting to remove WAL segments older than log file 000000000000000000000000
< 2015-07-03 12:32:11.501 MSK >DEBUG: SlruScanDirectory invoking callback on pg_subtrans/0000
< 2015-07-03 12:32:11.502 MSK >DEBUG: SlruScanDirectory invoking callback on pg_multixact/offsets/0000
< 2015-07-03 12:32:11.502 MSK >DEBUG: SlruScanDirectory invoking callback on pg_multixact/members/0000
< 2015-07-03 12:32:11.503 MSK >DEBUG: SlruScanDirectory invoking callback on pg_multixact/offsets/0000
< 2015-07-03 12:32:11.503 MSK >LOG: database system is shut down
< 2015-07-03 12:32:11.508 MSK >DEBUG: writing stats file "pg_stat/global.stat"
< 2015-07-03 12:32:11.509 MSK >DEBUG: writing stats file "pg_stat/db_1.stat"
< 2015-07-03 12:32:11.517 MSK >DEBUG: removing temporary stats file "pg_stat_tmp/db_1.stat"
< 2015-07-03 12:32:11.517 MSK >DEBUG: writing stats file "pg_stat/db_13003.stat"
< 2015-07-03 12:32:11.519 MSK >DEBUG: removing temporary stats file "pg_stat_tmp/db_13003.stat"
< 2015-07-03 12:32:11.520 MSK >DEBUG: writing stats file "pg_stat/db_0.stat"
< 2015-07-03 12:32:11.523 MSK >DEBUG: removing temporary stats file "pg_stat_tmp/db_0.stat"
< 2015-07-03 12:32:39.702 MSK >DEBUG: sending replication keepalive
< 2015-07-03 12:33:09.703 MSK >LOG: terminating walsender process due to replication timeout
< 2015-07-03 12:33:09.704 MSK >DEBUG: server process (PID 32697) exited with exit code 0
< 2015-07-03 12:33:09.705 MSK >DEBUG: cleaning up dynamic shared memory control segment with ID 1681692777
< 2015-07-03 12:33:09.735 MSK >DEBUG: logger shutting down




< 2015-07-03 12:34:10.446 MSK >DEBUG: forked new backend, pid=49259 socket=10
< 2015-07-03 12:34:10.446 MSK >FATAL: the database system is starting up
< 2015-07-03 12:34:10.447 MSK >LOG: database system was shut down at 2015-07-03 12:32:11 MSK
< 2015-07-03 12:34:10.449 MSK >DEBUG: server process (PID 49259) exited with exit code 1
< 2015-07-03 12:34:10.450 MSK >DEBUG: standby_mode = 'on'
< 2015-07-03 12:34:10.450 MSK >DEBUG: primary_conninfo = 'host=192.168.111.101 port=5433 user=replication application_name=my_server_name keepalives_idle=60 keepalives_interval=5 keepalives_count=5'
< 2015-07-03 12:34:10.450 MSK >DEBUG: restore_command = 'cp /shared_storage/archive_log/%f %p'
< 2015-07-03 12:34:10.450 MSK >DEBUG: recovery_target_timeline = latest
< 2015-07-03 12:34:10.458 MSK >LOG: restored log file "00000003.history" from archive
cp: cannot stat `shared_storage/archive_log/00000004.history': No such file or directory
< 2015-07-03 12:34:10.461 MSK >DEBUG: could not restore file "00000004.history" from archive: child process exited with exit code 1
< 2015-07-03 12:34:10.461 MSK >LOG: entering standby mode
< 2015-07-03 12:34:10.467 MSK >LOG: restored log file "00000003.history" from archive
cp: cannot stat `/shared_storage/archive_log/00000003000000000000000E': No such file or directory
< 2015-07-03 12:34:10.473 MSK >DEBUG: could not restore file "00000003000000000000000E" from archive: child process exited with exit code 1
cp: cannot stat `/shared_storage/archive_log/00000002000000000000000E': No such file or directory
< 2015-07-03 12:34:10.475 MSK >DEBUG: could not restore file "00000002000000000000000E" from archive: child process exited with exit code 1
< 2015-07-03 12:34:10.478 MSK >DEBUG: checkpoint record is at 0/E000028
< 2015-07-03 12:34:10.478 MSK >FATAL: requested timeline 3 is not a child of this server's history
< 2015-07-03 12:34:10.478 MSK >DETAIL: Latest checkpoint is at 0/E000028 on timeline 2, but in the history of the requested timeline, the server forked off from that timeline at 0/E000000.
< 2015-07-03 12:34:10.479 MSK >LOG: startup process (PID 49258) exited with exit code 1
< 2015-07-03 12:34:10.479 MSK >LOG: aborting startup due to startup process failure
< 2015-07-03 12:34:10.479 MSK >DEBUG: cleaning up dynamic shared memory control segment with ID 1681692777
< 2015-07-03 12:34:10.518 MSK >DEBUG: logger shutting down


почему может появляться рассинхрон ? подскажите пожалуйста, в какую сторону смотреть?

Максим,

как вы считаете pg_rewind поможет в этом варианте?
интересно в 9.5 уже можно будет так переключаться?