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