See debug steps in the original ticket. We need to add KRB5_TRACE and wait for a repeat failure.

PR for debugging linked. Please do not close the issue on merge.

master:

• e7319f628fd70bb7abc77aff1a819326bf52cb5c tasks.py: add krb5_trace to create_active_user and kinit_as_user
• 8f8c560ffd37ea7c23a609fb0b3713a133d9f15f ipatests: add KRB5_TRACE to kinit in test_adtrust_install.py

ipa-4-8:

• 01f27e292211e949c1ee2de727a203503ddfffa8 tasks.py: add krb5_trace to create_active_user and kinit_as_user
• 2032a619bb0a618b0d39fee0f61fbbc0a71ad77c ipatests: add KRB5_TRACE to kinit in test_adtrust_install.py

Passing in https://github.com/freeipa-pr-ci2/freeipa/pull/238

@pcech apologies if it was not clear here, but as noted in https://pagure.io/freeipa/issue/8271 the issue is sporadic. Reopening.

@rharwood we have a failure with debug: logs

bug

Also happened in PR 265, with logs

master:

• 0df4e8813d573f3e6ad1d084823764cf40a4b5c9 ipatests: display SSSD kdcinfo in test_adtrust_install.py

ipa-4-8:

• c5abea2341b9e478625ea5a46c346550bc648a01 ipatests: display SSSD kdcinfo in test_adtrust_install.py

Also happened in test_adtrust_install in PR #688

Also happened in [testing_master_previous] Nightly PR #798 , report

Failure observed also in [testing_ipa-4.9_latest_selinux] Nightly PR #841 , report

Failure observed in [testing_ipa-4.9_latest_selinux] Nightly PR #856, report

Failures observed in [testing_master_pki] Nightly PR #1035 , report

Also affecting test_ipa_user_s4u2self_pac in the same test suite. [testing_ipa-4.9_latest] Nightly PR #1075 , report

Another failure in PR #1111, report

TL;DR kpasswd_server should be set in kerberos conf.

Note: I skip here any log files for readability.

I have the issue with ipatests/test_integration/test_adtrust_install.py::TestIpaAdTrustInstall::test_add_agent_not_allowed with identical symptom.

The reproducer script:

#!/bin/bash -eu
kdestroy -A
export KRB5_TRACE=/dev/stdout
export SSSD_KRB5_LOCATOR_DEBUG=1
echo Secret123 | kinit admin
ipa user-del nonadmin ||:
systemctl restart dirsrv@IPA-TEST.service
echo -e Secret123\\nSecret123 | ipa user-add nonadmin \
        --first nonadmin --last nonadmin --password
echo -e Secret123\\nSecret123\\nSecret123 | kinit nonadmin

What is going on:
1 . The previous test step test_samba_config_file executes ipa-adtrust-install, which in turn, triggers the restart of systemd's instance of dirsrv.

2 . ns-slapd for dropping privileges calls getpwnam with dirsrv user

3 . nsswitch.conf points passwd db to sss service

4 . sss tries to resolve user dirsrv
there is a difference between Fedora 34 and ALTLinux. SSSD for Fedora 34 is configured with --enable-files-domain at compile time, which stands for

If this feature is enabled, then SSSD always enables a domain with id_provider=files even if the domain is not specified in the config file

while ALTLinux is configured with the default one (off).

Fedora 34 : dirsrv@implicit_files is resolved by sss and SSSD doesn't even touch the IPA provider, SSSD assumes IPA online at this point (actually, offline).

ALTLinux: sss tries to resolve dirsrv in IPA provider (which is off during 389-ds restart) and marks this provider as offline (retry time 85sec if IIRC).

This can be checked with
getent passwd -s sss dirsrv.

Important note: as of Fedora 35 SSSD is configured with the default one:
https://fedoraproject.org/wiki/Changes/FlexibleLocalUserCache

So, the issue will be seen and for the recent Fedora too.

5 . since the provider IPA offline the SSSD's locator plugin for libkrb5 (https://linux.die.net/man/8/sssd_krb5_locator_plugin) can do nothing about
this:

[sssd_krb5_locator] sssd_krb5_locator_init called
[sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.IPA.TEST][2][No such file or directory].
[sssd_krb5_locator] get_krb5info failed.
[sssd_krb5_locator] sssd_krb5_locator_close called

and fallbacks to the standard libkrb5 algorithm (man 5 krb5.conf).

6 . krb5.conf on IPA server doesn't include kpasswd_server and kinit fallbacks to DNS way.
DNS (URI or SRV) RRs don't preserve any order and kinit may contact either master or replica kpasswd servers.

7 . two possible outcomes due to replication delay:
- password was changed on replica but was not replicated to master(kinit->master(initial)->replica(kpassw)->master(initial))
- new user wasn't replecated to replica before password change requested on replica
(kinit->master(initial)->replica(kpasswd))

Note: master_kdc(primary_kdc) doesn't help here because it is only used if the initial credentials obtaining fail (see krb5_get_init_creds_password in libkrb5) and not password change.

I propose to supply FreeIPA's configuration for libkrb5 with kpasswd_server.

Ok, Fedora 35 will not be affected by --disable-files-domain and passwd: sss files => passwd: files sss exactly for described above scenario, but this doesn't change the fact that the IPA provider can be offline at any moment (and this happens during the tests).

reproducer for F34(sporadic failure, server+at least 1 replica required):

#!/bin/bash -eu
kdestroy -A
export KRB5_TRACE=/dev/stdout
export SSSD_KRB5_LOCATOR_DEBUG=1
echo Secret123 | kinit admin
ipa user-del nonadmin ||:
systemctl stop sssd
echo -e Secret123\\nSecret123 | ipa user-add nonadmin --first nonadmin --last nonadmin --password
echo -e Secret123\\nSecret123\\nSecret123 | kinit nonadmin

master:

• 93126e01a5fe8da56928a65fd3848b27edb5eaa3 krb5: Pin kpasswd server to a primary one
• 4fa6afa922983cdc99fe1b43923b4b1829ebbcae ipatests: Log debug messages for locator plugin

ipa-4-9:

• 8fcc0f077bc24e0c7d0c7434fbd4e91372021217 krb5: Pin kpasswd server to a primary one
• 12ebc658a8bcde3cf5a9665e10981f822fa00dad ipatests: Log debug messages for locator plugin