#2330 compare_principal_realm failed
Closed: Invalid None Opened 9 years ago by cmatheson.

I'm trying to get my computer to authenticate against AD with pam_sss, but I'm getting the error: "krb5_auth_send] (0x0040): compare_principal_realm failed. "getent password whoever@corp.example.com" is working great. I was directed to file a bug in #sssd. Config files and Logs below (I used realm to generate the sssd config/join the domain/etc). Let me know if any other info is needed.

(I'm running sssd 1.11.5.1 on Arch Linux)

sssd.conf:

[sssd]
domains = corp.example.com
config_file_version = 2
services = nss, pam
debug_level = 3

[pam]
debug_level = 3
pam_verbosity = 3

[domain/corp.example.com]
debug_level = 7
ad_domain = corp.example.com
krb5_realm = CORP.EXAMPLE.COM
realmd_tags = manages-system joined-with-samba
cache_credentials = True
id_provider = ad
krb5_store_password_if_offline = True
default_shell = /bin/bash
ldap_id_mapping = True
use_fully_qualified_names = True
fallback_homedir = /home/%d/%u
access_provider = ad

Logs when running su - me@corp.example.com:

syslog:

May 07 15:28:27 me-laptop su[19211]: pam_sss(su-l:auth): received for user me@corp.example.com: 4 (System error)
May 07 15:28:27 me-laptop su[19211]: pam_sss(su-l:auth): authentication failure; logname=c uid=1000 euid=0 tty=pts/9 ruser=c rhost= user=me@corp.example.com

/var/log/sssd/sssd_corp.example.com.log:

(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [be_get_account_info] (0x0100): Got request for [3][1][name=me]
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [be_req_set_domain] (0x0400): Changing request domain from [corp.example.com] to [corp.example.com]
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD_GC'
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [get_server_status] (0x1000): Status of server 'it-dc01.corp.example.com' is 'working'
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [get_port_status] (0x1000): Port status of port 3268 for server 'it-dc01.corp.example.com' is 'working'
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [get_server_status] (0x1000): Status of server 'it-dc01.corp.example.com' is 'working'
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [be_resolve_server_process] (0x0200): Found address for server it-dc01.corp.example.com: [10.0.34.16] TTL 3600
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://it-dc02.corp.example.com:389/??base] with fd [21].
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][].
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*]
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer]
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts]
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl]
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension]
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures]
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion]
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms]
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality]
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext]
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN]
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN]
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [4]
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, me-LAPTOP$, CORP.example.COM, 86400)
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service AD
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD'
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [get_server_status] (0x1000): Status of server 'it-dc02.corp.example.com' is 'working'
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [get_port_status] (0x1000): Port status of port 389 for server 'it-dc02.corp.example.com' is 'working'
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [get_server_status] (0x1000): Status of server 'it-dc02.corp.example.com' is 'working'
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [be_resolve_server_process] (0x0200): Found address for server it-dc02.corp.example.com: [10.0.34.17] TTL 3600
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT...
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 51
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child
(Wed May  7 15:28:26 2014) [sssd[be[corp.example.com]]] [write_pipe_handler] (0x0400): All data has been sent!
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [read_pipe_handler] (0x0400): EOF received, client finished
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_CORP.EXAMPLE.COM], expired on [1399534107]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1399499007
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: me-LAPTOP$
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [child_sig_handler] (0x1000): Waiting for child [19212].
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [child_sig_handler] (0x0100): child [19212] finished successfully.
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [fo_set_port_status] (0x0100): Marking port 3268 of server 'it-dc01.corp.example.com' as 'working'
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [set_server_common_status] (0x0100): Marking server 'it-dc01.corp.example.com' as 'working'
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [ad_user_data_cmp] (0x1000): Comparing GC with GC
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [fo_set_port_status] (0x0400): Marking port 3268 of duplicate server 'it-dc01.corp.example.com' as 'working'
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [ad_user_data_cmp] (0x1000): Comparing GC with GC
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [ad_user_data_cmp] (0x1000): Comparing GC with GC
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_initgr_next_base] (0x0400): Searching for users with base [DC=corp,DC=example,DC=com]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(sAMAccountName=me)(objectclass=user)(objectSID=*))][DC=corp,DC=example,DC=com].
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_save_user] (0x0400): Save user
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_primary_name] (0x0400): Processing object me
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_save_user] (0x0400): Processing user me
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_save_user] (0x1000): Mapping user [me] objectSID [S-1-5-21-3322822159-133036858-2408800093-2302] to unix ID
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_save_user] (0x0400): Adding original memberOf attributes to [me].
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_save_user] (0x0400): Adding user principal [me] to attributes of [me].
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_save_user] (0x0400): Storing info for user me
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD'
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [get_server_status] (0x1000): Status of server 'it-dc02.corp.example.com' is 'working'
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [get_port_status] (0x1000): Port status of port 389 for server 'it-dc02.corp.example.com' is 'working'
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [get_server_status] (0x1000): Status of server 'it-dc02.corp.example.com' is 'working'
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [be_resolve_server_process] (0x0200): Found address for server it-dc02.corp.example.com: [10.0.34.17] TTL 3600
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://it-dc02.corp.example.com:389/??base] with fd [22].
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][].
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [4]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, me-LAPTOP$, CORP.example.COM, 86400)
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service AD
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD'
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [get_server_status] (0x1000): Status of server 'it-dc02.corp.example.com' is 'working'
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [get_port_status] (0x1000): Port status of port 389 for server 'it-dc02.corp.example.com' is 'working'
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [get_server_status] (0x1000): Status of server 'it-dc02.corp.example.com' is 'working'
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [be_resolve_server_process] (0x0200): Found address for server it-dc02.corp.example.com: [10.0.34.17] TTL 3600
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT...
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 51
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [write_pipe_handler] (0x0400): All data has been sent!
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [child_sig_handler] (0x1000): Waiting for child [19213].
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [child_sig_handler] (0x0100): child [19213] finished successfully.
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [read_pipe_handler] (0x0400): EOF received, client finished
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_CORP.EXAMPLE.COM], expired on [1399534107]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1399499007
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: ME-LAPTOP$
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'it-dc02.corp.example.com' as 'working'
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [set_server_common_status] (0x0100): Marking server 'it-dc02.corp.example.com' as 'working'
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [ad_user_data_cmp] (0x1000): Comparing LDAP with LDAP
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'it-dc02.corp.example.com' as 'working'
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [ad_user_data_cmp] (0x1000): Comparing LDAP with LDAP
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [ad_user_data_cmp] (0x1000): Comparing LDAP with LDAP
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [no filter][CN=me ,OU=example Users,DC=corp,DC=example,DC=com].
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [tokenGroups]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_ad_tokengroups_initgr_mapping_done] (0x1000): Processing membership SID [S-1-5-32-545]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_idmap_sid_to_unix] (0x0400): Object SID [S-1-5-32-545] is a built-in one.
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_ad_tokengroups_initgr_mapping_done] (0x0400): Skipping built-in object.
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_ad_tokengroups_initgr_mapping_done] (0x1000): Processing membership SID [S-1-5-21-3322822159-133036858-2408800093-513]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_ad_tokengroups_initgr_mapping_done] (0x1000): SID [S-1-5-21-3322822159-133036858-2408800093-513] maps to GID [1628200513]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_ad_tokengroups_initgr_mapping_done] (0x1000): Processing membership SID [S-1-5-21-3322822159-133036858-2408800093-3102]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_ad_tokengroups_initgr_mapping_done] (0x1000): SID [S-1-5-21-3322822159-133036858-2408800093-3102] maps to GID [1628203102]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_ad_tokengroups_initgr_mapping_done] (0x1000): Processing membership SID [S-1-5-21-3322822159-133036858-2408800093-2616]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_ad_tokengroups_initgr_mapping_done] (0x1000): SID [S-1-5-21-3322822159-133036858-2408800093-2616] maps to GID [1628202616]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_ad_tokengroups_initgr_mapping_done] (0x1000): Processing membership SID [S-1-5-21-3322822159-133036858-2408800093-2623]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_ad_tokengroups_initgr_mapping_done] (0x1000): SID [S-1-5-21-3322822159-133036858-2408800093-2623] maps to GID [1628202623]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_ad_tokengroups_update_members] (0x1000): Updating memberships for [me]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [sdap_get_initgr_done] (0x1000): Mapping primary group to unix ID
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [be_req_set_domain] (0x0400): Changing request domain from [corp.example.com] to [corp.example.com]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [be_pam_handler] (0x0100): Got request with the following data
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [pam_print_data] (0x0100): command: PAM_AUTHENTICATE
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [pam_print_data] (0x0100): domain: corp.example.com
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [pam_print_data] (0x0100): user: me
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [pam_print_data] (0x0100): service: su-l
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [pam_print_data] (0x0100): tty: pts/9
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [pam_print_data] (0x0100): ruser: c
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [pam_print_data] (0x0100): rhost:
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [pam_print_data] (0x0100): authtok type: 1
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [pam_print_data] (0x0100): newauthtok type: 0
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [pam_print_data] (0x0100): priv: 0
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [pam_print_data] (0x0100): cli_pid: 19211
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [krb5_pam_handler] (0x1000): Wait queue of user [me] is empty, running request immediately.
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [krb5_auth_send] (0x0040): compare_principal_realm failed.
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [check_wait_queue] (0x1000): Wait queue for user [me] is empty.
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 4, <NULL>) [Success]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [be_pam_handler_callback] (0x0100): Sending result [4][corp.example.com]
(Wed May  7 15:28:27 2014) [sssd[be[corp.example.com]]] [be_pam_handler_callback] (0x0100): Sent result [4][corp.example.com]

/var/log/sssd/ldap_child.log

(Wed May  7 15:28:26 2014) [[sssd[ldap_child[19212]]]] [main] (0x0400): ldap_child started.
(Wed May  7 15:28:26 2014) [[sssd[ldap_child[19212]]]] [unpack_buffer] (0x1000): total buffer size: 51
(Wed May  7 15:28:26 2014) [[sssd[ldap_child[19212]]]] [unpack_buffer] (0x1000): realm_str size: 20
(Wed May  7 15:28:26 2014) [[sssd[ldap_child[19212]]]] [unpack_buffer] (0x1000): got realm_str: CORP.example.COM
(Wed May  7 15:28:26 2014) [[sssd[ldap_child[19212]]]] [unpack_buffer] (0x1000): princ_str size: 15
(Wed May  7 15:28:26 2014) [[sssd[ldap_child[19212]]]] [unpack_buffer] (0x1000): got princ_str: me-LAPTOP$
(Wed May  7 15:28:26 2014) [[sssd[ldap_child[19212]]]] [unpack_buffer] (0x1000): keytab_name size: 0
(Wed May  7 15:28:26 2014) [[sssd[ldap_child[19212]]]] [unpack_buffer] (0x1000): lifetime: 86400
(Wed May  7 15:28:26 2014) [[sssd[ldap_child[19212]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [ME-LAPTOP$@CORP.EXAMPLE.COM]
(Wed May  7 15:28:26 2014) [[sssd[ldap_child[19212]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [default]
(Wed May  7 15:28:27 2014) [[sssd[ldap_child[19212]]]] [prepare_response] (0x0400): Building response for result [0]
(Wed May  7 15:28:27 2014) [[sssd[ldap_child[19212]]]] [pack_buffer] (0x1000): result [0] krberr [0] msgsize [48] msg [FILE:/var/lib/sss/db/ccache_CORP.EXAMPLE.COM]
(Wed May  7 15:28:27 2014) [[sssd[ldap_child[19212]]]] [main] (0x0400): ldap_child completed successfully
(Wed May  7 15:28:27 2014) [[sssd[ldap_child[19213]]]] [main] (0x0400): ldap_child started.
(Wed May  7 15:28:27 2014) [[sssd[ldap_child[19213]]]] [unpack_buffer] (0x1000): total buffer size: 51
(Wed May  7 15:28:27 2014) [[sssd[ldap_child[19213]]]] [unpack_buffer] (0x1000): realm_str size: 20
(Wed May  7 15:28:27 2014) [[sssd[ldap_child[19213]]]] [unpack_buffer] (0x1000): got realm_str: CORP.example.COM
(Wed May  7 15:28:27 2014) [[sssd[ldap_child[19213]]]] [unpack_buffer] (0x1000): princ_str size: 15
(Wed May  7 15:28:27 2014) [[sssd[ldap_child[19213]]]] [unpack_buffer] (0x1000): got princ_str: me-LAPTOP$
(Wed May  7 15:28:27 2014) [[sssd[ldap_child[19213]]]] [unpack_buffer] (0x1000): keytab_name size: 0
(Wed May  7 15:28:27 2014) [[sssd[ldap_child[19213]]]] [unpack_buffer] (0x1000): lifetime: 86400
(Wed May  7 15:28:27 2014) [[sssd[ldap_child[19213]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [ME-LAPTOP$@CORP.EXAMPLE.COM]
(Wed May  7 15:28:27 2014) [[sssd[ldap_child[19213]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [default]
(Wed May  7 15:28:27 2014) [[sssd[ldap_child[19213]]]] [prepare_response] (0x0400): Building response for result [0]
(Wed May  7 15:28:27 2014) [[sssd[ldap_child[19213]]]] [pack_buffer] (0x1000): result [0] krberr [0] msgsize [48] msg [FILE:/var/lib/sss/db/ccache_CORP.EXAMPLE.COM]
(Wed May  7 15:28:27 2014) [[sssd[ldap_child[19213]]]] [main] (0x0400): ldap_child completed successfully

I added a debug statement in compare_principal_realm. My upn is 'me' (no '@ corp.example.com').

_comment0: I added a debug statement in compare_principal_realm. My upn is 'me' (no '@corp.example.com'). => 1399506750550321

It was suggested in #sssd that I add the line

ldap_user_principal = nosuchattribute

to my sssd.conf and this has fixed the problem. Closing this "bug."

Closing per previous comment.

resolution: => invalid
status: new => closed

Metadata Update from @cmatheson:
- Issue set to the milestone: NEEDS_TRIAGE

7 years ago

SSSD is moving from Pagure to Github. This means that new issues and pull requests
will be accepted only in SSSD's github repository.

This issue has been cloned to Github and is available here:
- https://github.com/SSSD/sssd/issues/3372

If you want to receive further updates on the issue, please navigate to the github issue
and click on subscribe button.

Thank you for understanding. We apologize for all inconvenience.

Login to comment on this ticket.

Metadata