WinSCP authentication fails, FileZilla authenticates instantly

Advertisement

coldfact
Joined:
Posts:
2
Location:
Europe

WinSCP authentication fails, FileZilla authenticates instantly

I am trying to get to a SFTP site using the latest version (5.21.6) but I have also tested with other versions. For WinSCP the authentication process takes a long time and eventually fails with:
Remote side sent disconnect message type 11 (by application)
But for FileZilla the connection is instantaneous.

Attached are the verbose logs (deidentified) for both.
Any idea what FileZilla is doing that WinSCP is not?
Thanks for any help with this.
FileZilla:
Status:   Connecting to THESFTPSITE...
Trace:   CControlSocket::SendNextCommand()
Trace:   CSftpDeleteOpData::Send() in state 0
Trace:   Going to execute C:\Program Files\FileZilla FTP Client\fzsftp.exe
Response:   fzSftp started, protocol_version=8
Trace:   CSftpDeleteOpData::ParseResponse() in state 0
Trace:   CControlSocket::SendNextCommand()
Trace:   CSftpDeleteOpData::Send() in state 3
Command:   open "MYUSER@THESFTPSITE" 22
Trace:   Connecting to 123.456.7.890 port 22
Trace:   We claim version: SSH-2.0-FileZilla_3.39.0
Trace:   Server version: SSH-2.0-7.9.0.0_openssh GlobalSCAPE
Trace:   Using SSH protocol version 2
Trace:   Doing Diffie-Hellman group exchange
Trace:   Doing Diffie-Hellman key exchange with hash SHA-256
Trace:   Host key fingerprint is:
Trace:   ssh-rsa 2048 14:88:etc etc etc etc
Trace:   Initialised AES-256 SDCTR client->server encryption
Trace:   Initialised HMAC-SHA-256 client->server MAC algorithm
Trace:   Initialised AES-256 SDCTR server->client encryption
Trace:   Initialised HMAC-SHA-256 server->client MAC algorithm
Trace:   Attempting keyboard-interactive authentication
Trace:   Using keyboard-interactive authentication. inst_len: 0, num_prompts: 1
Command:   Pass: **********
Trace:   Access granted
Trace:   Opening session as main channel
Trace:   Opened main channel
Trace:   Started a shell/command
Status:   Connected to THESFTPSITE
Trace:   CSftpDeleteOpData::ParseResponse() in state 3
Trace:   CControlSocket::ResetOperation(0)
Trace:   CSftpDeleteOpData::Reset(0) in state 3
Trace:   CFileZillaEnginePrivate::ResetOperation(0)
Status:   Retrieving directory listing...
Trace:   CControlSocket::SendNextCommand()
Trace:   CSftpListOpData::Send() in state 0
Trace:   CSftpChangeDirOpData::Send() in state 0
Trace:   CSftpChangeDirOpData::Send() in state 1
Command:   pwd
Response:   Current directory is: "/"
Trace:   CSftpChangeDirOpData::ParseResponse() in state 1
Trace:   CControlSocket::ResetOperation(0)
Trace:   CSftpChangeDirOpData::Reset(0) in state 1
Trace:   CSftpListOpData::SubcommandResult(0) in state 1
Trace:   CControlSocket::SendNextCommand()
Trace:   CSftpListOpData::Send() in state 2
Trace:   CSftpListOpData::Send() in state 3
Command:   ls
Status:   Listing directory /
Trace:   CSftpListOpData::ParseResponse() in state 3
Trace:   CControlSocket::ResetOperation(0)
Trace:   CSftpListOpData::Reset(0) in state 3
Status:   Directory listing of "/" successful
Trace:   CFileZillaEnginePrivate::ResetOperation(0)
WinSCP
. 2023-01-19 02:29:32.370 WinSCP Version 5.21.6 (Build 12913 2022-11-28) (OS 6.3.9600 - Windows Server 2012 R2 Standard)
. 2023-01-19 02:29:32.370 Configuration: HKCU\Software\Martin Prikryl\WinSCP 2\
. 2023-01-19 02:29:32.370 Log level: Debug 2
. 2023-01-19 02:29:32.370 Local account: MYACCOUNT
. 2023-01-19 02:29:32.370 Working directory: C:\Program Files (x86)\WinSCP
. 2023-01-19 02:29:32.370 Process ID: 14620
. 2023-01-19 02:29:32.388 Ancestor processes: ...
. 2023-01-19 02:29:32.389 Command-line: "C:\Program Files (x86)\WinSCP\WinSCP.exe" 
. 2023-01-19 02:29:32.389 Time zone: Current: GMT-5, Standard: GMT-5 (Eastern Standard Time), DST: GMT-4 (Eastern Daylight Time), DST Start: 3/12/2023, DST End: 11/5/2023
. 2023-01-19 02:29:32.390 Login time: Thursday, January 19, 2023 2:29:32 AM
. 2023-01-19 02:29:32.390 --------------------------------------------------------------------------
. 2023-01-19 02:29:32.390 Session name: THESFTPSITE (Modified site)
. 2023-01-19 02:29:32.390 Host name: THESFTPSITE (Port: 22)
. 2023-01-19 02:29:32.390 User name: MYUSER (Password: Yes, Key file: No, Passphrase: No)
. 2023-01-19 02:29:32.390 Tunnel: No
. 2023-01-19 02:29:32.390 Transfer Protocol: SFTP (SCP)
. 2023-01-19 02:29:32.390 Ping type: Null, Ping interval: 30 sec; Timeout: 45 sec
. 2023-01-19 02:29:32.390 Disable Nagle: No
. 2023-01-19 02:29:32.390 Proxy: None
. 2023-01-19 02:29:32.390 Send buffer: 262144
. 2023-01-19 02:29:32.390 Compression: No
. 2023-01-19 02:29:32.390 Bypass authentication: No
. 2023-01-19 02:29:32.391 Try agent: Yes; Agent forwarding: No; KI: Yes; GSSAPI: Yes
. 2023-01-19 02:29:32.391 GSSAPI: KEX: No; Forwarding: No; Libs: gssapi32,sspi,custom; Custom: 
. 2023-01-19 02:29:32.391 Ciphers: aes,chacha20,blowfish,3des,WARN,arcfour,des; Ssh2DES: No
. 2023-01-19 02:29:32.391 KEX: ecdh,dh-gex-sha1,dh-group14-sha1,rsa,WARN,dh-group1-sha1
. 2023-01-19 02:29:32.391 SSH Bugs: Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto
. 2023-01-19 02:29:32.391 Simple channel: Yes
. 2023-01-19 02:29:32.391 Return code variable: Autodetect; Lookup user groups: Auto
. 2023-01-19 02:29:32.391 Shell: default
. 2023-01-19 02:29:32.391 EOL: LF, UTF: Auto
. 2023-01-19 02:29:32.391 Clear aliases: Yes, Unset nat.vars: Yes, Resolve symlinks: Yes; Follow directory symlinks: No
. 2023-01-19 02:29:32.391 LS: ls -la, Ign LS warn: Yes, Scp1 Comp: No; Exit code 1 is error: No
. 2023-01-19 02:29:32.391 SFTP Bugs: Auto,Auto
. 2023-01-19 02:29:32.391 SFTP Server: default
. 2023-01-19 02:29:32.391 Local directory: default, Remote directory: home, Update: Yes, Cache: Yes
. 2023-01-19 02:29:32.392 Cache directory changes: Yes, Permanent: Yes
. 2023-01-19 02:29:32.392 Recycle bin: Delete to: No, Overwritten to: No, Bin path: 
. 2023-01-19 02:29:32.392 DST mode: Unix
. 2023-01-19 02:29:32.392 --------------------------------------------------------------------------
. 2023-01-19 02:29:32.424 Looking up host "THESFTPSITE" for SSH connection
. 2023-01-19 02:29:32.425 Connecting to 123.456.7.890 port 22
. 2023-01-19 02:29:32.479 Connected to 123.456.7.890
. 2023-01-19 02:29:32.479 Selecting events 63 for socket 1272
. 2023-01-19 02:29:32.505 Waiting for the server to continue with the initialization
. 2023-01-19 02:29:32.505 Looking for incoming data
. 2023-01-19 02:29:32.505 Looking for network events
. 2023-01-19 02:29:32.505 We claim version: SSH-2.0-WinSCP_release_5.21.6
. 2023-01-19 02:29:32.506 Detected network event
. 2023-01-19 02:29:32.506 Enumerating network events for socket 1272
. 2023-01-19 02:29:32.506 Enumerated 18 network events making 18 cumulative events for socket 1272
. 2023-01-19 02:29:32.506 Handling network write event on socket 1272 with error 0
. 2023-01-19 02:29:32.506 Handling network connect event on socket 1272 with error 0
. 2023-01-19 02:29:32.506 Connected to 123.456.7.890
. 2023-01-19 02:29:32.506 Looking for network events
. 2023-01-19 02:29:32.533 Detected network event
. 2023-01-19 02:29:32.533 Enumerating network events for socket 1272
. 2023-01-19 02:29:32.533 Enumerated 1 network events making 1 cumulative events for socket 1272
. 2023-01-19 02:29:32.533 Handling network read event on socket 1272 with error 0
. 2023-01-19 02:29:32.533 Waiting for the server to continue with the initialization
. 2023-01-19 02:29:32.533 Looking for incoming data
. 2023-01-19 02:29:32.533 Looking for network events
. 2023-01-19 02:29:32.533 Remote version: SSH-2.0-7.9.0.0_openssh GlobalSCAPE
. 2023-01-19 02:29:32.534 Using SSH protocol version 2
. 2023-01-19 02:29:32.538 Have a known host key of type rsa2
. 2023-01-19 02:29:32.604 Detected network event
. 2023-01-19 02:29:32.605 Enumerating network events for socket 1272
. 2023-01-19 02:29:32.605 Enumerated 1 network events making 1 cumulative events for socket 1272
. 2023-01-19 02:29:32.605 Handling network read event on socket 1272 with error 0
. 2023-01-19 02:29:32.605 Waiting for the server to continue with the initialization
. 2023-01-19 02:29:32.605 Looking for incoming data
. 2023-01-19 02:29:32.605 Looking for network events
. 2023-01-19 02:29:32.605 Doing Diffie-Hellman group exchange
. 2023-01-19 02:29:32.780 Detected network event
. 2023-01-19 02:29:32.780 Enumerating network events for socket 1272
. 2023-01-19 02:29:32.780 Enumerated 1 network events making 1 cumulative events for socket 1272
. 2023-01-19 02:29:32.780 Handling network read event on socket 1272 with error 0
. 2023-01-19 02:29:32.781 Waiting for the server to continue with the initialization
. 2023-01-19 02:29:32.781 Looking for incoming data
. 2023-01-19 02:29:32.781 Looking for network events
. 2023-01-19 02:29:32.781 Doing Diffie-Hellman key exchange using 8192-bit modulus and hash SHA-256 with a server-supplied group
. 2023-01-19 02:30:10.693 Detected network event
. 2023-01-19 02:30:10.693 Enumerating network events for socket 1272
. 2023-01-19 02:30:10.693 Enumerated 1 network events making 1 cumulative events for socket 1272
. 2023-01-19 02:30:10.693 Handling network read event on socket 1272 with error 0
. 2023-01-19 02:30:10.693 Waiting for the server to continue with the initialization
. 2023-01-19 02:30:10.693 Looking for incoming data
. 2023-01-19 02:30:10.693 Looking for network events
. 2023-01-19 02:30:46.033 Host key fingerprint is:
. 2023-01-19 02:30:46.033 ssh-rsa 2048 SHA256:BfTIetcetcetc
. 2023-01-19 02:30:46.033 Verifying host key rsa2 0x11,0x919e8etcetc  with fingerprints ssh-rsa 2048 SHA256:BfTIetcetcetc
. 2023-01-19 02:30:46.075 Host key matches cached key
. 2023-01-19 02:30:46.077 Initialised AES-256 SDCTR (AES-NI accelerated) [aes256-ctr] outbound encryption
. 2023-01-19 02:30:46.077 Initialised HMAC-SHA-256 outbound MAC algorithm
. 2023-01-19 02:30:46.078 Initialised AES-256 SDCTR (AES-NI accelerated) [aes256-ctr] inbound encryption
. 2023-01-19 02:30:46.078 Initialised HMAC-SHA-256 inbound MAC algorithm
. 2023-01-19 02:30:46.078 Detected network event
. 2023-01-19 02:30:46.078 Enumerating network events for socket 1272
. 2023-01-19 02:30:46.078 Enumerated 33 network events making 33 cumulative events for socket 1272
. 2023-01-19 02:30:46.078 Handling network close event on socket 1272 with error 0
. 2023-01-19 02:30:46.078 Handling network read event on socket 1272 with error 0
. 2023-01-19 02:30:46.078 Waiting for the server to continue with the initialization
. 2023-01-19 02:30:46.079 Looking for incoming data
. 2023-01-19 02:30:46.079 Looking for network events
. 2023-01-19 02:30:46.079 Selecting events 0 for socket 1272
. 2023-01-19 02:30:46.080 Remote side sent disconnect message type 11 (by application): ""
* 2023-01-19 02:30:46.089 (EFatal) Remote side sent disconnect message
* 2023-01-19 02:30:46.089 type 11 (by application):
* 2023-01-19 02:30:46.089 ""
* 2023-01-19 02:30:46.089 Authentication failed.

Reply with quote

Advertisement

martin
Site Admin
martin avatar
Joined:
Posts:
41,276
Location:
Prague, Czechia

Re: WinSCP authentication fails, FileZilla authenticates instantly

Did you check server-side logs for any hints, why it closes the connection?

Is your server accessible on the Internet? Can I get (even privately) its IP address?

It seems to be a common issue with GlobalSCAPE SFTP servers:
Issue 2159 – Spurious "Remote side sent disconnect message: type 11 (by application)" when connecting to GlobalSCAPE server

Reply with quote

Advertisement

You can post new topics in this forum