server unexpectedly closed network connection
JohnK
on a server and find that I need to use PuTTY 0.58 in order to connect.
0.59 and 0.60 both fail to connect with a 'Server unexpectedly closed
network connection' error.
Running sshd in debug mode gives this output
Any suggestions what could be the issue?
debug1: HPN Disabled: 1, HPN Buffer Size: 131072
debug1: Client protocol version 2.0; client software version
PuTTY_Release_0.60
SSH: Server;Ltype: Version;Remote: 10.xxx.xxx.xxx-1046;Protocol:
2.0;Client: PuTTY_Release_0.60
debug1: no match: PuTTY_Release_0.60
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-1.99-OpenSSH_5.1p1-hpn13v5
debug1: permanently_set_uid: 601/601
debug1: MYFLAG IS 1
debug1: list_hostkey_types: ssh-rsa,ssh-dss
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug1: AUTH STATE IS 0
debug1: REQUESTED ENC.NAME is 'aes256-ctr'
debug1: kex: client->server aes256-ctr hmac-sha1 none
SSH: Server;Ltype: Kex;Remote: 10.xxx.xxx.xxx-1046;Enc: aes256-ctr;MAC:
hmac-sha1;Comp: none
debug1: REQUESTED ENC.NAME is 'aes256-ctr'
debug1: kex: server->client aes256-ctr hmac-sha1 none
debug1: SSH2_MSG_KEX_DH_GEX_REQUEST_OLD received
debug1: SSH2_MSG_KEX_DH_GEX_GROUP sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_INIT
debug1: SSH2_MSG_KEX_DH_GEX_REPLY sent
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug1: SSH2_MSG_NEWKEYS received
debug1: KEX done
debug1: userauth-request for user johnk service ssh-connection method none
SSH: Server;Ltype: Authname;Remote: 10.xxx.xxx.xxx-1046;Name: johnk
debug1: attempt 0 failures 0
debug1: Config token is allowtcpforwarding
debug1: Config token is banner
debug1: Config token is challengeresponseauthentication
debug1: Config token is clientaliveinterval
debug1: Config token is clientalivecountmax
debug1: Config token is compression
debug1: Config token is gatewayports
debug1: Config token is hostbasedauthentication
debug1: Config token is ignorerhosts
debug1: Config token is ignoreuserknownhosts
debug1: Config token is keyregenerationinterval
debug1: Config token is port
debug1: Config token is listenaddress
debug1: Config token is logingracetime
debug1: Config token is loglevel
debug1: Config token is maxauthtries
debug1: Config token is maxstartups
debug1: Config token is passwordauthentication
debug1: Config token is permitemptypasswords
debug1: Config token is permitrootlogin
debug1: Config token is permituserenvironment
debug1: Config token is pidfile
debug1: Config token is printlastlog
debug1: Config token is printmotd
debug1: Config token is protocol
debug1: Config token is pubkeyauthentication
debug1: Config token is rhostsrsaauthentication
debug1: Config token is serverkeybits
debug1: Config token is strictmodes
debug1: Config token is subsystem
debug1: Config token is syslogfacility
debug1: Config token is tcpkeepalive
debug1: Config token is usepam
debug1: Config token is usedns
debug1: Config token is uselogin
debug1: Config token is useprivilegeseparation
debug1: Config token is x11displayoffset
debug1: Config token is x11forwarding
debug1: Config token is x11uselocalhost
debug1: Config token is xauthlocation
debug1: Config token is noneenabled
debug1: Config token is hpndisabled
debug1: PAM: initializing for "johnk"
debug1: PAM: setting PAM_RHOST to "10.xxx.xxx.xxx"
debug1: userauth_send_banner: sent
Failed none for johnk from 10.xxx.xxx.xxx port 1046 ssh2
debug1: do_cleanup
debug1: PAM: cleanup
JohnK
...
Outgoing packet type 21 / 0x15 (SSH2_MSG_NEWKEYS)
Event Log: Initialised AES-256 SDCTR client->server encryption
Event Log: Initialised HMAC-SHA1 client->server MAC algorithm
Incoming packet type 21 / 0x15 (SSH2_MSG_NEWKEYS)
Event Log: Initialised AES-256 SDCTR server->client encryption
Event Log: Initialised HMAC-SHA1 server->client MAC algorithm
Outgoing packet type 5 / 0x05 (SSH2_MSG_SERVICE_REQUEST)
00000000 00 00 00 0c 73 73 68 2d 75 73 65 72 61 75 74 68
....ssh-userauth
Incoming packet type 6 / 0x06 (SSH2_MSG_SERVICE_ACCEPT)
00000000 00 00 00 0c 73 73 68 2d 75 73 65 72 61 75 74 68
....ssh-userauth
Event Log: Reading private key file "C:\Documents and Settings\john\My
Documents\id_rsa.PPK"
Event Log: Pageant is running. Requesting keys.
Event Log: Pageant has 1 SSH-2 keys
Event Log: Pageant key #0 matches configured key file
Outgoing packet type 50 / 0x32 (SSH2_MSG_USERAUTH_REQUEST)
00000000 00 00 00 08 6a 6a 6a 6a 6a 6a 6a 6a 00 00 00 0e
....kkkkkkkk....
00000010 73 73 68 2d 63 6f 6e 6e 65 63 74 69 6f 6e 00 00
ssh-connection..
00000020 00 04 6e 6f 6e 65 ..none
Event Log: Server unexpectedly closed network connection**
Todd H.
When the ssh service or overall host is tcpwrapped on the server I've
seen these unexpectedly closed network connection issues. I never
debugged exactly how far it got in the login process with verbose
messages, but one possible explanation is that the server is running
tcp wrappers, and you're coming from an IP it doesn't have in the
allow list.
That's at best a guess as I'm sure it could be a number of other
things. But it smells like a network level issue rather than ssh.
--
Todd H.
http://www.toddh.net/
JohnK
> seen these unexpectedly closed network connection issues. I never
> debugged exactly how far it got in the login process with verbose
> messages, but one possible explanation is that the server is running
> tcp wrappers, and you're coming from an IP it doesn't have in the
> allow list.
>
> That's at best a guess as I'm sure it could be a number of other
> things. But it smells like a network level issue rather than ssh.
>
Todd, thanks for your input but as I said, I can connect using Putty
0.58. That would discount any network issues surely? It looks like
some kind of incompatibility between Putty 0.59 (and later) and this
version of OpenSSH.
Jacob Nevins
>Todd, thanks for your input but as I said, I can connect using Putty
>0.58. That would discount any network issues surely? It looks like
>some kind of incompatibility between Putty 0.59 (and later) and this
>version of OpenSSH.
It is odd that it's dependent on the version of PuTTY. I'd be
interested to see the point of divergence in the PuTTY log between
0.58 and a later version.
Have you tried a development snapshot of PuTTY?
JohnK
Development snapshot version dropped the connection too. Here is the
log from Putty 0.58.
I hacked out the packet data. Hope this leaves enough to see it working.
PuTTY log 2009.08.18 12:41:46
Event Log: Writing new session log (SSH packets mode) to file: putty.log
Event Log: Looking up host "10.xxx.xxx.xxx"
Event Log: Connecting to 10.xxx.xxx.xxx port 22
Event Log: Server version: SSH-1.99-OpenSSH_5.1p1-hpn13v5
Event Log: We claim version: SSH-2.0-PuTTY_Release_0.58
Event Log: Using SSH protocol version 2
Incoming packet type 20 / 0x14 (SSH2_MSG_KEXINIT)
...
Outgoing packet type 20 / 0x14 (SSH2_MSG_KEXINIT)
...
Event Log: Doing Diffie-Hellman group exchange
Outgoing packet type 30 / 0x1e (SSH2_MSG_KEX_DH_GEX_REQUEST)
...
Incoming packet type 31 / 0x1f (SSH2_MSG_KEX_DH_GEX_GROUP)
...
Event Log: Doing Diffie-Hellman key exchange
Outgoing packet type 32 / 0x20 (SSH2_MSG_KEX_DH_GEX_INIT)
...
Incoming packet type 33 / 0x21 (SSH2_MSG_KEX_DH_GEX_REPLY)
...
Event Log: Host key fingerprint is:
Event Log: ssh-rsa 2048 xx.xx.xx.xx.xx.xx.xx.xx.xx.xx.xx.xx
Outgoing packet type 21 / 0x15 (SSH2_MSG_NEWKEYS)
Event Log: Initialised AES-256 client->server encryption
Event Log: Initialised HMAC-SHA1 client->server MAC algorithm
Incoming packet type 21 / 0x15 (SSH2_MSG_NEWKEYS)
Event Log: Initialised AES-256 server->client encryption
Event Log: Initialised HMAC-SHA1 server->client MAC algorithm
Outgoing packet type 5 / 0x05 (SSH2_MSG_SERVICE_REQUEST)
00000000 00 00 00 0c 73 73 68 2d 75 73 65 72 61 75 74 68
....ssh-userauth
Incoming packet type 6 / 0x06 (SSH2_MSG_SERVICE_ACCEPT)
00000000 00 00 00 0c 73 73 68 2d 75 73 65 72 61 75 74 68
....ssh-userauth
Outgoing packet type 50 / 0x32 (SSH2_MSG_USERAUTH_REQUEST)
00000000 00 00 00 08 6a 6b 6b 6b 6b 6b 6b 6b 00 00 00 0e
....jkkkkkkk....
00000010 73 73 68 2d 63 6f 6e 6e 65 63 74 69 6f 6e 00 00
ssh-connection..
00000020 00 04 6e 6f 6e 65 ..none
Event Log: Reading private key file "C:\Documents and Settings\john\My
Documents\id_rsa.PPK"
Incoming packet type 53 / 0x35 (SSH2_MSG_USERAUTH_BANNER)
...
Incoming packet type 51 / 0x33 (SSH2_MSG_USERAUTH_FAILURE)
00000000 00 00 00 27 70 75 62 6c 69 63 6b 65 79 2c 70 61
...'publickey,pa
00000010 73 73 77 6f 72 64 2c 6b 65 79 62 6f 61 72 64 2d
ssword,keyboard-
00000020 69 6e 74 65 72 61 63 74 69 76 65 00 interactive.
Event Log: Pageant is running. Requesting keys.
Event Log: Pageant has 1 SSH-2 keys
Event Log: Trying Pageant key #0
Event Log: This key matches configured key file
Outgoing packet type 50 / 0x32 (SSH2_MSG_USERAUTH_REQUEST)
...
Incoming packet type 60 / 0x3c (SSH2_MSG_USERAUTH_PK_OK)
...
Event Log: Sending Pageant's response
Outgoing packet type 50 / 0x32 (SSH2_MSG_USERAUTH_REQUEST)
...
Incoming packet type 52 / 0x34 (SSH2_MSG_USERAUTH_SUCCESS)
Event Log: Access granted
Outgoing packet type 90 / 0x5a (SSH2_MSG_CHANNEL_OPEN)
...
...
Jacob Nevins
>Jacob Nevins wrote:
>> It is odd that it's dependent on the version of PuTTY. I'd be
>> interested to see the point of divergence in the PuTTY log between
>> 0.58 and a later version.
>
>I hacked out the packet data. Hope this leaves enough to see it working.
The only obvious differences on a quick look are (a) the failing log
uses the SDCTR cipher mode rather than CBC, (b) the username is
different ("kkkkkkkk" in failure case vs "jkkkkkkk" in working case).
There's no configurability around (a) so I can't suggest a diagnostic
(although I suppose you could try messing around with the cipher
selection in general, as it's not unknown for miscompiled/mismatched
OpenSSH/OpenSSL to have cipher-dependent misbehaviour). I assume you'd
know if (b) was significant.
I was interested in the packet data, to see if there was any obvious
difference in what we sent that might cause the server to slam the
connection shut.
Can you find out if there's anything in the server logs that may be
relevant?
Let's take this to email. Please send the full packet logs from both
cases to the PuTTY development team address.
<http://www.chiark.greenend.org.uk/~sgtatham/putty/feedback.html>
Jacob Nevins
>Let's take this to email.
We're still looking, but for the group's benefit, here's how far we've
got:
- Problem is specific to AES-CTR (introduced in PuTTY 0.59). PuTTY
0.60 is able to connect to the server in question if another cipher
is used (including AES-CBC).
- The server disconnects us at about the point where it should send
us a substantial SSH2_MSG_USERAUTH_BANNER, which is the first
packet of substantial size after the cipher has been brought into
use.
- Another SSH client (OpenSSH, I think) is able to connect to the
server in question using aes256-ctr.
- PuTTY 0.60 is able to interoperate with a variety of servers using
aes256-ctr. (Well, it works for me, and I've not heard any other
complaints.)
- I've just noticed that the HPN OpenSSH page mentions that the
current HPN patches include a multithreaded implementation of
AES-CTR (specifically) to reduce CPU bottlenecks, and that there's
some suggestion that there are known issues with it.
(Which presumably implies that if you use an older version of PuTTY
with these servers, or a different cipher, to work around these
problems, you may hit that bottleneck.)
<http://www.psc.edu/networking/projects/hpn-ssh/>
Also, someone else with the same problem has come forward.