Re: unexpected pageaddr error in db log

On Thu, Dec 19, 2013 at 12:25 PM, wd <wd(at)wdicc(dot)com> wrote:
>
> hi,
>
> We have upgrade our database from PostgreSQL 9.2.4 to 9.3.2, use dump & restore in a fresh db created by initdb.
>
> Then use pg_basebackup created 2 slave db, the error occur when start the database.
>
> db1
>
> [ 2013-12-19 04:00:56.882 CST 17956 52b1fef8.4624 1 0]LOG: database system was interrupted; last known up at 2013-12-19 03:54:05 CST
> [ 2013-12-19 04:00:56.883 CST 17956 52b1fef8.4624 2 0]LOG: entering standby mode
> [ 2013-12-19 04:00:57.395 CST 17956 52b1fef8.4624 3 0]LOG: restored log file "00000001000000040000001D" from archive
> [ 2013-12-19 04:00:57.415 CST 17956 52b1fef8.4624 4 0]LOG: redo starts at 4/1D000028
> [ 2013-12-19 04:00:57.923 CST 17956 52b1fef8.4624 5 0]LOG: restored log file "00000001000000040000001E" from archive
> [ 2013-12-19 04:00:57.933 CST 17956 52b1fef8.4624 6 0]LOG: consistent recovery state reached at 4/1E012088
> [ 2013-12-19 04:00:57.933 CST 17948 52b1fef8.461c 4 0]LOG: database system is ready to accept read only connections
> [ 2013-12-19 04:00:58.078 CST 17956 52b1fef8.4624 7 0]LOG: unexpected pageaddr 3/2B000000 in log segment 00000001000000040000001F, offset 0
> [ 2013-12-19 04:00:58.084 CST 17969 52b1fefa.4631 1 0]LOG: started streaming WAL from primary at 4/1F000000 on timeline 1
>
>
> db2
>
> [ 2013-12-19 04:14:20.366 CST 18340 52b2021c.47a4 1 0]LOG: database system was interrupted; last known up at 2013-12-19 04:07:43 CST
> [ 2013-12-19 04:14:20.367 CST 18340 52b2021c.47a4 2 0]LOG: entering standby mode
> [ 2013-12-19 04:14:20.870 CST 18340 52b2021c.47a4 3 0]LOG: restored log file "000000010000000400000021" from archive
> [ 2013-12-19 04:14:20.881 CST 18340 52b2021c.47a4 4 0]LOG: redo starts at 4/21000028
> [ 2013-12-19 04:14:21.648 CST 18340 52b2021c.47a4 5 0]LOG: restored log file "000000010000000400000022" from archive
> [ 2013-12-19 04:14:22.415 CST 18340 52b2021c.47a4 6 0]LOG: restored log file "000000010000000400000023" from archive
> [ 2013-12-19 04:14:23.061 CST 18340 52b2021c.47a4 7 0]LOG: restored log file "000000010000000400000024" from archive
> [ 2013-12-19 04:14:23.831 CST 18340 52b2021c.47a4 8 0]LOG: restored log file "000000010000000400000025" from archive
> [ 2013-12-19 04:14:24.598 CST 18340 52b2021c.47a4 9 0]LOG: restored log file "000000010000000400000026" from archive
> [ 2013-12-19 04:14:25.365 CST 18340 52b2021c.47a4 10 0]LOG: restored log file "000000010000000400000027" from archive
> [ 2013-12-19 04:14:26.093 CST 18340 52b2021c.47a4 11 0]LOG: restored log file "000000010000000400000028" from archive
> [ 2013-12-19 04:14:26.857 CST 18340 52b2021c.47a4 12 0]LOG: restored log file "000000010000000400000029" from archive
> [ 2013-12-19 04:14:27.592 CST 18340 52b2021c.47a4 13 0]LOG: restored log file "00000001000000040000002A" from archive
> [ 2013-12-19 04:14:28.355 CST 18340 52b2021c.47a4 14 0]LOG: restored log file "00000001000000040000002B" from archive
> [ 2013-12-19 04:14:29.077 CST 18340 52b2021c.47a4 15 0]LOG: restored log file "00000001000000040000002C" from archive
> [ 2013-12-19 04:14:29.843 CST 18340 52b2021c.47a4 16 0]LOG: restored log file "00000001000000040000002D" from archive
> [ 2013-12-19 04:14:30.564 CST 18340 52b2021c.47a4 17 0]LOG: restored log file "00000001000000040000002E" from archive
> [ 2013-12-19 04:14:31.319 CST 18340 52b2021c.47a4 18 0]LOG: restored log file "00000001000000040000002F" from archive
> [ 2013-12-19 04:14:32.071 CST 18340 52b2021c.47a4 19 0]LOG: restored log file "000000010000000400000030" from archive
> [ 2013-12-19 04:14:32.923 CST 18340 52b2021c.47a4 20 0]LOG: restored log file "000000010000000400000031" from archive
> [ 2013-12-19 04:14:33.587 CST 18340 52b2021c.47a4 21 0]LOG: restored log file "000000010000000400000032" from archive
> [ 2013-12-19 04:14:33.909 CST 18340 52b2021c.47a4 22 0]LOG: consistent recovery state reached at 4/32CCAA88
> [ 2013-12-19 04:14:33.909 CST 18332 52b2021c.479c 4 0]LOG: database system is ready to accept read only connections
> [ 2013-12-19 04:14:34.059 CST 18340 52b2021c.47a4 23 0]LOG:
> unexpected pageaddr 3/5A000000 in log segment 000000010000000400000033, offset 0
> [ 2013-12-19 04:14:34.065 CST 18431 52b2022a.47ff 1 0]LOG: started streaming WAL from primary at 4/33000000 on timeline 1
>
>
> Both db1 and db2 are working properly, so what's the error mean? Is this a bug?

"unexpected pageaddr" log entry in this case means the standby reached
the end of existing WAL.
So, just before connecting to walsender for streaming replication, it logs this.

--
Amit