FTPS Issue with WinSCP but works fine with FileZilla

I am hoping someone has ran into this before and can help. We are trying to use WinSCP to connect to a FTPS site with TLS/SSL Explicit encryption. Here is the log from both WinSCP and FileZilla. The FileZilla prompts to accept the certificate and WinSCP does not. If I accept the certificate on FileZilla the connection will complete successfully.


WINSCP LOG

. 2015-03-24 14:25:58.843 --------------------------------------------------------------------------
. 2015-03-24 14:25:58.843 WinSCP Version 5.7 (Build 5125) (OS 6.1.7601 Service Pack 1 - Windows Server 2008 R2 Enterprise)
. 2015-03-24 14:25:58.843 Configuration: E:\winscp570\WinSCP.ini
. 2015-03-24 14:25:58.843 Log level: Debug 2
. 2015-03-24 14:25:58.843 Local account:
. 2015-03-24 14:25:58.843 Working directory: E:\winscp570
. 2015-03-24 14:25:58.843 Process ID: 20732
. 2015-03-24 14:25:58.843 Command-line: "E:\winscp570\WinSCP.exe"
. 2015-03-24 14:25:58.843 Time zone: Current: GMT-5, Standard: GMT-6 (Central Standard Time), DST: GMT-5 (Central Daylight Time), DST Start: 3/8/2015, DST End: 11/1/2015
. 2015-03-24 14:25:58.843 Login time: Tuesday, March 24, 2015 2:25:58 PM
. 2015-03-24 14:25:58.843 --------------------------------------------------------------------------
. 2015-03-24 14:25:58.843 Session name: Site (Modified site)
. 2015-03-24 14:25:58.843 Host name: host
. 2015-03-24 14:25:58.843 User name: User (Password: Yes, Key file: No)
. 2015-03-24 14:25:58.843 Transfer Protocol: FTP
. 2015-03-24 14:25:58.843 Ping type: C, Ping interval: 30 sec; Timeout: 15 sec
. 2015-03-24 14:25:58.843 Disable Nagle: No
. 2015-03-24 14:25:58.843 Proxy: none
. 2015-03-24 14:25:58.843 Send buffer: 262144
. 2015-03-24 14:25:58.843 UTF: 2
. 2015-03-24 14:25:58.843 FTP: FTPS: Explicit TLS; Passive: Yes [Force IP: A]; MLSD: A [List all: A]
. 2015-03-24 14:25:58.843 Session reuse: Yes
. 2015-03-24 14:25:58.843 TLS/SSL versions: TLSv1.0-TLSv1.2
. 2015-03-24 14:25:58.843 Local directory: default, Remote directory: home, Update: Yes, Cache: Yes
. 2015-03-24 14:25:58.843 Cache directory changes: Yes, Permanent: Yes
. 2015-03-24 14:25:58.843 Timezone offset: 0h 0m
. 2015-03-24 14:25:58.843 --------------------------------------------------------------------------
. 2015-03-24 14:25:58.843 Session upkeep
. 2015-03-24 14:25:58.905 Connecting to site ...
. 2015-03-24 14:25:58.905 TLS layer changed state from unconnected to connecting
. 2015-03-24 14:25:58.905 TLS layer changed state from connecting to connected
. 2015-03-24 14:25:58.905 Connected with host, negotiating TLS connection...
< 2015-03-24 14:25:58.905 220 site FTP server (webMethods Integration Server version 9.0.1.0) ready.
> 2015-03-24 14:25:58.905 AUTH TLS
< 2015-03-24 14:25:58.952 234 AUTH TLS OK.
. 2015-03-24 14:25:58.983 TLS connect: error in SSLv2/v3 read server hello A
. 2015-03-24 14:25:58.983 Can't establish TLS connection
. 2015-03-24 14:25:58.983 Disconnected from server
. 2015-03-24 14:25:58.983 Connection failed.
. 2015-03-24 14:25:58.983 Got reply 1004 to the command 1
* 2015-03-24 14:25:59.030 (EFatal) Connection failed.
* 2015-03-24 14:25:59.030 TLS connect: error in SSLv2/v3 read server hello A
* 2015-03-24 14:25:59.030 Can't establish TLS connection
* 2015-03-24 14:25:59.030 Disconnected from server
* 2015-03-24 14:25:59.030 Connection failed.

SSL3 alert read: fatal: handshake failure
TLS connect: error in SSLv2/v3 read server hello A
Can't establish TLS connection
Disconnected from server
Connection failed.



FILEZILLA LOG

2015-03-24 14:22:43 14724 1 Status: Resolving address of site
2015-03-24 14:22:43 14724 1 Status: Connecting to IP...
2015-03-24 14:22:43 14724 1 Status: Connection established, waiting for welcome message...
2015-03-24 14:22:43 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:43 14724 1 Response: 220 site FTP server (webMethods Integration Server version 9.0.1.0) ready.
2015-03-24 14:22:43 14724 1 Trace: CFtpControlSocket::SendNextCommand()
2015-03-24 14:22:43 14724 1 Command: AUTH TLS
2015-03-24 14:22:43 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:43 14724 1 Response: 234 AUTH TLS OK.
2015-03-24 14:22:43 14724 1 Status: Initializing TLS...
2015-03-24 14:22:43 14724 1 Trace: CTlsSocket::Handshake()
2015-03-24 14:22:43 14724 1 Trace: CTlsSocket::ContinueHandshake()
2015-03-24 14:22:43 14724 1 Trace: CTlsSocket::OnSend()
2015-03-24 14:22:43 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:43 14724 1 Trace: CTlsSocket::ContinueHandshake()
2015-03-24 14:22:43 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:43 14724 1 Trace: CTlsSocket::ContinueHandshake()
2015-03-24 14:22:43 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:43 14724 1 Trace: CTlsSocket::ContinueHandshake()
2015-03-24 14:22:43 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:43 14724 1 Trace: CTlsSocket::ContinueHandshake()
2015-03-24 14:22:43 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:43 14724 1 Trace: CTlsSocket::ContinueHandshake()
2015-03-24 14:22:43 14724 1 Trace: TLS Handshake successful
2015-03-24 14:22:43 14724 1 Trace: Protocol: TLS1.0, Key exchange: RSA, Cipher: AES-128-CBC, MAC: SHA1
2015-03-24 14:22:43 14724 1 Status: Verifying certificate...
2015-03-24 14:22:43 14724 1 Status: TLS connection established.
2015-03-24 14:22:43 14724 1 Trace: CFtpControlSocket::SendNextCommand()
2015-03-24 14:22:43 14724 1 Command: USER user
2015-03-24 14:22:43 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:43 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:44 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:44 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:44 14724 1 Response: 331 Password required for user.
2015-03-24 14:22:44 14724 1 Trace: CFtpControlSocket::SendNextCommand()
2015-03-24 14:22:44 14724 1 Command: PASS *************
2015-03-24 14:22:44 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:44 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:44 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:44 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:44 14724 1 Response: 230 User user logged in.
2015-03-24 14:22:44 14724 1 Trace: CFtpControlSocket::SendNextCommand()
2015-03-24 14:22:44 14724 1 Command: SYST
2015-03-24 14:22:44 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:44 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:44 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:44 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:44 14724 1 Response: 215 UNIX Type: L8 Version: webMethods IS FTP version 9.0.1.0
2015-03-24 14:22:44 14724 1 Trace: CFtpControlSocket::SendNextCommand()
2015-03-24 14:22:44 14724 1 Command: FEAT
2015-03-24 14:22:44 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:44 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:44 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:44 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:44 14724 1 Response: 500 'FEAT': command not understood.
2015-03-24 14:22:44 14724 1 Status: Server does not support non-ASCII characters.
2015-03-24 14:22:44 14724 1 Trace: CFtpControlSocket::SendNextCommand()
2015-03-24 14:22:44 14724 1 Command: PBSZ 0
2015-03-24 14:22:44 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:44 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:45 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:45 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:45 14724 1 Response: 200 PBSZ Command successful. (PBSZ=0)
2015-03-24 14:22:45 14724 1 Trace: CFtpControlSocket::SendNextCommand()
2015-03-24 14:22:45 14724 1 Command: PROT P
2015-03-24 14:22:45 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:45 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:45 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:45 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:45 14724 1 Response: 200 PROT set to P.
2015-03-24 14:22:45 14724 1 Status: Connected
2015-03-24 14:22:45 14724 1 Trace: CFtpControlSocket::ResetOperation(0)
2015-03-24 14:22:45 14724 1 Trace: CControlSocket::ResetOperation(0)
2015-03-24 14:22:45 14724 1 Trace: CFileZillaEnginePrivate::ResetOperation(0)
2015-03-24 14:22:45 14724 1 Trace: Measured latency of 31 ms
2015-03-24 14:22:45 14724 1 Status: Retrieving directory listing...
2015-03-24 14:22:45 14724 1 Trace: CFtpControlSocket::SendNextCommand()
2015-03-24 14:22:45 14724 1 Trace: CFtpControlSocket::ChangeDirSend()
2015-03-24 14:22:45 14724 1 Command: PWD
2015-03-24 14:22:45 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:45 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:45 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:45 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:45 14724 1 Response: 257 "/" is current directory.
2015-03-24 14:22:45 14724 1 Trace: CFtpControlSocket::ResetOperation(0)
2015-03-24 14:22:45 14724 1 Trace: CControlSocket::ResetOperation(0)
2015-03-24 14:22:45 14724 1 Trace: CFtpControlSocket::ParseSubcommandResult(0)
2015-03-24 14:22:45 14724 1 Trace: CFtpControlSocket::ListSubcommandResult()
2015-03-24 14:22:45 14724 1 Trace: state = 1
2015-03-24 14:22:45 14724 1 Trace: CFtpControlSocket::SendNextCommand()
2015-03-24 14:22:45 14724 1 Trace: CFtpControlSocket::TransferSend()
2015-03-24 14:22:45 14724 1 Trace: state = 1
2015-03-24 14:22:45 14724 1 Command: TYPE I
2015-03-24 14:22:45 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:45 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:46 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:46 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:46 14724 1 Response: 200 Type set to I.
2015-03-24 14:22:46 14724 1 Trace: CFtpControlSocket::TransferParseResponse()
2015-03-24 14:22:46 14724 1 Trace: code = 2
2015-03-24 14:22:46 14724 1 Trace: state = 1
2015-03-24 14:22:46 14724 1 Trace: CFtpControlSocket::SendNextCommand()
2015-03-24 14:22:46 14724 1 Trace: CFtpControlSocket::TransferSend()
2015-03-24 14:22:46 14724 1 Trace: state = 2
2015-03-24 14:22:46 14724 1 Command: PASV
2015-03-24 14:22:46 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:46 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:46 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:46 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:46 14724 1 Response: 227 Entering Passive Mode (129,220,55,58,27,108)
2015-03-24 14:22:46 14724 1 Trace: CFtpControlSocket::TransferParseResponse()
2015-03-24 14:22:46 14724 1 Trace: code = 2
2015-03-24 14:22:46 14724 1 Trace: state = 2
2015-03-24 14:22:46 14724 1 Trace: CFtpControlSocket::SendNextCommand()
2015-03-24 14:22:46 14724 1 Trace: CFtpControlSocket::TransferSend()
2015-03-24 14:22:46 14724 1 Trace: state = 4
2015-03-24 14:22:46 14724 1 Command: LIST
2015-03-24 14:22:46 14724 1 Trace: CTransferSocket::OnConnect
2015-03-24 14:22:46 14724 1 Trace: CTlsSocket::Handshake()
2015-03-24 14:22:46 14724 1 Trace: Trying to resume existing TLS session.
2015-03-24 14:22:46 14724 1 Trace: CTlsSocket::ContinueHandshake()
2015-03-24 14:22:46 14724 1 Trace: CTlsSocket::OnSend()
2015-03-24 14:22:46 14724 1 Trace: CTlsSocket::OnSend()
2015-03-24 14:22:46 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:46 14724 1 Trace: CTlsSocket::ContinueHandshake()
2015-03-24 14:22:46 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:46 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:46 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:46 14724 1 Trace: CTlsSocket::ContinueHandshake()
2015-03-24 14:22:46 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:46 14724 1 Trace: CTlsSocket::ContinueHandshake()
2015-03-24 14:22:46 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:46 14724 1 Trace: CTlsSocket::ContinueHandshake()
2015-03-24 14:22:46 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:46 14724 1 Trace: CTlsSocket::ContinueHandshake()
2015-03-24 14:22:46 14724 1 Trace: TLS Handshake successful
2015-03-24 14:22:46 14724 1 Trace: Protocol: TLS1.0, Key exchange: RSA, Cipher: AES-128-CBC, MAC: SHA1
2015-03-24 14:22:46 14724 1 Trace: CTransferSocket::OnConnect
2015-03-24 14:22:46 14724 1 Trace: CTransferSocket::OnReceive(), m_transferMode=0
2015-03-24 14:22:46 14724 1 Trace: CTransferSocket::TransferEnd(1)
2015-03-24 14:22:46 14724 1 Trace: CFtpControlSocket::TransferEnd()
2015-03-24 14:22:46 14724 1 Trace: CTlsSocket::OnRead()
2015-03-24 14:22:46 14724 1 Trace: CFtpControlSocket::OnReceive()
2015-03-24 14:22:46 14724 1 Response: 150 ASCII mode SSL data connection for /bin/ls (IP).
2015-03-24 14:22:46 14724 1 Trace: CFtpControlSocket::TransferParseResponse()
2015-03-24 14:22:46 14724 1 Trace: code = 1
2015-03-24 14:22:46 14724 1 Trace: state = 6
2015-03-24 14:22:46 14724 1 Trace: CFtpControlSocket::SendNextCommand()
2015-03-24 14:22:46 14724 1 Trace: CFtpControlSocket::TransferSend()
2015-03-24 14:22:46 14724 1 Trace: state = 7
2015-03-24 14:22:46 14724 1 Response: 226 ASCII transfer complete.
2015-03-24 14:22:46 14724 1 Trace: CFtpControlSocket::TransferParseResponse()
2015-03-24 14:22:46 14724 1 Trace: code = 2
2015-03-24 14:22:46 14724 1 Trace: state = 7
2015-03-24 14:22:46 14724 1 Trace: CFtpControlSocket::ResetOperation(0)
2015-03-24 14:22:46 14724 1 Trace: CControlSocket::ResetOperation(0)
2015-03-24 14:22:46 14724 1 Trace: CFtpControlSocket::ParseSubcommandResult(0)
2015-03-24 14:22:46 14724 1 Trace: CFtpControlSocket::ListSubcommandResult()
2015-03-24 14:22:46 14724 1 Trace: state = 3
2015-03-24 14:22:46 14724 1 Trace: CFtpControlSocket::ResetOperation(0)
2015-03-24 14:22:46 14724 1 Trace: CControlSocket::ResetOperation(0)
2015-03-24 14:22:46 14724 1 Status: Directory listing of "/" successful
2015-03-24 14:22:46 14724 1 Trace: CFileZillaEnginePrivate::ResetOperation(0)

The FileZilla connects and prompts for certificate verification. Once accepted it session connects.

Can we get a host name of your server, so that we can test the connection? Note we do not need any credentials, as the problem occurs even before authentication starts.

You can attach the host name in a text file marked as private, if you do not want to post it publicly.

I found in another forum that the following versions work. I am not sure what breaks it in the other versions but it would be nice to get the latest release working.

Version 4.3.7 is working (This is the version I used and it worked fine.)
Version 4.3.8 is not working
Version 4.3.9 is not working
Version 5.0.6 is working
Version 5.0.7 is not working (and upwards)

Did you test these versions yourself?

Can we get the hostname (as requested in my previous post)?

I know I'm late joining in on this, but am having a similar problem. I've tried playing with all the connection settings/bug detection settings as well as using a couple versions. WinSCP is on the list of allowed programs in Windows Firewall, FYI.

Here's the log for a failed connection attempt. Since it's prior to authentication, I assume it will work for your needs:

. 2015-07-24 08:28:23.858 --------------------------------------------------------------------------
. 2015-07-24 08:28:23.859 WinSCP Version 5.7.4 (Build 5553) (OS 6.1.7601 Service Pack 1 - Windows 7 Professional)
. 2015-07-24 08:28:23.859 Configuration: HKCU\Software\Martin Prikryl\WinSCP 2\
. 2015-07-24 08:28:23.859 Log level: Debug 2
. 2015-07-24 08:28:23.859 Local account: [removed]
. 2015-07-24 08:28:23.859 Working directory: C:\Program Files (x86)\WinSCP
. 2015-07-24 08:28:23.859 Process ID: 8068
. 2015-07-24 08:28:23.859 Command-line: "C:\Program Files (x86)\WinSCP\WinSCP.exe"
. 2015-07-24 08:28:23.859 Time zone: Current: GMT-6, Standard: GMT-7 (Mountain Standard Time), DST: GMT-6 (Mountain Daylight Time), DST Start: 3/8/2015, DST End: 11/1/2015
. 2015-07-24 08:28:23.859 Login time: Friday, July 24, 2015 8:28:23 AM
. 2015-07-24 08:28:23.859 --------------------------------------------------------------------------
. 2015-07-24 08:28:23.859 Session name: VMWare (Modified site)
. 2015-07-24 08:28:23.859 Host name: sftp2.eng.vmware.com (Port: 443)
. 2015-07-24 08:28:23.860 User name: [removed] (Password: Yes, Key file: No)
. 2015-07-24 08:28:23.860 Tunnel: No
. 2015-07-24 08:28:23.860 Transfer Protocol: SFTP (SCP)
. 2015-07-24 08:28:23.860 Ping type: N, Ping interval: 30 sec; Timeout: 15 sec
. 2015-07-24 08:28:23.860 Disable Nagle: No
. 2015-07-24 08:28:23.860 Proxy: none
. 2015-07-24 08:28:23.860 Send buffer: 0
. 2015-07-24 08:28:23.860 SSH protocol version: 2; Compression: Yes
. 2015-07-24 08:28:23.860 Bypass authentication: No
. 2015-07-24 08:28:23.860 Try agent: No; Agent forwarding: Yes; TIS/CryptoCard: No; KI: Yes; GSSAPI: Yes
. 2015-07-24 08:28:23.860 GSSAPI: Forwarding: No; Server realm:
. 2015-07-24 08:28:23.860 Ciphers: aes,blowfish,3des,WARN,arcfour,des; Ssh2DES: Yes
. 2015-07-24 08:28:23.860 KEX: dh-gex-sha1,dh-group14-sha1,dh-group1-sha1,rsa,WARN
. 2015-07-24 08:28:23.860 SSH Bugs: A,A,A,A,A,A,A,A,A,A,A
. 2015-07-24 08:28:23.860 Simple channel: No
. 2015-07-24 08:28:23.860 Return code variable: Autodetect; Lookup user groups: A
. 2015-07-24 08:28:23.860 Shell: default
. 2015-07-24 08:28:23.860 EOL: 0, UTF: 2
. 2015-07-24 08:28:23.860 Clear aliases: Yes, Unset nat.vars: Yes, Resolve symlinks: Yes
. 2015-07-24 08:28:23.860 LS: ls -la, Ign LS warn: Yes, Scp1 Comp: No
. 2015-07-24 08:28:23.860 SFTP Bugs: A,A
. 2015-07-24 08:28:23.860 SFTP Server: default
. 2015-07-24 08:28:23.860 Local directory: default, Remote directory: home, Update: Yes, Cache: Yes
. 2015-07-24 08:28:23.860 Cache directory changes: Yes, Permanent: Yes
. 2015-07-24 08:28:23.860 DST mode: 1
. 2015-07-24 08:28:23.860 --------------------------------------------------------------------------
. 2015-07-24 08:28:23.943 Looking up host "sftp2.eng.vmware.com"
. 2015-07-24 08:28:23.947 Connecting to 208.91.0.170 port 443
. 2015-07-24 08:28:23.950 Selecting events 63 for socket 972
. 2015-07-24 08:28:23.995 Waiting for the server to continue with the initialization
. 2015-07-24 08:28:23.995 Looking for incoming data
. 2015-07-24 08:28:23.995 Looking for network events
. 2015-07-24 08:28:23.995 Detected network event
. 2015-07-24 08:28:23.995 Enumerating network events for socket 972
. 2015-07-24 08:28:23.995 Enumerated 18 network events making 18 cumulative events for socket 972
. 2015-07-24 08:28:23.995 Handling network write event on socket 972 with error 0
. 2015-07-24 08:28:23.995 Handling network connect event on socket 972 with error 0
. 2015-07-24 08:28:23.995 Looking for network events
. 2015-07-24 08:28:38.997 Timeout waiting for network events
. 2015-07-24 08:28:38.997 Waiting for data timed out, asking user what to do.
. 2015-07-24 08:28:38.997 Asking user:
. 2015-07-24 08:28:38.997 **Host is not communicating for 15 seconds.
. 2015-07-24 08:28:38.997
. 2015-07-24 08:28:38.997 Wait for another 15 seconds?** ()
. 2015-07-24 08:28:39.512 Pooling for data in case they finally arrives
. 2015-07-24 08:28:39.512 Looking for network events
. 2015-07-24 08:28:39.512 Timeout waiting for network events
. 2015-07-24 08:28:40.028 Pooling for data in case they finally arrives
. 2015-07-24 08:28:40.028 Looking for network events
. 2015-07-24 08:28:40.028 Timeout waiting for network events
. 2015-07-24 08:28:40.541 Pooling for data in case they finally arrives
. 2015-07-24 08:28:40.541 Looking for network events
. 2015-07-24 08:28:40.542 Timeout waiting for network events
. 2015-07-24 08:28:41.056 Pooling for data in case they finally arrives
. 2015-07-24 08:28:41.056 Looking for network events
. 2015-07-24 08:28:41.056 Timeout waiting for network events
. 2015-07-24 08:28:41.560 Pooling for data in case they finally arrives
. 2015-07-24 08:28:41.560 Looking for network events
. 2015-07-24 08:28:41.560 Timeout waiting for network events
. 2015-07-24 08:28:42.070 Pooling for data in case they finally arrives
. 2015-07-24 08:28:42.070 Looking for network events
. 2015-07-24 08:28:42.070 Timeout waiting for network events
. 2015-07-24 08:28:42.574 Pooling for data in case they finally arrives
. 2015-07-24 08:28:42.574 Looking for network events
. 2015-07-24 08:28:42.574 Timeout waiting for network events
. 2015-07-24 08:28:43.084 Pooling for data in case they finally arrives
. 2015-07-24 08:28:43.084 Looking for network events
. 2015-07-24 08:28:43.084 Timeout waiting for network events
. 2015-07-24 08:28:43.587 Pooling for data in case they finally arrives
. 2015-07-24 08:28:43.587 Looking for network events
. 2015-07-24 08:28:43.587 Timeout waiting for network events
. 2015-07-24 08:28:44.098 Pooling for data in case they finally arrives
. 2015-07-24 08:28:44.098 Looking for network events
. 2015-07-24 08:28:44.098 Timeout waiting for network events
. 2015-07-24 08:28:44.598 Pooling for data in case they finally arrives
. 2015-07-24 08:28:44.598 Looking for network events
. 2015-07-24 08:28:44.598 Timeout waiting for network events
. 2015-07-24 08:28:45.114 Pooling for data in case they finally arrives
. 2015-07-24 08:28:45.114 Looking for network events
. 2015-07-24 08:28:45.114 Timeout waiting for network events
. 2015-07-24 08:28:45.616 Pooling for data in case they finally arrives
. 2015-07-24 08:28:45.616 Looking for network events
. 2015-07-24 08:28:45.616 Timeout waiting for network events
. 2015-07-24 08:28:46.127 Pooling for data in case they finally arrives
. 2015-07-24 08:28:46.127 Looking for network events
. 2015-07-24 08:28:46.127 Timeout waiting for network events
. 2015-07-24 08:28:46.633 Pooling for data in case they finally arrives
. 2015-07-24 08:28:46.633 Looking for network events
. 2015-07-24 08:28:46.633 Timeout waiting for network events
. 2015-07-24 08:28:47.141 Pooling for data in case they finally arrives
. 2015-07-24 08:28:47.141 Looking for network events
. 2015-07-24 08:28:47.141 Timeout waiting for network events
. 2015-07-24 08:28:47.644 Pooling for data in case they finally arrives
. 2015-07-24 08:28:47.644 Looking for network events
. 2015-07-24 08:28:47.644 Timeout waiting for network events
. 2015-07-24 08:28:48.156 Pooling for data in case they finally arrives
. 2015-07-24 08:28:48.156 Looking for network events
. 2015-07-24 08:28:48.156 Timeout waiting for network events
. 2015-07-24 08:28:48.669 Pooling for data in case they finally arrives
. 2015-07-24 08:28:48.669 Looking for network events
. 2015-07-24 08:28:48.669 Timeout waiting for network events
. 2015-07-24 08:28:49.169 Pooling for data in case they finally arrives
. 2015-07-24 08:28:49.169 Looking for network events
. 2015-07-24 08:28:49.169 Timeout waiting for network events
. 2015-07-24 08:28:49.683 Pooling for data in case they finally arrives
. 2015-07-24 08:28:49.683 Looking for network events
. 2015-07-24 08:28:49.683 Timeout waiting for network events
. 2015-07-24 08:28:50.183 Pooling for data in case they finally arrives
. 2015-07-24 08:28:50.184 Looking for network events
. 2015-07-24 08:28:50.184 Timeout waiting for network events
. 2015-07-24 08:28:50.697 Pooling for data in case they finally arrives
. 2015-07-24 08:28:50.697 Looking for network events
. 2015-07-24 08:28:50.697 Timeout waiting for network events
. 2015-07-24 08:28:51.197 Pooling for data in case they finally arrives
. 2015-07-24 08:28:51.197 Looking for network events
. 2015-07-24 08:28:51.197 Timeout waiting for network events
. 2015-07-24 08:28:51.711 Pooling for data in case they finally arrives
. 2015-07-24 08:28:51.711 Looking for network events
. 2015-07-24 08:28:51.711 Timeout waiting for network events
. 2015-07-24 08:28:52.211 Pooling for data in case they finally arrives
. 2015-07-24 08:28:52.211 Looking for network events
. 2015-07-24 08:28:52.211 Timeout waiting for network events
. 2015-07-24 08:28:52.725 Pooling for data in case they finally arrives
. 2015-07-24 08:28:52.725 Looking for network events
. 2015-07-24 08:28:52.725 Timeout waiting for network events
. 2015-07-24 08:28:53.225 Pooling for data in case they finally arrives
. 2015-07-24 08:28:53.225 Looking for network events
. 2015-07-24 08:28:53.225 Timeout waiting for network events
. 2015-07-24 08:28:53.739 Pooling for data in case they finally arrives
. 2015-07-24 08:28:53.739 Looking for network events
. 2015-07-24 08:28:53.739 Timeout waiting for network events
. 2015-07-24 08:28:54.239 Pooling for data in case they finally arrives
. 2015-07-24 08:28:54.239 Looking for network events
. 2015-07-24 08:28:54.239 Timeout waiting for network events
. 2015-07-24 08:28:54.753 Pooling for data in case they finally arrives
. 2015-07-24 08:28:54.753 Looking for network events
. 2015-07-24 08:28:54.753 Timeout waiting for network events
. 2015-07-24 08:28:55.254 Pooling for data in case they finally arrives
. 2015-07-24 08:28:55.254 Looking for network events
. 2015-07-24 08:28:55.254 Timeout waiting for network events
. 2015-07-24 08:28:55.768 Pooling for data in case they finally arrives
. 2015-07-24 08:28:55.768 Looking for network events
. 2015-07-24 08:28:55.768 Timeout waiting for network events
. 2015-07-24 08:28:56.269 Pooling for data in case they finally arrives
. 2015-07-24 08:28:56.269 Looking for network events
. 2015-07-24 08:28:56.269 Timeout waiting for network events
. 2015-07-24 08:28:56.782 Pooling for data in case they finally arrives
. 2015-07-24 08:28:56.782 Looking for network events
. 2015-07-24 08:28:56.782 Timeout waiting for network events
. 2015-07-24 08:28:57.282 Pooling for data in case they finally arrives
. 2015-07-24 08:28:57.282 Looking for network events
. 2015-07-24 08:28:57.282 Timeout waiting for network events
. 2015-07-24 08:28:57.500 Attempt to close connection due to fatal exception:
* 2015-07-24 08:28:57.500 **Terminated by user.**
. 2015-07-24 08:28:57.500 Closing connection.
. 2015-07-24 08:28:57.500 Sending special code: 12
. 2015-07-24 08:28:57.500 Selecting events 0 for socket 972
* 2015-07-24 08:28:57.564 (EFatal) **Terminated by user.**

Nobody wrote:

I know I'm late joining in on this, but am having a similar problem. I've tried playing with all the connection settings/bug detection settings as well as using a couple versions. WinSCP is on the list of allowed programs in Windows Firewall, FYI.

Here's the log for a failed connection attempt. Since it's prior to authentication, I assume it will work for your needs:

Why are you connecting to a port 443? It's for HTTPS, not for SFTP (or any other file transfer protocol).

I have no idea why VMWare has chosen to run their SFTP servers behind a non-standard port, but that's definitely where they have them.

Perhaps some very poor understanding of how ports, protocols, and security are related, e.g. 80 == insecure, 443 == secure? Maybe their IT staff have it locked down for SSH access only? Obviously I have no control over that.

Whatever the case 443 is definitely where the SFTP server responds and FileZilla doesn't have a problem opening that connection. I tried port 22 to be sure, and it's completely closed.

Can you attach a FileZilla log (not message log) showing that?

Sorry for the delay, I forgot to check for responses. Here's the log from a successful connection (hopefully this is the one you meant). I've put logging at debug level. It's version 3.10.3 of FileZilla, backed by GnuTLS version 3.3.13, in case it matters.

2015-08-07 10:31:27 10796 1 Status: Selected port usually in use by a different protocol.
2015-08-07 10:31:27 10796 1 Status: Connecting to sftp2.eng.vmware.com:443...
2015-08-07 10:31:27 10796 1 Trace: Going to execute C:\Program Files (x86)\FileZilla FTP Client\fzsftp.exe
2015-08-07 10:31:27 10796 1 Response: fzSftp started, protocol_version=2
2015-08-07 10:31:27 10796 1 Trace: CSftpControlSocket::ConnectParseResponse(fzSftp started, protocol_version=2)
2015-08-07 10:31:27 10796 1 Trace: CSftpControlSocket::SendNextCommand()
2015-08-07 10:31:27 10796 1 Trace: CSftpControlSocket::ConnectSend()
2015-08-07 10:31:27 10796 1 Command: open "[Account Name]@sftp2.eng.vmware.com" 443
2015-08-07 10:31:27 10796 1 Trace: Looking up host "sftp2.eng.vmware.com"
2015-08-07 10:31:28 10796 1 Trace: Connecting to 208.91.0.170 port 443
2015-08-07 10:31:28 10796 1 Trace: We claim version: SSH-2.0-PuTTY_Local:_Mar_29_2015_12:29:40
2015-08-07 10:31:28 10796 1 Trace: Server version: SSH-2.0-OpenSSH_5.3
2015-08-07 10:31:28 10796 1 Trace: We believe remote version has SSH-2 channel request bug
2015-08-07 10:31:28 10796 1 Trace: Using SSH protocol version 2
2015-08-07 10:31:28 10796 1 Trace: Doing Diffie-Hellman group exchange
2015-08-07 10:31:28 10796 1 Trace: Doing Diffie-Hellman key exchange with hash SHA-256
2015-08-07 10:31:28 10796 1 Trace: Host key fingerprint is:
2015-08-07 10:31:28 10796 1 Trace: ssh-rsa 2048 2b:0e:c2:1e:8f:e7:44:50:22:de:1b:db:00:df:71:39
2015-08-07 10:31:28 10796 1 Trace: Initialised AES-256 SDCTR client->server encryption
2015-08-07 10:31:28 10796 1 Trace: Initialised HMAC-SHA-256 client->server MAC algorithm
2015-08-07 10:31:28 10796 1 Trace: Initialised AES-256 SDCTR server->client encryption
2015-08-07 10:31:28 10796 1 Trace: Initialised HMAC-SHA-256 server->client MAC algorithm
2015-08-07 10:31:28 10796 1 Command: Pass: ********
2015-08-07 10:31:28 10796 1 Trace: Sent password
2015-08-07 10:31:33 10796 1 Trace: Access granted
2015-08-07 10:31:33 10796 1 Trace: Opening session as main channel
2015-08-07 10:31:34 10796 1 Trace: Opened main channel
2015-08-07 10:31:34 10796 1 Trace: Started a shell/command
2015-08-07 10:31:34 10796 1 Status: Connected to sftp2.vmware.com
2015-08-07 10:31:34 10796 1 Trace: CSftpControlSocket::ConnectParseResponse()
2015-08-07 10:31:34 10796 1 Trace: CSftpControlSocket::ResetOperation(0)
2015-08-07 10:31:34 10796 1 Trace: CControlSocket::ResetOperation(0)
2015-08-07 10:31:34 10796 1 Trace: CFileZillaEnginePrivate::ResetOperation(0)
2015-08-07 10:31:34 10796 1 Status: Retrieving directory listing...
2015-08-07 10:31:34 10796 1 Trace: CSftpControlSocket::SendNextCommand()
2015-08-07 10:31:34 10796 1 Trace: CSftpControlSocket::ChangeDirSend()
2015-08-07 10:31:34 10796 1 Command: pwd
2015-08-07 10:31:34 10796 1 Response: Current directory is: "/"
2015-08-07 10:31:34 10796 1 Trace: CSftpControlSocket::ResetOperation(0)
2015-08-07 10:31:34 10796 1 Trace: CControlSocket::ResetOperation(0)
2015-08-07 10:31:34 10796 1 Trace: CSftpControlSocket::ParseSubcommandResult(0)
2015-08-07 10:31:34 10796 1 Trace: CSftpControlSocket::ListSubcommandResult()
2015-08-07 10:31:34 10796 1 Trace: state = 1
2015-08-07 10:31:34 10796 1 Trace: CSftpControlSocket::SendNextCommand()
2015-08-07 10:31:34 10796 1 Trace: CSftpControlSocket::ListSend()
2015-08-07 10:31:34 10796 1 Trace: state = 2
2015-08-07 10:31:34 10796 1 Command: ls
2015-08-07 10:31:34 10796 1 Status: Listing directory /
2015-08-07 10:31:34 10796 1 Trace: CSftpControlSocket::ListParseResponse()
2015-08-07 10:31:34 10796 1 Trace: CSftpControlSocket::ResetOperation(0)
2015-08-07 10:31:34 10796 1 Trace: CControlSocket::ResetOperation(0)
2015-08-07 10:31:34 10796 1 Status: Directory listing of "/" successful
2015-08-07 10:31:34 10796 1 Trace: CFileZillaEnginePrivate::ResetOperation(0)
2015-08-07 10:31:36 10796 1 Status: Disconnected from server
2015-08-07 10:31:36 10796 1 Trace: CControlSocket::DoClose(64)
2015-08-07 10:31:36 10796 1 Trace: CSftpControlSocket::ResetOperation(66)
2015-08-07 10:31:36 10796 1 Trace: CControlSocket::ResetOperation(66)
2015-08-07 10:31:36 10796 1 Trace: CFileZillaEnginePrivate::ResetOperation(66)
2015-08-07 10:31:36 10796 1 Trace: CControlSocket::DoClose(64)
2015-08-07 10:31:36 10796 1 Trace: CControlSocket::DoClose(64)
2015-08-07 10:31:36 10796 1 Trace: CFileZillaEnginePrivate::ResetOperation(0)

I can connect without any problem to sftp2.eng.vmware.com with WinSCP (I should have tried straight away).
So it looks like a local problem on your machine. A firewall blocking WinSCP specifically? Can you try to turn it off temporarily?

Oh, shit, you're completely right. I can connect from my home connection, just not the office.

This must be local IT-related nonsense.

I'm very sorry to have wasted your time.

Since this is the first result in Google, here is what has worked for me

Apparently there seems a bug that causes WinSCP not to be able to connect when the remote directory (Edit-> Advanced->Environment->Directories->Remote directory) is not set.
Once I have set it to something, I was able to connect.
I am saying it might be a bug because, from this point on, the connection works even when I clear the value.

More info:
- Session was initially imported from FileZilla, but then deleted and recreated from scratch
- WinScp 5.7.6

Beemen wrote:

Since this is the first result in Google, here is what has worked for me

Apparently there seems a bug that causes WinSCP not to be able to connect when the remote directory (Edit-> Advanced->Environment->Directories->Remote directory) is not set.
Once I have set it to something, I was able to connect.
I am saying it might be a bug because, from this point on, the connection works even when I clear the value.

More info:
- Session was initially imported from FileZilla, but then deleted and recreated from scratch
- WinScp 5.7.6

Please attach a full log file showing the problem (using the latest version of WinSCP).