Discuss (FTP), (FTP on .NET CF) and (FTPS, SFTP and SCP).
no avatar
User

dcriswell

Posts

3

Joined

Fri Nov 30, 2012 8:17 am

Timing issue in edtFTPnet DownloadFile method?

by dcriswell » Fri Nov 30, 2012 8:19 am

Hello, I?m using the free FTP .NET library (which is generally a great product by the way). I have encountered an issue when downloading a file where it looks like the server responses are being processed out of sync, which is causing an exception in the DownloadFile method.

Using version 2.1.0 of the library, the log shows the sequence below. It looks like the method is looking for a 227 response to the PASV command at 10:44:26.718 and throwing an exception. The log shows that the 227 response occurs at 10:44:26.752, which is after the exception is thrown:

DEBUG [FTPControlSocket] 29 Nov 2012 10:44:24.879 : ---> RETR smithb.20121128.txt
DEBUG [FTPControlSocket] 29 Nov 2012 10:44:25.278 : 150 ASCII data connection for smithb.20121128.txt (192.245.63.17,62489) (864 bytes).
DEBUG [FTPConnection] 29 Nov 2012 10:44:26.697 : DownloadFile(c:\sba\smithb.txt,smithb.20121128.txt)
DEBUG [FTPControlSocket] 29 Nov 2012 10:44:26.718 : ---> PASV
DEBUG [FTPControlSocket] 29 Nov 2012 10:44:26.718 : 226 ASCII Transfer complete.
DEBUG [FTPControlSocket] 29 Nov 2012 10:44:26.718 : Server supplied address=...
ERROR [FTPClient] 29 Nov 2012 10:44:26.729 : Caught exception
ERROR [FTPClient] 29 Nov 2012 10:44:26.729 : System.FormatException: Input string was not in a correct format.
ERROR [FTPClient] 29 Nov 2012 10:44:26.729 : at System.Number.StringToNumber(String str, NumberStyles options, NumberBuffer& number, NumberFormatInfo info, Boolean parseDecimal)
ERROR [FTPClient] 29 Nov 2012 10:44:26.729 : at System.Number.ParseInt32(String s, NumberStyles style, NumberFormatInfo info)
ERROR [FTPClient] 29 Nov 2012 10:44:26.729 : at EnterpriseDT.Net.Ftp.FTPControlSocket.CreateDataSocketPASV()
ERROR [FTPClient] 29 Nov 2012 10:44:26.729 : at EnterpriseDT.Net.Ftp.FTPControlSocket.CreateDataSocket(FTPConnectMode connectMode)
ERROR [FTPClient] 29 Nov 2012 10:44:26.729 : at EnterpriseDT.Net.Ftp.FTPClient.InitGet(String remoteFile)
ERROR [FTPClient] 29 Nov 2012 10:44:26.729 : at EnterpriseDT.Net.Ftp.FTPClient.GetASCII(String localPath, String remoteFile)
DEBUG [FTPControlSocket] 29 Nov 2012 10:44:26.734 : Setting socket timeout=500
DEBUG [FTPControlSocket] 29 Nov 2012 10:44:26.752 : 227 Entering Passive Mode (199,181,252,17,244,56)
DEBUG [FTPControlSocket] 29 Nov 2012 10:44:26.752 : Setting socket timeout=300000
ERROR [FTPClient] 29 Nov 2012 10:44:26.752 : SystemException in Get(string,string)
ERROR [FTPClient] 29 Nov 2012 10:44:26.752 : System.FormatException: Input string was not in a correct format.
ERROR [FTPClient] 29 Nov 2012 10:44:26.752 : at EnterpriseDT.Net.Ftp.FTPClient.GetASCII(String localPath, String remoteFile)
ERROR [FTPClient] 29 Nov 2012 10:44:26.752 : at EnterpriseDT.Net.Ftp.FTPClient.Get(String localPath, String remoteFile)
DEBUG [FTPConnection] 29 Nov 2012 10:44:26.763 : Closing connection (instance=0)
DEBUG [FTPFileFactory] 29 Nov 2012 10:44:26.765 : Defaulting to Unix parsing
DEBUG [FTPControlSocket] 29 Nov 2012 10:44:26.765 : ---> QUIT
DEBUG [FTPControlSocket] 29 Nov 2012 10:44:26.798 : 221 Goodbye.

Using version 2.2.2 of the library, a different exception occurs but it follows a similar pattern, where the 227 response occurs after the exception is thrown:

DEBUG [FTPControlSocket] 29 Nov 2012 10:21:17.409 : ---> RETR smithb.20121128.txt
DEBUG [FTPControlSocket] 29 Nov 2012 10:21:17.812 : 150 ASCII data connection for smithb.20121128.txt (192.245.63.17,51285) (864 bytes).
DEBUG [FTPConnection] 29 Nov 2012 10:21:23.622 : DownloadFile(c:\sba\smithb.txt,smithb.20121128.txt)
DEBUG [FTPControlSocket] 29 Nov 2012 10:21:23.631 : ---> REST 0
DEBUG [FTPControlSocket] 29 Nov 2012 10:21:23.631 : 226 ASCII Transfer complete.
INFO [FTPControlSocket] 29 Nov 2012 10:21:23.631 : Expected reply codes = [350] (strict=False)
DEBUG [FTPClient] 29 Nov 2012 10:21:23.638 : REST failed which is ok (ASCII Transfer complete. (code=226))
DEBUG [FTPControlSocket] 29 Nov 2012 10:21:23.652 : ---> PASV
DEBUG [FTPControlSocket] 29 Nov 2012 10:21:23.664 : 502 REST command not implemented.
INFO [FTPControlSocket] 29 Nov 2012 10:21:23.664 : Expected reply codes = [227] (strict=False)
ERROR [FTPClient] 29 Nov 2012 10:21:23.675 : Caught exception REST command not implemented. (code=502)
ERROR [FTPClient] 29 Nov 2012 10:21:23.677 : Caught exception
ERROR [FTPClient] 29 Nov 2012 10:21:23.677 : EnterpriseDT.Net.Ftp.FTPException: REST command not implemented. (code=502)
ERROR [FTPClient] 29 Nov 2012 10:21:23.677 : at EnterpriseDT.Net.Ftp.FTPControlSocket.ValidateReply(FTPReply reply, String[] expectedReplyCodes)
ERROR [FTPClient] 29 Nov 2012 10:21:23.677 : at EnterpriseDT.Net.Ftp.FTPControlSocket.CreateDataSocketPASVInternal()
ERROR [FTPClient] 29 Nov 2012 10:21:23.677 : at EnterpriseDT.Net.Ftp.FTPControlSocket.CreateDataSocketPASV()
ERROR [FTPClient] 29 Nov 2012 10:21:23.677 : at EnterpriseDT.Net.Ftp.FTPControlSocket.CreateDataSocket(FTPConnectMode connectMode)
ERROR [FTPClient] 29 Nov 2012 10:21:23.677 : at EnterpriseDT.Net.Ftp.FTPClient.InitGet(String remoteFile)
ERROR [FTPClient] 29 Nov 2012 10:21:23.677 : at EnterpriseDT.Net.Ftp.FTPClient.GetASCII(String localPath, String remoteFile)
WARN [FTPConnection] 29 Nov 2012 10:21:23.779 : Could not get length of file 'c:\sba\smithb.txt'
WARN [FTPConnection] 29 Nov 2012 10:21:23.779 : System.IO.FileNotFoundException: Could not find file 'c:\sba\smithb.txt'.
WARN [FTPConnection] 29 Nov 2012 10:21:23.779 : at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)
WARN [FTPConnection] 29 Nov 2012 10:21:23.779 : at System.IO.FileInfo.get_Length()
WARN [FTPConnection] 29 Nov 2012 10:21:23.779 : at EnterpriseDT.Net.Ftp.FTPConnection.GetLocalFileSize(String localPath)
DEBUG [FTPConnection] 29 Nov 2012 10:21:25.721 : Closing connection (instance=0)
DEBUG [FTPFileFactory] 29 Nov 2012 10:21:25.725 : Defaulting to Unix parsing
DEBUG [FTPControlSocket] 29 Nov 2012 10:21:25.725 : ---> QUIT
DEBUG [FTPControlSocket] 29 Nov 2012 10:21:25.726 : 227 Entering Passive Mode (199,181,252,17,200,198)

In both cases, the download does not complete even though the log shows a server response of 226 (ASCII Transfer complete).

Any assistance that you can provide is greatly appreciated!
no avatar
User

support2

Posts

3987

Joined

Tue May 18, 2004 8:30 am

Re: Timing issue in edtFTPnet DownloadFile method?

by support2 » Fri Nov 30, 2012 9:59 am

It looks to me like DownloadFile is being called before an existing download is completed.

PASV is called prior to RETR.
no avatar
User

dcriswell

Posts

3

Joined

Fri Nov 30, 2012 8:17 am

Re: Timing issue in edtFTPnet DownloadFile method?

by dcriswell » Fri Nov 30, 2012 11:31 pm

The RETR in the log is from an FTPConnection.Exists method call, which occurs immediately prior to the DownloadFile call. So it looks like the sequence of events is:

Exists called (issues RETR command)
DownloadFile called (issues PASV command)
Server responds to the RETR with "226 ASCII Transfer complete."
DownloadFile, expecting a response to the PASV command, throws an exception and never issues its own RETR command.

Since this is all happening in the FTPConnection method calls I don't think I can do anything in my code to alter the sequence.

While I wait for a response on the forum I'm going to modify the code to close and re-open the connection between the Exists and DownloadFile calls and see if that solves the problem. Perhaps this is what I'm supposed to be doing anyway? I haven't run into this issue before and I use this sequence of calls in many, many download processes.

Thanks for your continued assistance.
no avatar
User

dcriswell

Posts

3

Joined

Fri Nov 30, 2012 8:17 am

Re: Timing issue in edtFTPnet DownloadFile method?

by dcriswell » Sat Dec 01, 2012 12:56 am

I figured it out once I realized that your Exists method is attempting a SIZE, then a MDTM, then a RETR command. I should have posted the entire log. This particular server does not allow the SIZE or MDTM commands, and it looks like the Exists method has some trouble parsing the response from the RETR command. I came up with the workaround of getting the file list and looking for my file, rather than calling the Exists method.

Then I found the comment below from support in the forum at (http://www.enterprisedt.com/forums/viewtopic.php?t=3076):

***
This is happening because the commands are getting mixed up.

The Exists() method is a bit of a hack - there is no exists functionality in FTP.

Try using GetFiles() to get the file list, and check for the filename in there rather than use Exists().
***

So, it looks like this is a known issue. I've tested the workaround and it's suitable for my purposes.

Thanks for a good product.

Who is online

Users browsing this forum: No registered users and 16 guests

Powered by phpBB ® | phpBB3 Style by KomiDesign
cron