Connection has been unexpectedly closed -- logs attached -

Another day and another post on the forum about "Connection has been unexpectedly closed. Server sent command exit status 0"

I have read the FAQ and searched this site and documentation for help but unfortunately am stumped and must post this request for help.

I am using winscp to connect to a very old Debian box, I have no problems using the GUI to connect. I have connected successfully many time and continue to be able to connect. Today I thought it would be nice to create a script to copy my one file to my Debian box automagically, but have run into a problem when I use the command line to connect to the Linux box. The problem occurs without any scripting just using "winscp" at the command line, then "open" then "home.hostname.ca:1873". I connect to the server, get prompted for a username, which seems to go ok, then a message about Using keyboard-interactive authentication and finally a prompt for a password. Once I've entered in my password I get a message "Using keyboard-interactive authentication." "Connection has been unexpectedly closed. Server send command exit status 0." "Authentication failed."

I've monkeyed around with the settings in the GUI of WINSCP to see if I could reproduce the error in it, but to no avail. I do have two log files below, the red is the console attempt to login, and the green is the GUI working login.

I appreciate anyone who can take the time to point me in the right direction.

I have attached two log files below, the RED is the non-working console login, and the GREEN is the working GUI login.

. 2009-05-26 23:11:10.046 --------------------------------------------------------------------------
. 2009-05-26 23:11:10.046 WinSCP Version 4.2.1 (Build 428) (OS 5.1.2600 Service Pack 2)
. 2009-05-26 23:11:10.046 Login time: Tuesday, May 26, 2009 11:11:10 PM
. 2009-05-26 23:11:10.046 --------------------------------------------------------------------------
. 2009-05-26 23:11:10.046 Session name: myname@home.domain.ca
. 2009-05-26 23:11:10.046 Host name: home.domain.ca (Port: 1873)
. 2009-05-26 23:11:10.046 User name: myname (Password: No, Key file: No)
. 2009-05-26 23:11:10.046 Tunnel: No
. 2009-05-26 23:11:10.046 Transfer Protocol: SFTP
. 2009-05-26 23:11:10.046 Ping type: -, Ping interval: 30 sec; Timeout: 15 sec
. 2009-05-26 23:11:10.046 Proxy: none
. 2009-05-26 23:11:10.046 SSH protocol version: 2; Compression: No
. 2009-05-26 23:11:10.046 Bypass authentication: No
. 2009-05-26 23:11:10.046 Try agent: Yes; Agent forwarding: No; TIS/CryptoCard: No; KI: Yes; GSSAPI: No
. 2009-05-26 23:11:10.046 Ciphers: aes,blowfish,3des,WARN,arcfour,des; Ssh2DES: No
. 2009-05-26 23:11:10.046 SSH Bugs: -,-,-,-,-,-,-,-,-
. 2009-05-26 23:11:10.046 SFTP Bugs: -,-
. 2009-05-26 23:11:10.046 Return code variable: Autodetect; Lookup user groups: Yes
. 2009-05-26 23:11:10.046 Shell: default, EOL: 0
. 2009-05-26 23:11:10.046 Clear aliases: Yes, Unset nat.vars: Yes, Resolve symlinks: Yes
. 2009-05-26 23:11:10.046 LS: ls -la, Ign LS warn: Yes, Scp1 Comp: No
. 2009-05-26 23:11:10.046 Local directory: C:\Documents and Settings\name\My Documents, Remote directory: /home/name, Update: No, Cache: Yes
. 2009-05-26 23:11:10.046 Cache directory changes: Yes, Permanent: Yes
. 2009-05-26 23:11:10.046 DST mode: 1
. 2009-05-26 23:11:10.046 --------------------------------------------------------------------------
. 2009-05-26 23:11:10.046 Looking up host "home.domain.ca"
. 2009-05-26 23:11:10.109 Connecting to 154.20.xxx.xxx port 1873
. 2009-05-26 23:11:10.109 Waiting for the server to continue with the initialisation
. 2009-05-26 23:11:10.109 Detected network event
. 2009-05-26 23:11:10.171 Detected network event
. 2009-05-26 23:11:10.171 Server version: SSH-2.0-OpenSSH_4.3p2 Debian-3
. 2009-05-26 23:11:10.171 Using SSH protocol version 2
. 2009-05-26 23:11:10.171 We claim version: SSH-2.0-WinSCP_release_4.2.1
. 2009-05-26 23:11:10.171 Waiting for the server to continue with the initialisation
. 2009-05-26 23:11:10.171 Detected network event
. 2009-05-26 23:11:10.171 Doing Diffie-Hellman group exchange
. 2009-05-26 23:11:10.171 Waiting for the server to continue with the initialisation
. 2009-05-26 23:11:10.187 Detected network event
. 2009-05-26 23:11:10.187 Doing Diffie-Hellman key exchange with hash SHA-1
. 2009-05-26 23:11:10.281 Waiting for the server to continue with the initialisation
. 2009-05-26 23:11:10.359 Detected network event
. 2009-05-26 23:11:10.453 Host key fingerprint is:
. 2009-05-26 23:11:10.453 ssh-rsa 1024 de:ad:be:ef:de:ad:be:efde:ad:be:ef
. 2009-05-26 23:11:10.453 Initialised AES-256 SDCTR client->server encryption
. 2009-05-26 23:11:10.453 Initialised HMAC-SHA1 client->server MAC algorithm
. 2009-05-26 23:11:10.453 Initialised AES-256 SDCTR server->client encryption
. 2009-05-26 23:11:10.453 Initialised HMAC-SHA1 server->client MAC algorithm
. 2009-05-26 23:11:10.453 Waiting for the server to continue with the initialisation
. 2009-05-26 23:11:10.453 Detected network event
! 2009-05-26 23:11:10.453 Using username "myname".
. 2009-05-26 23:11:10.453 Waiting for the server to continue with the initialisation
. 2009-05-26 23:11:11.984 Detected network event
. 2009-05-26 23:11:11.984 Waiting for the server to continue with the initialisation
. 2009-05-26 23:11:11.984 Detected network event
. 2009-05-26 23:11:11.984 Prompt (5, SSH server authentication, Using keyboard-interactive authentication., Password: )
. 2009-05-26 23:11:13.593 Waiting for the server to continue with the initialisation
. 2009-05-26 23:11:13.593 Detected network event
. 2009-05-26 23:11:13.593 Prompt (5, SSH server authentication, Using keyboard-interactive authentication., <no prompt>)
. 2009-05-26 23:11:13.593 Disconnected: Unable to authenticate




. 2009-05-26 23:30:42.187 --------------------------------------------------------------------------
. 2009-05-26 23:30:42.187 WinSCP Version 4.2.1 (Build 428) (OS 5.1.2600 Service Pack 2)
. 2009-05-26 23:30:42.187 Login time: Tuesday, May 26, 2009 11:30:42 PM
. 2009-05-26 23:30:42.187 --------------------------------------------------------------------------
. 2009-05-26 23:30:42.187 Session name: jamie@home.domain.ca
. 2009-05-26 23:30:42.187 Host name: home.domain.ca (Port: 1873)
. 2009-05-26 23:30:42.187 User name: jamie (Password: No, Key file: No)
. 2009-05-26 23:30:42.187 Tunnel: No
. 2009-05-26 23:30:42.187 Transfer Protocol: SFTP
. 2009-05-26 23:30:42.187 Ping type: -, Ping interval: 30 sec; Timeout: 15 sec
. 2009-05-26 23:30:42.187 Proxy: none
. 2009-05-26 23:30:42.187 SSH protocol version: 2; Compression: No
. 2009-05-26 23:30:42.187 Bypass authentication: No
. 2009-05-26 23:30:42.187 Try agent: Yes; Agent forwarding: No; TIS/CryptoCard: No; KI: Yes; GSSAPI: No
. 2009-05-26 23:30:42.187 Ciphers: aes,blowfish,3des,WARN,arcfour,des; Ssh2DES: No
. 2009-05-26 23:30:42.187 SSH Bugs: -,-,-,-,-,-,-,-,-
. 2009-05-26 23:30:42.203 SFTP Bugs: -,-
. 2009-05-26 23:30:42.203 Return code variable: Autodetect; Lookup user groups: Yes
. 2009-05-26 23:30:42.203 Shell: /bin/bash, EOL: 0
. 2009-05-26 23:30:42.203 Clear aliases: Yes, Unset nat.vars: Yes, Resolve symlinks: Yes
. 2009-05-26 23:30:42.203 LS: ls -la, Ign LS warn: Yes, Scp1 Comp: No
. 2009-05-26 23:30:42.203 Local directory: C:\Documents and Settings\James\My Documents, Remote directory: /home/jamie, Update: No, Cache: Yes
. 2009-05-26 23:30:42.203 Cache directory changes: Yes, Permanent: Yes
. 2009-05-26 23:30:42.203 DST mode: 1
. 2009-05-26 23:30:42.203 --------------------------------------------------------------------------
. 2009-05-26 23:30:42.250 Looking up host "home.domain.ca"
. 2009-05-26 23:30:42.343 Connecting to 154.20.xxx.xxx port 1873
. 2009-05-26 23:30:42.359 Waiting for the server to continue with the initialisation
. 2009-05-26 23:30:42.359 Detected network event
. 2009-05-26 23:30:42.406 Detected network event
. 2009-05-26 23:30:42.406 Server version: SSH-2.0-OpenSSH_4.3p2 Debian-3
. 2009-05-26 23:30:42.406 Using SSH protocol version 2
. 2009-05-26 23:30:42.406 We claim version: SSH-2.0-WinSCP_release_4.2.1
. 2009-05-26 23:30:42.406 Waiting for the server to continue with the initialisation
. 2009-05-26 23:30:42.421 Detected network event
. 2009-05-26 23:30:42.421 Doing Diffie-Hellman group exchange
. 2009-05-26 23:30:42.421 Waiting for the server to continue with the initialisation
. 2009-05-26 23:30:42.468 Detected network event
. 2009-05-26 23:30:42.468 Doing Diffie-Hellman key exchange with hash SHA-1
. 2009-05-26 23:30:42.671 Waiting for the server to continue with the initialisation
. 2009-05-26 23:30:42.750 Detected network event
. 2009-05-26 23:30:42.968 Host key fingerprint is:
. 2009-05-26 23:30:42.968 ssh-rsa 1024 de:ad:be:ef:de:ad:be:ef:de:ad:be:ef:de:ad:be:ef:
. 2009-05-26 23:30:42.968 Initialised AES-256 SDCTR client->server encryption
. 2009-05-26 23:30:42.968 Initialised HMAC-SHA1 client->server MAC algorithm
. 2009-05-26 23:30:42.968 Initialised AES-256 SDCTR server->client encryption
. 2009-05-26 23:30:42.968 Initialised HMAC-SHA1 server->client MAC algorithm
. 2009-05-26 23:30:42.968 Waiting for the server to continue with the initialisation
. 2009-05-26 23:30:42.968 Detected network event
! 2009-05-26 23:30:42.968 Using username "jamie".
. 2009-05-26 23:30:42.968 Waiting for the server to continue with the initialisation
. 2009-05-26 23:30:44.515 Detected network event
. 2009-05-26 23:30:44.515 Waiting for the server to continue with the initialisation
. 2009-05-26 23:30:44.515 Detected network event
. 2009-05-26 23:30:44.515 Prompt (5, SSH server authentication, Using keyboard-interactive authentication., Password: )
. 2009-05-26 23:30:46.250 Waiting for the server to continue with the initialisation
. 2009-05-26 23:30:46.250 Detected network event
. 2009-05-26 23:30:46.250 Prompt (5, SSH server authentication, Using keyboard-interactive authentication., <no prompt>)
. 2009-05-26 23:30:48.343 Waiting for the server to continue with the initialisation
. 2009-05-26 23:30:48.343 Detected network event
. 2009-05-26 23:30:48.343 Access granted
. 2009-05-26 23:30:48.343 Waiting for the server to continue with the initialisation
. 2009-05-26 23:30:48.359 Detected network event
. 2009-05-26 23:30:48.359 Opened channel for session
. 2009-05-26 23:30:48.359 Waiting for the server to continue with the initialisation
. 2009-05-26 23:30:48.390 Detected network event
. 2009-05-26 23:30:48.390 Started a shell/command
. 2009-05-26 23:30:48.390 --------------------------------------------------------------------------
. 2009-05-26 23:30:48.390 Using SFTP protocol.
. 2009-05-26 23:30:48.390 Doing startup conversation with host.
> 2009-05-26 23:30:48.390 Type: SSH_FXP_INIT, Size: 5, Number: -1
. 2009-05-26 23:30:48.390 Sent 9 bytes
. 2009-05-26 23:30:48.390 There are 0 bytes remaining in the send buffer
. 2009-05-26 23:30:48.390 Waiting for another 4 bytes
. 2009-05-26 23:30:48.406 Detected network event
. 2009-05-26 23:30:48.406 Received 9 bytes (0)
. 2009-05-26 23:30:48.406 Read 4 bytes (5 pending)
. 2009-05-26 23:30:48.406 Read 5 bytes (0 pending)
< 2009-05-26 23:30:48.406 Type: SSH_FXP_VERSION, Size: 5, Number: -1
. 2009-05-26 23:30:48.406 SFTP version 3 negotiated.
. 2009-05-26 23:30:48.406 We believe the server has signed timestamps bug
. 2009-05-26 23:30:48.406 We will use UTF-8 strings for status messages only
. 2009-05-26 23:30:48.406 Limiting packet size to OpenSSH sftp-server limit of 262148 bytes

Can please try it with with 4.1.9? Post both log files again.

martin wrote:

Can please try it with with 4.1.9? Post both log files again.

Ok, I've downgraded to 4.1.9 and reattempted to connect to my SCP server. Everything is connecting fine now. Thanks for the tip, if you'd still like a copy of my log files let me know and I'll attach them.

Cheers,
Jamie

OK, so it was possibly related to this bug. The fix will be included in 4.2.2. Please once it gets out, try it to verify that it indeed fixes your problem. Thanks.

Uh OK. I'm affected by this bug. I noticed that this has been fixed for a while. Can I download it? I need the FTPS version, so I have to use 4.2.x. But at the same time, I need the regular version too for SSH. So, any estimates on 4.2.2 release? I think it's an urgent bug.

xyz wrote:

Uh OK. I'm affected by this bug. I noticed that this has been fixed for a while. Can I download it? I need the FTPS version, so I have to use 4.2.x. But at the same time, I need the regular version too for SSH. So, any estimates on 4.2.2 release? I think it's an urgent bug.

I hope to release 4.2.2 at the end of this month.

martin wrote:

I hope to release 4.2.2 at the end of this month.

I too am affected by this exact same problem. I am glad to see it has already been corrected and will be in the next release. Thanks!