Forum » Support and Bug Reports »

SSL Negotiation Timeout

Advertisement

jferrin
Joined:
Posts:
5
Location:
Lincoln, NE

SSL Negotiation Timeout

I'm using WinSCP 4.2.5 on Win XP SP3 and Server 2008 SP1 to connect to what appears to be a WS_FTP Server version 5.0.5 with Explicit SSL FTPS. Upon connection it indicates that SSL is enabled and it's waiting for negotiation. It then timeouts and will retry. Below is a log of the connection attempt. I've also tried Explicit TLS FTPS but it behaves the same way. I do know that Implicit FTPS will not work as it's not setup on the remote server.

I should also mention, I can connect to this remote server with other secure FTP clients such as FileZilla.

I'm looking for some guidance on what to try next? Is this an incompatibility with WinSCP and WS_FTP Server? Any assistance would be appreciated.

Thanks 
. 2010-02-08 14:26:46.603 --------------------------------------------------------------------------
. 2010-02-08 14:26:46.603 WinSCP Version 4.2.5 (Build 624) (OS 5.1.2600 Service Pack 3)
. 2010-02-08 14:26:46.603 Login time: Monday, February 08, 2010 2:26:46 PM
. 2010-02-08 14:26:46.603 --------------------------------------------------------------------------
. 2010-02-08 14:26:46.603 Session name: username@remote.host.name
. 2010-02-08 14:26:46.603 Host name: remote.host.name (Port: 21)
. 2010-02-08 14:26:46.603 User name: username (Password: Yes, Key file: No)
. 2010-02-08 14:26:46.603 Tunnel: No
. 2010-02-08 14:26:46.603 Transfer Protocol: FTP
. 2010-02-08 14:26:46.603 Ping type: C, Ping interval: 30 sec; Timeout: 15 sec
. 2010-02-08 14:26:46.603 Proxy: none
. 2010-02-08 14:26:46.603 FTP: FTPS: Explicit TLS; Passive: No [Force IP: No]
. 2010-02-08 14:26:46.603 Local directory: default, Remote directory: home, Update: No, Cache: Yes
. 2010-02-08 14:26:46.603 Cache directory changes: Yes, Permanent: Yes
. 2010-02-08 14:26:46.603 DST mode: 0
. 2010-02-08 14:26:46.603 --------------------------------------------------------------------------
. 2010-02-08 14:26:46.618 Connecting to remote.host.name ...
. 2010-02-08 14:26:46.634 m_pSslLayer changed state from 0 to 1
. 2010-02-08 14:26:46.634 m_pSslLayer changed state from 1 to 2
. 2010-02-08 14:26:46.634 m_pSslLayer changed state from 2 to 4
. 2010-02-08 14:26:46.634 Connected with remote.host.name, negotiating SSL connection...
< 2010-02-08 14:26:46.634 220-remote.host.name X2 WS_FTP Server 5.0.5 (1263842134)
< 2010-02-08 14:26:46.821 220-This is for authorized use only. LOG OFF IMMEDIATELY if you are not and authorized user.
< 2010-02-08 14:26:46.821 220-Remote Server
< 2010-02-08 14:26:46.821 220 remote.host.name X2 WS_FTP Server 5.0.5 (1263842134)
> 2010-02-08 14:26:46.821 AUTH TLS
< 2010-02-08 14:26:47.321 234 SSL enabled and waiting for negotiation
. 2010-02-08 14:27:02.603 Timeout detected.
. 2010-02-08 14:27:02.603 Connection failed.
. 2010-02-08 14:27:02.603 Got reply 1004 to the command 1
* 2010-02-08 14:27:02.603 (ESshFatal) Connection failed.
* 2010-02-08 14:27:02.603 Timeout detected.
* 2010-02-08 14:27:02.603 Connection failed.
* 2010-02-08 14:27:02.603 SSL enabled and waiting for negotiation

Reply with quote

Advertisement

jferrin
Joined:
Posts:
5
Location:
Lincoln, NE

Re: SSL Negotiation Timeout

Here is the FileZilla log. It does seem to negotiate the SSL connection but does appear to have problems with the data stream once I'm connected, which I'll take up with the remote server admin. I wasn't seeing this message before as I didn't let the connect continue that far. I was ending the connecting once the SSL negotiation happened.

Hopefully this will provide some clues as to why WinSCP won't negotiate the SSL connection initially. 
09:57:13   Status:   Resolving address of remote.host.name
09:57:13   Status:   Connecting to remote.IP.Address...
09:57:13   Status:   Connection established, waiting for welcome message...
09:57:13   Response:   220-remote.host.name X2 WS_FTP Server 5.0.5 (785254641)
09:57:13   Response:   220-This is for authorized use only. LOG OFF IMMEDIATELY if you are not and authorized user.
09:57:13   Response:   220 remote.host.name X2 WS_FTP Server 5.0.5 (785254641)
09:57:13   Command:   AUTH TLS
09:57:13   Response:   234 SSL enabled and waiting for negotiation
09:57:13   Status:   Initializing TLS...
09:57:13   Status:   Verifying certificate...
09:57:15   Command:   USER username
09:57:15   Status:   TLS/SSL connection established.
09:57:16   Response:   331 Password required
09:57:16   Command:   PASS *************
09:57:16   Response:   230-user logged in
09:57:16   Response:   230- username ,  your IP: my.IP.Address has been logged.
09:57:16   Response:   230-If you experience any problems please email sysadmin@host.name for assistance.
09:57:16   Response:   230 user logged in
09:57:16   Command:   SYST
09:57:16   Response:   215 UNIX
09:57:16   Command:   FEAT
09:57:16   Response:   211-Extensions supported
09:57:16   Response:    SIZE
09:57:16   Response:    MDTM
09:57:16   Response:    MLST
09:57:16   Response:    XCRC
09:57:16   Response:    XMD5
09:57:16   Response:    XSHA1
09:57:16   Response:    size*;type*;perm*;create*;modify*;
09:57:16   Response:    LANG EN*
09:57:16   Response:    REST STREAM
09:57:16   Response:    TVFS
09:57:16   Response:    UTF8
09:57:16   Response:    AUTH SSL;TLS-P;
09:57:16   Response:    PBSZ
09:57:16   Response:    PROT C;P;
09:57:16   Response:   211 end
09:57:16   Command:   OPTS UTF8 ON
09:57:16   Response:   501 invalid option
09:57:16   Command:   PBSZ 0
09:57:16   Response:   200 PBSZ=0
09:57:16   Command:   PROT P
09:57:16   Response:   200 PRIVATE data channel protection level set
09:57:16   Status:   Connected
09:57:16   Status:   Retrieving directory listing...
09:57:16   Command:   PWD
09:57:16   Response:   257 "/sis" is current directory
09:57:16   Command:   TYPE I
09:57:16   Response:   200 Type set to IMAGE.
09:57:16   Command:   PASV
09:57:16   Response:   227 Entering Passive Mode (Remote,server,IP,address,11,184).
09:57:16   Command:   MLSD
09:57:16   Response:   150 Opening ASCII data connection for directory listing
09:57:16   Error:   GnuTLS error -9: A TLS packet with unexpected length was received.
09:57:16   Status:   Server did not properly shut down TLS connection
09:57:16   Error:   Could not read from transfer socket: ECONNABORTED - Connection aborted
09:57:16   Response:   226 transfer complete
09:57:16   Error:   Failed to retrieve directory listing
10:02:16   Response:   500 connection timed out
10:02:16   Error:   GnuTLS error -9: A TLS packet with unexpected length was received.
10:02:16   Status:   Server did not properly shut down TLS connection
10:02:16   Error:   Disconnected from server: ECONNABORTED - Connection aborted

Reply with quote

jferrin
Joined:
Posts:
5
Location:
Lincoln, NE

Re: SSL Negotiation Timeout

This is a log from CoreFTP which does connect and get a directory listing. Hopefully this will help. 
Welcome to Core FTP, release ver 2.1, build 1637 (U) -- (c) 2003-2010
WinSock 2.0
Mem -- 2,096,624 KB, Virt -- 2,097,024 KB
Started on Wednesday February 10, 2010 at 11:43:AM
Resolving remote.host.name...  
Connect socket #720 to remote.ip.address, port 21...
220-ftp.unmc.edu X2 WS_FTP Server 5.0.5 (4080094086)  
220-This is for authorized use only. LOG OFF IMMEDIATELY if you are not and authorized user.  
220-remote.host.name X2 WS_FTP Server 5.0.5 (4080094086)  
AUTH SSL  
234 SSL enabled and waiting for negotiation  
SSLv3 (RC4/MD5), 128 bits
USER username  
331 Password required  
PASS **********  
230-user logged in  
230- username ,  your IP: my.ip.address has been logged.  
230-If you experience any problems please email sysadmin@host.name for assistance.  
230 user logged in  
SYST  
215 UNIX  
Keep alive off...
PWD  
257 "/sis" is current directory  
PBSZ 0  
200 PBSZ=0  
PROT P  
200 PRIVATE data channel protection level set  
PASV  
227 Entering Passive Mode (Remote,server,IP,address,11,191).  
LIST  
Connect socket #1156 to remote.ip.address, port 3007...
SSLv3 (RC4/MD5), 128 bits
150 Opening ASCII data connection for directory listing  
226 transfer complete  
Transferred 473 bytes in 0.141 seconds

Reply with quote

martin◆
Site Admin
martin avatar

Re: SSL Negotiation Timeout

The Core FTP session uses SSL, can you try it also with TLS as you do with WinSCP and Filezilla?

Reply with quote

Advertisement

jferrin
Joined:
Posts:
5
Location:
Lincoln, NE

Re: SSL Negotiation Timeout

If I change CoreFTP to TLS I I get SSL/TLS error and it won't connect. Here's the log from that connection attempt. 
WinSock 2.0
Mem -- 2,096,624 KB, Virt -- 2,097,024 KB
Started on Friday February 12, 2010 at 13:00:PM
Resolving remote.server.name...  
Connect socket #708 to remote.server.IP.address, port 21...
220-remote.server.name X2 WS_FTP Server 5.0.5 (4257392727)  
220-This is for authorized use only. LOG OFF IMMEDIATELY if you are not and authorized user.  
220-remote.server.name X2 WS_FTP Server 5.0.5 (4257392727)  
AUTH TLS  
234 SSL enabled and waiting for negotiation  
SSL/TLS error - 0, SSL error - 1, error:00000001:lib(0):func(0):reason(1)   
Winsock error 10060 (A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond.  )  
SSL Connection not established
If I change WinSCP to use SSL I get the same error message that I've been getting. Here's a log from that connection attempt. 
. 2010-02-12 13:03:43.691 --------------------------------------------------------------------------
. 2010-02-12 13:03:43.691 WinSCP Version 4.2.5 (Build 624) (OS 5.1.2600 Service Pack 3)
. 2010-02-12 13:03:43.691 Login time: Friday, February 12, 2010 1:03:43 PM
. 2010-02-12 13:03:43.691 --------------------------------------------------------------------------
. 2010-02-12 13:03:43.691 Session name: username@remote.server.name
. 2010-02-12 13:03:43.691 Host name: remote.server.name (Port: 21)
. 2010-02-12 13:03:43.691 User name: username (Password: Yes, Key file: No)
. 2010-02-12 13:03:43.691 Tunnel: No
. 2010-02-12 13:03:43.691 Transfer Protocol: FTP
. 2010-02-12 13:03:43.691 Ping type: C, Ping interval: 30 sec; Timeout: 15 sec
. 2010-02-12 13:03:43.691 Proxy: none
. 2010-02-12 13:03:43.691 FTP: FTPS: Explicit SSL; Passive: No [Force IP: No]
. 2010-02-12 13:03:43.691 Local directory: default, Remote directory: home, Update: No, Cache: Yes
. 2010-02-12 13:03:43.691 Cache directory changes: Yes, Permanent: Yes
. 2010-02-12 13:03:43.691 DST mode: 0
. 2010-02-12 13:03:43.691 --------------------------------------------------------------------------
. 2010-02-12 13:03:43.738 Connecting to remote.server.name ...
. 2010-02-12 13:03:43.753 m_pSslLayer changed state from 0 to 1
. 2010-02-12 13:03:43.753 m_pSslLayer changed state from 1 to 2
. 2010-02-12 13:03:43.753 m_pSslLayer changed state from 2 to 4
. 2010-02-12 13:03:43.753 Connected with remote.server.name, negotiating SSL connection...
< 2010-02-12 13:03:43.769 220-remote.server.name X2 WS_FTP Server 5.0.5 (4257574273)
< 2010-02-12 13:03:43.988 220-This is for authorized use only. LOG OFF IMMEDIATELY if you are not and authorized user.
< 2010-02-12 13:03:43.988 220 remote.server.name X2 WS_FTP Server 5.0.5 (4257574273)
> 2010-02-12 13:03:43.988 AUTH SSL
< 2010-02-12 13:03:44.472 234 SSL enabled and waiting for negotiation
. 2010-02-12 13:04:00.722 Timeout detected.
. 2010-02-12 13:04:00.722 Connection failed.
. 2010-02-12 13:04:00.722 Got reply 1004 to the command 1
* 2010-02-12 13:04:00.738 (ESshFatal) Connection failed.
* 2010-02-12 13:04:00.738 Timeout detected.
* 2010-02-12 13:04:00.738 Connection failed.
* 2010-02-12 13:04:00.738 SSL enabled and waiting for negotiation
So is there a difference between the way these products, WinSCP, CoreFTP, FileZilla, implement the SSL connections?

Reply with quote

Advertisement

You can post new topics in this forum

Documentation

Support

Associations

Follow Us