ssh/sshd go off in limbo-land after closing remote session (v2.9.9p2)

[Ed Phillips]

When I run a remote xterm, the ssh hangs even after I quit the xterm.

Below is the output for the following sequence:

client> ssh -v -v -v dazel xterm
xterm> exit
client> ^C

The outcome is always the same - the ssh doesn't exit with I quit the
xterm... I have to hit CTRL-C on the client side.

polycut:~> ssh -v -v -v dazel xterm
OpenSSH_2.9p2, SSH protocols 1.5/2.0, OpenSSL 0x0090601f
debug1: Reading configuration data /opt/openssh2.9p2/etc/ssh_config
debug3: Reading output from 'ls -alni /var/log'
debug3: Time elapsed: 36 msec
debug3: Got 2.00 bytes of entropy from 'ls -alni /var/log'
debug3: Reading output from 'ls -alni /var/adm'
debug3: Time elapsed: 28 msec
debug3: Got 2.00 bytes of entropy from 'ls -alni /var/adm'
debug3: Reading output from 'ls -alni /var/mail'
debug3: Time elapsed: 18 msec
debug3: Got 0.71 bytes of entropy from 'ls -alni /var/mail'
debug3: Reading output from 'ls -alni /proc'
debug3: Time elapsed: 68 msec
debug3: Got 2.00 bytes of entropy from 'ls -alni /proc'
debug3: Reading output from 'ls -alni /tmp'
debug3: Time elapsed: 23 msec
debug3: Got 2.00 bytes of entropy from 'ls -alni /tmp'
debug3: Reading output from 'ls -alni /var/tmp'
debug3: Time elapsed: 119 msec
debug3: Got 2.00 bytes of entropy from 'ls -alni /var/tmp'
debug3: Reading output from 'ls -alni /usr/tmp'
debug3: Time elapsed: 21 msec
debug3: Got 0.18 bytes of entropy from 'ls -alni /usr/tmp'
debug3: Reading output from 'netstat -an'
debug3: Time elapsed: 42 msec
debug3: Got 2.00 bytes of entropy from 'netstat -an'
debug3: Reading output from 'netstat -in'
debug3: Time elapsed: 36 msec
debug3: Got 2.00 bytes of entropy from 'netstat -in'
debug3: Reading output from 'netstat -rn'
debug3: Time elapsed: 35 msec
debug3: Got 1.84 bytes of entropy from 'netstat -rn'
debug3: Reading output from 'netstat -pn'
debug3: Time elapsed: 58 msec
debug3: Got 2.00 bytes of entropy from 'netstat -pn'
debug3: Reading output from 'netstat -s'
debug3: Time elapsed: 42 msec
debug3: Got 2.00 bytes of entropy from 'netstat -s'
debug3: Reading output from 'arp -a -n'
debug3: Time elapsed: 192 msec
debug3: Got 2.00 bytes of entropy from 'arp -a -n'
debug3: Reading output from 'ifconfig -a'
debug3: Time elapsed: 41 msec
debug3: Got 0.86 bytes of entropy from 'ifconfig -a'
debug3: Reading output from 'ps -al'
debug3: Time elapsed: 50 msec
debug3: Got 2.00 bytes of entropy from 'ps -al'
debug3: Reading output from 'ps -efl'
debug3: Time elapsed: 113 msec
debug3: Got 2.00 bytes of entropy from 'ps -efl'
debug3: Reading output from 'w'
debug3: Time elapsed: 79 msec
debug3: Got 2.00 bytes of entropy from 'w'
debug3: Reading output from 'last'
debug3: Time elapsed: 194 msec
debug2: Command 'last' timed out
debug3: Got 2.00 bytes of entropy from 'last'
debug3: Reading output from 'df'
debug3: Time elapsed: 23 msec
debug3: Got 0.71 bytes of entropy from 'df'
debug3: Reading output from 'vmstat'
debug3: Time elapsed: 30 msec
debug3: Got 0.23 bytes of entropy from 'vmstat'
debug3: Reading output from 'uptime'
debug3: Time elapsed: 31 msec
debug3: Got 0.07 bytes of entropy from 'uptime'
debug3: Reading output from 'ipcs -a'
debug3: Time elapsed: 264 msec
debug2: Command 'ipcs -a' timed out
debug3: Got 0.00 bytes of entropy from 'ipcs -a'
debug3: Reading output from 'tail -200 /var/log/syslog'
debug3: Time elapsed: 15 msec
debug3: Got 0.00 bytes of entropy from 'tail -200 /var/log/syslog'
debug3: Reading output from 'tail -200 /var/adm/messages'
debug3: Time elapsed: 15 msec
debug3: Got 1.05 bytes of entropy from 'tail -200 /var/adm/messages'
debug1: Seeded RNG with 40 bytes from programs
debug1: Seeded RNG with 3 bytes from system calls
debug1: Rhosts Authentication disabled, originating port will not be
trusted.
debug1: restore_uid
debug1: ssh_connect: getuid 16476 geteuid 0 anon 1
debug1: Connecting to dazel [128.175.13.68] port 22.
debug1: temporarily_use_uid: 16476/10 (e=0)
debug1: restore_uid
debug1: temporarily_use_uid: 16476/10 (e=0)
debug1: restore_uid
debug1: Connection established.
debug1: read PEM private key done: type DSA
debug1: read PEM private key done: type RSA
debug1: identity file /home/polycut.nss/usra/ed/.ssh/identity type 0
debug3: No RSA1 key file /home/polycut.nss/usra/ed/.ssh/id_rsa.
debug2: key_type_from_name: unknown key type '-----BEGIN'
debug3: key_read: no key found
debug2: key_type_from_name: unknown key type 'Proc-Type:'
debug3: key_read: no key found
debug2: key_type_from_name: unknown key type 'DEK-Info:'
debug3: key_read: no key found
debug3: key_read: no space
debug3: key_read: no space
debug3: key_read: no space
debug3: key_read: no space
debug3: key_read: no space
debug3: key_read: no space
debug3: key_read: no space
debug3: key_read: no space
debug3: key_read: no space
debug3: key_read: no space
debug3: key_read: no space
debug3: key_read: no space
debug3: key_read: no space
debug2: key_type_from_name: unknown key type '-----END'
debug3: key_read: no key found
debug1: identity file /home/polycut.nss/usra/ed/.ssh/id_rsa type 1
debug1: identity file /home/polycut.nss/usra/ed/.ssh/id_dsa type -1
debug1: Remote protocol version 1.99, remote software version
OpenSSH_2.9.9p2
debug1: match: OpenSSH_2.9.9p2 pat ^OpenSSH
Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_2.9p2
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit:
diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit:
aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
debug2: kex_parse_kexinit:
aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none
debug2: kex_parse_kexinit: none
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-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit:
aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
debug2: kex_parse_kexinit:
aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib
debug2: kex_parse_kexinit: none,zlib
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug2: mac_init: found hmac-md5
debug1: kex: server->client aes128-cbc hmac-md5 none
debug2: mac_init: found hmac-md5
debug1: kex: client->server aes128-cbc hmac-md5 none
debug1: SSH2_MSG_KEX_DH_GEX_REQUEST sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
debug1: dh_gen_key: priv key bits set: 123/256
debug1: bits set: 1611/3191
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug3: check_host_in_hostfile: filename
/home/polycut.nss/usra/ed/.ssh/known_hosts2
debug3: check_host_in_hostfile: match line 8
debug3: check_host_in_hostfile: filename
/home/polycut.nss/usra/ed/.ssh/known_hosts2
debug3: check_host_in_hostfile: match line 8
debug1: Host 'dazel' is known and matches the RSA host key.
debug1: Found key in /home/polycut.nss/usra/ed/.ssh/known_hosts2:8
debug1: bits set: 1593/3191
debug1: ssh_rsa_verify: signature correct
debug1: kex_derive_keys
debug1: newkeys: mode 1
debug1: SSH2_MSG_NEWKEYS sent
debug1: waiting for SSH2_MSG_NEWKEYS
debug1: newkeys: mode 0
debug1: SSH2_MSG_NEWKEYS received
debug1: done: ssh_kex2.
debug1: send SSH2_MSG_SERVICE_REQUEST
debug1: service_accept: ssh-userauth
debug1: got SSH2_MSG_SERVICE_ACCEPT
debug1: authentications that can continue:
publickey,password,keyboard-interactive
debug3: start over, passed a different list
publickey,password,keyboard-interactive
debug3: preferred publickey,password,keyboard-interactive
debug3: authmethod_lookup publickey
debug3: remaining preferred: password,keyboard-interactive
debug3: authmethod_is_enabled publickey
debug1: next auth method to try is publickey
debug1: userauth_pubkey_agent: testing agent key
/home/polycut.nss/usra/ed/.ssh/id_rsa
debug3: send_pubkey_test
debug2: we sent a publickey packet, wait for reply
debug1: input_userauth_pk_ok: pkalg ssh-rsa blen 149 lastkey 147a50 hint
-1
debug2: input_userauth_pk_ok: fp
f7:19:b1:e8:56:1c:81:55:44:9b:b4:f7:e1:b0:c8:ca
debug3: sign_and_send_pubkey
debug3: clear_auth_state: key_free 147a50
debug1: ssh-userauth2 successful: method publickey
debug3: clear hostkey 0
debug3: clear hostkey 1
debug3: clear hostkey 2
debug1: channel 0: new [client-session]
debug1: channel_new: 0
debug1: send channel open 0
debug1: Entering interactive session.
debug2: callback start
debug1: client_init id 0 arg 0
debug1: Requesting X11 forwarding with authentication spoofing.
debug1: Sending command: xterm
debug2: callback done
debug1: channel 0: open confirm rwindow 0 rmax 16384
debug2: channel 0: rcvd adjust 32768
debug1: client_input_channel_open: ctype x11 rchan 3 win 4096 max 2048
debug1: client_request_x11: request from 128.175.13.68 36968
debug1: fd 10 setting O_NONBLOCK
debug1: fd 10 IS O_NONBLOCK
debug1: channel 1: new [x11]
debug1: confirm x11
debug2: channel 1: rcvd adjust 2088
debug2: channel 1: rcvd adjust 2336
debug2: channel 1: rcvd adjust 3580
debug2: channel 1: rcvd adjust 3744
debug1: channel 1: rcvd eof
debug1: channel 1: output open -> drain
debug1: channel 1: obuf empty
debug1: channel 1: output drain -> closed
debug1: channel 1: close_write
debug1: channel 1: read<=0 rfd 10 len 0
debug1: channel 1: read failed
debug1: channel 1: input open -> drain
debug1: channel 1: close_read
debug1: channel 1: input: no drain shortcut
debug1: channel 1: ibuf empty
debug1: channel 1: input drain -> closed
debug1: channel 1: send eof
debug1: channel 1: send close
debug2: channel 1: no data after CLOSE
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
debug1: channel 0: rcvd eof
debug1: channel 0: output open -> drain
debug1: channel 0: rcvd close
debug1: channel 0: input open -> closed
debug1: channel 0: close_read
debug2: channel 0: no data after CLOSE
debug2: channel 1: no data after CLOSE
debug1: channel 0: obuf empty
debug1: channel 0: output drain -> closed
debug1: channel 0: close_write
debug1: channel 0: send close
debug1: channel 0: is dead
debug1: channel_free: channel 0: status: The following connections are
open:
  #0 client-session (t4 r0 i8/0 o128/0 fd -1/-1)
  #1 x11 (t4 r3 i8/0 o128/0 fd 10/10)

debug1: channel_free: channel 0: dettaching channel user
debug1: channel 1: rcvd close
debug2: channel 1: no data after CLOSE
debug1: channel 1: is dead
debug1: channel_free: channel 1: status: The following connections are
open:
  #1 x11 (t4 r3 i8/0 o128/0 fd 10/10)

^CKilled by signal 2.
debug1: Calling cleanup 0x43e48(0x0)
debug1: Calling cleanup 0x54520(0x0)
debug1: Calling cleanup 0x5de88(0x0)
debug1: writing PRNG seed to file /home/polycut.nss/usra/ed/.ssh/prng_seed

---

I also notice that while the ssh is hanging on the client side, there is
still an sshd running on the server side (which I'd guess is the
encoder/decoder process - which has not detected that it's child has gone
bye-bye or for some reason things there are still file descriptors to be
handled)...

server> ptree 20441
20441 /opt/ssh/sbin/sshd -f /opt/ssh/etc/sshd_config
  20497 /opt/ssh/sbin/sshd -f /opt/ssh/etc/sshd_config
server> pfiles 20497
20497:  /opt/ssh/sbin/sshd -f /opt/ssh/etc/sshd_config
  Current rlimit: 1024 file descriptors
   0: S_IFCHR mode:0666 dev:136,0 ino:37794 uid:0 gid:3 rdev:13,2
      O_RDWR
   1: S_IFCHR mode:0666 dev:136,0 ino:37794 uid:0 gid:3 rdev:13,2
      O_RDWR
   2: S_IFCHR mode:0666 dev:136,0 ino:37794 uid:0 gid:3 rdev:13,2
      O_RDWR
   3: S_IFREG mode:0644 dev:136,5 ino:500893 uid:0 gid:1 size:1999
      O_RDONLY
   4: S_IFDOOR mode:0444 dev:240,0 ino:29463 uid:0 gid:0 size:0
      O_RDONLY|O_LARGEFILE FD_CLOEXEC  door to nscd[235]
   5: S_IFCHR mode:0666 dev:136,0 ino:37794 uid:0 gid:3 rdev:13,2
      O_RDWR
   6: S_IFSOCK mode:0666 dev:235,0 ino:43049 uid:0 gid:0 size:0
      O_RDWR|O_NONBLOCK
        sockname: AF_INET6 ::  port: 6013
   7: S_IFSOCK mode:0666 dev:235,0 ino:39941 uid:0 gid:0 size:0
      O_RDWR|O_NONBLOCK
        sockname: AF_INET 0.0.0.0  port: 6013
   8: S_IFSOCK mode:0666 dev:235,0 ino:45982 uid:0 gid:0 size:0
      O_RDWR|O_NONBLOCK
        sockname: AF_INET 128.175.13.68  port: 22
        peername: AF_INET 128.175.13.38  port: 49867

Please help!

	Ed

Ed Phillips <ed at udel.edu> University of Delaware (302) 831-6082
Systems Programmer III, Network and Systems Services
finger -l ed at polycut.nss.udel.edu for PGP public key