Description of problem: When using sssd-kcm, Kerberos credentials forwarded over SSH are not cached. This works OK when using the kernel keyring. A worked example. Connecting to 'kowalski' from 'iseult'. First let's purge the cache on kowalski: [james@iseult ~]$ ssh kowalski Last login: Sat Jul 21 18:33:52 2018 from 192.168.0.146 [james@kowalski ~]$ klist klist: Credentials cache 'KCM:1402400001' not found [james@kowalski ~]$ su james First Factor: Second Factor: [james@kowalski ~]$ klist Ticket cache: KCM:1402400001:84894 Default principal: james Valid starting Expires Service principal 21/07/18 18:34:22 22/07/18 18:34:22 krbtgt/CB.ETTLE [james@kowalski ~]$ kdestroy [james@kowalski ~]$ klist klist: Credentials cache 'KCM:1402400001' not found Now, back on iseult the credentials are: [james@iseult ~]$ klist -A Ticket cache: KCM:1402400001:38015 Default principal: james Valid starting Expires Service principal 21/07/18 16:46:29 22/07/18 15:24:21 host/kowalski.cb.ettle 21/07/18 15:24:21 22/07/18 15:24:21 krbtgt/CB.ETTLE 21/07/18 16:37:07 22/07/18 15:24:21 host/buck.cb.ettle 21/07/18 18:15:13 22/07/18 15:24:21 host/skipper.cb.ettle Let's try logging into kowalski again with delegation: [james@iseult ~]$ ssh -K kowalski Last login: Sat Jul 21 18:34:23 2018 [james@kowalski ~]$ klist klist: Credentials cache 'KCM:1402400001' not found I'd expect a new ccache here, like with kernel keyring. I have to 'su james' and re-authenticate to get tickets. Version-Release number of selected component (if applicable): sssd-kcm-1.16.2-4.fc28.x86_64 openssh-7.7p1-5.fc28.x86_64
I was not using KCM in F28 but now I'm testing F29 for deployment and the KCM is default there. Immediately I'm seeing what I think is the problem described above: ssh-delegated credentials just don't go into the KCM at all. So I install a fresh F29 machine and give it a host principal. Then I ssh into it: ἐπιθυμία:~❯ ssh -vvv -x ld00 [...] debug1: Offering GSSAPI proposal: gss-gex-sha1-toWM5Slw5Ew8Mqkay+al2g==,gss-group14-sha1-toWM5Slw5Ew8Mqkay+al2g==,gss-gex-sha1-eipGX3TCiQSrx573bT1o1Q==,gss-group14-sha1-eipGX3TCiQSrx573bT1o1Q== [...] 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: send packet: type 50 debug2: we sent a gssapi-with-mic packet, wait for reply debug3: receive packet: type 60 debug1: Delegating credentials debug3: send packet: type 61 debug3: receive packet: type 61 debug1: Delegating credentials debug3: send packet: type 66 debug3: receive packet: type 52 debug1: Authentication succeeded (gssapi-with-mic). Authenticated to ld00 ([172.21.84.191]:22). [...] Last login: Sat Nov 17 09:22:30 2018 from 172.21.86.85 Could not chdir to home directory /home/tibbs: Permission denied [tibbs@ld00]/% klist klist: Credentials cache 'KCM:7225' not found [tibbs@ld00]/% I can at this point do kinit just fine, though, and that does let me see my home directory and do kerberos stuff as usual. If I log out and (as root on another login) simply comment out those lines from /etc/krb5.conf.d/kcm_default_ccache while changing nothing else, principal forwarding works: ἐπιθυμία:~❯ ssh -vvv -x ld00 [...] debug1: Offering GSSAPI proposal: gss-gex-sha1-toWM5Slw5Ew8Mqkay+al2g==,gss-group14-sha1-toWM5Slw5Ew8Mqkay+al2g==,gss-gex-sha1-eipGX3TCiQSrx573bT1o1Q==,gss-group14-sha1-eipGX3TCiQSrx573bT1o1Q== [...] 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: send packet: type 50 debug2: we sent a gssapi-with-mic packet, wait for reply debug3: receive packet: type 60 debug1: Delegating credentials debug3: send packet: type 61 debug3: receive packet: type 61 debug1: Delegating credentials debug3: send packet: type 66 debug3: receive packet: type 52 debug1: Authentication succeeded (gssapi-with-mic). [...] Last login: Sat Nov 17 09:57:59 2018 from 172.21.86.85 ld00:~❯ klist Ticket cache: KEYRING:persistent:7225:krb_ccache_Chv18D6 Default principal: tibbs.EDU Valid starting Expires Service principal 11/17/2018 09:58:52 11/17/2018 22:43:39 krbtgt/MATH.UH.EDU.EDU renew until 11/23/2018 22:43:39 I dropped this into /etc/sssd/conf.d/11_kcm.conf: [kcm] debug_level = 10 debug_microseconds = true [secrets] debug_level = 10 debug_microseconds = true but there is nothing at all in /var/log/sssd/sssd_kcm.log besides (Sat Nov 17 09:32:30 2018) [sssd[kcm]] [orderly_shutdown] (0x0010): SIGTERM: killing children and nothing useful in the journal, either: Nov 17 09:22:29 ld00.e.math.uh.edu systemd[1]: Started SSSD Kerberos Cache Manager. Nov 17 09:22:29 ld00.e.math.uh.edu sssd[kcm][2603]: Starting up Nov 17 09:32:30 ld00.e.math.uh.edu sssd[kcm][2603]: Shutting down Nov 17 09:49:32 ld00.e.math.uh.edu systemd[1]: Started SSSD Kerberos Cache Manager. Nov 17 09:49:32 ld00.e.math.uh.edu sssd[kcm][4147]: Starting up I did strace the sssd_kcm process and verified that it is at least doing something when I connect, though it seems that a third of the calls it makes are to getpid(). Grepping those out, here's what it does when I ssh in: strace: Process 5550 attached epoll_wait(4, [{EPOLLIN, {u32=2410360752, u64=94079374012336}}], 1, 3566) = 1 accept(3, {sa_family=AF_UNIX}, [110->2]) = 14 getsockopt(14, SOL_SOCKET, SO_PEERCRED, {pid=5969, uid=7225, gid=7225}, [12]) = 0 getsockopt(14, SOL_SOCKET, SO_PEERSEC, "system_u:system_r:sshd_t:s0-s0:c"..., [256->40]) = 0 epoll_ctl(4, EPOLL_CTL_ADD, 14, {EPOLLIN|EPOLLERR|EPOLLHUP, {u32=2431352320, u64=94079395003904}}) = 0 epoll_wait(4, [{EPOLLIN, {u32=2431352320, u64=94079395003904}}], 1, 696) = 1 readv(14, [{iov_base="\0\0\0\4", iov_len=4}], 1) = 4 readv(14, [{iov_base="\2\0\0\3", iov_len=4}], 1) = 4 epoll_ctl(4, EPOLL_CTL_DEL, 14, 0x7fff48f60944) = 0 geteuid() = 0 geteuid() = 0 epoll_create(64) = 15 fcntl(15, F_GETFD) = 0 fcntl(15, F_SETFD, FD_CLOEXEC) = 0 fcntl(13, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=168, l_len=40000}) = 0 fcntl(13, F_SETLKW, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=40168, l_len=0}) = 0 fcntl(13, F_SETLKW, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=168, l_len=0}) = 0 close(15) = 0 epoll_ctl(4, EPOLL_CTL_ADD, 14, {EPOLLOUT|EPOLLERR|EPOLLHUP, {u32=2431352320, u64=94079395003904}}) = 0 epoll_wait(4, [{EPOLLOUT, {u32=2431352320, u64=94079395003904}}], 1, 691) = 1 writev(14, [{iov_base="\0\0\0\17", iov_len=4}], 1) = 4 writev(14, [{iov_base="\0\0\0\0", iov_len=4}], 1) = 4 writev(14, [{iov_base="\0\0\0\0007225:91481\0", iov_len=15}], 1) = 15 epoll_ctl(4, EPOLL_CTL_DEL, 14, 0x7fff48f60954) = 0 epoll_ctl(4, EPOLL_CTL_ADD, 14, {EPOLLIN|EPOLLERR|EPOLLHUP, {u32=2431352320, u64=94079395003904}}) = 0 epoll_wait(4, [{EPOLLIN, {u32=2431352320, u64=94079395003904}}], 1, 690) = 1 readv(14, [{iov_base="\0\0\0\17", iov_len=4}], 1) = 4 readv(14, [{iov_base="\2\0\0\0257225:91481\0", iov_len=15}], 1) = 15 epoll_ctl(4, EPOLL_CTL_DEL, 14, 0x7fff48f60944) = 0 geteuid() = 0 geteuid() = 0 epoll_create(64) = 15 fcntl(15, F_GETFD) = 0 fcntl(15, F_SETFD, FD_CLOEXEC) = 0 fcntl(13, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=168, l_len=40000}) = 0 fcntl(13, F_SETLKW, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=40168, l_len=0}) = 0 fcntl(13, F_SETLKW, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=168, l_len=0}) = 0 close(15) = 0 epoll_ctl(4, EPOLL_CTL_ADD, 14, {EPOLLOUT|EPOLLERR|EPOLLHUP, {u32=2431352320, u64=94079395003904}}) = 0 epoll_wait(4, [{EPOLLOUT, {u32=2431352320, u64=94079395003904}}], 1, 689) = 1 writev(14, [{iov_base="\0\0\0\0", iov_len=4}], 1) = 4 writev(14, [{iov_base="\226\307:\215", iov_len=4}], 1) = 4 epoll_ctl(4, EPOLL_CTL_DEL, 14, 0x7fff48f60954) = 0 epoll_ctl(4, EPOLL_CTL_ADD, 14, {EPOLLIN|EPOLLERR|EPOLLHUP, {u32=2431352320, u64=94079395003904}}) = 0 epoll_wait(4, [], 1, 689) = 0 epoll_wait(4, 0x7fff48f60a14, 1, 10000) = -1 EINTR (Interrupted system call) --- SIGRT_2 {si_signo=SIGRT_2, si_code=SI_TIMER, si_timerid=0, si_overrun=0, si_value={int=-1878190400, ptr=0x7fc3900d16c0}} --- rt_sigreturn({mask=[INT FPE USR1 USR2 PIPE]}) = -1 EINTR (Interrupted system call) epoll_wait(4, But note that at some point earlier in my F29 prep, the problem mysteriously stopped and everything started working. But I have no idea what changed and since the last reinstall the system has stayed in the broken state illustrated here. (I do know the NFS client will cache user principals even after you do kdestroy; that's not what I'm talking about here.) The machine in question is running sssd-kcm-2.0.0-4.fc29.x86_64 and openssh-server-7.9p1-1.fc29.x86_64. The machine where I'm calling ssh is running openssh-7.8p1-3.fc28.x86_64.
A relevant SSSD ticket which discusses the underlying technical issue is https://pagure.io/SSSD/sssd/issue/3873
FWIW - I'm seeing the same with RHEL 8 beta as well.
This message is a reminder that Fedora 28 is nearing its end of life. On 2019-May-28 Fedora will stop maintaining and issuing updates for Fedora 28. It is Fedora's policy to close all bug reports from releases that are no longer maintained. At that time this bug will be closed as EOL if it remains open with a Fedora 'version' of '28'. Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, simply change the 'version' to a later Fedora version. Thank you for reporting this issue and we are sorry that we were not able to fix it before Fedora 28 is end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora, you are encouraged change the 'version' to a later Fedora version prior this bug is closed as described in the policy above. Although we aim to fix as many bugs as possible during every release's lifetime, sometimes those efforts are overtaken by events. Often a more recent Fedora release includes newer upstream software that fixes bugs or makes them obsolete.
This was fixed in 2.1 upstream, can't we close this bug?
Works for me, closing.
*** Bug 1670457 has been marked as a duplicate of this bug. ***