Why does FtpWebRequest throw a WebException exactly at the end of a long transfer?

Question

I am trying to connect to an FTP server and download a file but I am having some trouble.

Originally I used WebClient.DownloadFileAsync and it worked fine for a small file but a large file would reach the end of the download but never call DownloadFileCompleted...

I tried switching to FtpWebRequest and using a FileStream to write the file using a standard method:

var FtpRequest = WebRequest.Create(uri) as FtpWebRequest
FtpRequest.Credentials = _Credentials;
FtpRequest.Method = WebRequestMethods.Ftp.DownloadFile;

using(var InputResponse = (FtpWebResponse)FtpRequest.GetResponse())
using (var InputStream = InputResponse.GetResponseStream())
using (var OutputStream = new FileStream(_DownloadDirectory + "\\" + fileName, FileMode.Create))
{
    var Buffer = new byte[1024];
    int TotalReadBytesCount = 0;
    int ReadBytesCount;
    while ((ReadBytesCount = InputStream.Read(Buffer, 0, Buffer.Length)) > 0)
    {
        OutputStream.Write(Buffer, 0, ReadBytesCount);
        TotalReadBytesCount += ReadBytesCount;
        var Progress = (int)(((double)TotalReadBytesCount / (double)FileSize) * 100);
        UpdateProgressBar(progressBar, Progress);
    }
}

This one also works fine with small files but with a large file it will download the whole file and then I will get a System.Net.WebException at InputStream.Read.

EDIT: The exception moves around depending on how the code is structured... removing the "using" statments and closing each stream and the response results in the exception being thrown by the last x.close(). Also I note that the TotalBytesReceived is == to fileSize so the download is technically complete. END EDIT

Inner Exception: The underlying connection was closed: An unexpected error occurred on a receive.

After enabling system.Net.Tracing I got the following logfile:

System.Net Verbose: 0 : [2440] WebRequest::Create(ftp://ftp.******.com/)
System.Net Information: 0 : [2440] FtpWebRequest#63621045::.ctor(ftp://ftp.******.com/)
System.Net Verbose: 0 : [2440] Exiting WebRequest::Create()     -> FtpWebRequest#63621045
System.Net Verbose: 0 : [2440] FtpWebRequest#63621045::GetResponse()
System.Net Information: 0 : [2440] FtpWebRequest#63621045::GetResponse(Method=SIZE.)
System.Net Information: 0 : [2440] FtpControlStream#44374744 - Created connection from ***.**.***.**:***** to **.**.**.**:**.
System.Net Information: 0 : [2440] Associating FtpWebRequest#63621045 with FtpControlStream#44374744
System.Net Information: 0 : [2440] FtpControlStream#44374744 - Received response [220 Microsoft FTP Service]
System.Net Information: 0 : [2440] FtpControlStream#44374744 - Sending command [USER ******]
System.Net Information: 0 : [2440] FtpControlStream#44374744 - Received response [331 Password required for cashipftp.]
System.Net Information: 0 : [2440] FtpControlStream#44374744 - Sending command [PASS ********]
System.Net Information: 0 : [2440] FtpControlStream#44374744 - Received response [230 User logged in.]
System.Net Information: 0 : [2440] FtpControlStream#44374744 - Sending command [OPTS utf8 on]
System.Net Information: 0 : [2440] FtpControlStream#44374744 - Received response [200 OPTS UTF8 command successful - UTF8 encoding now ON.]
System.Net Information: 0 : [2440] FtpControlStream#44374744 - Sending command [PWD]
System.Net Information: 0 : [2440] FtpControlStream#44374744 - Received response [257 "/" is current directory.]
System.Net Information: 0 : [2440] FtpControlStream#44374744 - Sending command [SIZE Superintendents/MSK/Stock Keeper_be.zip]
System.Net Information: 0 : [2440] FtpControlStream#44374744 - Received response [213 96601015]
System.Net Information: 0 : [2440] FtpControlStream#44374744 - Sending command [QUIT]
System.Net Information: 0 : [2440] FtpControlStream#44374744 - Received response [221 Goodbye.]
System.Net Information: 0 : [2440] FtpWebRequest#63621045::(Releasing FTP connection#44374744.)
System.Net Verbose: 0 : [2440] Exiting FtpWebRequest#63621045::GetResponse() 
System.Net Verbose: 0 : [2440] FtpWebResponse#50706457::Close()
System.Net Verbose: 0 : [2440] Exiting FtpWebResponse#50706457::Close() 
System.Net Verbose: 0 : [2440] WebRequest::Create(ftp://ftp.******.com/)
System.Net Information: 0 : [2440] FtpWebRequest#89223::.ctor(ftp://ftp.*****.com/)
System.Net Verbose: 0 : [2440] Exiting WebRequest::Create()     -> FtpWebRequest#89223
System.Net Verbose: 0 : [2440] FtpWebRequest#89223::GetResponse()
System.Net Information: 0 : [2440] FtpWebRequest#89223::GetResponse(Method=RETR.)
System.Net Information: 0 : [2440] FtpControlStream#4015056 - Created connection from ***.**.***.**:***** to **.**.**.**:**.
System.Net Information: 0 : [2440] Associating FtpWebRequest#89223 with FtpControlStream#4015056
System.Net Information: 0 : [2440] FtpControlStream#4015056 - Received response [220 Microsoft FTP Service]
System.Net Information: 0 : [2440] FtpControlStream#4015056 - Sending command [USER ******]
System.Net Information: 0 : [2440] FtpControlStream#4015056 - Received response [331 Password required for cashipftp.]
System.Net Information: 0 : [2440] FtpControlStream#4015056 - Sending command [PASS ********]
System.Net Information: 0 : [2440] FtpControlStream#4015056 - Received response [230 User logged in.]
System.Net Information: 0 : [2440] FtpControlStream#4015056 - Sending command [OPTS utf8 on]
System.Net Information: 0 : [2440] FtpControlStream#4015056 - Received response [200 OPTS UTF8 command successful - UTF8 encoding now ON.]
System.Net Information: 0 : [2440] FtpControlStream#4015056 - Sending command [PWD]
System.Net Information: 0 : [2440] FtpControlStream#4015056 - Received response [257 "/" is current directory.]
System.Net Information: 0 : [2440] FtpControlStream#4015056 - Sending command [TYPE I]
System.Net Information: 0 : [2440] FtpControlStream#4015056 - Received response [200 Type set to I.]
System.Net Information: 0 : [2440] FtpControlStream#4015056 - Sending command [PASV]
System.Net Information: 0 : [2440] FtpControlStream#4015056 - Received response [227 Entering Passive Mode (77,44,60,82,106,69).]
System.Net Information: 0 : [2440] FtpControlStream#4015056 - Sending command [RETR *****]
System.Net Information: 0 : [2440] FtpControlStream#4015056 - Received response [125 Data connection already open; Transfer starting.]
System.Net Verbose: 0 : [2440] Exiting FtpWebRequest#89223::GetResponse() 
System.Net Information: 0 : [1312] ServicePoint#42865679 - Closed as idle.
System.Net.Sockets Error: 0 : [2440] Socket#10316078::UpdateStatusAfterSocketError() - TimedOut
System.Net.Sockets Error: 0 : [2440] Exception in Socket#10316078::Receive - A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond.
System.Net Information: 0 : [2440] FtpWebRequest#89223::(Releasing FTP connection#4015056.)
System.Net Verbose: 0 : [2440] FtpWebResponse#19201658::Close()
System.Net Verbose: 0 : [2440] Exiting FtpWebResponse#19201658::Close()

EDIT 19/04/2012: I gave wireshark a go with ftp filter and I may have uncovered some more info which I also don't know where to go with...

EDIT: New information... I found some info on another forum which sheds a little more light but still doesn't provide an answer... It looks like the file size makes no difference. Downloading a small file but sleeping the thread in the loop to extend the download time has the same effect. It seems that any operation longer than x amount of time (the other post reckons 100s) will reach the end and immediately time out. Also I noted when stepping through with the debugger that the total received bytes is equal to the file size so it is exactly as it tries to read the last of the file only to find there is none left except it never finds out because the server never tells it! END EDIT

The ftp server is suppose to respons with 226 - Closing data connection. Requested file action successful (for example, file transfer or file abort).

However when I used wireshark I can see that this is not coming in with [TCP Retransmission] in front of it. Not sure yet what this is... still googling. But I'm sure it has relevance.

So it looks like something is timing out or being closed early but being new to both FTP and somewhat to .net I am not sure where to proceed from here.

I have tried many different things:

Keep-alive = false
SetPointManager.MaxIdleTime
Increasing server timeout

It seems like it is the server kicking me off but it works fine with filezilla so there must be some way to avoid this.

EDIT 20/04/2012: It does not work fine with filezilla (or explorer) I tried downloading from ftp using explorer and received a message that the operation had timed out. Filezilla downloads the file then times out but it cleverly tries again with a REST command. I suspect implementing this could be the ideal soulution so I am off to figure that out. Will post as answer if I succeed. END EDIT

One point to note is that until the WebException is passed access to the downloaded file is blocked. So in the case of WebClient which I can't affect timeouts it will just hang at 100% for a long time. and then throw the exception. If I set the FtpRequest timeout to 1000 and handle the exception the file appears to have downloaded completely and I am able to extract it without any corruption.

If anyone has any tips or pointers, or even better a solution :) I would be very grateful. All input will be accepted.

Thank you

P.S I tried to provide as much info as possible but if you need more let me know.

Related: [FTPWebRequest is broken](http://mattmitchell.com.au/ftpwebrequest-is-broken/). I am running into this issue too. If I do `netstat` I see thousands of open connections even though I dispose the response immediately and `keepalive` is `false`. If you look in the .NET reference source for `FTPWebRequest` it seems like it's designed to deliberately keep connections open in the hope these ports will be re-used but the reality is it uses a different port each time... — jrh, Oct 26 '16 at 11:19
... my current theory is that it keeps trying a different port each time until the server starts rejecting connections. I wrote a program that sends a huge amount of files to test the problem. It may literally be running out of port numbers, netstat shows ports going from 49157 to 65535. Note that I only send one file at a time. — jrh, Oct 26 '16 at 11:35

score 0 · Answer 1 · answered Apr 18 '12 at 17:06

0

Try to look if the source application config is limiting the size of download.

answered Apr 18 '12 at 17:06

Gustavo Gondim

1,635
2
18
39

If you mean in the app.config? All that is in there ATM is the tracing and a couple of settings. I read about httpRuntime settings to that effect but this is FTP. Is there a similar setting that I can alter? – Dave Williams Apr 18 '12 at 17:49

Why does FtpWebRequest throw a WebException exactly at the end of a long transfer?

1 Answers1