robinrodricks / FluentFTP

An FTP and FTPS client for .NET & .NET Standard, optimized for speed. Provides extensive FTP commands, File uploads/downloads, SSL/TLS connections, Automatic directory listing parsing, File hashing/checksums, File permissions/CHMOD, FTP proxies, FXP support, UTF-8 support, Async/await support, Powershell support and more. Written entirely in C#.
MIT License
3.14k stars 656 forks source link

Failed file upload returns an FtpResult with neither IsFailed nor IsSuccess flags set to true #1671

Open trinnan42 opened 3 weeks ago

trinnan42 commented 3 weeks ago

FTP Server OS: Windows

FTP Server Type: The FTP server is running on FANUC R-30iB/R-30iB+ Robot Controllers. I'm not sure about what exactly our FTP server is, but my best guess is that it's a custom FTP implementation.

Client Computer OS: Windows

FluentFTP Version: 51.1.0

Framework: .NET 8

We're attempting to upload a set of files to our Robot Controller using the UploadFiles method on the AsyncFtpClient. We are using the returned list of FtpResult instances to determine whether each file was successful or not with the IsSuccess and IsFailed flags. In the Fluent FTP logging we're seeing that the file failed to upload due with error code 550 "Device Function Code invalid". Despite the failure, we're not seeing the IsFailed flag as true in the FtpResult object.

Looking into the source code, it looks like the IsFailed flag only gets set to true if an exception occurs and the FtpStatus.Failed result we were returned from the UploadFileFromFile method is not reflected in the FtpResult if it fails.

Would something like this make sense to do?

UploadFiles.cs -> AsyncFtpClient.UploadFiles -> Line 99

// try to upload it
try {
    var ok = await UploadFileFromFile(result.LocalPath, result.RemotePath, false, existsMode, FileListings.FileExistsInNameListing(existingFiles, result.RemotePath), true, verifyOptions, token, progress, metaProgress);

    // mark that the file succeeded
    result.IsSuccess = ok.IsSuccess();
    result.IsSkipped = ok == FtpStatus.Skipped;

    // trinnan42: Add this line?
    result.IsFailed = ok.IsFailure();

    if (ok.IsSuccess()) {
        successfulUploads.Add(result.RemotePath);
    }
    else if ((int)errorHandling > 1) {
        errorEncountered = true;
        break;
    }
}

I'd also like to have the information of why the file failed top copy, in this case the 550 error

Logs :

[Edited to remove some private information]

# AutoConnect()

# AutoDetect(CloneConnection = False, FirstOnly = True, IncludeImplicit = True, AbortOnTimeout = True, RequireEncryption = False, ProtocolPriority = [Tls11, Tls12])
Status:   Auto-Detect trying encryption mode "Auto" with "Tls11, Tls12"

# Connect(False)
Status:   FluentFTP 51.1.0.0(.NET 6.0) AsyncFtpClient
Status:   Connecting(async) AsyncFtpClient.FtpSocketStream(control) IP #1 = ***:21
Status:   Waiting for a response
Response: 220 R-30iB FTP server ready. [SpotTool+ V8.30P/70] [739182.711d]
Command:  AUTH TLS
Status:   Waiting for response to: AUTH TLS
Response: 500 Command not understood. [6ms]
Command:  USER ***
Status:   Waiting for response to: USER ***
Response: 230 User logged in [NORM]. [13ms]
Command:  FEAT
Status:   Waiting for response to: FEAT
Response: 500 Command not understood. [12ms]
Status:   Text encoding: System.Text.UTF8Encoding+UTF8EncodingSealed
Command:  OPTS UTF8 ON
Status:   Waiting for response to: OPTS UTF8 ON
Response: 500 Command not understood. [3ms]
Command:  SYST
Status:   Waiting for response to: SYST
Response: 215 UNKNOWN [SpotTool+ V8.30P/70]. [20ms]
Status:   Active ServerHandler is: None
Warning:  Cannot auto-detect listing parser for system 'Unknown', using Unix parser
Status:   Listing parser set to: Unix
Command:  PWD
Status:   Waiting for response to: PWD
Response: 257 "md:\" is current directory. [3ms]

# SetWorkingDirectory("MD:")
Command:  CWD MD:
Status:   Waiting for response to: CWD MD:
Response: 250 CWD command successful. [4ms]
Command:  PWD
Status:   Waiting for response to: PWD
Response: 257 "md:\" is current directory. [7ms]

# UploadFiles(System.Linq.Enumerable+WhereSelectListIterator`2[System.String], "/", Skip, False, Retry, None)

# GetNameListing("/")
Command:  TYPE I
Status:   Waiting for response to: TYPE I
Response: 200 Type set to  I [5ms]

# OpenDataStreamAsync("NLST /", 0)

# OpenPassiveDataStreamAsync(PASV, "NLST /", 0)
Command:  PASV
Status:   Waiting for response to: PASV
Response: 227 Entering Passive Mode (XXX,XXX,XXX,XXX,107,110) [6ms]
Status:   Connecting(async) AsyncFtpClient.FtpSocketStream(data) IP #1 = ***:27502
Command:  NLST /
Status:   Waiting for response to: NLST /
Response: 150 ASCII data connection. [17ms]
+---------------------------------------+
Listing:  fr:
Listing:  mc:
Listing:  md:
Listing:  mdb:
Listing:  rd:
Listing:  ud1:
Listing:  ut1:
Status:   Disposing(async) AsyncFtpClient.FtpSocketStream(data)

# CloseDataStream()
Status:   Waiting for response to: NLST /
Response: 226 ASCII Transfer complete. [54ms]
-----------------------------------------
Status:   Disposing(async) AsyncFtpClient.FtpSocketStream(data) (redundant)

# UploadFile("/test.xml", "/test.xml", Skip, False, Retry)

# OpenWrite("/test.xml", Binary, -1, False)

# OpenDataStreamAsync("STOR /test.xml", 0)

# OpenPassiveDataStreamAsync(PASV, "STOR /test.xml", 0)
Command:  PASV
Status:   Waiting for response to: PASV
Response: 227 Entering Passive Mode (XXX,XXX,XXX,XXX,109,111) [5ms]
Status:   Connecting(async) AsyncFtpClient.FtpSocketStream(data) IP #1 = ***:28015
Command:  STOR /test.xml
Status:   Waiting for response to: STOR /test.xml
Response: 150 Binary data connection. [15ms]
Status:   Uploaded 83 bytes, 3ms, 26.4 KB/s
Status:   Disposing(async) AsyncFtpClient.FtpSocketStream(data)
Status:   Waiting for response to: STOR /test.xml
Response: 550 Device Function Code invalid [64ms]
Source server does not support any common hashing algorithm
Falling back to file size comparison

# GetFileSize("/test.xml", -1)
Status:   File Verification: FAIL

# Disconnect()
Command:  QUIT
Status:   Waiting for response to: QUIT
Response: 221 Goodbye. [9ms]
Status:   Disposing(async) AsyncFtpClient.FtpSocketStream(control)

# Dispose()
Status:   Warning: sync dispose called for AsyncFtpClient object

# DisposeAsync()
Status:   Disposing(async) AsyncFtpClient

# Disconnect()
Status:   Connection already closed, nothing to do.
Status:   Disposing(async) AsyncFtpClient.FtpSocketStream(control) (redundant)

To give a little more information, we don't have a problem with the FTP process itself. I believe our Robot Controller is denying this file to be copied for a legitimate reason. We are able to successfully download and upload other legitimate files. Our concern is only with the reporting so that we can display why things failed: display the 550 error, etc.

If you need any additional information, please let me know. Thanks!

FanDjango commented 3 weeks ago

Thanks for this input.

I have made some initial changes to take the IsFailed() fact, just as you suggested, and merged those changes. Perhaps you could try out the current master instead of Nuget and we can take this from there to see if we can percolate the failure reason into the FtpResult as a next step.

Note that I can find "550 Device Function Code invalid" in Google - especially in FANUC and Robotics contexts, just as an aside.

FanDjango commented 3 weeks ago

Despite the failure, we're not seeing the IsFailed flag as true in the FtpResult object.

I feel that IsFailed is sort of redundant, in that IsFailed is in effect <---- not IsSuccess and not IsSkipped, but I suppose it is included more or less for completeness.

trinnan42 commented 3 weeks ago

I feel that IsFailed is sort of redundant, in that IsFailed is in effect <---- not IsSuccess and not IsSkipped, but I suppose it is included more or less for completeness.

Yeah that makes sense. My concern was that we were also seeing some situations where we were successfully copying but not getting the IsSuccess flag (nor any other flag). I'll need to look into that some more though, because later I was getting the IsSuccess flag. Not sure yet if we can recreate it or not...

We're working on testing with the current master.

trinnan42 commented 3 weeks ago

We tested with those changes and we are now getting IsSuccess and IsFailed as expected.

see if we can percolate the failure reason into the FtpResult as a next step.

That would be great!

FanDjango commented 2 weeks ago

@trinnan42

I just realised that there might already be a nice way for you to check "what happened". About a year or even longer ago, I put a property into the client called

        /// <summary> Gets the last replies received from the server</summary>
        public List<FtpReply> LastReplies { get; set; }

This will supply you with the last 5 FtpReplys. You should be able to see a 5xx and text et al.

I think, at the time, I needed more information myself in an application I was coding - especially as sometimes a failure message may be preceeded by more information (otherwise lost).

trinnan42 commented 2 weeks ago

Could we assign the LastReply to an FtpReply property of each FtpResult?

If we only have the LastReply and LastReplies properties, I think we would need to write some logic to determine how to associate the replies with each file we're uploading/downloading. Especially since we're also now using the UploadDirectory and DownloadDirectory methods so at the moment we don't have a list on our end of the files we're intending to copy. (Speaking of: will the changes for populating the IsFailed property on FtpResult be reflected in those.)

I appreciate your time helping us out here and I would be willing to do a PR to make these changes if you want. Thanks!

FanDjango commented 2 weeks ago

Could we assign the LastReply to an FtpReply property of each FtpResult?

Oops, my bad. I totally forgot that we are populating this list. And yes, one would need to add the LastReplies list to the FtpReply list.

I think I also want to investigate passing other errors (beyond FTP server error replies) up to the top. Think of I/O errors, timeouts and so on.

So my previous suggestions was simply premature and born out of over-enthusiasm.

would be willing to do a PR to make these changes

Always appreciated. But let's find the most beautiful way do fix this first.

FanDjango commented 2 weeks ago

I've been playing around with the current code (with our recent addition).

Look - failures should be found in the Exception field of the FtpResult.

image

550 Device Function Code invalid as response would also cause such a result. The problem seems to be that a verification is subsquently performed, whose failure masks the previous failure.

Need to look at that in more detail.

FanDjango commented 1 week ago

Can you also check what I mentioned in my last post?