testing HS/SR - invalid magic number - Mailing list pgsql-hackers

This replication test that was working well earlier (it ran daily), stopped working
after reinstall of new instances of cvs HEAD. I think the change must have been today (or at least
recent).

This test copies a schema from a 8.4.3 instance to the 9.0 primary:

pg_dump -c -h /tmp -p 5432 -n public --no-owner --no-privileges ms \  | psql -1qtA -h /tmp -p 7575 -d replicas


I tried it twice, with a complete reinstall from the cvs repository;
last one just now (created 20100414 0128), and once a few hours earlier.





-- logfile primary:

LOG:  database system was shut down at 2010-04-14 02:15:01 CEST
LOG:  autovacuum launcher started
LOG:  database system is ready to accept connections
LOG:  received smart shutdown request
LOG:  autovacuum launcher shutting down
LOG:  shutting down
LOG:  database system is shut down
2010-04-14 02:15:14 CEST 14756   start=2010-04-14 02:15:14 CEST LOG:  database system was shut
down at 2010-04-14 02:15:12 CEST
2010-04-14 02:15:14 CEST 14752   start=2010-04-14 02:15:13 CEST LOG:  database system is ready to
accept connections
2010-04-14 02:18:23 CEST 15100 [unknown] rijkers start=2010-04-14 02:18:22 CEST LOG:  replication
connection authorized: user=rijkers host=127.0.0.1 port=55248
[...]
2010-04-14 02:21:10 CEST 15100 [unknown] rijkers start=2010-04-14 02:18:22 CEST FATAL:  requested
WAL segment 000000010000000000000032 has already been removed
2010-04-14 02:21:11 CEST 15377 [unknown] rijkers start=2010-04-14 02:21:11 CEST LOG:  replication
connection authorized: user=rijkers host=127.0.0.1 port=50869
2010-04-14 02:21:11 CEST 15377 [unknown] rijkers start=2010-04-14 02:21:11 CEST FATAL:  requested
WAL segment 000000010000000000000032 has already been removed
2010-04-14 02:21:16 CEST 15384 [unknown] rijkers start=2010-04-14 02:21:16 CEST LOG:  replication
connection authorized: user=rijkers host=127.0.0.1 port=50870
2010-04-14 02:21:16 CEST 15384 [unknown] rijkers start=2010-04-14 02:21:16 CEST FATAL:  requested
WAL segment 000000010000000000000032 has already been removed
2010-04-14 02:21:21 CEST 15400 [unknown] rijkers start=2010-04-14 02:21:21 CEST LOG:  replication
connection authorized: user=rijkers host=127.0.0.1 port=50871
2010-04-14 02:21:22 CEST 15400 [unknown] rijkers start=2010-04-14 02:21:21 CEST FATAL:  requested
WAL segment 000000010000000000000032 has already been removed
2010-04-14 02:21:26 CEST 15406 [unknown] rijkers start=2010-04-14 02:21:26 CEST LOG:  replication
connection authorized: user=rijkers host=127.0.0.1 port=50872

etc.


-- logfile standby:
2010-04-14 02:18:22 CEST 5598   start=2010-04-14 02:18:22 CEST LOG:  database system was
interrupted; last known up at 2010-04-14 02:17:54 CEST
2010-04-14 02:18:22 CEST 5598   start=2010-04-14 02:18:22 CEST LOG:  entering standby mode
cp: cannot stat `/var/data1/pg_stuff/dump/hotslave/replication_archive/000000010000000000000001':
No such file or directory
2010-04-14 02:18:23 CEST 5601   start=2010-04-14 02:18:22 CEST LOG:  streaming replication
successfully connected to primary
2010-04-14 02:18:24 CEST 5598   start=2010-04-14 02:18:22 CEST LOG:  redo starts at 0/1000020
2010-04-14 02:18:24 CEST 5598   start=2010-04-14 02:18:22 CEST LOG:  consistent recovery state
reached at 0/2000000
2010-04-14 02:18:24 CEST 5597   start=2010-04-14 02:18:22 CEST LOG:  database system is ready to
accept read only connections
2010-04-14 02:21:11 CEST 5601   start=2010-04-14 02:18:22 CEST FATAL:  could not receive data from
WAL stream: FATAL:  requested WAL segment 000000010000000000000032 has already been removed

cp: cannot stat `/var/data1/pg_stuff/dump/hotslave/replication_archive/000000010000000000000032':
No such file or directory
2010-04-14 02:21:11 CEST 5598   start=2010-04-14 02:18:22 CEST LOG:  invalid magic number 0000 in
log file 0, segment 50, offset 13795328
cp: cannot stat `/var/data1/pg_stuff/dump/hotslave/replication_archive/000000010000000000000032':
No such file or directory
2010-04-14 02:21:11 CEST 5784   start=2010-04-14 02:21:11 CEST LOG:  streaming replication
successfully connected to primary
2010-04-14 02:21:11 CEST 5784   start=2010-04-14 02:21:11 CEST FATAL:  could not receive data from
WAL stream: FATAL:  requested WAL segment 000000010000000000000032 has already been removed

cp: cannot stat `/var/data1/pg_stuff/dump/hotslave/replication_archive/000000010000000000000032':
No such file or directory
2010-04-14 02:21:11 CEST 5598   start=2010-04-14 02:18:22 CEST LOG:  invalid magic number 0000 in
log file 0, segment 50, offset 13795328
cp: cannot stat `/var/data1/pg_stuff/dump/hotslave/replication_archive/000000010000000000000032':
No such file or directory
2010-04-14 02:21:16 CEST 5790   start=2010-04-14 02:21:16 CEST LOG:  streaming replication
successfully connected to primary
2010-04-14 02:21:16 CEST 5790   start=2010-04-14 02:21:16 CEST FATAL:  could not receive data from
WAL stream: FATAL:  requested WAL segment 000000010000000000000032 has already been removed

cp: cannot stat `/var/data1/pg_stuff/dump/hotslave/replication_archive/000000010000000000000032':
No such file or directory
2010-04-14 02:21:16 CEST 5598   start=2010-04-14 02:18:22 CEST LOG:  invalid magic number 0000 in
log file 0, segment 50, offset 13795328
cp: cannot stat `/var/data1/pg_stuff/dump/hotslave/replication_archive/000000010000000000000032':
No such file or directory
2010-04-14 02:21:21 CEST 5795   start=2010-04-14 02:21:21 CEST LOG:  streaming replication
successfully connected to primary
2010-04-14 02:21:22 CEST 5795   start=2010-04-14 02:21:21 CEST FATAL:  could not receive data from
WAL stream: FATAL:  requested WAL segment 000000010000000000000032 has already been removed


etc....  that block of lines then endlessly repeats.