Sftp async - one connection works, but two or more do not when seeking to delete a file on the remote server.

+1 vote
asked Dec 18, 2020 by jncode (130 points)
edited Dec 18, 2020 by jncode

I have a console application which is designed to connect to all of the retail stores via sftp. Deletes simply do not work when I'm doing multiple [new Sftp()] connections. If I have only one that I'm doing, it works flawlessly, every time. It's when I specify doing multiple simultaneous connections, that things go awry. Please advise.

I will also add that I'm using the current trial version available. I can purchase once I have a working solution.

It's basically just a list of tasks awaited (Task.WhenAll), but the results each time do indeed show that the rock-solid functionality of deletes is affected when not processing only one at a time. Not sure why. In any case, I'm on a deadline, so any help is greatly appreciated. I have truly enjoyed this product otherwise.

One final thing to add... When I run it with two endpoints to run the delete against, the first which did have a file, had it deleted successfully, but the second, which also had a file, did not delete, and my code routes it to the error section where it states it did not find a file (when there is indeed one there). The pathing is the same at each endpoint, so that would not affect anything or be different from endpoint(retail store) to endpoint.

Update:
Well, I thought I had narrowed out the connection info. It does appear that multiple connections (not all) share the same connection info. I'm investigating to see if it's something I'm doing on my end.

My code:

        private async Task<HpcTaskResult> SftpDeleteRemoteFileAsync(string remoteFilename)
    {
        var result = new HpcTaskResult { Store = base.ContextConfig.Store };
        using (var sftp = new Sftp
        {
            Timeout = _timeoutInSecs * 1000,
            ServerType = _sftpServerType,
            TransferType = _sftpXferType
        })
        {
            try
            {
                await SftpConnectAsync(sftp).ConfigureAwait(false);

                bool remoteFileExists = await sftp.FileExistsAsync(remoteFilename).ConfigureAwait(false);
                LogDebug($"'{remoteFilename}' existence: {remoteFileExists}");
                if (remoteFileExists)
                {
                    Log.Verbose("Sftp-deleting file '{0}' now...", remoteFilename);
                    await sftp.DeleteFileAsync(remoteFilename).ConfigureAwait(false);
                    remoteFileExists = await sftp.FileExistsAsync(remoteFilename).ConfigureAwait(false);
                    if (remoteFileExists)
                    {
                        throw new Exception($"Sftp-deletion of '{remoteFilename}' failed.  The file still exists!");
                    }
                    else
                    {
                        Log.Verbose("Sftp file deletion of '{RemoteFilename}' was successful.", remoteFilename);
                        return result;
                    }
                }
                else
                {
                    Log.Verbose("File deletion of '{0}' canceled. Nothing to delete.", remoteFilename);
                    return result;
                }
            }
            catch (Exception ex)
            {
                string err = ex.GetBaseException().ToString();
                if (err.ToLower().Contains("no such file"))
                {
                    Log.Verbose("File deletion of '{0}' canceled. Nothing to delete.", remoteFilename);
                    return result;
                }
                if (OS4690.FalseFlagIdentified(err) || OS4690.DisconnectedByServer(err))
                {
                    Log.Verbose("Success reported on error stream. Sftp deletion of file '{0}' was successful.", remoteFilename);
                    return result;
                }
                result.Error = ex;
                Log.Error("Sftp file deletion failed for file '{0}'. Error: {1}", remoteFilename, err);
            }
            finally
            {
                await SftpDisconnectAsync(sftp).ConfigureAwait(false);
            }
        }
        return result;
    }
Applies to: Rebex SFTP
commented Dec 21, 2020 by jncode (130 points)
edited Dec 21, 2020 by jncode
I had originally posted this as a comment, but I will include a screenshot in the original message as an update.
commented Dec 21, 2020 by Lukas Pokorny (124,610 points)
It would also be very useful if you could create a communication log using Sftp object's LogWriter property (as described at https://www.rebex.net/kb/logging/) and either post it here or mail it to support@rebex.net - hopefully, this would make it possible to tell what actually goes awry.
commented Dec 21, 2020 by Lukas Pokorny (124,610 points)
Also, regarding "multiple connections (not all) share the same connection info" - in Rebex SFTP, a single instance of `Sftp` represents a single SFTP protocol session. So if multiple instances of `Sftp` seem to interact in an unexpected way, the reason is almost certainly at the server site. Hopefully the log would provide additional information.

1 Answer

0 votes
answered Dec 21, 2020 by Lukas Matyska (60,650 points)

It is possible that you are connecting to the wrong servers - when you call:

await SftpConnectAsync(sftp).ConfigureAwait(false);

you pass only Sftp instance argument, but no connection info. How the SftpConnectAsync(sftp) method know where to connect?

It probably uses some internal fields, which are probably not synchronized with simultaneous calls of SftpConnectAsync(sftp).

You probably need to pass a connection info argument to the SftpDeleteRemoteFileAsync(string remoteFilename) method.


If you create a communication log, you can see what is going on. It can be created like this:

using (var sftp = new Sftp
{
    LogWriter = new Rebex.FileLogWriter(@"c:\data\sftp.log", Rebex.LogLevel.Debug)
})

If you have any issues with understanding the log, you can send it to support@rebex.net for analyzis.

commented Dec 21, 2020 by jncode (130 points)
edited Dec 21, 2020 by jncode
Thank you for your response, Lucas.
Please note that I am not using a static assignment.  I had thought this myself, but this is not the case.  I do have a static dictionary lookup acting as cache lookup for the connection info.  It’s assigned before dependency injection even so much as injects the first transient context housing the sftp logic, so this has been fully ruled out.  If that piece was not working correctly, I wouldn’t have any such connection info on each ConnectAsync method of the Sftp object.  Regarding the Sftp object and it knowing how to connect, I do not see that the Sftp object has the configurability for host /user/pwd at that stage.  I do however see that it can be passed in upon connecting, and this is indeed where I assign that connection info (ConnectAsync method).  This is where I’m a bit confused as to how it keeps getting off.  Also, and some more information to this issue, is the fact that it is happening not only with deletes, but anything I do.  It’s affecting uploads, downloads, deletes and the like.  I'm sending you the information you requested via email, now.

I will further add that in the logs, I can clearly see that the stores intended to be connected to, and the host information for connecting, aren't matching up.  I've been working on tracing it through, but so far, I simply do not see where the host string is getting off.  The host string is getting assigned at the time dependency injection creates the new object per the interface specified.  It's a transient object created on the fly, as that object is needed, so there should not be any such caching by DI.  It does seem to scream a DI issue though.  Normally, if I had the dependency object getting created as a transient but it is hosted in a singleton, that would cause similar issues, but I'm not doing that.  The scope is valid throughout per how things are getting called, so this is a bit of an enigma thus far.
commented Dec 21, 2020 by Lukas Matyska (60,650 points)
I am sorry, we cannot help you with this issue. It seems that the bug is not related to the Rebex Sftp at all. You are passing wrong arguments to the ConnectAsync() method.

It can be seen in your own log you provided us using email - store 7 is not connecting to the correct IP address - it is connecting to store 8 IP address.

Once you are able to fix this assignment and log correctly:

  Attempting sftp connection for store 7 to remote host 'correct_IP' now...

you will see in the Rebex Sftp log that the instances are also connecting to correct remote hosts.
commented Dec 21, 2020 by jncode (130 points)
Yes, as I stated, it is something of an enigma, but I've narrowed it down to async assignments.  It's either this component (unlikely) or another async component I'm using, or it is with the dependency injection itself.  This does not happen when I step through the debugger or have only one connection going.  Thanks and take care.
commented Dec 21, 2020 by jncode (130 points)
and yes, this log was produced after I had filed this.
...