#258131 openssh: intermittant failure with GSSAPI authentication

#258131#5
Date:
2004-07-07 19:59:16 UTC
From:
To:
This may be related to the recent bug report (219519) about ssh refusing
to connect to servers of a different version.  However, this does not
seem to be version related.  I'm including the log entries that sshd
generated when I attempted to ssh to localhost, which was running the
ssh-krb5 3.6.1p2-5 sshd.  I'll provide debugging output from ssh -v and
sshd -d if you want it.

Don't hesitate to ask if there's anything else I can provide for you.
The bit about failed publickey login is not surprising, since my keys
live in an unreadable AFS directory, but I can not explain why GSSAPI
authentication is failing.  Other GSSAPI based tools (ksu, at least) do
not have issues.

noah

#258131#10
Date:
2004-07-07 21:33:21 UTC
From:
To:
Did you really ssh to localhost?  If so, I wouldn't expect that to
work because you probably don't have the host/localhost key on your
server.

#258131#15
Date:
2004-07-07 21:33:21 UTC
From:
To:
Did you really ssh to localhost?  If so, I wouldn't expect that to
work because you probably don't have the host/localhost key on your
server.

#258131#20
Date:
2004-07-07 21:46:15 UTC
From:
To:
No.  Sorry for not being clear.  I sshed to the hostname associated with
the principal in /etc/krb5.keytab.  I was staying on the localhost to
insure that no version skew between ssh and sshd was involved.  The
problem occurs between hosts.  On all hosts involved, other GSSAPI-based
authentication works, but ssh does not.

I am working on getting more details for you using gdb, but I'm sure you
are more familiar with both GSSAPI and ssh-krb5 than I am, so I'm not
sure how much success I'll have.

I can create accounts on a couple machines to demonstrate this for you,
if you'd like; they're all located in CSAIL at MIT.

noah

#258131#25
Date:
2004-07-08 01:15:26 UTC
From:
To:
    Noah> On Wed, Jul 07, 2004 at 05:33:21PM -0400, Sam Hartman wrote:
    >> Did you really ssh to localhost?  If so, I wouldn't expect that
    >> to work because you probably don't have the host/localhost key
    >> on your server.

    Noah> No.  Sorry for not being clear.  I sshed to the hostname
    Noah> associated with the principal in /etc/krb5.keytab.  I was
    Noah> staying on the localhost to insure that no version skew
    Noah> between ssh and sshd was involved.  The problem occurs
    Noah> between hosts.  On all hosts involved, other GSSAPI-based
    Noah> authentication works, but ssh does not.

OK, then please look at sshd -d -d and ssh -v -v and see which gss
error you get.

#258131#30
Date:
2004-07-22 15:19:09 UTC
From:
To:
Hi Sam.  It had been a while since sshd was failing to work with gssapi
logins, so I didn't have any debugging output for you.  Today it is
failing.  I ran sshd with the '-d -d' flags and tried to ssh in with '-v
-v'.  Strangely enough, there doesn't seem to be any indication of a gss
error in the output of either command.  sshd reports the gss_complete
complete message, but later on in the file indicates "Failed gssapi for
noahm from 128.30.28.112 port 32776 ssh2"

I've attached the output from both commands in the hopes that it will be
of some help to you.  Please let me know if there's anything that I can
do to help you gather more info.

noah

#258131#35
Date:
2004-07-22 20:43:32 UTC
From:
To:
It sounds like some sort of authorization problem.  Is it possible
that your home directory or .k5login file or something is unreadable?

#258131#38
Date:
2004-08-07 21:42:41 UTC
From:
To:
Hi.  We're also seeing intermitant failure with ssh-krb5 or similar
programs.  In particular, we're seeing some sort of failure that looks
a lot like you describe.  So far we're not having much luck tracking
it down.

The expected failure location is the handler for gssapi exchange
complete in auth2-gss.c.

#258131#47
Date:
2012-07-05 15:17:30 UTC
From:
To:
Hello, I am having strange SIGSEGV issues with sshd, but good news: it is reproductible.

When trying to use both KerberosAuthentication and GSSAPIAuthentication, you get two cases:

* If you connect with a client using "GSSAPIAuthentication yes", with a valid Kerberos ticket, everything
connects fine and you get a valid ticket on the remote host.
* If you connect with a client using "GSSAPIAuthentication no", ssh exits just after outputing:

"Connection closed by 192.168.100.10"

Here is the Server Debug:
---8<---
debug1: Server will not fork when running in debugging mode.
debug1: rexec start in 5 out 5 newsock 5 pipe -1 sock 8
debug1: inetd sockets after dupping: 3, 3
Connection from 192.168.100.1 port 58888
debug1: Client protocol version 2.0; client software version OpenSSH_6.0p1 Debian-2
debug1: match: OpenSSH_6.0p1 Debian-2 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_6.0p1 Debian-2
debug1: permanently_set_uid: 103/65534 [preauth]
debug1: list_hostkey_types: ssh-rsa,ssh-dss,ecdsa-sha2-nistp256 [preauth]
debug1: SSH2_MSG_KEXINIT sent [preauth]
debug1: SSH2_MSG_KEXINIT received [preauth]
debug1: kex: client->server aes128-ctr hmac-md5 none [preauth]
debug1: kex: server->client aes128-ctr hmac-md5 none [preauth]
debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
debug1: SSH2_MSG_NEWKEYS sent [preauth]
debug1: expecting SSH2_MSG_NEWKEYS [preauth]
debug1: SSH2_MSG_NEWKEYS received [preauth]
debug1: KEX done [preauth]
debug1: userauth-request for user mcerda service ssh-connection method none [preauth]
debug1: attempt 0 failures 0 [preauth]
debug1: PAM: initializing for "mcerda"
debug1: PAM: setting PAM_RHOST to "192.168.100.1"
debug1: PAM: setting PAM_TTY to "ssh"
debug1: userauth-request for user mcerda service ssh-connection method publickey [preauth]
debug1: attempt 1 failures 0 [preauth]
debug1: test whether pkalg/pkblob are acceptable [preauth]
debug1: Checking blacklist file /usr/share/ssh/blacklist.RSA-2048
debug1: Checking blacklist file /etc/ssh/blacklist.RSA-2048
debug1: temporarily_use_uid: 1000/1000 (e=0/0)
debug1: trying public key file /home/mcerda/.ssh/authorized_keys
debug1: Could not open authorized keys '/home/mcerda/.ssh/authorized_keys': No such file or directory
debug1: restore_uid: 0/0
debug1: temporarily_use_uid: 1000/1000 (e=0/0)
debug1: trying public key file /home/mcerda/.ssh/authorized_keys2
debug1: Could not open authorized keys '/home/mcerda/.ssh/authorized_keys2': No such file or directory
debug1: restore_uid: 0/0
Failed publickey for mcerda from 192.168.100.1 port 58888 ssh2
debug1: userauth-request for user mcerda service ssh-connection method password [preauth]
debug1: attempt 2 failures 1 [preauth]
debug1: temporarily_use_uid: 1000/1000 (e=0/0)
debug1: restore_uid: 0/0
debug1: temporarily_use_uid: 1000/1000 (e=0/0)
---8<---

And the client one:
---8<--- OpenSSH_6.0p1 Debian-2, OpenSSL 1.0.1c 10 May 2012 debug1: Reading configuration data /home/mcerda/.ssh/config debug1: Reading configuration data /etc/ssh/ssh_config debug1: /etc/ssh/ssh_config line 19: Applying options for * debug1: Connecting to dashie.zea.zen [192.168.100.10] port 22. debug1: Connection established. debug1: identity file /home/mcerda/.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/mcerda/.ssh/id_rsa-cert type -1 debug1: identity file /home/mcerda/.ssh/id_dsa type -1 debug1: identity file /home/mcerda/.ssh/id_dsa-cert type -1 debug1: identity file /home/mcerda/.ssh/id_ecdsa type -1 debug1: identity file /home/mcerda/.ssh/id_ecdsa-cert type -1 debug1: Remote protocol version 2.0, remote software version OpenSSH_6.0p1 Debian-2 debug1: match: OpenSSH_6.0p1 Debian-2 pat OpenSSH* debug1: Enabling compatibility mode for protocol 2.0 debug1: Local version string SSH-2.0-OpenSSH_6.0p1 Debian-2 debug1: SSH2_MSG_KEXINIT sent debug1: SSH2_MSG_KEXINIT received debug1: kex: server->client aes128-ctr hmac-md5 none debug1: kex: client->server aes128-ctr hmac-md5 none debug1: sending SSH2_MSG_KEX_ECDH_INIT debug1: expecting SSH2_MSG_KEX_ECDH_REPLY debug1: Server host key: ECDSA 35:5d:08:41:bf:ac:d2:b3:1c:ce:4b:b4:7b:18:21:d8 debug1: Host 'dashie.zea.zen' is known and matches the ECDSA host key. debug1: Found key in /home/mcerda/.ssh/known_hosts:1 debug1: ssh_ecdsa_verify: signature correct debug1: SSH2_MSG_NEWKEYS sent debug1: expecting SSH2_MSG_NEWKEYS debug1: SSH2_MSG_NEWKEYS received debug1: Roaming not allowed by server debug1: SSH2_MSG_SERVICE_REQUEST sent debug1: SSH2_MSG_SERVICE_ACCEPT received debug1: Authentications that can continue: publickey,gssapi-keyex,gssapi-with-mic,password debug1: Next authentication method: publickey debug1: Offering RSA public key: /home/mcerda/.ssh/id_rsa debug1: Authentications that can continue: publickey,gssapi-keyex,gssapi-with-mic,password debug1: Trying private key: /home/mcerda/.ssh/id_dsa debug1: Trying private key: /home/mcerda/.ssh/id_ecdsa debug1: Next authentication method: password mcerda@dashie.zea.zen's password: Connection closed by 192.168.100.10 ---8<--- (not much details here. Looks like the remote just hung up without saying anything) Here is a GDB session when this bug is encountered:
---8<--- Program received signal SIGSEGV, Segmentation fault. 0x00007ffff6347f9a in ?? () from /lib/x86_64-linux-gnu/libc.so.6 (gdb) thr apply all bt Thread 1 (Thread 0x7ffff7fe27c0 (LWP 9007)): #0 0x00007ffff6347f9a in ?? () from /lib/x86_64-linux-gnu/libc.so.6 #1 0x00007ffff634b87c in free () from /lib/x86_64-linux-gnu/libc.so.6 #2 0x00007ffff68d182b in ?? () from /usr/lib/x86_64-linux-gnu/libkrb5.so.3 #3 0x00007ffff68d2216 in krb5_aname_to_localname () from /usr/lib/x86_64-linux-gnu/libkrb5.so.3 #4 0x00007ffff68d55eb in krb5_kuserok () from /usr/lib/x86_64-linux-gnu/libkrb5.so.3 #5 0x00005555555804ba in ?? () #6 0x000055555556647b in ?? () #7 0x000055555557a72a in ?? () #8 0x000055555557b7ca in ?? () #9 0x000055555557c5ed in ?? () #10 0x0000555555564103 in main () ---8<--- Well, I hope this helps.
#258131#52
Date:
2012-07-05 16:54:50 UTC
From:
To:
Matthieu CERDA <matthieu.cerda@normation.com> writes:

[...]

Could you install libkrb5-dbg and libc6-dbg and then get a new backtrace?
I'm particularly interested in the call site of that free.

Running sshd under valgrind might also help, since this may be heap
corruption.

I assume that you're using libpam-krb5 to do the password checking.  What
version of libpam-krb5 do you have installed?

#258131#57
Date:
2012-07-06 10:32:40 UTC
From:
To:
Le 05/07/2012 18:54, Russ Allbery a écrit :
[...]
Yep, I'll do it right away.
It's been a while since I used valgrind but again, no prob.
This is version 4.6-1

Thanks for your help.

#258131#62
Date:
2012-07-06 11:05:06 UTC
From:
To:
Le 05/07/2012 18:54, Russ Allbery a écrit :

[...]

Program received signal SIGSEGV, Segmentation fault.
_int_free (av=0x7ffff6653e60, p=0x4e455a2e41455a) at malloc.c:4892
4892    malloc.c: Aucun fichier ou dossier de ce type.
(gdb) thr apply all bt

Thread 1 (Thread 0x7ffff7fe27c0 (LWP 10254)):
#0  _int_free (av=0x7ffff6653e60, p=0x4e455a2e41455a) at malloc.c:4892
#1  0x00007ffff634b87c in *__GI___libc_free (mem=<optimized out>) at
malloc.c:3738
#2  0x00007ffff68d182b in default_an_to_ln
(context=context@entry=0x5555557fbda0, aname=aname@entry=0x5555557fc3b0,
    lnsize=lnsize@entry=65, lname=lname@entry=0x7fffffffda30 "\200t~UUU")
    at ../../../../src/lib/krb5/os/an_to_ln.c:632
#3  0x00007ffff68d2216 in krb5_aname_to_localname
(context=context@entry=0x5555557fbda0,
    aname=aname@entry=0x5555557fc3b0, lnsize_in=lnsize_in@entry=65,
lname=lname@entry=0x7fffffffda30 "\200t~UUU")
    at ../../../../src/lib/krb5/os/an_to_ln.c:793
#4  0x00007ffff68d55eb in an2ln_ok (luser=0x5555557e7480 "mcerda",
principal=0x5555557fc3b0, context=0x5555557fbda0)
    at ../../../../src/lib/krb5/os/kuserok.c:168
#5  krb5_kuserok (context=0x5555557fbda0, principal=0x5555557fc3b0,
luser=0x5555557e7480 "mcerda")
    at ../../../../src/lib/krb5/os/kuserok.c:181
#6  0x00005555555804ba in ?? ()
#7  0x000055555556647b in ?? ()
#8  0x000055555557a72a in ?? ()
#9  0x000055555557b7ca in ?? ()
#10 0x000055555557c5ed in ?? ()
#11 0x0000555555564103 in main ()

Looks like sshd tries to free() something that it should not. I'll try
to have a peek at the related code.

Valgrind does not output anything interesting except some of these while
the binary is just being started:

==10666== Using Valgrind-3.7.0 and LibVEX; rerun with -h for copyright info
==10666== Command: /usr/sbin/sshd -d
==10666==
==10666== Warning: invalid file descriptor 1024 in syscall close()
==10666== Warning: invalid file descriptor 1025 in syscall close()
==10666== Warning: invalid file descriptor 1026 in syscall close()
==10666==    Use --log-fd=<number> to select an alternative log fd.
==10666== Warning: invalid file descriptor 1027 in syscall close()
==10666== Warning: invalid file descriptor 1028 in syscall close()
==10666== Warning: invalid file descriptor 1029 in syscall close()

It does not seem related to the issue.

#258131#67
Date:
2012-07-06 16:55:18 UTC
From:
To:
Matthieu CERDA <matthieu.cerda@normation.com> writes:

Oh.  I knew that looked familiar.  This is #512410.  I thought that was
fixed in unstable already.

#258131#72
Date:
2012-07-06 20:14:00 UTC
From:
To:
Le 6 juil. 2012 à 18:55, Russ Allbery a écrit :

Oh ! Well thanks a lot anyway, this is a testing / wheezy machine so the package has certainly not been sent to the testing archive yet. Thanks for your help !

#258131#77
Date:
2012-07-06 20:36:13 UTC
From:
To:
Matthieu CERDA <matthieu.cerda@normation.com> writes:

It turns out it's not fixed in unstable yet either (it was fixed in
Ubuntu, which is what I was remembering).  I pinged Sam on the status;
I've been holding off doing uploads myself since he was in the middle of
some repository and VCS system migrations.

This bug definitely needs to be fixed for wheezy.