Hi, hackers.
When running pg_basebackup with -X s with network file system as target we would consistently get "could not receive data from WAL stream: server closed the connection unexpectedly".
On server we see this error firing: "terminating walsender process due to replication timeout"
The problem occurs during a network or file system acting very slow. One example of such case looks like this (strace output for fsync calls):
0.033383 fsync(8) = 0 <20.265275>
20.265399 fsync(8) = 0 <0.000011>
0.022892 fsync(7) = 0 <48.350566>
48.350654 fsync(7) = 0 <0.000005>
0.000674 fsync(8) = 0 <0.851536>
0.851619 fsync(8) = 0 <0.000007>
0.000067 fsync(7) = 0 <0.000006>
0.000045 fsync(7) = 0 <0.000005>
0.031733 fsync(8) = 0 <0.826957>
0.827869 fsync(8) = 0 <0.000016>
0.005344 fsync(7) = 0 <1.437103>
1.446450 fsync(6) = 0 <0.063148>
0.063246 fsync(6) = 0 <0.000006>
0.000381 +++ exited with 1 +++
So the longest fsync call took 48 seconds, but how would that result in a termination if wal_sender_timeout is (default) 60 seconds?
The problem is in the way wal_sender handles this timeout:
/*
* If half of wal_sender_timeout has lapsed without receiving any reply
* from the standby, send a keep-alive message to the standby requesting
* an immediate reply.
*/
Obviously the receiver cannot respond immediately while in a syscall.
This begs a question, why is the GUC handled the way it is? What would be the correct way to solve this? Shall we change the behaviour or do a better job explaining what are implications of wal_sender_timeout in the docs?
Regards,
Nick.
