I have filtered the log to only show the affected transfer:
2010-03-18 13:14:52.744 INFO Ftp(1) Response: 227 Entering Passive Mode (***,145).
2010-03-18 13:14:52.760 DEBUG Ftp(1) Info: Establishing data connection to ***:61329.
2010-03-18 13:14:52.838 INFO Ftp(1) Command: RETR ***.wmv
2010-03-18 13:14:52.932 INFO Ftp(1) Response: 150 Opening BINARY mode data connection for ***.wmv (1176154131 bytes).
2010-03-18 14:14:53.705 DEBUG Ftp(1) Info: Closing data connection.
2010-03-18 14:14:53.721 ERROR Ftp(1) Info: Error while reading data: Rebex.Net.FtpException: An existing connection was forcibly closed by the remote host. ---> System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host
at System.Net.Sockets.Socket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
The reason for "closing data connection" message is not apparent from the log in this case without some knowledge about Rebex FTP internals. We will surely enhance the log to make it more informative. For now, this is basically what's going on inside:
void ProcessResponse()
{
try
{
ReadResponseIfAvailable(); // 1. The SocketException occured in this method.
}
catch (FtpException x)
{
// 2. We catched it here
if (x.Status == FtpExceptionStatus.ConnectionClosed)
{
// 3. The control connection is closed, let's shutdown the rest
// and write "Closing data connection" message into the log.
Log("Closing data connection.");
CloseDataConnection();
}
// 4. Re-throw the original exception. At this point, it has not been logged yet.
throw;
}
}
void ReceiveData()
{
try
{
ReadData();
ProcessResponse();
}
catch (Exception x)
{
// 5. Here, the original exception is logged.
Log("Error while reading data:", x);
throw;
}
}
What does this mean? The SocketException occured first. Then we reacted by closing the still-active data connection as well. The actual two messages in the log are reversed.
So what does this mean? You are probably right and this is network related. After 60mins, something closes the FTP control connection.
And this is something we have encoutered in the past - it sometimes happens with badly behaved firewalls or routers that silently close the main FTP connection because of inactivity, even though the main FTP connection is actually supposed to be inactive while the transfer is in progress (it uses a separate TCP connection).
Rebex FTP includes a workaround for this issue, but it doesn't work reliably with all FTP servers so it's disabled by default. To enable it, use this code:
client.Options |= FtpOptions.KeepAliveDuringTransfer;
This will cause a dummy NOOP command to be sent every 600 seconds (10 minutes) - you can also specify a longer interval by changing the value of Ftp object's KeepAliveDuringTransferInterval property.
Does enabling this option help?
