openssh unix dev - Jul 2011 - intermittent problems obtaining shell with gssapi-with-mic

Hi,

I am seeing a rather strange issue with openssh-5.3p1 (both client and
server) under scientific linux 6. The systems in question are set up
to authenticate against a Kerberos server. ssh'ing between machines
works fine 99% of the time with the gssapi-with-mic method. But on
occasion an ssh session will fail to spawn a sheel for the user after
authentication. An example -vvv output in this situation is below:

$ ssh -vvv callista
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 callista [128.40.5.73] port 22.
debug1: Connection established.
debug1: identity file /home/jgu/.ssh/identity type -1
debug1: identity file /home/jgu/.ssh/id_rsa type -1
debug1: identity file /home/jgu/.ssh/id_dsa type -1
debug1: Remote protocol version 2.0, 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 4 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
at 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
at lysator.liu.se
debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,umac-64 at openssh.com,hmac-ripemd160,hmac-ripemd160 at
openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,umac-64 at openssh.com,hmac-ripemd160,hmac-ripemd160 at
openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib at openssh.com,zlib
debug2: kex_parse_kexinit: none,zlib at 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
at 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
at lysator.liu.se
debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,umac-64 at openssh.com,hmac-ripemd160,hmac-ripemd160 at
openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,umac-64 at openssh.com,hmac-ripemd160,hmac-ripemd160 at
openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib at openssh.com
debug2: kex_parse_kexinit: none,zlib at 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: 140/256
debug2: bits set: 537/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 /home/jgu/.ssh/known_hosts
debug3: check_host_in_hostfile: match line 11
debug3: check_host_in_hostfile: filename /home/jgu/.ssh/known_hosts
debug3: check_host_in_hostfile: match line 11
debug1: Host 'callista' is known and matches the RSA host key.
debug1: Found key in /home/jgu/.ssh/known_hosts:11
debug2: bits set: 511/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: /home/jgu/.ssh/identity ((nil))
debug2: key: /home/jgu/.ssh/id_rsa ((nil))
debug2: key: /home/jgu/.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 128.40.5.73.
debug2: we sent a gssapi-with-mic packet, wait for reply
debug3: Wrote 96 bytes for a total of 1205
debug3: Wrote 704 bytes for a total of 1909
debug3: Wrote 64 bytes for a total of 1973
debug1: Authentication succeeded (gssapi-with-mic).
debug1: channel 0: new [client-session]
debug3: ssh_session2_open: channel_new: 0
debug2: channel 0: send open
debug1: Requesting no-more-sessions at openssh.com
debug1: Entering interactive session.
debug3: Wrote 128 bytes for a total of 2101
debug2: callback start
debug2: client_session2_setup: id 0
debug2: channel 0: request pty-req confirm 1
debug1: Sending environment.
debug3: Ignored env MKLROOT
debug3: Ignored env MANPATH
debug3: Ignored env ORBIT_SOCKETDIR
debug3: Ignored env HOSTNAME
debug3: Ignored env IMSETTINGS_INTEGRATE_DESKTOP
debug3: Ignored env INTEL_LICENSE_FILE
debug3: Ignored env GPG_AGENT_INFO
debug3: Ignored env SHELL
debug3: Ignored env TERM
debug3: Ignored env HISTSIZE
debug3: Ignored env XDG_SESSION_COOKIE
debug3: Ignored env LIBRARY_PATH
debug3: Ignored env GTK_RC_FILES
debug3: Ignored env WINDOWID
debug3: Ignored env FPATH
debug3: Ignored env QTDIR
debug3: Ignored env QTINC
debug3: Ignored env IMSETTINGS_MODULE
debug3: Ignored env USER
debug3: Ignored env LS_COLORS
debug3: Ignored env LD_LIBRARY_PATH
debug3: Ignored env CPATH
debug3: Ignored env SSH_AUTH_SOCK
debug3: Ignored env GNOME_KEYRING_SOCKET
debug3: Ignored env COBBLER_SERVER
debug3: Ignored env USERNAME
debug3: Ignored env SESSION_MANAGER
debug3: Ignored env NLSPATH
debug3: Ignored env PATH
debug3: Ignored env DESKTOP_SESSION
debug3: Ignored env MAIL
debug3: Ignored env QT_IM_MODULE
debug3: Ignored env PWD
debug1: Sending env XMODIFIERS = @im=none
debug2: channel 0: request env confirm 0
debug3: Ignored env GDM_KEYBOARD_LAYOUT
debug3: Ignored env KDE_IS_PRELINKED
debug1: Sending env LANG = en_GB.utf8
debug2: channel 0: request env confirm 0
debug3: Ignored env GNOME_KEYRING_PID
debug3: Ignored env GDM_LANG
debug3: Ignored env MODULEPATH
debug3: Ignored env LOADEDMODULES
debug3: Ignored env KDEDIRS
debug3: Ignored env GDMSESSION
debug3: Ignored env HISTCONTROL
debug3: Ignored env KRB5CCNAME
debug3: Ignored env SSH_ASKPASS
debug3: Ignored env HOME
debug3: Ignored env SHLVL
debug3: Ignored env GNOME_DESKTOP_SESSION_ID
debug3: Ignored env LOGNAME
debug3: Ignored env CVS_RSH
debug3: Ignored env QTLIB
debug3: Ignored env DBUS_SESSION_BUS_ADDRESS
debug3: Ignored env MODULESHOME
debug3: Ignored env LESSOPEN
debug3: Ignored env WINDOWPATH
debug3: Ignored env DISPLAY
debug3: Ignored env INCLUDE
debug3: Ignored env G_BROKEN_FILENAMES
debug3: Ignored env XAUTHORITY
debug3: Ignored env COLORTERM
debug3: Ignored env module
debug3: Ignored env _
debug2: channel 0: request shell confirm 1
debug2: fd 4 setting TCP_NODELAY
debug2: callback done
debug2: channel 0: open confirm rwindow 0 rmax 32768
debug3: Wrote 512 bytes for a total of 2613
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

At this point the session hangs seemingly forever and a command prompt
never appears. When I see this issue, it isn't resolved by restarting
the sshd server, and it continues to be an issue if I kill the session
and start again. However, if I then do a

ssh -o GSSAPIAuthentication=no callista

I enter the password and log in successfully, as expected.
Subsequently if I disconnect, and then retry without
GSSAPIAuthentication=no everything is fine again.

I am having a hard time with debugging this any further, any advice
would be happily received.

Please cc me on any responses as I am not subscribed to the list.

Thanks in advance,
Jonathan.

On 2011-07-28 at 17:35 +0100, Jonathan Underwood wrote:
> I am seeing a rather strange issue with openssh-5.3p1 (both client and
> server) under scientific linux 6. The systems in question are set up
> to authenticate against a Kerberos server. ssh'ing between machines
> works fine 99% of the time with the gssapi-with-mic method. But on
> occasion an ssh session will fail to spawn a sheel for the user after
> authentication. An example -vvv output in this situation is below:
> At this point the session hangs seemingly forever and a command prompt
> never appears. When I see this issue, it isn't resolved by restarting
> the sshd server, and it continues to be an issue if I kill the session
> and start again. However, if I then do a
> 
> ssh -o GSSAPIAuthentication=no callista
> 
> I enter the password and log in successfully, as expected.
> Subsequently if I disconnect, and then retry without
> GSSAPIAuthentication=no everything is fine again.
> 
> I am having a hard time with debugging this any further, any advice
> would be happily received.
If your home directory NFS mounted, with Kerberised authentication
against the NFS server?

If so, then when things fail, your credentials on the remote machine
have expired and /home/$you is not mounted, and logging in with a
password supplied to the remote site is getting /home/$you mounted.

Try instead:
  ssh -o GSSAPIDelegateCredentials=yes callista

If that works, then since you're willing to supply your password to the
remote side, you presumably trust it enough to delegate a Kerberos
TGT to it.  Add GSSAPIDelegateCredentials=yes to the ~/.ssh/config entry
for this host.

-Phil