macOS API ccache, kinit for multiple principals gives internal credentials cache error

[A. Karl Kornel]

Hello!

I have run into an issue with krb5 1.21.1 on macOS 14+, related to the
new API ccache type: If I already have a credential cache, doing a
`kinit` for a different principal will return "Internal credentials
cache error while generating new ccache". However, using macOS
Kerberos' `kinit` works fine. I thought to report it here, in case it
is fixable.

I am running MIT Kerberos 1.21.3, as packaged by MacPorts. When I do
these tests, I do not have the KRB5CCNAME environment variable set.

I found that the following sequence of operations ultimately fails:

* MIT Kerberos `kdestroy -A`
* MIT Kerberos `kinit -F ***@stanford.edu` -- works
* MIT Kerberos `kinit -F akkornel/***@stanford.edu` -- fails
* MIT Kerberos `klist -l` -- lists one ccache, for ***@stanford.edu

But these sequences work:

* MIT Kerberos `kdestroy -A`
* MIT Kerberos `kinit -F ***@stanford.edu` -- works
* macOS/Heimdal Kerberos `kinit --no-forward akkornel/***@stanford.edu`
-- works
* MIT Kerberos `klist -l` -- lists both ccaches

* MIT Kerberos `kdestroy -A`
* macOS/Heimdal Kerberos `kinit --no-forward ***@stanford.edu` --
works
* macOS/Heimdal Kerberos `kinit --no-forward akkornel/***@stanford.edu`
-- works
* MIT Kerberos `klist -l` -- lists both ccaches

In other words...

* MIT Kerberos is able to see and use all API ccaches.
* MIT Kerberos can only create a new API ccache if none exists.
* macOS/Heimdal Kerberos can create a new API ccache, even if one
already exists.

I decided to try clearing everything with `kdestroy -A`, and then
running MIT Kerberos commands with KRB_TRACE set. Here are the outputs
from the first sequence that I listed above.

My first `kinit` works fine:

FV9D5J4T23:~ akkornel(nc)$ KRB5_TRACE=/dev/stderr kinit -F
***@stanford.edu
2025-02-12T14:56:46 set-error: -1765328243: no credential for
D61D8910-6938-4563-8FA0-7B38147AA094
2025-02-12T14:56:46 set-error: -1765328243: no credential for
D61D8910-6938-4563-8FA0-7B38147AA094
2025-02-12T14:56:46 set-error: -1765328243: no credential for
D61D8910-6938-4563-8FA0-7B38147AA094
2025-02-12T14:56:46 set-error: -1765328243: no credential for
D61D8910-6938-4563-8FA0-7B38147AA094
2025-02-12T14:56:46 set-error: -1765328242: Reached end of credential
caches
[25286] 1739401006.849757: Matching ***@stanford.edu in collection
with result: -1765328243/Can't find client principal
***@stanford.edu in cache collection
[25286] 1739401006.849758: Getting initial credentials for
***@stanford.edu
... snip ...
[25286] 1739401017.285780: FAST negotiation: available
[25286] 1739401017.285781: Resolving unique ccache of type MEMORY
[25286] 1739401017.285782: Initializing MEMORY:mnLlukm with default
princ ***@stanford.edu
[25286] 1739401017.285783: Storing config in MEMORY:mnLlukm for
krbtgt/***@stanford.edu: fast_avail: yes
[25286] 1739401017.285784: Storing ***@stanford.edu ->
krb5_ccache_conf_data/fast_avail/krbtgt\/stanford.edu\@***@X-CACHECONF:
in MEMORY:mnLlukm
[25286] 1739401017.285785: Storing config in MEMORY:mnLlukm for
krbtgt/***@stanford.edu: pa_type: 2
[25286] 1739401017.285786: Storing ***@stanford.edu ->
krb5_ccache_conf_data/pa_type/krbtgt\/stanford.edu\@***@X-CACHECONF:
in MEMORY:mnLlukm
[25286] 1739401017.285787: Storing ***@stanford.edu ->
krbtgt/***@stanford.edu in MEMORY:mnLlukm
[25286] 1739401017.285788: Moving ccache MEMORY:mnLlukm to
API:D61D8910-6938-4563-8FA0-7B38147AA094
[25286] 1739401017.285789: Initializing
API:D61D8910-6938-4563-8FA0-7B38147AA094 with default princ
***@stanford.edu
2025-02-12T14:56:57 set-error: -1765328243: no credential for
D61D8910-6938-4563-8FA0-7B38147AA094
[25286] 1739401017.285790: Storing ***@stanford.edu ->
krb5_ccache_conf_data/fast_avail/krbtgt\/stanford.edu\@***@X-CACHECONF:
in API:D61D8910-6938-4563-8FA0-7B38147AA094
[25286] 1739401017.285791: Storing ***@stanford.edu ->
krb5_ccache_conf_data/pa_type/krbtgt\/stanford.edu\@***@X-CACHECONF:
in API:D61D8910-6938-4563-8FA0-7B38147AA094
[25286] 1739401017.285792: Storing ***@stanford.edu ->
krbtgt/***@stanford.edu in
API:D61D8910-6938-4563-8FA0-7B38147AA094
[25286] 1739401017.285793: Destroying ccache MEMORY:mnLlukm

My second `kinit` attempt errors out very quickly:

FV9D5J4T23:~ akkornel(p)$ KRB5_TRACE=/dev/stderr kinit -F
akkornel/***@stanford.edu
2025-02-12T14:57:02 set-error: -1765328242: Reached end of credential
caches
[25366] 1739401022.226472: Matching akkornel/***@stanford.edu in
collection with result: -1765328243/Can't find client principal
akkornel/***@stanford.edu in cache collection
[25366] 1739401022.226473: Resolving unique ccache of type API
2025-02-12T14:57:02 set-error: -1765328167: unable to find realm of host
FV9D5J4T23
2025-02-12T14:57:02 set-error: -1765328167: Unable to find realm of self
kinit: Internal credentials cache error while generating new ccache

I don't know if there are any other logs I can capture or debugging that
I can do, but I'm willing to try!

[A. Karl Kornel]

<<<snip>>>
The way that the MacOS X credential cache support works is that it
explicitly links in the MacOS X Kerberos framework when building MIT
Kerberos via the '-framework Kerberos' command-line option and then
makes calls to the ccapi functions to do the appropriate things. From
my memory, Heimdal took a slightly different approach and decided to
dlopen that framework library instead and then do the ccapi calls.
My gut feeling is that this is a MacPorts problem, but I am open to
being proven wrong.

That's entirely possible, and I should've tried to reproduce this on a
stock krb5 build first. So, I just did that.

I also switched to a macOS 15.3 system, which I'll be using from now on.

To confirm, the steps I followed to build krb5:

* Cloned from https://github.com/krb5/krb5.git
* Checked out tag 'krb5-1.21.3-final'
* `mkdir ~/bin/krb5`
* `cd src && autoreconf`
* `./configure --prefix "$HOME/bin/krb5" --enable-dns-for-realm
--disable-pkinit && make && make install`

With the build complete, I did the following tests:

* `~/bin/krb5/bin/kdestroy -A`
* `~/bin/krb5/bin/kinit -F ***@stanford.edu` -- works
* `~/bin/krb5/bin/kinit -F akkornel/***@stanford.edu` -- fails
* `~/bin/krb5/bin/klist -l` -- lists one ccache, for akkornel at
stanford.edu

So, still failing, unfortunately.

I think, however, you're going to have to debug
this yourself further; this looks like it is failing inside of
api_macos_gen_new(), and is probably failing in either cc_initialize(),
cc_context_create_new_ccache(), or cc_ccache_get_name().

I've never use LLDB before, but I decided to give it a try. On my first
try, I got a warning about `kinit` being optimized. So, I erased
"~/bin/krb5", set environment variable CFLAGS="-O0 -g", and re-ran the
`./configure … && make && make install`.

With the newly-installed non-optimized krb5, I reran my tests and got
the same results:

* `~/bin/krb5/bin/kdestroy -A`
* `~/bin/krb5/bin/kinit -F ***@stanford.edu` -- works
* `~/bin/krb5/bin/kinit -F akkornel/***@stanford.edu` -- fails
* `~/bin/krb5/bin/klist -l` -- lists one ccache, for akkornel at
stanford.edu

So, debug time! I used…

lldb -- ~/bin/krb5/bin/kinit -F akkornel/***@stanford.edu

… to start LLDB. Then …

breakpoint set --name api_macos_gen_new

… to set the breakpoint. I ran until it hit the breakpoint, then
started stepping through.

* cc_initialize returned returned 0, so not that.

* cc_context_create_new_ccache returned 2529639136. There we go.

It took me some work, but I eventually realized that
cc_context_create_new_ccache wasn't an actual function, and was
resolving to the Kerberos Framework's context_create_new_ccache.

I'm not sure how to debug macOS Frameworks. I tried single-stepping
through assembly, and I noticed execution was making it through the
Kerberos Framework and into the Heimdal Framework. And then back into
MIT Kerberos code‽ I think the first parameter is a struct with a ton
of pointers, and that's being passed around.

I'll continue exploring. I'm also considering setting up a macOS VM—via
UTM—to see if this also happens on a completely-clean system.

~ Karl

[A. Karl Kornel]

Thanks for digging into this!

You're welcome! It's been an interesting experience.

<<<snip>>>

Post by A. Karl Kornel
It took me some work, but I eventually realized that
cc_context_create_new_ccache wasn't an actual function, and was
resolving to the Kerberos Framework's context_create_new_ccache.

#define cc_context_create_new_ccache(context, version,
principal, ccache) \
((context) -> functions -> create_new_ccache (context, version,
principal, ccache))

Yup, that's what I discovered.

<<<snip>>>
However, some suggestions here. You can get a fair amount of the
source
code for these pieces from opensource.apple.com (go under "View
Releases").
The latest OS release is 15.2, but it doesn't sound like there were
changes that affected this behavior. You want the "Heimdal" and
"MITKerberosShim" packages.

I had found the Heimdal software on
http://github.com/apple-oss-distributions/Heimdal. I did not think to
look for anything else, but indeed, there it is on GitHub at
https://github.com/apple-oss-distributions/MITKerberosShim.

It looks like this is in the MITKerberosShim package, specifically
ccache.c. And it looks like it calls the macro LOG_FAILURE(), which
calls the function mshim_failure(), in misc.c. It looks like THAT
might
turn on logging if you create the preference file

When I was stepping through assembly, LLDB was able to give me symbol
names from the Frameworks, and I recognize `mshim_failure` in that list.

/Library/Preferences/com.apple.MITKerberosShim
and in it set "EnableDebugging" to "true" (looks like it logs via
syslog()).
heim_krb5_parse_name
heim_krb5_cc_new_unique
heim_krb5_cc_initialize
So one of those is failing and I think the log information will tell
you
which one. From THERE ... well, there's a lot of squinting at the
source
code and seeing which function you're in to try to determine what is
happening. It looks like you're mostly in open-source bits so I think
it is possible to get much closer to the issue.

Got it. I'll remember that, in case it's needed.

~ Karl

[A. Karl Kornel]

<<<snip>>>
First, do you have a default_realm set in /etc/krb5.conf ? Maybe that
would fix it, and that would explain why it works for me.

I did not actually have a krb5.conf installed on my computer. Stanford
has the necessary SRV records in DNS for domain-to-realm lookup, KDC
lookup, etc.. Plus, my normal workflow involves using bash aliases to
do `kinit`, and those `kinit` commands include the realm name. So, I've
never been hurt (until now?) by not having a default realm set.

Plus, I didn't know that later macOS even supported putting something at
path /etc/krb5.conf! I thought that pretty much everything under / was
locked down now.

Stanford's canonical krb5.conf is at
https://web.stanford.edu/dept/its/support/kerberos/dist/krb5.conf -- I
just downloaded it, and was able to install it to /etc/krb5.conf.

With the krb5.conf installed, I repeated my original test. Here are the
results:

* MacPorts MIT Kerberos `kdestroy -A`
* MacPorts MIT Kerberos `kinit -F ***@stanford.edu` -- works
* MacPorts MIT Kerberos `kinit -F akkornel/***@stanford.edu` -- works!
* MacPorts MIT Kerberos `klist -l` -- lists two credential caches!

To confirm your hypothesis, I edited the downloaded /etc/krb5.conf,
removing the default_realm entry. I then re-ran the tests with MIT
Kerberos:

* MacPorts MIT Kerberos `kdestroy -A`
* MacPorts MIT Kerberos `kinit -F ***@stanford.edu` -- works
* MacPorts MIT Kerberos `kinit -F akkornel/***@stanford.edu` -- fails
* MacPorts MIT Kerberos `klist -l` -- lists a single credentials cache,
for ***@stanford.edu

And I then did the same tests with the MIT Kerberos that I built:

* `~/bin/krb5/bin/kdestroy -A`
* `~/bin/krb5/bin/kinit -F ***@stanford.edu` -- works
* `~/bin/krb5/bin/kinit -F akkornel/***@stanford.edu` -- fails
* `~/bin/krb5/bin/klist -l` -- lists a single credentials cache, for
***@stanford.edu

So, I think your hypothesis is confirmed:

If you already have a credentials cache (created against one principal),
and you use `kinit` with a different principal, and you do not have a
default realm set, then `kinit` will fail with an "Internal credentials
cache error while generating new ccache" error.

Still, I would like to get confirmation by looking at the syslog. And
it's been a heck of a time trying to figure out how to enable logging.

It looks like this is in the MITKerberosShim package, specifically
ccache.c. And it looks like it calls the macro LOG_FAILURE(), which
calls the function mshim_failure(), in misc.c. It looks like THAT
might
turn on logging if you create the preference file
/Library/Preferences/com.apple.MITKerberosShim

In init_log(), it looks like CopyKeyFromFile() is defined up in misc.c,
starting at line 60. It ends up looking for the file at path
"/Library/Preferences/com.apple.MITKerberosShim.plist". So, I used
these two commands to create the plist and populate it:

sudo plutil -create xml1
/Library/Preferences/com.apple.MITKerberosShim.plist
sudo plutil -insert EnableDebugging -bool True
/Library/Preferences/com.apple.MITKerberosShim.plist

Even so, when I check in the Console app, I do not see anything being
logged. I do see that mshim_failure() calls init_log(), and it seems to
have a mechanism to ensure that log init is only performed once. Maybe
I need to reboot?

I do have an OS update to do, so I'll leave the plist file created, and
see if I start getting debug logs after a reboot.

err = cc_context_create_new_ccache(cc_context, cc_credentials_v5,
"",
&cc_ccache);
The third argument is supposed to be the principal name, and I thought
"" was valid, but maybe technically it isn't, especially if you don't
have a principal name defined?

I had a look through https://github.com/apple-oss-distributions/Heimdal,
looking for calls to `create_new_ccache`. I found create_new_ccache was
called at three places:

* In acc_get_name(): The code calls _krb5_get_default_principal_local(),
uses the resulting principal to call krb5_unparse_name(), and then uses
the resulting name in create_new_ccache().

* In acc_initialize(): A principal is provided as a function parameter,
which is passed to krb5_unparse_name(), and the resulting name is sent
to create_new_ccache().

* In acc_move(): The call is only used if the destination cache does not
exist. get_principal() is called with the source cache, and the
resulting name is sent to create_new_ccache().

So, at least in Heimdal, all of the call sites for create_new_ccache do
provide a principal name.

I wonder, maybe there's an alternate path for creating a credentials
cache?

~ Karl