ssh connections disconnects automatically

[Søren Holm]

When I connect to a serve here at work I get kicked of after some random time. It happenens even if something is going on in the session, so it can't be some timeout.

I have seen the same thing happen on different servers using differen clients. One common factor is that they all run ubuntu 10.10

A session disconnection looks like this :

sgh@koontz:~$ ssh -v -v -v -v -v -v -v -v -v zemeckis
OpenSSH_5.5p1 Debian-4ubuntu5, OpenSSL 0.9.8o 01 Jun 2010
debug1: Reading configuration data /home/sgh/.ssh/config
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: Applying options for *
debug2: ssh_connect: needpriv 0
debug1: Connecting to zemeckis [10.115.0.50] port 22.
debug1: Connection established.
debug3: Not a RSA1 key file /home/sgh/.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 /home/sgh/.ssh/id_rsa type 1
debug1: Checking blacklist file /usr/share/ssh/blacklist.RSA-2048
debug1: Checking blacklist file /etc/ssh/blacklist.RSA-2048
debug1: identity file /home/sgh/.ssh/id_rsa-cert type -1
debug1: identity file /home/sgh/.ssh/id_dsa type -1
debug1: identity file /home/sgh/.ssh/id_dsa-cert type -1
debug1: Remote protocol version 2.0, remote software version OpenSSH_5.5p1 Debian-4ubuntu5
debug1: match: OpenSSH_5.5p1 Debian-4ubuntu5 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_5.5p1 Debian-4ubuntu5
debug2: fd 3 setting O_NONBLOCK
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: <email address hidden>,<email address hidden>,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,<email address hidden>
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,<email address hidden>
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,<email address hidden>,hmac-ripemd160,<email address hidden>,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,<email address hidden>,hmac-ripemd160,<email address hidden>,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,<email address hidden>,zlib
debug2: kex_parse_kexinit: none,<email address hidden>,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,<email address hidden>
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,<email address hidden>
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,<email address hidden>,hmac-ripemd160,<email address hidden>,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,<email address hidden>,hmac-ripemd160,<email address hidden>,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,<email address hidden>
debug2: kex_parse_kexinit: none,<email address hidden>
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
debug2: dh_gen_key: priv key bits set: 130/256
debug2: bits set: 498/1024
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug3: check_host_in_hostfile: host zemeckis filename /home/sgh/.ssh/known_hosts
debug3: check_host_in_hostfile: host zemeckis filename /home/sgh/.ssh/known_hosts
debug3: check_host_in_hostfile: match line 55
debug3: check_host_in_hostfile: host 10.115.0.50 filename /home/sgh/.ssh/known_hosts
debug3: check_host_in_hostfile: host 10.115.0.50 filename /home/sgh/.ssh/known_hosts
debug3: check_host_in_hostfile: match line 65
debug1: Host 'zemeckis' is known and matches the RSA host key.
debug1: Found key in /home/sgh/.ssh/known_hosts:55
debug2: bits set: 512/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: /home/sgh/.ssh/id_rsa (0xb8161620)
debug2: key: /home/sgh/.ssh/id_dsa ((nil))
debug1: Authentications that can continue: publickey
debug3: start over, passed a different list publickey
debug3: preferred gssapi-keyex,gssapi-with-mic,publickey,keyboard-interactive,password
debug3: authmethod_lookup publickey
debug3: remaining preferred: keyboard-interactive,password
debug3: authmethod_is_enabled publickey
debug1: Next authentication method: publickey
debug1: Offering public key: /home/sgh/.ssh/id_rsa
debug3: send_pubkey_test
debug2: we sent a publickey packet, wait for reply
debug1: Server accepts key: pkalg ssh-rsa blen 277
debug2: input_userauth_pk_ok: fp f8:0e:76:7e:dc:37:1d:50:96:0f:c4:91:03:5a:64:25
debug3: sign_and_send_pubkey
debug1: read PEM private key done: type RSA
debug1: Authentication succeeded (publickey).
debug1: channel 0: new [client-session]
debug3: ssh_session2_open: channel_new: 0
debug2: channel 0: send open
debug1: Requesting <email address hidden>
debug1: Entering interactive session.
debug2: callback start
debug2: client_session2_setup: id 0
debug2: channel 0: request pty-req confirm 1
debug1: Sending environment.
debug3: Ignored env SSH_AGENT_PID
debug3: Ignored env KDE_MULTIHEAD
debug3: Ignored env DM_CONTROL
debug3: Ignored env SHELL
debug3: Ignored env TERM
debug3: Ignored env XDG_SESSION_COOKIE
debug3: Ignored env XDM_MANAGED
debug3: Ignored env GTK2_RC_FILES
debug3: Ignored env KONSOLE_DBUS_SERVICE
debug3: Ignored env GS_LIB
debug3: Ignored env GTK_RC_FILES
debug3: Ignored env WINDOWID
debug3: Ignored env SHELL_SESSION_ID
debug3: Ignored env KDE_FULL_SESSION
debug3: Ignored env VTK_INCLUDE
debug3: Ignored env USER
debug3: Ignored env LS_COLORS
debug3: Ignored env SSH_AUTH_SOCK
debug3: Ignored env SESSION_MANAGER
debug3: Ignored env DESKTOP_SESSION
debug3: Ignored env PATH
debug3: Ignored env PWD
debug3: Ignored env EDITOR
debug3: Ignored env KDE_SESSION_UID
debug1: Sending env LANG = da_DK.utf8
debug2: channel 0: request env confirm 0
debug3: Ignored env VTK_LIBS
debug3: Ignored env KONSOLE_DBUS_SESSION
debug3: Ignored env HOME
debug3: Ignored env COLORFGBG
debug3: Ignored env SHLVL
debug3: Ignored env KDE_SESSION_VERSION
debug3: Ignored env LANGUAGE
debug3: Ignored env XCURSOR_THEME
debug3: Ignored env LOGNAME
debug3: Ignored env XDG_DATA_DIRS
debug3: Ignored env DBUS_SESSION_BUS_ADDRESS
debug3: Ignored env LESSOPEN
debug3: Ignored env VTK_LIB
debug3: Ignored env WINDOWPATH
debug3: Ignored env PROFILEHOME
debug3: Ignored env DISPLAY
debug3: Ignored env QT_PLUGIN_PATH
debug3: Ignored env LESSCLOSE
debug3: Ignored env _
debug2: channel 0: request shell confirm 1
debug2: fd 3 setting TCP_NODELAY
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: shell request accepted on channel 0
Linux zemeckis 2.6.35-25-server #44-Ubuntu SMP Fri Jan 21 19:09:14 UTC 2011 x86_64 GNU/Linux
Ubuntu 10.10

Welcome to the Ubuntu Server!
 * Documentation: http://www.ubuntu.com/server/doc

  System information as of Thu Feb 10 10:12:59 CET 2011

  System load: 0.0 Processes: 208
  Usage of /home: 74.6% of 246.08GB Users logged in: 0
  Memory usage: 46% IP address for eth0: 10.115.0.50
  Swap usage: 0% IP address for tun0: 10.213.13.46

  Graph this data and manage this system at https://landscape.canonical.com/

0 packages can be updated.
0 updates are security updates.

Last login: Thu Feb 10 09:59:19 2011 from 10.115.0.105
sgh@zemeckis:~$ 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 4/5 cc -1)

debug3: channel 0: close_fds r 4 w 5 e 6
########################################### Here some random time passes. In this case it was less than 20 seconds.
debug1: Killed by signal 15.
sgh@koontz:~$

ProblemType: Bug
DistroRelease: Ubuntu 10.10
Package: openssh-client 1:5.5p1-4ubuntu5
Uname: Linux 2.6.38-rc3-20110205 i686
Architecture: i386
Date: Thu Feb 10 10:11:40 2011
InstallationMedia: Kubuntu 10.10 "Maverick Meerkat" - Release i386 (20101006.1)
ProcEnviron:
 LANGUAGE=da_DK
 PATH=(custom, user)
 LANG=da_DK.utf8
 SHELL=/bin/bash
RelatedPackageVersions:
 ssh-askpass N/A
 libpam-ssh N/A
 keychain N/A
 ssh-askpass-gnome N/A
SSHClientVersion: OpenSSH_5.5p1 Debian-4ubuntu5, OpenSSL 0.9.8o 01 Jun 2010
SourcePackage: openssh

[Søren Holm (sgh)]

I can add that putty on linux does not disconnect.

[Clint Byrum (clint-fewbar)]

Hello Soren, can you please check to see if you have the file

/var/run/sshd.pid

and also run the command

sudo status ssh

If you do have the pid file, this may be a duplicate of bug #531912

Marking Incomplete pending response from Soren.

[Søren Holm (sgh)]

$ ls -al /var/run/sshd.pid
-rw-r--r-- 1 root root 5 2011-02-09 22:13 /var/run/sshd.pid
$ sudo status ssh
ssh start/running, process 1019
$

Why/how could bug #531912 make my connections disconnect ?
Using another ssh client (fx putty) does not disconnect.

[Clint Byrum (clint-fewbar)]

Oops, I also meant to ask you to cat the /var/run/sshd.pid to make sure it is in fact the same as the one in status.

My suspicion is/was that the upstart managed sshd is conflicting with a /etc/init.d/ssh managed sshd. On second thought I'm not so sure.

Can you try running an sshd in debug mode on an alternate port on the server?

/usr/sbin/sshd -dd -p 2222

Then connect to it with

ssh -p 2222 affected_host

and paste the output of those, noting when the disconnection happens?

[Søren Holm (sgh)]

Ok on another server I administer :

sgh@zemeckis:~$ sudo status ssh
ssh stop/waiting
sgh@zemeckis:~$ cat /var/run/sshd.pid
11889
sgh@zemeckis:~$

that is not good I guess? since I did the login over ssh.

[Søren Holm (sgh)]

Another observation :

running this command :

watch -n 1 date

on two difference ssh-conntection to two different servers continously show the running date and time.
The time is of cause offset by some amount of seconds (20 in my case).

Based on that offset I can see that those two connections are dropped at the exact same time.

I have also tried running sshd on an alternative port. I will post the log after this.

[Clint Byrum (clint-fewbar)]

Soren, I just now re-read your original description, and I see this:

debug1: Killed by signal 15.

That suggests that your *client* ssh is being killed.

The sshd debug supports that:

debug3: fd 9 is O_NONBLOCK
debug1: Setting controlling tty using TIOCSCTTY.
Received disconnect from 10.115.0.105: 11: disconnected by user

Is it possible there is something on your local machine killing ssh's for some reason? You said they get killed at the same exact time.. maybe a cron job?

Also re the pid file being present but ssh in stop/waiting.. if that pid is running sshd, then you have hit bug #531912 by accidentally using /etc/init.d/ssh instead of the upstart start/stop commands.

[Søren Holm (sgh)]

Clint - I owe you beer or something. I develop machine-control software, and apparently the exit procedure of our application is to kill all ssh-client - since our application creates some ssh-tunnels. I was not aware of that until your hit about something must be killed my ssh.

Thanks your very much for your ansvers. My server do otoh suffer from bug #531912 - I will suscribe to that.

[Søren Holm (sgh)]

ssh was killed by non ubuntu app.

[Clint Byrum (clint-fewbar)]

On Mon, 2011-02-14 at 21:13 +0000, Søren Holm wrote:
> Clint - I owe you beer or something. I develop machine-control software,
> and apparently the exit procedure of our application is to kill all ssh-
> client - since our application creates some ssh-tunnels. I was not aware
> of that until your hit about something must be killed my ssh.
>
> Thanks your very much for your ansvers. My server do otoh suffer from
> bug #531912 - I will suscribe to that.
>

Søren, I'm glad this worked out for you, and thanks again for taking the
time to work through it!