Search code examples
c#azure.net-corefluentftp

FluentFtp Azure ftp user cannot log in after few successful connections


I am having some issues when trying to hit ftp many times. For example we have hundred files in ftp and I try to download one with each request/endpoint hit. After random connections number, log shows that for some time we no longer can log in to ftp but further in process it corrects itself. Can this be caused by too many requests in short time? Any idea for improving reliability of connection much appreciated?

2021-02-24 14:56:02.601 +00:00 [Information] Status:   Connecting to xx.xx.xx.xx:21
2021-02-24 14:56:02.613 +00:00 [Information] Response: 220 Microsoft FTP Service
2021-02-24 14:56:02.614 +00:00 [Information] Status:   Detected FTP server: WindowsServerIIS
2021-02-24 14:56:02.617 +00:00 [Information] Command:  AUTH TLS
2021-02-24 14:56:02.624 +00:00 [Information] Response: 234 AUTH command ok. Expecting TLS Negotiation.
2021-02-24 14:56:02.629 +00:00 [Information] Status:   FTPS Authentication Successful
2021-02-24 14:56:02.630 +00:00 [Information] Command:  USER xxx\$xxxftp
2021-02-24 14:56:02.634 +00:00 [Information] Response: 331 Password required
2021-02-24 14:56:02.635 +00:00 [Information] Command:  PASS ***
2021-02-24 14:56:02.696 +00:00 [Information] Response: 230 User logged in.
2021-02-24 14:56:02.697 +00:00 [Information] Command:  PBSZ 0
2021-02-24 14:56:02.702 +00:00 [Information] Response: 200 PBSZ command successful.
2021-02-24 14:56:02.703 +00:00 [Information] Command:  PROT P
2021-02-24 14:56:02.707 +00:00 [Information] Response: 200 PROT command successful.
2021-02-24 14:56:02.708 +00:00 [Information] Command:  FEAT
2021-02-24 14:56:02.711 +00:00 [Information] Response: 211 END
2021-02-24 14:56:02.712 +00:00 [Information] Status:   Text encoding: System.Text.UTF8Encoding+UTF8EncodingSealed
2021-02-24 14:56:02.713 +00:00 [Information] Command:  OPTS UTF8 ON
2021-02-24 14:56:02.716 +00:00 [Information] Response: 200 OPTS UTF8 command successful - UTF8 encoding now ON.
2021-02-24 14:56:02.716 +00:00 [Information] Command:  SYST
2021-02-24 14:56:02.719 +00:00 [Information] Response: 215 Windows_NT
2021-02-24 14:56:02.720 +00:00 [Information] Command:  TYPE I
2021-02-24 14:56:02.723 +00:00 [Information] Response: 200 Type set to I.
2021-02-24 14:56:02.724 +00:00 [Information] Command:  PASV
2021-02-24 14:56:02.727 +00:00 [Information] Response: 227 Entering Passive Mode (xx,xxx,xxx,xxx,xx,x).
2021-02-24 14:56:02.728 +00:00 [Information] Status:   Connecting to xx.xx.xx.xx:10246
2021-02-24 14:56:02.731 +00:00 [Information] Command:  RETR /site/ftp/xxx.pdf
2021-02-24 14:56:02.736 +00:00 [Information] Response: 125 Data connection already open; Transfer starting.
2021-02-24 14:56:02.741 +00:00 [Information] Status:   FTPS Authentication Successful
2021-02-24 14:56:02.835 +00:00 [Information] Response: 226 Transfer complete.
2021-02-24 14:56:02.836 +00:00 [Information] Command:  QUIT
2021-02-24 14:56:02.842 +00:00 [Information] Response: 221 Goodbye.
2021-02-24 14:56:02.854 +00:00 [Information] Status:   Connecting to xx.xxx.xxx.xxx:21
2021-02-24 14:56:02.861 +00:00 [Information] Response: 220 Microsoft FTP Service
2021-02-24 14:56:02.861 +00:00 [Information] Status:   Detected FTP server: WindowsServerIIS
2021-02-24 14:56:02.862 +00:00 [Information] Command:  AUTH TLS
2021-02-24 14:56:02.865 +00:00 [Information] Response: 234 AUTH command ok. Expecting TLS Negotiation.
2021-02-24 14:56:02.870 +00:00 [Information] Status:   FTPS Authentication Successful
2021-02-24 14:56:02.872 +00:00 [Information] Command:  USER xxxftp\$xxxftp
2021-02-24 14:56:02.874 +00:00 [Information] Response: 331 Password required
2021-02-24 14:56:02.875 +00:00 [Information] Command:  PASS ***
2021-02-24 14:56:02.884 +00:00 [Information] Response: 530 User cannot log in.
2021-02-24 14:56:02.884 +00:00 [Information] Command:  QUIT
2021-02-24 14:56:02.887 +00:00 [Information] Response: 221 Goodbye.

And code responsible for connection:

 private void InitializeFtpConnection(FtpClient _ftpClient)
    {
        if (!_ftpClient.IsConnected)
        {
            _ftpClient.EncryptionMode = FtpEncryptionMode.Explicit;
            _ftpClient.SslProtocols = SslProtocols.Tls12;
            _ftpClient.DataConnectionType = FtpDataConnectionType.PASV;
            _ftpClient.RetryAttempts = 10;
            _ftpClient.OnLogEvent = OnFTPLogEvent;
            _ftpClient.ValidateCertificate += new FtpSslValidation(OnValidateCertificate);

            _ftpClient.Connect();              
        }
    }

    //method called from service
    private byte[] TryGetFile(string filename, FileStorageLocation fromLocation)
    {
        byte[] fileDownload = null;

        for (int i = 1; i <= retryCount; i++)
        {
            using (var _ftpClient = new FtpClient(_activeAddress, _username, _password))
            {
                try
                {
                    InitializeFtpConnection(_ftpClient);
                    _ftpClient.Download(out fileDownload, $"{GetBaseUrl(fromLocation)}/{filename}");
                    return fileDownload;
                }
                catch (Exception e)
                {
                    if (i == retryCount)
                    {
                        throw new Exception("Failed downloading a file from the FTP server.", e);
                    }
                }
            }
        }
        return null;
    }

Update: It as on azure app service acting as an FTP.


Solution

  • Posting an answer how i mitigated this issue. According to this thread https://social.msdn.microsoft.com/Forums/en-US/61532ef2-d3d8-4151-bcdf-c4c2dc144197/is-there-an-ftp-connection-limit-to-azure-web-apps?forum=windowsazurewebsitespreview, Azure App Service Ftp has limit of 3 connections per second and as FTP requires new connection for each operation we were exceeding this limit, thus getting errors that user cannot log in. Adding Polly and retry pattern, usually after second attempt app reconnects and continue executing tasks. Here is some example code:

     private Polly.Retry.RetryPolicy retryPolicy;
    
        public FtpServerDocumentReader()
        {
            
    
            retryPolicy = Policy.Handle<Exception>().WaitAndRetry(5,retryAttempt => TimeSpan.FromSeconds(Math.Pow(2, retryAttempt)),
                        onRetry: (response, calculatedWaitDuration) =>
                        {
                            logger.LogWarning($"Failed attempt. Waited for {calculatedWaitDuration}. Retrying. {response.Message} - {response.StackTrace}");
                        });
        }
       private void InitializeFtpConnection(FtpClient _ftpClient)
            {
                if (!_ftpClient.IsConnected)
                {
                    _ftpClient.EncryptionMode = FtpEncryptionMode.Explicit;
                    _ftpClient.SslProtocols = SslProtocols.Tls12;
                    _ftpClient.DataConnectionType = FtpDataConnectionType.PASV;
                    _ftpClient.RetryAttempts = 10;
                    _ftpClient.OnLogEvent = OnFTPLogEvent;
                    _ftpClient.ValidateCertificate += new FtpSslValidation(OnValidateCertificate);
    
                    retryPolicy.Execute(() =>
                    {
                        _ftpClient.Connect();
                    });
                }
            }
       private void UploadFile(string filename, byte[] file, FileStorageLocation toLocation = FileStorageLocation.Archive)
            {
                FtpStatus result = new FtpStatus();
    
                using (var _ftpClient = new FtpClient(_activeAddress, _username, _password))
                {
                    try
                    {
                        InitializeFtpConnection(_ftpClient);
                        result = _ftpClient.Upload(file, $"{GetBaseUrl(toLocation)}/{filename}");
                        if (result == FtpStatus.Success)
                        {
                            _logger.LogInformation($"File {filename} uploaded to {toLocation} on FTP server");
                        }
                    }
                    catch (Exception e)
                    {
                        _logger.LogError(e, $"Failed uploading a file to the server. Filename: {filename}, username: {_username}, server: {_archiveAddress}");
                    }
                }
            }