Our Products:   CompleteFTP  edtFTPnet/Free  edtFTPnet/PRO  edtFTPj/Free  edtFTPj/PRO
0 votes
8.6k views
in .NET FTP by (120 points)
edtEFTPnetPRO version: 7.4.0.20

We are receiving SFTP exceptions "No such file (code=2)", when transferring using UploadStream fairly regularly.  The ftp site in question renames and automatically moves the file after the transfer is completed.  I believe this rename and moving is causing a race condition with the operations performed by the ftp component (such as chmod) after the upload is complete.  The owners of the FTP site aren't going to change anything, but do have a test location (which they claim is the same as the production location).  Unfortunately, I have been unable to duplicate the exception on the test location.  Therefore I am unable to really provide a log with the exception being thrown.  The log for the test location does have the error in it but it does not cause an exception in the .NET code.  I have included a copy of the log for the test location and the test code which I am using.  I know the chmod can be turned off, but am unsure that will help as there are other operations done by the ftp component after the upload is complete.  Any assistance would be greatly appreciated.

JP
by (120 points)
try
                {
                    string ftpLogFile = @"FTP.log";
                    if(File.Exists(ftpLogFile))
                        File.Delete(ftpLogFile);
     
                    using (SecureFTPConnection ftp = new SecureFTPConnection()
                    {
                        LicenseOwner = "REDACTED",
                        LicenseKey = "REDACTED",
                        ServerAddress = "REDACTED",
                        ServerPort = 22,
                        UserName = "REDACTED",
                        Password = "REDACTED",
                        Protocol = FileTransferProtocol.SFTP,
                        ServerValidation = SecureFTPServerValidationType.None,
                        ConnectMode = FTPConnectMode.PASV,
                    })
                    {
                        SecureFTPConnection.LogFile = ftpLogFile;
                        SecureFTPConnection.LogLevel = EnterpriseDT.Util.Debug.LogLevel.All;
     
                        Console.WriteLine("Before Connect");
                        ftp.Connect();
                        Console.WriteLine("After Connect");
                        Console.WriteLine("Changing to directory: 'Samples/To'");
                        ftp.ChangeWorkingDirectory("Samples/To");
                       
                        foreach (var fileName in Directory.GetFiles("Test", "IgnoreTest*.txt"))
                        {
                            using (var stream = File.Open(fileName, FileMode.Open, FileAccess.Read, FileShare.Read))
                            {
                                Console.WriteLine("Uploading file '{0}'", stream.Name);
                                ftp.UploadStream(stream, Path.GetFileName(fileName), false);
                                Console.WriteLine("Upload Complete");
                            }
                        }
     
                        ftp.Close();
                    }
                }
                catch (Exception ex)
                {
                    Console.WriteLine(ex.ToString());
                }
     
                Console.WriteLine("Press any key to continue.");
                Console.ReadKey();
by (120 points)
DEBUG [SSH2Connection] 16 Nov 2016 09:15:43.683 : ProcessPacket pt=SSH_MSG_CHANNEL_SUCCESS
DEBUG [SSH2Channel] 16 Nov 2016 09:15:43.683 : ProcessPacket: status= 1, pt=SSH_MSG_CHANNEL_SUCCESS
DEBUG [SSH2Channel] 16 Nov 2016 09:15:43.683 : OpenSFTP pt=SSH_MSG_CHANNEL_SUCCESS
DEBUG [SSHFTPClient] 16 Nov 2016 09:15:43.784 : SSH channel opened
ALL [SFTPMessage] 16 Nov 2016 09:15:43.789 : Send : Name=SSH_FXP_INIT,Type=1,RequestID=0
    version=3
DEBUG [SSH2Channel] 16 Nov 2016 09:15:43.792 : Transmit 9 bytes
DEBUG [ChannelDataWindow] 16 Nov 2016 09:15:43.793 : Remote window size decreased to 131063
DEBUG [PlainSocket] 16 Nov 2016 09:15:43.904 : RepeatCallback received 52 bytes
DEBUG [SSH2Connection] 16 Nov 2016 09:15:43.904 : ProcessPacket pt=SSH_MSG_CHANNEL_DATA
DEBUG [SSHChannel] 16 Nov 2016 09:15:43.905 : Channel 0: sent SSH_MSG_CHANNEL_WINDOW_ADJUST
DEBUG [SSH2Channel] 16 Nov 2016 09:15:43.905 : Local window size increased to 131071
ALL [AbstractSFTPChannelReceiver] 16 Nov 2016 09:15:43.908 : NextMessageLength=5
DEBUG [SFTPMessageFactory] 16 Nov 2016 09:15:43.910 : Received message (type=2,len=5)
DEBUG [SFTPMessageStore] 16 Nov 2016 09:15:43.912 : AddMessage(0) - added to store
ALL [SFTPMessage] 16 Nov 2016 09:15:43.912 : Reply : Name=SSH_FXP_VERSION,Type=2,RequestID=0
    version=3
    extension count=0
DEBUG [SFTPSubsystem] 16 Nov 2016 09:15:43.913 : SFTP subsystem started
DEBUG [SSHFTPClient] 16 Nov 2016 09:15:43.913 : Connect() succeeded
ALL [SFTPMessage] 16 Nov 2016 09:15:43.916 : Send : Name=SSH_FXP_REALPATH,Type=16,RequestID=1
...
DEBUG [SSHFTPClient] 16 Nov 2016 09:16:06.603 : ResolveRemotePath('IgnoreTest4.txt')
DEBUG [SSHFTPClient] 16 Nov 2016 09:16:06.603 : Resolved to '/Samples/To/IgnoreTest4.txt'
DEBUG [SSHFTPClient] 16 Nov 2016 09:16:06.604 : Remote path=/Samples/To/IgnoreTest4.txt
DEBUG [SSHFTPClient] 16 Nov 2016 09:16:06.604 : ResolveRemotePath('/Samples/To/IgnoreTest4.txt')
DEBUG [SSHFTPClient] 16 Nov 2016 09:16:06.604 : Resolved to '/Samples/To/IgnoreTest4.txt'
DEBUG [SFTPSubsystem] 16 Nov 2016 09:16:06.604 : GetAttributes(/Samples/To/IgnoreTest4.txt)
ALL [SFTPMessage] 16 Nov 2016 09:16:06.604 : Send : Name=SSH_FXP_STAT,Type=17,RequestID=34
    path=/Samples/To/IgnoreTest4.txt
DEBUG [SSH2Channel] 16 Nov 2016 09:16:06.604 : Transmit 46 bytes
DEBUG [ChannelDataWindow] 16 Nov 2016 09:16:06.604 : Remote window size decreased to 101811
DEBUG [PlainSocket] 16 Nov 2016 09:16:07.599 : RepeatCallback received 84 bytes
DEBUG [SSH2Connection] 16 Nov 2016 09:16:07.599 : ProcessPacket pt=SSH_MSG_CHANNEL_DATA
ALL [AbstractSFTPChannelReceiver] 16 Nov 2016 09:16:07.599 : NextMessageLength=29
DEBUG [SFTPMessageFactory] 16 Nov 2016 09:16:07.599 : Received message (type=101,len=29)
DEBUG [SFTPMessage] 16 Nov 2016 09:16:07.599 : ErrorCode|Status=2
DEBUG [SFTPMessageStore] 16 Nov 2016 09:16:07.599 : AddMessage(34) - added to store
ALL [SFTPMessage] 16 Nov 2016 09:16:07.599 : Reply : Name=SSH_FXP_STATUS,Type=101,RequestID=34
    errorCode=2
    errorMessage=No such file
    language=
    WARN [SFTPSubsystem] 16 Nov 2016 09:16:07.599 : GetAttributes: No such file : /Samples/To/IgnoreTest4.txt
DEBUG [SSHFTPClient] 16 Nov 2016 09:16:07.624 : Catching and ignoring exception: No such file : /Samples/To/IgnoreTest4.txt (code=2)
ALL [SFTPMessage] 16 Nov 2016 09:16:07.624 : Send : Name=SSH_FXP_OPEN,Type=3,RequestID=35
    absolutePath=/Samples/To/IgnoreTest4.txt
    flags=26
    attributes=US=, G=, D=False, F=False, LI=False, R=True, W=True, AT=0, AD=1/1/1970 12:00:00 AM, MT=0, MD=1/1/1970 12:00:00 AM, P=493, S=0, U=prwxr-xr-x
DEBUG [SSH2Channel] 16 Nov 2016 09:16:07.624 : Transmit 62 bytes
by (162k points)
There is a flag where you can disable the chmod.

Also, consider uploading with a different name that the server won't automatically move (if possible), and then do a rename.
by (120 points)
I already knew about the flag for chmod.  Unfortunately, edtFTPnetPRO is used in a large job/task application and there is not a way to set the flag without a complete recompile, and test cycle.  Unless there is a way to set the flag via the app.config file.

Changing the name of the file will not have any effect, as the ftp site does the rename and moving of the file, immediately after the upload is complete.

This is my assumption of the problem.
1. We use edtFTPnetPRO to upload the file.
2. edtFTPnetPRO does some operations behind the scenes after the transfer is complete (i.e. chmod, check file length, etc.  These are two that I have seen in the log).
3. While edtFTPnetPRO is doing the extra operations after the transfer but before the UploadStream function returns to us, the ftp site renames and moves the file.
4. This causes the error due to the extra operations fail.

Does this make sense?
by (162k points)
Sounds right.

Please log in or register to answer this question.

Categories

...