Take the 2-minute tour ×
Super User is a question and answer site for computer enthusiasts and power users. It's 100% free, no registration required.

I'm using ssh to execute commands on another host and have noticed that occasionally the connection is closed before it ever connects. Both hosts are CentOS release 6.3 running OpenSSH_5.3p1, OpenSSL 1.0.0-fips

I ran the test below

[hadoop@SERVER1 ~]$ cat sshtest.sh 
#!/bin/bash
OK=0
for i in {1..100}; do
A=`ssh SERVER2 uptime`
if [ $? == 0 ]; then
  let "OK += + 1"
fi
done
echo "$OK connections succeeded"

[hadoop@SERVER1 ~]$ sh sshtest.sh
#omitted numerous "Connection closed by 1.2.3.4" here
64 connections succeeded

Here is what -vvv logging says when it's a failure

[hadoop@SERVER1 ~]$ ssh -vvv SERVER2 uptime
OpenSSH_5.3p1, OpenSSL 1.0.0-fips 29 Mar 2010
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: Applying options for *
debug2: ssh_connect: needpriv 0
debug1: Connecting to SERVER2 [1.2.3.4] port 22.
debug1: Connection established.
debug1: identity file /u/0/hadoop/.ssh/identity type -1
debug3: Not a RSA1 key file /u/0/hadoop/.ssh/id_rsa.
debug2: key_type_from_name: unknown key type '-----BEGIN'
debug3: key_read: missing keytype
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug2: key_type_from_name: unknown key type '-----END'
debug3: key_read: missing keytype
debug1: identity file /u/0/hadoop/.ssh/id_rsa type 1
debug1: identity file /u/0/hadoop/.ssh/id_dsa type -1
debug1: Remote protocol version 1.99, remote software version OpenSSH_5.3
debug1: match: OpenSSH_5.3 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_5.3
debug2: fd 3 setting O_NONBLOCK
debug1: SSH2_MSG_KEXINIT sent
debug3: Wrote 792 bytes for a total of 813
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib
debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: first_kex_follows 0 
debug2: kex_parse_kexinit: reserved 0 
debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib@openssh.com
debug2: kex_parse_kexinit: none,zlib@openssh.com
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: first_kex_follows 0 
debug2: kex_parse_kexinit: reserved 0 
debug2: mac_setup: found hmac-md5
debug1: kex: server->client aes128-ctr hmac-md5 none
debug2: mac_setup: found hmac-md5
debug1: kex: client->server aes128-ctr hmac-md5 none
debug1: SSH2_MSG_KEX_DH_GEX_REQUEST(1024<1024<8192) sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
debug3: Wrote 24 bytes for a total of 837
debug2: dh_gen_key: priv key bits set: 125/256
debug2: bits set: 528/1024
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug3: Wrote 144 bytes for a total of 981
debug3: check_host_in_hostfile: filename /u/0/hadoop/.ssh/known_hosts
debug3: check_host_in_hostfile: match line 36
debug3: check_host_in_hostfile: filename /u/0/hadoop/.ssh/known_hosts
debug3: check_host_in_hostfile: match line 33
debug1: Host 'ihedn202.ihe.ibm.com' is known and matches the RSA host key.
debug1: Found key in /u/0/hadoop/.ssh/known_hosts:36
debug2: bits set: 522/1024
debug1: ssh_rsa_verify: signature correct
debug2: kex_derive_keys
debug2: set_newkeys: mode 1
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug3: Wrote 16 bytes for a total of 997
debug2: set_newkeys: mode 0
debug1: SSH2_MSG_NEWKEYS received
debug1: SSH2_MSG_SERVICE_REQUEST sent
debug3: Wrote 48 bytes for a total of 1045
debug2: service_accept: ssh-userauth
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug2: key: /u/0/hadoop/.ssh/identity ((nil))
debug2: key: /u/0/hadoop/.ssh/id_rsa (0x7ffdde77a4c0)
debug2: key: /u/0/hadoop/.ssh/id_dsa ((nil))
debug3: Wrote 64 bytes for a total of 1109
debug1: Authentications that can continue: publickey,gssapi-keyex,gssapi-with-mic,password
debug3: start over, passed a different list publickey,gssapi-keyex,gssapi-with-mic,password
debug3: preferred gssapi-keyex,gssapi-with-mic,publickey,keyboard-interactive,password
debug3: authmethod_lookup gssapi-keyex
debug3: remaining preferred: gssapi-with-mic,publickey,keyboard-interactive,password
debug3: authmethod_is_enabled gssapi-keyex
debug1: Next authentication method: gssapi-keyex
debug1: No valid Key exchange context
debug2: we did not send a packet, disable method
debug3: authmethod_lookup gssapi-with-mic
debug3: remaining preferred: publickey,keyboard-interactive,password
debug3: authmethod_is_enabled gssapi-with-mic
debug1: Next authentication method: gssapi-with-mic
debug3: Trying to reverse map address 1.2.3.4.
debug1: Unspecified GSS failure.  Minor code may provide more information
Credentials cache file '/tmp/krb5cc_200016' not found

debug1: Unspecified GSS failure.  Minor code may provide more information
Credentials cache file '/tmp/krb5cc_200016' not found

debug1: Unspecified GSS failure.  Minor code may provide more information


debug1: Unspecified GSS failure.  Minor code may provide more information


debug2: we did not send a packet, disable method
debug3: authmethod_lookup publickey
debug3: remaining preferred: keyboard-interactive,password
debug3: authmethod_is_enabled publickey
debug1: Next authentication method: publickey
debug1: Trying private key: /u/0/hadoop/.ssh/identity
debug3: no such identity: /u/0/hadoop/.ssh/identity
debug1: Offering public key: /u/0/hadoop/.ssh/id_rsa
debug3: send_pubkey_test
debug2: we sent a publickey packet, wait for reply
debug3: Wrote 368 bytes for a total of 1477
debug1: Server accepts key: pkalg ssh-rsa blen 277
debug2: input_userauth_pk_ok: SHA1 fp 8e:bb:56:07:93:be:ae:65:a1:bf:d5:12:17:11:a9:18:af:54:4f:1c
debug3: sign_and_send_pubkey
debug1: read PEM private key done: type RSA
debug3: Wrote 640 bytes for a total of 2117
Connection closed by 1.2.3.4

If it succeeds the very next line (instead of connection closed)

debug1: Authentication succeeded (publickey).
debug1: channel 0: new [client-session]

Also, I ran the bash script above going the other direction and it was pretty much the same result with only 58 connections succeeding.

When using strace on a failing ssh connection here is the end of the output

munmap(0x7fe1f807b000, 4096)            = 0
open("/dev/urandom", O_RDONLY)          = 4
fcntl(4, F_SETFD, FD_CLOEXEC)           = 0
fstat(4, {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 9), ...}) = 0
read(4, "\353\305\302\177\23\324\373;n\263\377}\304\221\357B4\212\245\321", 20) = 20
close(4)                                = 0
stat("/etc/krb5.conf", {st_mode=S_IFREG|0644, st_size=449, ...}) = 0
open("/etc/krb5.conf", O_RDONLY)        = 4
fcntl(4, F_SETFD, FD_CLOEXEC)           = 0
fstat(4, {st_mode=S_IFREG|0644, st_size=449, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fe1f807b000
read(4, "[logging]\n default = FILE:/var/l"..., 4096) = 449
read(4, "", 4096)                       = 0
close(4)                                = 0
munmap(0x7fe1f807b000, 4096)            = 0
open("/dev/urandom", O_RDONLY)          = 4
fcntl(4, F_SETFD, FD_CLOEXEC)           = 0
fstat(4, {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 9), ...}) = 0
read(4, "\334^b\325e]\312g\222\211 \0232a\343\251\2732\222\31", 20) = 20
close(4)                                = 0
stat("/u/0/hadoop/.ssh/identity", 0x7fffc9564540) = -1 ENOENT (No such file or directory)
write(3, "\t\37CS\365\355\220?\327X\321\4 \0237\273k\321\31U#\255\335<+\333\260\267\275:\311\332"..., 368) = 368
select(4, [3], NULL, NULL, NULL)        = 1 (in [3])
read(3, "\3\323\260\241CX8\2\230\27\243\244\24\204VX)fX\366R?\24\356-K\366\233\256\337\355\\"..., 8192) = 320
stat("/u/0/hadoop/.ssh/id_rsa", {st_mode=S_IFREG|0600, st_size=1675, ...}) = 0
open("/u/0/hadoop/.ssh/id_rsa", O_RDONLY) = 4
fstat(4, {st_mode=S_IFREG|0600, st_size=1675, ...}) = 0
getuid()                                = 200016
fcntl(4, F_GETFL)                       = 0x8000 (flags O_RDONLY|O_LARGEFILE)
fstat(4, {st_mode=S_IFREG|0600, st_size=1675, ...}) = 0
mmap(NULL, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fe1f806c000
lseek(4, 0, SEEK_CUR)                   = 0
read(4, "-----BEGIN RSA PRIVATE KEY-----\n"..., 65536) = 1675
close(4)                                = 0
munmap(0x7fe1f806c000, 65536)           = 0
write(3, "l[{\\\222\32>\300\300s\310\256\3711\372kM\361\315G\2\5\375\\\333\255\347\342yG\253O"..., 640) = 640
select(4, [3], NULL, NULL, NULL)        = 1 (in [3])
read(3, "", 8192)                       = 0
getpeername(3, {sa_family=AF_INET, sin_port=htons(22), sin_addr=inet_addr("1.2.3.43")}, [16]) = 0
write(2, "Connection closed by 1.2.3.43\r"..., 33) = 33
exit_group(255)                        = ?
share|improve this question
2  
Is the key on a network share or some other non-local fs? –  ckhan Aug 30 '12 at 6:32
    
Yes, it looks like it is. –  Dan R Aug 30 '12 at 15:42
1  
Two things to try: 1) move the key to a local fs (use -F to use different config file, and confirm that it doesn't happen) and 2) use strace -o strace.out on each of the ssh invocations so we can see if you're getting a failure from fs when reading key file. –  ckhan Aug 31 '12 at 2:58
    
I've added some strace output. –  Dan R Sep 4 '12 at 20:04
add comment

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Browse other questions tagged or ask your own question.