Hi,
You are right, the question is why does a second ldap child get forked - the /var/log/sssd/domain_$domain.log should give some clues. As a guess you may need to set `ad_enabled_domains = domain.bu.edu' in sssd.conf to disable auto discovery of trusted domains. If this doesn't help please send me the sanitized domain log directly and I can take a look.
-Justin
On Tue, Feb 23, 2021 at 2:21 PM Conwell, Nik nik@bu.edu wrote:
Hi all, can anyone offer some insight into how password authentication works with sssd-ad on the 2.3 version (CentOS 8)? It doesn’t seem to working as it was under the 1.16. Details below.
We’ve been running SSSD 1.16 on CentOS7 for a while without issue. But on CentOS 8 at the 2.3 levels we are having issues with AD password auth. Authenticating in with KRB5 works just fine, we’re able to realm join, get the keytabs, etc., that all seems reasonable.
The issue with the password auth not working seems to be related to SSSD not being able to get a service ticket for the host/myhost.bu.edu@DOMAIN possibly making an unauthenticated call instead of previously using the krb5tgt in the /var/lib/sss/db ccache?
Cranking up debug I see ldap_child working fine when getting our initial TGT:
(2021-02-23 11:31:29): [ldap_child[1485202]] [main] (0x0400): ldap_child started.
(2021-02-23 11:31:29): [ldap_child[1485202]] [main] (0x2000): context initialized
(2021-02-23 11:31:29): [ldap_child[1485202]] [unpack_buffer] (0x1000): total buffer size: 41
(2021-02-23 11:31:29): [ldap_child[1485202]] [unpack_buffer] (0x1000): realm_str size: 9
(2021-02-23 11:31:29): [ldap_child[1485202]] [unpack_buffer] (0x1000): got realm_str: [DOMAIN.BU.EDU]
(2021-02-23 11:31:29): [ldap_child[1485202]] [unpack_buffer] (0x1000): princ_str size: 8
(2021-02-23 11:31:29): [ldap_child[1485202]] [unpack_buffer] (0x1000): got princ_str: [server]$
(2021-02-23 11:31:29): [ldap_child[1485202]] [unpack_buffer] (0x1000): keytab_name size: 0
(2021-02-23 11:31:29): [ldap_child[1485202]] [unpack_buffer] (0x1000): lifetime: 86400
(2021-02-23 11:31:29): [ldap_child[1485202]] [unpack_buffer] (0x0200): Will run as [0][0].
[…]
(2021-02-23 11:31:29): [ldap_child[1485202]] [main] (0x2000): getting TGT sync
(2021-02-23 11:31:29): [ldap_child[1485202]] [ldap_child_get_tgt_sync] (0x2000): got realm_name: [DOMAIN.BU.EDU]
(2021-02-23 11:31:29): [ldap_child[1485202]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [server]$@DOMAIN.BU.EDU]
(2021-02-23 11:31:29): [ldap_child[1485202]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [MEMORY:/etc/krb5.keytab]
(2021-02-23 11:31:29): [ldap_child[1485202]] [sss_child_krb5_trace_cb] (0x4000): [1485202] 1614097889.649498: Getting initial credentials for [server]$@DOMAIN.BU.EDU
(2021-02-23 11:31:29): [ldap_child[1485202]] [sss_child_krb5_trace_cb] (0x4000): [1485202] 1614097889.649499: Looked up etypes in keytab: aes128-cts, aes256-cts
(2021-02-23 11:31:29): [ldap_child[1485202]] [sss_child_krb5_trace_cb] (0x4000): [1485202] 1614097889.649501: Sending unauthenticated request
[…]
(2021-02-23 11:31:29): [ldap_child[1485202]] [sss_child_krb5_trace_cb] (0x4000): [1485202] 1614097889.649507: Response was from master KDC
(2021-02-23 11:31:29): [ldap_child[1485202]] [sss_child_krb5_trace_cb] (0x4000): [1485202] 1614097889.649508: Received error from KDC: -1765328359/Additional pre-authentication required
(2021-02-23 11:31:29): [ldap_child[1485202]] [sss_child_krb5_trace_cb] (0x4000): [1485202] 1614097889.649511: Preauthenticating using KDC method data
(2021-02-23 11:31:29): [ldap_child[1485202]] [sss_child_krb5_trace_cb] (0x4000): [1485202] 1614097889.649512: Processing preauth types: PA-PK-AS-REQ (16), PA-PK-AS-REP_OLD (15), PA-ETYPE-INFO2 (19), PA-ENC-TIMESTAMP (2)
[…]
(2021-02-23 11:31:29): [ldap_child[1485202]] [sss_child_krb5_trace_cb] (0x4000): [1485202] 1614097889.649525: Response was from master KDC
[…]
(2021-02-23 11:31:29): [ldap_child[1485202]] [ldap_child_get_tgt_sync] (0x2000): credentials initialized
(2021-02-23 11:31:29): [ldap_child[1485202]] [ldap_child_get_tgt_sync] (0x2000): keytab ccname: [FILE:/var/lib/sss/db/ccache_DOMAIN.BU.EDU_j0b5Vd]
(2021-02-23 11:31:29): [ldap_child[1485202]] [sss_child_krb5_trace_cb] (0x4000): [1485202] 1614097889.649532: Initializing FILE:/var/lib/sss/db/ccache_DOMAIN.BU.EDU_j0b5Vd with default princ server$@DOMAIN.BU.EDU
[…]
(2021-02-23 11:31:29): [ldap_child[1485202]] [ldap_child_get_tgt_sync] (0x2000): credentials stored
(2021-02-23 11:31:29): [ldap_child[1485202]] [ldap_child_get_tgt_sync] (0x2000): Got KDC time offset
(2021-02-23 11:31:29): [ldap_child[1485202]] [ldap_child_get_tgt_sync] (0x2000): Renaming [/var/lib/sss/db/ccache_DOMAIN.BU.EDU_j0b5Vd] to [/var/lib/sss/db/ccache_DOMAIN.BU.EDU]
[…]
(2021-02-23 11:31:29): [ldap_child[1485202]] [pack_buffer] (0x1000): result [0] krberr [0] msgsize [37] msg [FILE:/var/lib/sss/db/ccache_DOMAIN.BU.EDU]
(2021-02-23 11:31:29): [ldap_child[1485202]] [main] (0x0400): ldap_child completed successfully
But then right after I see ldap_child being called to get a host ticket:
(2021-02-23 11:31:29): [ldap_child[1485203]] [main] (0x0400): ldap_child started.
(2021-02-23 11:31:29): [ldap_child[1485203]] [main] (0x2000): context initialized
(2021-02-23 11:31:29): [ldap_child[1485203]] [unpack_buffer] (0x1000): total buffer size: 52
(2021-02-23 11:31:29): [ldap_child[1485203]] [unpack_buffer] (0x1000): realm_str size: 9
(2021-02-23 11:31:29): [ldap_child[1485203]] [unpack_buffer] (0x1000): got realm_str: DOMAIN.BU.EDU
(2021-02-23 11:31:29): [ldap_child[1485203]] [unpack_buffer] (0x1000): princ_str size: 19
(2021-02-23 11:31:29): [ldap_child[1485203]] [unpack_buffer] (0x1000): got princ_str: host/server.bu.edu
(2021-02-23 11:31:29): [ldap_child[1485203]] [unpack_buffer] (0x1000): keytab_name size: 0
(2021-02-23 11:31:29): [ldap_child[1485203]] [unpack_buffer] (0x1000): lifetime: 86400
(2021-02-23 11:31:29): [ldap_child[1485203]] [unpack_buffer] (0x0200): Will run as [0][0].
(2021-02-23 11:31:29): [ldap_child[1485203]] [privileged_krb5_setup] (0x2000): Kerberos context initialized
(2021-02-23 11:31:29): [ldap_child[1485203]] [main] (0x2000): Kerberos context initialized
(2021-02-23 11:31:29): [ldap_child[1485203]] [become_user] (0x0200): Trying to become user [0][0].
(2021-02-23 11:31:29): [ldap_child[1485203]] [become_user] (0x0200): Already user [0].
(2021-02-23 11:31:29): [ldap_child[1485203]] [main] (0x2000): Running as [0][0].
(2021-02-23 11:31:29): [ldap_child[1485203]] [main] (0x2000): getting TGT sync
(2021-02-23 11:31:29): [ldap_child[1485203]] [ldap_child_get_tgt_sync] (0x2000): got realm_name: [DOMAIN.BU.EDU]
(2021-02-23 11:31:29): [ldap_child[1485203]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [host/server.bu.edu@DOMAIN.BU.EDU]
(2021-02-23 11:31:29): [ldap_child[1485203]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [MEMORY:/etc/krb5.keytab]
(2021-02-23 11:31:29): [ldap_child[1485203]] [sss_child_krb5_trace_cb] (0x4000): [1485203] 1614097889.687429: Getting initial credentials for host/server.bu.edu@DOMAIN.BU.EDU
(2021-02-23 11:31:29): [ldap_child[1485203]] [sss_child_krb5_trace_cb] (0x4000): [1485203] 1614097889.687430: Looked up etypes in keytab: aes128-cts, aes256-cts
(2021-02-23 11:31:29): [ldap_child[1485203]] [sss_child_krb5_trace_cb] (0x4000): [1485203] 1614097889.687432: Sending unauthenticated request
(2021-02-23 11:31:29): [ldap_child[1485203]] [sss_child_krb5_trace_cb] (0x4000): [1485203] 1614097889.687433: Sending request (213 bytes) to DOMAIN.BU.EDU
(2021-02-23 11:31:29): [ldap_child[1485203]] [sss_child_krb5_trace_cb] (0x4000): [1485203] 1614097889.687434: Initiating TCP connection to stream [IP]:88
(2021-02-23 11:31:29): [ldap_child[1485203]] [sss_child_krb5_trace_cb] (0x4000): [1485203] 1614097889.687435: Sending TCP request to stream [IP]:88
(2021-02-23 11:31:29): [ldap_child[1485203]] [sss_child_krb5_trace_cb] (0x4000): [1485203] 1614097889.687436: Received answer (90 bytes) from stream [IP]:88
(2021-02-23 11:31:29): [ldap_child[1485203]] [sss_child_krb5_trace_cb] (0x4000): [1485203] 1614097889.687437: Terminating TCP connection to stream [IP]:88
(2021-02-23 11:31:29): [ldap_child[1485203]] [sss_child_krb5_trace_cb] (0x4000): [1485203] 1614097889.687438: Response was from master KDC
(2021-02-23 11:31:29): [ldap_child[1485203]] [sss_child_krb5_trace_cb] (0x4000): [1485203] 1614097889.687439: Received error from KDC: -1765328378/Client not found in Kerberos database
(2021-02-23 11:31:29): [ldap_child[1485203]] [ldap_child_get_tgt_sync] (0x0040): krb5_get_init_creds_keytab() failed: -1765328378
(2021-02-23 11:31:29): [ldap_child[1485203]] [ldap_child_get_tgt_sync] (0x0010): Failed to initialize credentials using keytab [MEMORY:/etc/krb5.keytab]: Client 'host/server.bu.edu@DOMAIN.BU.EDU' not found in Kerberos database. Unable to create GSSAPI-encrypted LDAP connection.
(2021-02-23 11:31:29): [ldap_child[1485203]] [unique_filename_destructor] (0x2000): Unlinking [/var/lib/sss/db/ccache_DOMAIN.BU.EDU_O03KMi]
(2021-02-23 11:31:29): [ldap_child[1485203]] [main] (0x0020): ldap_child_get_tgt_sync failed.
My /etc/krb5.keytab has a usable key:
[root@server sssd]# kinit nik
Password for nik@DOMAIN.BU.EDU:
[root@server sssd]# klist
Ticket cache: KCM:0
Default principal: nik@DOMAIN.BU.EDU
Valid starting Expires Service principal
02/23/2021 12:50:18 02/23/2021 22:50:18 krbtgt/DOMAIN.BU.EDU@DOMAIN.BU.EDU
renew until 03/02/2021 12:50:15
[root@server sssd]# klist -k
Keytab name: FILE:/etc/krb5.keytab
KVNO Principal
4 server$@DOMAIN.BU.EDU
4 server$@DOMAIN.BU.EDU
4 host/server@DOMAIN.BU.EDU
4 host/server@DOMAIN.BU.EDU
4 host/server.bu.edu@DOMAIN.BU.EDU
4 host/server.bu.edu@DOMAIN.BU.EDU
4 RestrictedKrbHost/server@DOMAIN.BU.EDU
4 RestrictedKrbHost/server@DOMAIN.BU.EDU
4 RestrictedKrbHost/server.bu.edu@DOMAIN.BU.EDU
4 RestrictedKrbHost/server.bu.edu@DOMAIN.BU.EDU
[root@server sssd]# kvno 'host/server.bu.edu@DOMAIN.BU.EDU'
host/server.bu.edu@DOMAIN.BU.EDU: kvno = 4
[root@server sssd]# klist
Ticket cache: KCM:0
Default principal: nik@DOMAIN.BU.EDU
Valid starting Expires Service principal
02/23/2021 12:50:18 02/23/2021 22:50:18 krbtgt/DOMAIN.BU.EDU@DOMAIN.BU.EDU
renew until 03/02/2021 12:50:15
02/23/2021 12:50:37 02/23/2021 22:50:18 host/server.bu.edu@DOMAIN.BU.EDU
When I KRB5_TRACE=/dev/stdout that kvno command then I see that the client uses the TGT to make an authenticated call to get the service ticket. But in SSSD when the ldap_client runs the second time to get the host/server.bu.edu service ticket it makes an unauthenticated call and doesn’t seem to be using the krb5tgt previously returned. Am I missing something about the use of the credential cache (/var/lib/sss/db/ccache_DOMAIN.BU.EDU) for this second call that’s causing things to break?
I don’t have a good sense of how things should work, and comparing with the working 1.9 shows that there’s no use of the host/server.bu.edu@DOMAIN.BU.EDU service ticket at all for password based authentication.
Does somebody who has this working at the 2.3 level have a good sense of how things should look normally so I can figure out where I’m going off the rails here?
Thanks.
-nik
Nik Conwell | Manager, Systems Engineering Boston University Information Services & Technology nik@bu.edu | 617.353.8274 | bu.edu/tech
sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/ List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines List Archives: https://lists.fedorahosted.org/archives/list/sssd-users@lists.fedorahosted.o... Do not reply to spam on the list, report it: https://pagure.io/fedora-infrastructure
Thanks Justin, very prescient. 😊
After looking through the logs it looks like we have a subdomain(?) or possibly our root domain(?) that is being automatically discovered which is causing a search for the host key and possibly is presenting some domain confusion as it is trying to request a TGT for that domain, but since the host is not joined to that domain the default host key is not working.
I have added the ad_enabled_domains to set the specific domain we are joined to and that seems to work OK and I can log in via password now. Aparently SSSD 2.X is much better at discovering domains than 1.16.
Thanks again for your help, much appreciated!
-nik
-----Original Message----- From: Justin Stephenson jstephen@redhat.com Sent: Tuesday, February 23, 2021 3:04 PM To: End-user discussions about the System Security Services Daemon <sssd- users@lists.fedorahosted.org> Subject: [SSSD-users] Re: SSSD-AD Password auth at 2.3 level (CentOS 8)?
Hi,
You are right, the question is why does a second ldap child get forked
- the /var/log/sssd/domain_$domain.log should give some clues. As a guess
you may need to set `ad_enabled_domains = domain.bu.edu' in sssd.conf to disable auto discovery of trusted domains. If this doesn't help please send me the sanitized domain log directly and I can take a look.
-Justin
sssd-users@lists.fedorahosted.org