SSH connections to EC2 hang sporadically

Tore Olsen

unread,

Nov 11, 2014, 7:53:57 AM11/11/14

to ansible...@googlegroups.com

Hello,

I'm having problems with SSH connections hanging seemingly indefinitely. I don't recognize any patterns as to what tasks or handlers this happens on. I'm running ansible 1.7.1 on OS X Yosemite against a bunch of ec2 instances. I also deploy to vagrant but don't think it has had similar SSH hangs.

Today I determined to kill -HUP the ssh process that was hung, and then ansible resumed happily.

I'd be grateful if anyone has troubleshooting tips for this.

-Tore

Tore Olsen

unread,

Nov 14, 2014, 6:52:01 AM11/14/14

to ansible...@googlegroups.com

Just thought I'd follow up with a typical output with -vvvv; This is a play where I'm installing a couple of apt packages to three AWS hosts (shortened host1-3 for brevity). You see one of the hosts succeed while the other two apparently do not. The one that succeeds is in EU (Ireland) while the unfinished hosts are both in different AZs in East US.

I logged in to the hosts which did not resume play and verified that the temporary directory actually had been deleted.

TASK: [common | Install common packages] **************************************

<host1> ESTABLISH CONNECTION FOR USER: ubuntu

<host2> ESTABLISH CONNECTION FOR USER: ubuntu

<host3> ESTABLISH CONNECTION FOR USER: ubuntu

<host2> REMOTE_MODULE apt pkg=git,supervisor update_cache=yes state=present

<host1> REMOTE_MODULE apt pkg=git,supervisor update_cache=yes state=present

<host3> REMOTE_MODULE apt pkg=git,supervisor update_cache=yes state=present

<host2> EXEC ['ssh', '-C', '-tt', '-vvv', '-o', 'ForwardAgent=yes', '-o', 'IdentityFile="/Users/toreo/.ssh/cargame-ssh.pem"', '-o', 'KbdInteractiveAuthentication=no', '-o', 'PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey', '-o', 'PasswordAuthentication=no', '-o', 'User=ubuntu', '-o', 'ConnectTimeout=10', u'host2', "/bin/sh -c 'mkdir -p $HOME/.ansible/tmp/ansible-tmp-1415964802.72-81109603826031 && chmod a+rx $HOME/.ansible/tmp/ansible-tmp-1415964802.72-81109603826031 && echo $HOME/.ansible/tmp/ansible-tmp-1415964802.72-81109603826031'"]

<host1> EXEC ['ssh', '-C', '-tt', '-vvv', '-o', 'ForwardAgent=yes', '-o', 'IdentityFile="/Users/toreo/.ssh/cargame-ssh.pem"', '-o', 'KbdInteractiveAuthentication=no', '-o', 'PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey', '-o', 'PasswordAuthentication=no', '-o', 'User=ubuntu', '-o', 'ConnectTimeout=10', u'host1', "/bin/sh -c 'mkdir -p $HOME/.ansible/tmp/ansible-tmp-1415964802.72-242263817184790 && chmod a+rx $HOME/.ansible/tmp/ansible-tmp-1415964802.72-242263817184790 && echo $HOME/.ansible/tmp/ansible-tmp-1415964802.72-242263817184790'"]

<host3> EXEC ['ssh', '-C', '-tt', '-vvv', '-o', 'ForwardAgent=yes', '-o', 'IdentityFile="/Users/toreo/.ssh/cargame-ssh.pem"', '-o', 'KbdInteractiveAuthentication=no', '-o', 'PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey', '-o', 'PasswordAuthentication=no', '-o', 'User=ubuntu', '-o', 'ConnectTimeout=10', u'host3', "/bin/sh -c 'mkdir -p $HOME/.ansible/tmp/ansible-tmp-1415964802.72-65992156942899 && chmod a+rx $HOME/.ansible/tmp/ansible-tmp-1415964802.72-65992156942899 && echo $HOME/.ansible/tmp/ansible-tmp-1415964802.72-65992156942899'"]

<host3> PUT /var/folders/f6/hp9f9y0933q95_9mlbhk27dm0000gn/T/tmpQGGHOr TO /home/ubuntu/.ansible/tmp/ansible-tmp-1415964802.72-65992156942899/apt

<host1> PUT /var/folders/f6/hp9f9y0933q95_9mlbhk27dm0000gn/T/tmp38enSO TO /home/ubuntu/.ansible/tmp/ansible-tmp-1415964802.72-242263817184790/apt

<host2> PUT /var/folders/f6/hp9f9y0933q95_9mlbhk27dm0000gn/T/tmpYViEBl TO /home/ubuntu/.ansible/tmp/ansible-tmp-1415964802.72-81109603826031/apt

<host3> EXEC ['ssh', '-C', '-tt', '-vvv', '-o', 'ForwardAgent=yes', '-o', 'IdentityFile="/Users/toreo/.ssh/cargame-ssh.pem"', '-o', 'KbdInteractiveAuthentication=no', '-o', 'PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey', '-o', 'PasswordAuthentication=no', '-o', 'User=ubuntu', '-o', 'ConnectTimeout=10', u'host3', u'/bin/sh -c \'sudo -k && sudo -H -S -p "[sudo via ansible, key=uuhortuzkrrxndipfnakoyezwvmlbrrg] password: " -u root /bin/sh -c \'"\'"\'echo SUDO-SUCCESS-uuhortuzkrrxndipfnakoyezwvmlbrrg; LANG=en_US.UTF-8 LC_CTYPE=en_US.UTF-8 /usr/bin/python /home/ubuntu/.ansible/tmp/ansible-tmp-1415964802.72-65992156942899/apt; rm -rf /home/ubuntu/.ansible/tmp/ansible-tmp-1415964802.72-65992156942899/ >/dev/null 2>&1\'"\'"\'\'']

<host1> EXEC ['ssh', '-C', '-tt', '-vvv', '-o', 'ForwardAgent=yes', '-o', 'IdentityFile="/Users/toreo/.ssh/cargame-ssh.pem"', '-o', 'KbdInteractiveAuthentication=no', '-o', 'PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey', '-o', 'PasswordAuthentication=no', '-o', 'User=ubuntu', '-o', 'ConnectTimeout=10', u'host1', u'/bin/sh -c \'sudo -k && sudo -H -S -p "[sudo via ansible, key=kmkiimakutvlojnbqartowszmpdbndzk] password: " -u root /bin/sh -c \'"\'"\'echo SUDO-SUCCESS-kmkiimakutvlojnbqartowszmpdbndzk; LANG=en_US.UTF-8 LC_CTYPE=en_US.UTF-8 /usr/bin/python /home/ubuntu/.ansible/tmp/ansible-tmp-1415964802.72-242263817184790/apt; rm -rf /home/ubuntu/.ansible/tmp/ansible-tmp-1415964802.72-242263817184790/ >/dev/null 2>&1\'"\'"\'\'']

<host2> EXEC ['ssh', '-C', '-tt', '-vvv', '-o', 'ForwardAgent=yes', '-o', 'IdentityFile="/Users/toreo/.ssh/cargame-ssh.pem"', '-o', 'KbdInteractiveAuthentication=no', '-o', 'PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey', '-o', 'PasswordAuthentication=no', '-o', 'User=ubuntu', '-o', 'ConnectTimeout=10', u'host2', u'/bin/sh -c \'sudo -k && sudo -H -S -p "[sudo via ansible, key=iyzsrbntouwziaxcxllqidtsopvifmac] password: " -u root /bin/sh -c \'"\'"\'echo SUDO-SUCCESS-iyzsrbntouwziaxcxllqidtsopvifmac; LANG=en_US.UTF-8 LC_CTYPE=en_US.UTF-8 /usr/bin/python /home/ubuntu/.ansible/tmp/ansible-tmp-1415964802.72-81109603826031/apt; rm -rf /home/ubuntu/.ansible/tmp/ansible-tmp-1415964802.72-81109603826031/ >/dev/null 2>&1\'"\'"\'\'']

ok: [host3] => (item=git,supervisor) => {"changed": false, "item": "git,supervisor"}

Tore Olsen

unread,

Nov 14, 2014, 7:01:24 AM11/14/14

to ansible...@googlegroups.com

If it helps, I just kill -HUP'ed one of the ssh processes and got a lot of debug output:

failed: [host1] => (item=git,supervisor) => {"failed": true, "item": "git,supervisor", "parsed": false}

invalid output was: SUDO-SUCCESS-kmkiimakutvlojnbqartowszmpdbndzk

OpenSSH_6.2p2, OSSLShim 0.9.8r 8 Dec 2011

debug1: Reading configuration data /Users/toreo/.ssh/config

debug1: Reading configuration data /etc/ssh_config

debug1: /etc/ssh_config line 20: Applying options for *

debug1: /etc/ssh_config line 53: Applying options for *

debug2: ssh_connect: needpriv 0

debug1: Connecting to host1 [<ip-addr>] port 22.

debug2: fd 3 setting O_NONBLOCK

debug1: fd 3 clearing O_NONBLOCK

debug1: Connection established.

debug3: timeout: 9894 ms remain after connect

debug3: Incorrect RSA1 identifier

debug3: Could not load "/Users/toreo/.ssh/cargame-ssh.pem" as a RSA1 public key

debug1: identity file /Users/toreo/.ssh/cargame-ssh.pem type -1

debug1: identity file /Users/toreo/.ssh/cargame-ssh.pem-cert type -1

debug1: Enabling compatibility mode for protocol 2.0

debug1: Local version string SSH-2.0-OpenSSH_6.2

debug1: Remote protocol version 2.0, remote software version OpenSSH_6.6.1p1 Ubuntu-2ubuntu2

debug1: match: OpenSSH_6.6.1p1 Ubuntu-2ubuntu2 pat OpenSSH*

debug2: fd 3 setting O_NONBLOCK

debug3: load_hostkeys: loading entries for host "host1" from file "/Users/toreo/.ssh/known_hosts"

debug3: load_hostkeys: found key type RSA in file /Users/toreo/.ssh/known_hosts:42

debug3: load_hostkeys: loaded 1 keys

debug3: order_hostkeyalgs: prefer hostkeyalgs: ssh-rsa-...@openssh.com,ssh-rsa-...@openssh.com,ssh-rsa

debug1: SSH2_MSG_KEXINIT sent

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-...@openssh.com,ssh-rsa-...@openssh.com,ssh-rsa,ssh-dss-...@openssh.com,ssh-dss-...@openssh.com,ssh-dss

debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes12...@openssh.com,aes25...@openssh.com,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijnda...@lysator.liu.se

debug2: kex_parse_kexinit: hmac-m...@openssh.com,hmac-s...@openssh.com,umac-...@openssh.com,umac-1...@openssh.com,hmac-sha...@openssh.com,hmac-sha...@openssh.com,hmac-ripe...@openssh.com,hmac-sha...@openssh.com,hmac-md...@openssh.com,hmac-md5,hmac-sha1,uma...@openssh.com,umac...@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-ripemd160,hmac-ri...@openssh.com,hmac-sha1-96,hmac-md5-96

debug2: kex_parse_kexinit: zl...@openssh.com,zlib,none

debug2: kex_parse_kexinit:

debug2: kex_parse_kexinit: first_kex_follows 0

debug2: kex_parse_kexinit: reserved 0

debug2: kex_parse_kexinit: curve255...@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,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,ecdsa-sha2-nistp256

debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes12...@openssh.com,aes25...@openssh.com,chacha20...@openssh.com,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijnda...@lysator.liu.se

debug2: kex_parse_kexinit: hmac-m...@openssh.com,hmac-s...@openssh.com,umac-...@openssh.com,umac-1...@openssh.com,hmac-sha...@openssh.com,hmac-sha...@openssh.com,hmac-ripe...@openssh.com,hmac-sha...@openssh.com,hmac-md...@openssh.com,hmac-md5,hmac-sha1,uma...@openssh.com,umac...@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-ripemd160,hmac-ri...@openssh.com,hmac-sha1-96,hmac-md5-96

debug2: kex_parse_kexinit: none,zl...@openssh.com

debug2: kex_parse_kexinit:

debug2: kex_parse_kexinit: first_kex_follows 0

debug2: kex_parse_kexinit: reserved 0

debug2: mac_setup: found hmac-m...@openssh.com

debug1: kex: server->client aes128-ctr hmac-m...@openssh.com zl...@openssh.com

debug2: mac_setup: found hmac-m...@openssh.com

debug1: kex: client->server aes128-ctr hmac-m...@openssh.com zl...@openssh.com

debug1: SSH2_MSG_KEX_DH_GEX_REQUEST(1024<1024<8192) sent

debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP

debug2: dh_gen_key: priv key bits set: 126/256

debug2: bits set: 494/1024

debug1: SSH2_MSG_KEX_DH_GEX_INIT sent

debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY

debug1: Server host key: RSA 90:5b:60:eb:fd:c3:96:b1:83:b7:9f:5e:b4:bd:c0:b3

debug3: load_hostkeys: loading entries for host "host1" from file "/Users/toreo/.ssh/known_hosts"

debug3: load_hostkeys: found key type RSA in file /Users/toreo/.ssh/known_hosts:42

debug3: load_hostkeys: loaded 1 keys

debug3: load_hostkeys: loading entries for host "<ip-addr>" from file "/Users/toreo/.ssh/known_hosts"

debug3: load_hostkeys: found key type RSA in file /Users/toreo/.ssh/known_hosts:42

debug3: load_hostkeys: loaded 1 keys

debug1: Host 'host1' is known and matches the RSA host key.

debug1: Found key in /Users/toreo/.ssh/known_hosts:42

debug2: bits set: 519/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

debug2: set_newkeys: mode 0

debug1: SSH2_MSG_NEWKEYS received

debug1: Roaming not allowed by server

debug1: SSH2_MSG_SERVICE_REQUEST sent

debug2: service_accept: ssh-userauth

debug1: SSH2_MSG_SERVICE_ACCEPT received

debug2: key: /Users/toreo/.ssh/id_rsa (0x7f816ab01280),

debug2: key: /Users/toreo/.ssh/cargame-ssh.pem (0x0), explicit

debug1: Authentications that can continue: publickey

debug3: start over, passed a different list publickey

debug3: preferred gssapi-with-mic,gssapi-keyex,hostbased,publickey

debug3: authmethod_lookup publickey

debug3: remaining preferred: ,gssapi-keyex,hostbased,publickey

debug3: authmethod_is_enabled publickey

debug1: Next authentication method: publickey

debug1: Offering RSA public key: /Users/toreo/.ssh/id_rsa

debug3: send_pubkey_test

debug2: we sent a publickey packet, wait for reply

debug1: Authentications that can continue: publickey

debug1: Trying private key: /Users/toreo/.ssh/cargame-ssh.pem

debug1: read PEM private key done: type RSA

debug3: sign_and_send_pubkey: RSA fd:98:17:09:b8:20:08:c2:66:d9:54:07:e6:04:b9:23

debug2: we sent a publickey packet, wait for reply

debug1: Enabling compression at level 6.

debug1: Authentication succeeded (publickey).

Authenticated to host1 ([<ip-addr>]:22).

debug2: fd 6 setting O_NONBLOCK

debug2: fd 7 setting O_NONBLOCK

debug1: channel 0: new [client-session]

debug3: ssh_session2_open: channel_new: 0

debug2: channel 0: send open

debug1: Requesting no-more-...@openssh.com

debug1: Entering interactive session.

debug2: callback start

debug1: Requesting authentication agent forwarding.

debug2: channel 0: request auth-ag...@openssh.com confirm 0

debug2: fd 3 setting TCP_NODELAY

debug3: packet_set_tos: set IP_TOS 0x10

debug2: client_session2_setup: id 0

debug2: channel 0: request pty-req confirm 1

debug1: Sending environment.

debug3: Ignored env VIRTUALENVWRAPPER_PROJECT_FILENAME

debug3: Ignored env TERM_PROGRAM

debug3: Ignored env TERM

debug3: Ignored env SHELL

debug3: Ignored env TMPDIR

debug3: Ignored env Apple_PubSub_Socket_Render

debug3: Ignored env TERM_PROGRAM_VERSION

debug3: Ignored env TERM_SESSION_ID

debug3: Ignored env USER

debug3: Ignored env SSH_AUTH_SOCK

debug3: Ignored env __CF_USER_TEXT_ENCODING

debug3: Ignored env WORKON_HOME

debug3: Ignored env PATH

debug3: Ignored env VIRTUALENVWRAPPER_HOOK_DIR

debug3: Ignored env PWD

debug3: Ignored env XPC_FLAGS

debug3: Ignored env PS1

debug3: Ignored env XPC_SERVICE_NAME

debug3: Ignored env HOME

debug3: Ignored env SHLVL

debug3: Ignored env LOGNAME

debug1: Sending env LC_CTYPE = UTF-8

debug2: channel 0: request env confirm 0

debug3: Ignored env GOPATH

debug3: Ignored env DISPLAY

debug3: Ignored env VIRTUALENVWRAPPER_LOG_DIR

debug3: Ignored env SECURITYSESSIONID

debug3: Ignored env OLDPWD

debug3: Ignored env _

debug3: Ignored env VERSIONER_PYTHON_VERSION

debug3: Ignored env VERSIONER_PYTHON_PREFER_32_BIT

debug1: Sending command: /bin/sh -c 'sudo -k && sudo -H -S -p "[sudo via ansible, key=kmkiimakutvlojnbqartowszmpdbndzk] password: " -u root /bin/sh -c '"'"'echo SUDO-SUCCESS-kmkiimakutvlojnbqartowszmpdbndzk; LANG=en_US.UTF-8 LC_CTYPE=en_US.UTF-8 /usr/bin/python /home/ubuntu/.ansible/tmp/ansible-tmp-1415964802.72-242263817184790/apt; rm -rf /home/ubuntu/.ansible/tmp/ansible-tmp-1415964802.72-242263817184790/ >/dev/null 2>&1'"'"''

debug2: channel 0: request exec confirm 1

debug2: callback done

debug2: channel 0: open confirm rwindow 0 rmax 32768

debug2: channel_input_status_confirm: type 99 id 0

debug2: PTY allocation request accepted on channel 0

debug2: channel 0: rcvd adjust 2097152

debug2: channel_input_status_confirm: type 99 id 0

debug2: exec request accepted on channel 0

debug1: channel 0: free: client-session, nchannels 1

debug3: channel 0: status: The following connections are open:

#0 client-session (t4 r0 i0/0 o0/0 fd 5/6 cc -1)

debug1: fd 1 clearing O_NONBLOCK

debug1: fd 2 clearing O_NONBLOCK

Killed by signal 1.

Wawrzek Niewodniczanski

unread,

Nov 17, 2014, 4:19:50 AM11/17/14

to ansible...@googlegroups.com

I'm checking output of your commands on the phone in the bus so I could miss something, but it looks like ssh is actually fine. Have you try to debug on remote host?

Have you compare ansible with normal ssh?

Cherers,
Wawrzek

--
You received this message because you are subscribed to the Google Groups "Ansible Project" group.
To unsubscribe from this group and stop receiving emails from it, send an email to ansible-proje...@googlegroups.com.
To post to this group, send email to ansible...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/ansible-project/b7e5e88e-f257-4d67-8f4a-aa3c11cc17de%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Tore Olsen

unread,

Nov 17, 2014, 5:16:05 AM11/17/14

to ansible...@googlegroups.com

Hi Wawrzek,

Thanks for your response. I believe my problem may have been caused by SSH connections being silently broken by NAT. I just added "ServerAliveInterval 50" to my ~/.ssh/config file and will see how it works out. Regular SSH connections would sometimes fail with a broken pipe, but of couse that happened because I would type something. Ansible is just waiting for data from the peer, so it won't detect this situation.