Upgraded to 8.6.0.20 and FTPS Explicit jobs stopped working

Question

Upgraded to 8.6.0.20 and FTPS Explicit jobs stopped working

asked Dec 19, 2014 in .NET FTP by BMackenzieJHA (450 points)

Not sure why upgrading would cause it to break but maybe you can give me some ideas. Substituted client's FTP name for confidentiality reasons.

Something to note is that we have one other FTPSExplicit job but it still works for some reason.

INFO [FTPConnection] 19 Dec 2014 15:55:18.409 : OS: 6.1.7601.65536, CLR: 2.0.50727.5485, DLL: 8.6.0.20
INFO [FTPConnection] 19 Dec 2014 15:55:18.409 : Built: 3-Jul-2014 22:57:04 EST
DEBUG [LicenseProperties] 19 Dec 2014 15:55:18.409 : Looking for subkey Software\Enterprise Distributed Technologies\edtFTPnet PRO (fallback )
DEBUG [LicenseProperties] 19 Dec 2014 15:55:18.409 : Found license subkey Software\Enterprise Distributed Technologies\edtFTPnet PRO
DEBUG [LicenseProperties] 19 Dec 2014 15:55:18.409 : Did not find license subkeys Software\Enterprise Distributed Technologies\edtFTPnet PRO or in registry
DEBUG [LicenseProperties] 19 Dec 2014 15:55:18.409 : Looking for subkey Software\Enterprise Distributed Technologies\edtFTPnet PRO (fallback )
DEBUG [LicenseProperties] 19 Dec 2014 15:55:18.409 : Found license subkey Software\Enterprise Distributed Technologies\edtFTPnet PRO
DEBUG [LicenseProperties] 19 Dec 2014 15:55:18.409 : Did not find license subkeys Software\Enterprise Distributed Technologies\edtFTPnet PRO or in registry
DEBUG [LicenseProperties] 19 Dec 2014 15:55:18.425 : Looking for subkey Software\Enterprise Distributed Technologies\edtFTPnet PRO (fallback )
DEBUG [LicenseProperties] 19 Dec 2014 15:55:18.425 : Found license subkey Software\Enterprise Distributed Technologies\edtFTPnet PRO
DEBUG [LicenseProperties] 19 Dec 2014 15:55:18.425 : Did not find license subkeys Software\Enterprise Distributed Technologies\edtFTPnet PRO or in registry
DEBUG [LicenseProperties] 19 Dec 2014 15:55:18.425 : Looking for subkey Software\Enterprise Distributed Technologies\edtFTPnet PRO (fallback )
DEBUG [LicenseProperties] 19 Dec 2014 15:55:18.425 : Found license subkey Software\Enterprise Distributed Technologies\edtFTPnet PRO
DEBUG [LicenseProperties] 19 Dec 2014 15:55:18.425 : Did not find license subkeys Software\Enterprise Distributed Technologies\edtFTPnet PRO or in registry
DEBUG [SFTPMessageStore] 19 Dec 2014 15:55:18.425 : Set timeout=120000
INFO [LicenseProperties] 19 Dec 2014 15:55:18.440 : Licence expiry date: 12/31/9999
INFO [LicenseProperties] 19 Dec 2014 15:55:18.440 : Production license
DEBUG [FTPConnection] 19 Dec 2014 15:55:18.440 : Set LocalDirectory='C:\WINDOWS\SysWOW64\inetsrv'
DEBUG [SecureFTPConnection] 19 Dec 2014 15:55:18.440 : Set LocalDirectory to C:\WINDOWS\SysWOW64\inetsrv
INFO [LicenseProperties] 19 Dec 2014 15:55:18.440 : Licence expiry date: 12/31/9999
INFO [LicenseProperties] 19 Dec 2014 15:55:18.440 : Production license
DEBUG [SSLFTPClient] 19 Dec 2014 15:55:18.440 : Connecting to ClientFTPServerName:5555
DEBUG [SSLFTPControlSocket] 19 Dec 2014 15:55:18.440 : waitOnShutdownSSL=True
DEBUG [ExFTPControlSocket] 19 Dec 2014 15:55:18.456 : Created control-socket: SocksContext=, ProxySettings=NoProxy, RemoteHost=ClientFTPServerName, controlPort=5555, timeout=120000
DEBUG [FTPControlSocket] 19 Dec 2014 15:55:18.456 : StrictReturnCodes=False
DEBUG [HostNameResolver] 19 Dec 2014 15:55:18.456 : Resolving ClientFTPServerName
DEBUG [HostNameResolver] 19 Dec 2014 15:55:18.456 : Obtained 1 addresses
DEBUG [HostNameResolver] 19 Dec 2014 15:55:18.456 : IP address: 140.108.21.109
DEBUG [HostNameResolver] 19 Dec 2014 15:55:18.456 : ClientFTPServerName resolved to 140.108.21.109
DEBUG [ExFTPControlSocket] 19 Dec 2014 15:55:18.456 : Connecting directly to ftp-server ClientFTPServerName:5555
INFO [SSLFTPSocket] 19 Dec 2014 15:55:18.456 : Connecting to 140.108.21.109:5555 with timeout 120000 ms
DEBUG [SSLFTPSocket] 19 Dec 2014 15:55:18.534 : Successfully connected to 140.108.21.109:5555
DEBUG [FTPControlSocket] 19 Dec 2014 15:55:18.534 : Setting socket timeout=120000
ALL [SecureSocket] 19 Dec 2014 15:55:18.534 : SecureSocket timeout=120000
ALL [SecureSocket] 19 Dec 2014 15:55:18.534 : SecureSocket timeout=120000
INFO [FTPControlSocket] 19 Dec 2014 15:55:18.534 : Command encoding=System.Text.SBCSCodePageEncoding
DEBUG [FTPControlSocket] 19 Dec 2014 15:55:18.612 : 220 CONNECT:Enterprise Gateway 2.1.00. FTP Server ready...
DEBUG [FTPControlSocket] 19 Dec 2014 15:55:18.612 : ---> AUTH TLS
DEBUG [FTPControlSocket] 19 Dec 2014 15:55:18.690 : 234 AUTH: command accepted. Securing command channel ...
DEBUG [SSLFTPControlSocket] 19 Dec 2014 15:55:18.690 : Beginning Ssl3, Tls1, Tls11 handshake.
DEBUG [SocketController] 19 Dec 2014 15:55:18.783 : FTPConnection.1 Processing hello
ALL [HandshakeLayer] 19 Dec 2014 15:55:18.799 : FTPConnection.1 ProcessMessages(Handshake)
ALL [HandshakeLayer] 19 Dec 2014 15:55:18.799 : FTPConnection.1 Handshake Message: ServerHello
ALL [HandshakeLayer] 19 Dec 2014 15:55:18.799 : FTPConnection.1 ProcessMessages(Handshake)
ALL [HandshakeLayer] 19 Dec 2014 15:55:18.799 : FTPConnection.1 Handshake Message: Certificate
ALL [HandshakeLayer] 19 Dec 2014 15:55:18.815 : FTPConnection.1 ProcessMessages(Handshake)
ALL [HandshakeLayer] 19 Dec 2014 15:55:18.815 : FTPConnection.1 Handshake Message: ServerHelloDone
WARN [SocketController] 19 Dec 2014 15:55:18.908 : FTPConnection.1 OnReceive - (An existing connection was forcibly closed by the remote host) - closing
DEBUG [SocketController] 19 Dec 2014 15:55:18.908 : FTPConnection.1 CloseConnection(e=An existing connection was forcibly closed by the remote host)
DEBUG [SocketController] 19 Dec 2014 15:55:18.908 : FTPConnection.1 Closed socket
DEBUG [TransferBuffer] 19 Dec 2014 15:55:18.908 : FTPConnection.1 Close() called when open
DEBUG [SecureSocket] 19 Dec 2014 15:55:18.908 : FTPConnection.1 OnHandshakeComplete(False,An existing connection was forcibly closed by the remote host)
ERROR [SecureSocket] 19 Dec 2014 15:55:18.908 : Exception during handshake: An existing connection was forcibly closed by the remote host
DEBUG [SocketController] 19 Dec 2014 15:55:50.433 : FTPConnection.1 Dispose()
DEBUG [SocketController] 19 Dec 2014 15:55:50.433 : FTPConnection.1 CloseConnection(e=null)

7 Answers

support2 · Answer 1 · 2014-12-20T00:17:54+0000

Perhaps the server doesn't support TLS 1?

Try setting the SSLVersion to SSLFTPSSLVersion.SSL3

BMackenzieJHA · Answer 2 · 2014-12-22T14:55:59+0000

That unfortunately did not seem to fix the issue. I tried hard coding the SSLVersion to SSLFTPSSLVersion.SSL3 just for a quick test and look to be getting the same results. I'm puzzled on this. I thought for sure that would work.

Here are the logs.

DEBUG [SocketController] 22 Dec 2014 09:44:22.425 : FTPConnection.1 CloseConnection(e=null)
INFO [FTPConnection] 22 Dec 2014 09:44:22.440 : OS: 6.1.7601.65536, CLR: 2.0.50727.5485, DLL: 8.6.3.20
INFO [FTPConnection] 22 Dec 2014 09:44:22.440 : Built: 18-Nov-2014 10:00:14 GMT
DEBUG [LicenseProperties] 22 Dec 2014 09:44:22.440 : Looking for subkey Software\Enterprise Distributed Technologies\edtFTPnet PRO (fallback )
DEBUG [LicenseProperties] 22 Dec 2014 09:44:22.440 : Found license subkey Software\Enterprise Distributed Technologies\edtFTPnet PRO
DEBUG [LicenseProperties] 22 Dec 2014 09:44:22.440 : Did not find license subkeys Software\Enterprise Distributed Technologies\edtFTPnet PRO or in registry
DEBUG [LicenseProperties] 22 Dec 2014 09:44:22.440 : Looking for subkey Software\Enterprise Distributed Technologies\edtFTPnet PRO (fallback )
DEBUG [LicenseProperties] 22 Dec 2014 09:44:22.440 : Found license subkey Software\Enterprise Distributed Technologies\edtFTPnet PRO
DEBUG [LicenseProperties] 22 Dec 2014 09:44:22.440 : Did not find license subkeys Software\Enterprise Distributed Technologies\edtFTPnet PRO or in registry
DEBUG [LicenseProperties] 22 Dec 2014 09:44:22.440 : Looking for subkey Software\Enterprise Distributed Technologies\edtFTPnet PRO (fallback )
DEBUG [LicenseProperties] 22 Dec 2014 09:44:22.440 : Found license subkey Software\Enterprise Distributed Technologies\edtFTPnet PRO
DEBUG [LicenseProperties] 22 Dec 2014 09:44:22.440 : Did not find license subkeys Software\Enterprise Distributed Technologies\edtFTPnet PRO or in registry
DEBUG [LicenseProperties] 22 Dec 2014 09:44:22.440 : Looking for subkey Software\Enterprise Distributed Technologies\edtFTPnet PRO (fallback )
DEBUG [LicenseProperties] 22 Dec 2014 09:44:22.440 : Found license subkey Software\Enterprise Distributed Technologies\edtFTPnet PRO
DEBUG [LicenseProperties] 22 Dec 2014 09:44:22.440 : Did not find license subkeys Software\Enterprise Distributed Technologies\edtFTPnet PRO or in registry
DEBUG [SFTPMessageStore] 22 Dec 2014 09:44:22.440 : Set timeout=120000
INFO [LicenseProperties] 22 Dec 2014 09:44:22.440 : Licence expiry date: 12/31/9999
INFO [LicenseProperties] 22 Dec 2014 09:44:22.440 : Production license
DEBUG [FTPConnection] 22 Dec 2014 09:44:22.440 : Set LocalDirectory='C:\WINDOWS\SysWOW64\inetsrv'
DEBUG [SecureFTPConnection] 22 Dec 2014 09:44:22.440 : Set LocalDirectory to C:\WINDOWS\SysWOW64\inetsrv
INFO [LicenseProperties] 22 Dec 2014 09:44:22.440 : Licence expiry date: 12/31/9999
INFO [LicenseProperties] 22 Dec 2014 09:44:22.440 : Production license
DEBUG [SSLFTPClient] 22 Dec 2014 09:44:22.440 : Connecting to ClientFTPServerName.com:5555
DEBUG [SSLFTPControlSocket] 22 Dec 2014 09:44:22.440 : waitOnShutdownSSL=True
DEBUG [ExFTPControlSocket] 22 Dec 2014 09:44:22.440 : Created control-socket: SocksContext=, ProxySettings=NoProxy, RemoteHost=ClientFTPServerName.com, controlPort=5555, timeout=120000
DEBUG [FTPControlSocket] 22 Dec 2014 09:44:22.440 : StrictReturnCodes=False
DEBUG [HostNameResolver] 22 Dec 2014 09:44:22.440 : Resolving ClientFTPServerName.com
DEBUG [HostNameResolver] 22 Dec 2014 09:44:22.440 : Obtained 1 addresses
DEBUG [HostNameResolver] 22 Dec 2014 09:44:22.440 : IP address: 140.108.21.109
DEBUG [HostNameResolver] 22 Dec 2014 09:44:22.440 : ClientFTPServerName.com resolved to 140.108.21.109
DEBUG [ExFTPControlSocket] 22 Dec 2014 09:44:22.440 : Connecting directly to ftp-server ClientFTPServerName.com:5555
INFO [SSLFTPSocket] 22 Dec 2014 09:44:22.440 : Connecting to 140.108.21.109:5555 with timeout 120000 ms
DEBUG [SSLFTPSocket] 22 Dec 2014 09:44:22.487 : Successfully connected to 140.108.21.109:5555
DEBUG [FTPControlSocket] 22 Dec 2014 09:44:22.487 : Setting socket timeout=120000
ALL [SecureSocket] 22 Dec 2014 09:44:22.487 : SecureSocket timeout=120000
ALL [SecureSocket] 22 Dec 2014 09:44:22.487 : SecureSocket timeout=120000
INFO [FTPControlSocket] 22 Dec 2014 09:44:22.487 : Command encoding=System.Text.SBCSCodePageEncoding
DEBUG [FTPControlSocket] 22 Dec 2014 09:44:22.550 : 220 CONNECT:Enterprise Gateway 2.1.00. FTP Server ready...
DEBUG [FTPControlSocket] 22 Dec 2014 09:44:22.550 : ---> AUTH TLS
DEBUG [FTPControlSocket] 22 Dec 2014 09:44:22.596 : 234 AUTH: command accepted. Securing command channel ...
DEBUG [SSLFTPControlSocket] 22 Dec 2014 09:44:22.596 : Beginning Tls1, Tls11 handshake.
DEBUG [CompatibilityLayer] 22 Dec 2014 09:44:22.596 : Local min SSL version: 3.1, max SSL version: 3.2
DEBUG [SocketController] 22 Dec 2014 09:44:22.674 : FTPConnection.2 Processing hello
DEBUG [CompatibilityLayer] 22 Dec 2014 09:44:22.674 : FTPConnection.2 Remote SSL version: 3.2
ALL [HandshakeLayer] 22 Dec 2014 09:44:22.674 : FTPConnection.2 ProcessMessages(Handshake)
ALL [HandshakeLayer] 22 Dec 2014 09:44:22.674 : FTPConnection.2 Handshake Message: ServerHello
ALL [HandshakeLayer] 22 Dec 2014 09:44:22.674 : FTPConnection.2 ProcessMessages(Handshake)
ALL [HandshakeLayer] 22 Dec 2014 09:44:22.674 : FTPConnection.2 Handshake Message: Certificate
ALL [HandshakeLayer] 22 Dec 2014 09:44:22.674 : FTPConnection.2 ProcessMessages(Handshake)
ALL [HandshakeLayer] 22 Dec 2014 09:44:22.674 : FTPConnection.2 Handshake Message: ServerHelloDone
WARN [SocketController] 22 Dec 2014 09:44:22.737 : FTPConnection.2 OnReceive - (An existing connection was forcibly closed by the remote host) - closing
DEBUG [SocketController] 22 Dec 2014 09:44:22.737 : FTPConnection.2 CloseConnection(e=An existing connection was forcibly closed by the remote host)
DEBUG [SocketController] 22 Dec 2014 09:44:22.737 : FTPConnection.2 Closed socket
DEBUG [TransferBuffer] 22 Dec 2014 09:44:22.737 : FTPConnection.2 Close() called when open
DEBUG [SecureSocket] 22 Dec 2014 09:44:22.737 : FTPConnection.2 OnHandshakeComplete(False,An existing connection was forcibly closed by the remote host)
ERROR [SecureSocket] 22 Dec 2014 09:44:22.737 : Exception during handshake: An existing connection was forcibly closed by the remote host

Here is the code for the download, with the code I just hard-coded for the SSL Version.

public void DownloadFile(FtpEntity ftp, string filePath, string remoteFileRename)
        {
            SecureFTPConnection ftpConnection = null;
            SSHFTPClient sshConnection = null;

            // TFS 44529 - RBM: Add EDT Logging.
            EnterpriseDT.Util.Debug.Logger.CurrentLevel = ftp.FtpLogLevel;
            if ((ftp.FtpLogLevel != EnterpriseDT.Util.Debug.Level.OFF) && (!String.IsNullOrEmpty(ftp.FtpRollingLogFile)))
            {
                ftpLoggingEnabled = true;
                EnterpriseDT.Util.Debug.Logger.AddAppender(new EnterpriseDT.Util.Debug.RollingFileAppender(ftp.FtpRollingLogFile, 5000000, 5));
            }
            // End TFS 44529 - RBM: Add EDT Logging.

            // RBM (TFS 31916): Code was not properly checking for the file.
            string fileExistCheck = filePath;
            if

support2 · Answer 3 · 2014-12-22T15:23:44+0000

The server claims to support TLS 1.1, so support for SSL3 is not the issue.

It's probably best to email support with the logs for the successful older version and the failed log for the newer version. It's also worth upgrading to 8.6.3 just in case that fixes the issue.

BMackenzieJHA · Answer 4 · 2014-12-22T16:27:03+0000

What is the support email for us to send the logs to? I'll see what I can get.

In the test that I just posted, I had upgraded EDT to v8.6.3.20 to make sure that wasn't the issue. You can see it noted in the logs. The older version that worked was v5.1.0.20. Did the default SSLVersion change from those two versions? Was there perhaps extra settings that we need to configure?

support2 · Answer 5 · 2014-12-22T18:20:04+0000

The default SSLVersion is now TLS 1.0, but 1.1 is also supported. The email address is support at our domain.

You could try explicitly setting the SSLVersion to 1.1.

Also, if you could email us the IP address (if it is externally reachable) that would help - we wouldn't need a login to test this problem.

BMackenzieJHA · Answer 6 · 2014-12-23T17:21:24+0000

I have sent an email with the logs, as you suggested. Thank you for your assistance.

support2 · Answer 7 · 2014-12-24T10:39:43+0000

Up to 7.2.0 succeeds and from 7.3.0 it fails. In 7.3.0, TLS1.1 was added. So by default TLS 1.1 is used from then on.

For whatever reason, your server doesn't like something about our implementation of TLS 1.1. If you are able to access the server log, that might tell us more.

The solution for now is to disable TLS11 by setting TLS1 explicitly.

ftpConnection.SSLVersion = SSLFTPSSLVersion.TLS1;

Upgraded to 8.6.0.20 and FTPS Explicit jobs stopped working

Please log in or register to add a comment.

Please log in or register to answer this question.

7 Answers

Please log in or register to add a comment.

Please log in or register to add a comment.

Please log in or register to add a comment.

Please log in or register to add a comment.

Please log in or register to add a comment.

Please log in or register to add a comment.

Please log in or register to add a comment.

Categories