streaming replication timeout error

Hello:

My customer encountered some connection timeout, while using one primary-one standby streaming replication.

The original log is japanese, because there are no error-code like oracle's ora-xxx,

I tried to translate the japanese information into English, But that might be not correct English for PG.

The most important part is:

2013-09-22 09:52:47 JST[28297][51d1fbcb.6e89-2][0][XX000]FATAL:  Could not receive data from WAL stream: could not receive data from server: connection timeout

scp: /opt/PostgresPlus/9.2AS/data/arch/000000AC000001F10000004A: No such file or directory

I was asked about:

In what occasion will the above fatal error occur?

I looked into the postgresql.conf file for the primary and standby server.

And made some experiences.

I found: 

Senario I:

If the wal file wanted is removed manually：

Both in primary and standby, log will be like this:

FATAL:  could not receive data from WAL stream: FATAL:  requested WAL segment 000000010000000000000011 has already been removed

Senario II:

If replication_timeout=60, wal_receiver_status_interval=0,

log will be like this:

On primary side：

LOG:  terminating walsender process due to replication timeout

On standby side：

FATAL: could not receive data from WAL stream: 

LOG:  streaming replication successfully connected to primary

But they are not the same to my customer's case.

And I also noticed that my customer's recovery.conf:

In it it has primary_conninfo as this:

host=DB1 port=5432 application_name=testpg user=postgres connect_timeout=10 keepalives_idle=5 keepalives_interval=1 

That is to say:

      keepalives_idle=5 

      keepalives_interval=1

      keepalives_count=3

With that setting, I think that For every 5 seconds,

In order to see whether the connection is alive, 3 keepalives package will be sent,

And if there is no repsonse in 1 seconds, then he connection will be invalid.

If my unserstanding is right, 

when master is busy at network,

the three keepalives_  parameter will also cause the connection time out error.

But I haven't found a  good explanation fitting the logs' FATAL error.

Can anybody give me some info?

2013-09-22 09:40:42 JST[27987][412d33c5.2d23-95024][0][00000]LOG:  Recovery replay at point 1F1/45EF8E20

2013-09-22 09:40:42 JST[27987][412d33c5.2d23-95025][0][00000]DETAIL:  Last transaction log time 2013-09-22 09:40:42.673062+09

2013-09-22 09:44:00 JST[27987][412d33c5.2d23-95026][0][00000]LOG:  restartpoint starting: time

2013-09-22 09:45:45 JST[27987][412d33c5.2d23-95027][0][00000]LOG:  restartpoint complete: wrote 1051 buffers (0.3%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=104.773 s, sync=0.003 s, total=104.781 s; sync files=90, longest=0.001 s, average=0.000 s

2013-09-22 09:45:45 JST[27987][412d33c5.2d23-95028][0][00000]LOG:  Recovery replay at point 1F1/45EF8E20

2013-09-22 09:45:45 JST[27987][412d33c5.2d23-95029][0][00000]DETAIL:  Last transaction log time 2013-09-22 09:45:44.77683+09

2013-09-22 09:49:00 JST[27987][412d33c5.2d23-95030][0][00000]LOG:  restartpoint starting: time

2013-09-22 09:50:36 JST[27987][412d33c5.2d23-95031][0][00000]LOG:  restartpoint complete: wrote 963 buffers (0.3%); 0 transaction log file(s) added, 0 removed, 2 recycled; write=96.096 s, sync=0.006 s, total=96.106 s; sync files=98, longest=0.002 s, average=0.000 s

2013-09-22 09:50:36 JST[27987][412d33c5.2d23-95032][0][00000]LOG:  Recovery replay at point 1F1/46CE8EA0

2013-09-22 09:50:36 JST[27987][412d33c5.2d23-95033][0][00000]DETAIL:  Last transaction log time 2013-09-22 09:50:36.564966+09

2013-09-22 09:52:47 JST[28297][51d1fbcb.6e89-2][0][XX000]FATAL:  Could not receive data from WAL stream: could not receive data from server: connection timeout

scp: /opt/PostgresPlus/9.2AS/data/arch/000000AC000001F10000004A: No such file or directory

2013-09-22 09:52:50 JST[27806][51d1fbc5.6c9e-12][0][00000]LOG:  Log file 497、Segment 74、Offset 12263424 Page address 1F0/8DBB2000 is not expected

scp: /opt/PostgresPlus/9.2AS/data/arch/000000AC000001F10000004A: No such file or directory

scp: /opt/PostgresPlus/9.2AS/data/arch/000000AD.history: No such file or directory

2013-09-22 09:52:51 JST[2878][523e3f63.b3e-1][0][00000]LOG:  Streaming replication connected to primary server successfully

2013-09-22 09:54:00 JST[27987][412d33c5.2d23-95034][0][00000]LOG:  restartpoint starting: time

2013-09-22 09:56:30 JST[27987][412d33c5.2d23-95035][0][00000]LOG:  restartpoint complete: wrote 9929 buffers (3.2%); 0 transaction log file(s) added, 0 removed, 10 recycled; write=149.436 s, sync=0.032 s, total=149.472 s; sync files=90, longest=0.012 s, average=0.000 s

2013-09-22 09:56:30 JST[27987][412d33c5.2d23-95036][0][00000]LOG:  Recovery replay at point 1F1/48E9D238

2013-09-22 09:56:30 JST[27987][412d33c5.2d23-95037][0][00000]DETAIL:  Last transaction log time 2013-09-22 09:56:29.015514+09

Thanks in advance

jian gao