Hi,
We are running into some SSSD authentication issues and would really appreciate any advice. Here’s some background:
Until now, all CentOS machines which use SSSD were joined to the same domain that also holds all user’s along with their respective groups. Let’s call this abc.xyz.local. Now, due to some compliance issue, we cannot have these Linux computer accounts in “abc” domain, and need to be moved to another domain called “def.xyz.local”. User’s / Groups who would be accessing these servers are unchanged and continue to be part of abc.xyz.local.
“xyz.local” is the forest whereas both “abc” & “def” are child domains with bi-directional trust. Was able to successfully join this machine to “def” domain. ad_access_filter and other SSSD configurations are kept the same except domains, ad_server, krb5_realm, ldap_uri which all point to the “DEF” domain now.
But when trying to authenticate, we get the following under /var/log/secure:
Jun 27 12:58:48 sshd[15716]: pam_sss(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost= user=first.last@ABC.XYZ.LOCAL Jun 27 12:58:48 sshd[15716]: pam_sss(sshd:auth): received for user first.last@ABC.XYZ.LOCAL: 6 (Permission denied)
From the logs, it looks like SSSD was able to change request domain from “def” to “abc” and was able to locate the OU where the user’s reside, but could not get any further.
Also, “id” commands returns only a default group of “domain users” instead of all the groups this user is member of in “ABC” domain. [root@]# id first.last@ABC.XYZ.LOCAL Uid=xxxxxxxxx(first.last@abc.xyz.local) gid=yyyyyyyyy(first.last@abc.xyz.local) groups=yyyyyyyyy(first.last@abc.xyz.local),xxxxxxxxx(domain users@abc.xyz.local)
Tried changing the ldap_user_search_base to dc=xyz,dc=local but still same results.
SSSD Configuration:
[sssd] domains = DEF.XYZ.LOCAL services = nss, pam, sudo config_file_version = 2 debug_level = 10 [nss] [pam] [sudo] debug_level=10 [domain/def.xyz.local] debug_level=10 ad_server = AD-Server.def.xyz.local id_provider = ad auth_provider = ad access_provider = ad sudo_provider = ad ldap_use_tokengroups = False krb5_realm = DEF.XYZ.LOCAL ldap_uri = ldap://<AD-Server>.def.xyz.local ldap_sudo_search_base = ......................... dc=abc,dc=xyz,dc=local ldap_user_search_base = dc=xyz,dc=local ldap_group_search_base = ........................ dc=abc,dc=xyz,dc=local ldap_access_order = filter, expire ad_access_filter = ... cache_credentials = true override_homedir = /home/%d/%u default_shell = /bin/bash
krb5.conf:
[logging] default = FILE:/var/log/krb5libs.log kdc = FILE:/var/log/krb5kdc.log admin_server = FILE:/var/log/kadmind.log [libdefaults] default_realm = DEF.XYZ.LOCAL dns_lookup_realm = true dns_lookup_kdc = true ticket_lifetime = 24h renew_lifetime = 7d forwardable = yes [realms] DEF.XYZ.LOCAL = { kdc = AD-Server.def.xyz.local:88 admin_server = AD-Server.def.xyz.local:749 } [domain_realm] .def.xyz.local = DEF.XYZ.LOCAL def.xyz.local = DEF.XYZ.LOCAL
Here is sssd_domain log set to level 10. Captured during authentication.
(Tue Jun 27 10:40:48 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): commit ldb transaction (nesting: 0) (Tue Jun 27 10:40:48 2017) [sssd[be[def.xyz.local]]] [sdap_sudo_full_refresh_done] (0x0400): Successful full refresh of sudo rules (Tue Jun 27 10:40:48 2017) [sssd[be[def.xyz.local]]] [be_ptask_done] (0x0400): Task [SUDO Full Refresh]: finished successfully (Tue Jun 27 10:40:48 2017) [sssd[be[def.xyz.local]]] [be_ptask_schedule] (0x0400): Task [SUDO Full Refresh]: scheduling task 21600 seconds from last execution time [1498596048] (Tue Jun 27 10:40:48 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] (0x2000): Trace: sh[0x11101b0], connected[1], ops[(nil)], ldap[0x1111cf0] (Tue Jun 27 10:40:48 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! (Tue Jun 27 10:40:57 2017) [sssd[be[def.xyz.local]]] [sbus_dispatch] (0x4000): dbus conn: 0x10b2500 (Tue Jun 27 10:40:57 2017) [sssd[be[def.xyz.local]]] [sbus_dispatch] (0x4000): Dispatching. (Tue Jun 27 10:40:57 2017) [sssd[be[def.xyz.local]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.service.ping on path /org/freedesktop/sssd/service (Tue Jun 27 10:40:57 2017) [sssd[be[def.xyz.local]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sbus_dispatch] (0x4000): dbus conn: 0x1109eb0 (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sbus_dispatch] (0x4000): Dispatching. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path /org/freedesktop/sssd/dataprovider (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [be_get_account_info] (0x0200): Got request for [0x3][BE_REQ_INITGROUPS][1][name=first.last] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [be_req_set_domain] (0x0400): Changing request domain from [def.xyz.local] to [abc.xyz.local] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_id_op_connect_step] (0x4000): beginning to connect (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD_GC' (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [get_server_status] (0x1000): Status of server 'AD_Server.def.xyz.local' is 'working' (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [get_port_status] (0x1000): Port status of port 0 for server 'AD_Server.def.xyz.local' is 'neutral' (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [get_server_status] (0x1000): Status of server 'AD_Server.def.xyz.local' is 'working' (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [be_resolve_server_process] (0x0200): Found address for server AD_Server.def.xyz.local: [x.x.x.x] TTL 3600 (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://AD_Server.def.xyz.local' (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [ad_resolve_callback] (0x0100): Constructed GC uri 'ldap://AD_Server.def.xyz.local:3268' (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sss_ldap_init_send] (0x4000): Using file descriptor [22] for LDAP connection. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://AD_Server.def.xyz.local:3268/??base] with fd [22]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_rootdse_send] (0x4000): Getting rootdse (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_print_server] (0x2000): Searching x.x.x.x (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. ... (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_op_add] (0x2000): New operation 1 timeout 6 (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] (0x2000): Trace: sh[0x1137ec0], connected[1], ops[0x111dcf0], ldap[0x11338c0] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_parse_entry] (0x1000): OriginalDN: []. ... (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_op_destructor] (0x2000): Operation 1 finished (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_rootdse_done] (0x2000): Got rootdse (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_server_opts_from_rootdse] (0x4000): USN value: 28129115 (int: 28129115) (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [6] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, HOSTNAME$, def.xyz.LOCAL, 86400) (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service AD (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [get_server_status] (0x1000): Status of server 'AD_Server.def.xyz.local' is 'working' (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [get_port_status] (0x1000): Port status of port 0 for server 'AD_Server.def.xyz.local' is 'working' (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [get_server_status] (0x1000): Status of server 'AD_Server.def.xyz.local' is 'working' (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [be_resolve_server_process] (0x0200): Found address for server AD_Server.def.xyz.local: [x.x.x.x] TTL 3600 (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 53 (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [14482] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [child_handler_setup] (0x2000): Signal handler set up for pid [14482] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] (0x2000): Trace: sh[0x1137ec0], connected[1], ops[(nil)], ldap[0x11338c0] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [write_pipe_handler] (0x0400): All data has been sent! (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [read_pipe_handler] (0x0400): EOF received, client finished (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_def.xyz.LOCAL], expired on [1498610460] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1498575360 (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: HOSTNAME$ (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [child_sig_handler] (0x1000): Waiting for child [14482]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [child_sig_handler] (0x0100): child [14482] finished successfully. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_cli_connect_recv] (0x0400): Connection established. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [_be_fo_set_port_status] (0x8000): Setting status: PORT_WORKING. Called from: src/providers/ldap/sdap_async_connection.c: sdap_cli_connect_recv: 2054 (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'AD_Server.def.xyz.local' as 'working' (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [set_server_common_status] (0x0100): Marking server 'AD_Server.def.xyz.local' as 'working' (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [fo_set_port_status] (0x0400): Marking port 0 of duplicate server 'AD_Server.def.xyz.local' as 'working' (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_id_op_connect_done] (0x2000): Old USN: 28129111, New USN: 28129115 (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_id_op_connect_done] (0x4000): notify connected to op #1 (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_initgr_send] (0x4000): Retrieving info for initgroups call (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_initgr_next_base] (0x0400): Searching for users with base [dc=abc,dc=xyz,dc=local] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_print_server] (0x2000): Searching x.x.x.x (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(sAMAccountName=first.last)(objectclass=user)(objectSID=*))][dc=abc,dc=xyz,dc=local]. ... (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 5 (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_op_add] (0x2000): New operation 5 timeout 6 (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_id_op_connect_done] (0x4000): caching successful connection after 1 notifies (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [be_run_unconditional_online_cb] (0x4000): List of unconditional online callbacks is empty, nothing to do. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] (0x2000): Trace: sh[0x1137ec0], connected[1], ops[0x1138340], ldap[0x11338c0] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_parse_entry] (0x1000): OriginalDN: [CN=first last,OU=Users, OU=company,DC=abc,DC=xyz,DC=local]. ... (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] (0x2000): Trace: sh[0x1137ec0], connected[1], ops[0x1138340], ldap[0x11338c0] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_op_destructor] (0x2000): Operation 5 finished (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_initgr_user] (0x4000): Receiving info for the user (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): start ldb transaction (nesting: 0) (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_initgr_user] (0x4000): Storing the user (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_save_user] (0x0400): Save user (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_primary_name] (0x0400): Processing object first.last@abc.xyz.local (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_save_user] (0x0400): Processing user first.last@abc.xyz.local (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_save_user] (0x1000): Mapping user [first.last@abc.xyz.local] objectSID [S-1-5-21-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx] to unix ID (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_save_user] (0x2000): Adding originalDN [CN=first last,OU=Users,OU=ITSS,OU=xyz Teams,OU=Offices,OU=United States,OU=company,DC=abc,DC=xyz,DC=local] to attributes of [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_save_user] (0x0400): Adding original memberOf attributes to [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding original mod-Timestamp [20170622141237.0Z] to attributes of [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_save_user] (0x0400): Adding user principal [first.last@company.COM] to attributes of [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowLastChange is not available for [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMin is not available for [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMax is not available for [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowWarning is not available for [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowInactive is not available for [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowExpire is not available for [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowFlag is not available for [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): krbLastPwdChange is not available for [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): krbPasswordExpiration is not available for [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): pwdAttribute is not available for [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedService is not available for [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): adAccountExpires is not available for [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding adUserAccountControl [512] to attributes of [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): nsAccountLock is not available for [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedHost is not available for [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginDisabled is not available for [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginExpirationTime is not available for [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginAllowedTimeMap is not available for [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): sshPublicKey is not available for [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): authType is not available for [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] (0x2000): userCertificate is not available for [first.last@abc.xyz.local]. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sysdb_attrs_get_aliases] (0x2000): Domain is case-insensitive; will add lowercased aliases (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_save_user] (0x0400): Storing info for user first.last@abc.xyz.local (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): start ldb transaction (nesting: 1)
(Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_initgr_user] (0x4000): Process user's groups (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_initgr_rfc2307bis_next_base] (0x0400): Searching for parent groups for user [CN=first last,OU=Users,OU=ITSS,OU=xyz Teams,OU=company,DC=abc,DC=xyz,DC=local] with base [dc=abc,dc=xyz,dc=local] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_print_server] (0x2000): Searching x.x.x.x (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(member=CN=first\20last,OU=Users,OU=ITSS,OU=xyz\20Teams,OU=company,DC=abc,DC=xyz,DC=local)(objectClass=group)(sAMAccountName=*)(objectSID=*))][dc=abc,dc=xyz,dc=local]. ... (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 6 (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_op_add] (0x2000): New operation 6 timeout 6 (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] (0x2000): Trace: sh[0x1137ec0], connected[1], ops[0x114c300], ldap[0x11338c0] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] (0x2000): Trace: sh[0x1137ec0], connected[1], ops[0x114c300], ldap[0x11338c0] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_parse_entry] (0x1000): OriginalDN: [CN=def Administrators,OU=Universal Groups,OU=Groups,OU=company,DC=abc,DC=xyz,DC=local]. ... (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_parse_range] (0x2000): No sub-attributes for [groupType] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] (0x2000): Trace: sh[0x1137ec0], connected[1], ops[0x114c300], ldap[0x11338c0] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_generic_op_finished] (0x2000): Total count [0] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_op_destructor] (0x2000): Operation 6 finished (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_initgr_rfc2307bis_process] (0x1000): Found 1 parent groups for user [first.last@abc.xyz.local] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [rfc2307bis_nested_groups_send] (0x2000): About to process 1 groups in nesting level 0 (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_primary_name] (0x0400): Processing object def Administrators@abc.xyz.local (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [rfc2307bis_nested_groups_step] (0x1000): Processing group [def Administrators@abc.xyz.local] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [rfc2307bis_nested_groups_next_base] (0x0400): Searching for parent groups of group [CN=def Administrators,OU=Universal Groups,OU=Groups,OU=company,DC=abc,DC=xyz,DC=local] with base [dc=abc,dc=xyz,dc=local] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_print_server] (0x2000): Searching x.x.x.x ... (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_op_add] (0x2000): New operation 7 timeout 6 (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] (0x2000): Trace: sh[0x1137ec0], connected[1], ops[0x114aa40], ldap[0x11338c0] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] (0x2000): Trace: sh[0x1137ec0], connected[1], ops[0x114aa40], ldap[0x11338c0] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_get_generic_op_finished] (0x2000): Total count [0] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_op_destructor] (0x2000): Operation 7 finished (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [rfc2307bis_nested_groups_process] (0x1000): Found 0 parent groups of [CN=def Administrators,OU=Universal Groups,OU=Groups,OU=All US abcorate Offices,OU=United States,OU=company,DC=abc,DC=xyz,DC=local] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sysdb_get_direct_parents] (0x2000): searching sysdb with filter [(&(objectClass=group)(member=name=def\20Administrators@abc.xyz.local,cn=groups,cn=abc.xyz.local,cn=sysdb))] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sysdb_get_direct_parents] (0x1000): def Administrators@abc.xyz.local is a member of 0 sysdb groups (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [save_rfc2307bis_user_memberships] (0x1000): Save parent groups to sysdb (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): start ldb transaction (nesting: 1) (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sysdb_get_direct_parents] (0x2000): searching sysdb with filter [(&(objectClass=group)(member=name=first.last@abc.xyz.local,cn=users,cn=abc.xyz.local,cn=sysdb))] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sysdb_get_direct_parents] (0x1000): first.last@abc.xyz.local is a member of 1 sysdb groups (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [save_rfc2307bis_user_memberships] (0x2000): Updating memberships for first.last@abc.xyz.local (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): commit ldb transaction (nesting: 0) (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] (0x2000): Trace: sh[0x1137ec0], connected[1], ops[(nil)], ldap[0x11338c0] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sbus_dispatch] (0x4000): dbus conn: 0x1109eb0 (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sbus_dispatch] (0x4000): Dispatching. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.pamHandler on path /org/freedesktop/sssd/dataprovider (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [be_req_set_domain] (0x0400): Changing request domain from [def.xyz.local] to [abc.xyz.local] (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [be_pam_handler] (0x0100): Got request with the following data ... (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [krb5_auth_queue_send] (0x1000): Wait queue of user [first.last@abc.xyz.local] is empty, running request [0x1136800] immediately. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [krb5_setup] (0x4000): No mapping for: first.last@abc.xyz.local
Are we missing any component in SSSD config which allows for such transitions? Or does it looks like something broken in the join itself?
[root@ ~]# net ads testjoin Join is OK
[root@ ~]# net ads info LDAP server: x.x.x.x LDAP server name: AD-Server.def.xyz.local Realm: DEF.XYZ.LOCAL Bind Path: dc=DEF,dc=XYZ,dc=LOCAL LDAP port: 389 Server time: Tue, 27 Jun 2017 13:13:47 EDT KDC server: x.x.x.x Server time offset: 0 Last machine account password change: Tue, 27 Jun 2017 10:09:01 EDT
Thanks,
~ Abhi
On Tue, Jun 27, 2017 at 01:35:18PM -0400, Abhijit Tikekar wrote:
Hi,
We are running into some SSSD authentication issues and would really appreciate any advice. Here’s some background:
Until now, all CentOS machines which use SSSD were joined to the same domain that also holds all user’s along with their respective groups. Let’s call this abc.xyz.local. Now, due to some compliance issue, we cannot have these Linux computer accounts in “abc” domain, and need to be moved to another domain called “def.xyz.local”. User’s / Groups who would be accessing these servers are unchanged and continue to be part of abc.xyz.local.
“xyz.local” is the forest whereas both “abc” & “def” are child domains with bi-directional trust. Was able to successfully join this machine to “def” domain. ad_access_filter and other SSSD configurations are kept the same except domains, ad_server, krb5_realm, ldap_uri which all point to the “DEF” domain now.
But when trying to authenticate, we get the following under /var/log/secure:
Jun 27 12:58:48 sshd[15716]: pam_sss(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost= user=first.last@ABC.XYZ.LOCAL Jun 27 12:58:48 sshd[15716]: pam_sss(sshd:auth): received for user first.last@ABC.XYZ.LOCAL: 6 (Permission denied)
This sounds like GPO access control prevented you from logging in.
Can you (just for a test!) please set either: ad_gpo_access_control = permissive or even: access_provider = permit
and see if the issue persists?
From the logs, it looks like SSSD was able to change request domain from “def” to “abc” and was able to locate the OU where the user’s reside, but could not get any further.
Also, “id” commands returns only a default group of “domain users” instead of all the groups this user is member of in “ABC” domain. [root@]# id first.last@ABC.XYZ.LOCAL Uid=xxxxxxxxx(first.last@abc.xyz.local) gid=yyyyyyyyy(first.last@abc.xyz.local) groups=yyyyyyyyy(first.last@abc.xyz.local),xxxxxxxxx(domain users@abc.xyz.local)
Tried changing the ldap_user_search_base to dc=xyz,dc=local but still same results.
SSSD Configuration:
[sssd] domains = DEF.XYZ.LOCAL services = nss, pam, sudo config_file_version = 2 debug_level = 10 [nss] [pam] [sudo] debug_level=10 [domain/def.xyz.local] debug_level=10 ad_server = AD-Server.def.xyz.local id_provider = ad auth_provider = ad access_provider = ad sudo_provider = ad ldap_use_tokengroups = False
Why exactly did you disable tokengroups?
krb5_realm = DEF.XYZ.LOCAL ldap_uri = ldap://<AD-Server>.def.xyz.local ldap_sudo_search_base = ......................... dc=abc,dc=xyz,dc=local ldap_user_search_base = dc=xyz,dc=local ldap_group_search_base = ........................ dc=abc,dc=xyz,dc=local ldap_access_order = filter, expire
Same here, can you test with a more vanilla configuration, removing anything that starts with ldap_ (unless you had a reason to set those) ?
Point being, the AD provider normally has the defaults set sensibly enough, so there shouldn't be any point in overriding the AD config..
ad_access_filter = ... cache_credentials = true override_homedir = /home/%d/%u default_shell = /bin/bash
krb5.conf:
[logging] default = FILE:/var/log/krb5libs.log kdc = FILE:/var/log/krb5kdc.log admin_server = FILE:/var/log/kadmind.log [libdefaults] default_realm = DEF.XYZ.LOCAL dns_lookup_realm = true dns_lookup_kdc = true ticket_lifetime = 24h renew_lifetime = 7d forwardable = yes [realms] DEF.XYZ.LOCAL = { kdc = AD-Server.def.xyz.local:88 admin_server = AD-Server.def.xyz.local:749 } [domain_realm] .def.xyz.local = DEF.XYZ.LOCAL def.xyz.local = DEF.XYZ.LOCAL
Here is sssd_domain log set to level 10. Captured during authentication.
Thank you for the logs, but I don't think the logs are complete, is there anything after:
(Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [krb5_auth_queue_send] (0x1000): Wait queue of user [first.last@abc.xyz.local] is empty, running request [0x1136800] immediately. (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [krb5_setup] (0x4000): No mapping for: first.last@abc.xyz.local
Hi Jakub,
Thanks for the response.
After enabling ldap_use_tokengroups = true, "id" command is now able to retrieve all the group memberships for that user. But Authentication still doesn't work.
Also tried setting ad_gpo_access_control = permissive / access_provider = permit but that didn't help.
I am attaching both krb5_child.log and sssd_domain.log ( Both with Logon level 10) here. These were captures during the authentication attempt.
Thanks,
~ Abhi
On Tue, Jun 27, 2017 at 2:39 PM, Jakub Hrozek jhrozek@redhat.com wrote:
On Tue, Jun 27, 2017 at 01:35:18PM -0400, Abhijit Tikekar wrote:
Hi,
We are running into some SSSD authentication issues and would really
appreciate any advice. Here’s some background:
Until now, all CentOS machines which use SSSD were joined to the same
domain that also holds all user’s along with their respective groups. Let’s call this abc.xyz.local. Now, due to some compliance issue, we cannot have these Linux computer accounts in “abc” domain, and need to be moved to another domain called “def.xyz.local”. User’s / Groups who would be accessing these servers are unchanged and continue to be part of abc.xyz.local.
“xyz.local” is the forest whereas both “abc” & “def” are child domains
with bi-directional trust. Was able to successfully join this machine to “def” domain. ad_access_filter and other SSSD configurations are kept the same except domains, ad_server, krb5_realm, ldap_uri which all point to the “DEF” domain now.
But when trying to authenticate, we get the following under
/var/log/secure:
Jun 27 12:58:48 sshd[15716]: pam_sss(sshd:auth): authentication
failure; logname= uid=0 euid=0 tty=ssh ruser= rhost= user=first.last@ABC.XYZ.LOCAL
Jun 27 12:58:48 sshd[15716]: pam_sss(sshd:auth): received for user
first.last@ABC.XYZ.LOCAL: 6 (Permission denied)
This sounds like GPO access control prevented you from logging in.
Can you (just for a test!) please set either: ad_gpo_access_control = permissive or even: access_provider = permit
and see if the issue persists?
From the logs, it looks like SSSD was able to change request domain
from “def” to “abc” and was able to locate the OU where the user’s reside, but could not get any further.
Also, “id” commands returns only a default group of “domain users”
instead of all the groups this user is member of in “ABC” domain.
[root@]# id first.last@ABC.XYZ.LOCAL Uid=xxxxxxxxx(first.last@abc.xyz.local) gid=yyyyyyyyy(first.last@abc.xyz.local)
groups=yyyyyyyyy(first.last@abc.xyz.local),xxxxxxxxx(domain users@abc.xyz.local)
Tried changing the ldap_user_search_base to dc=xyz,dc=local but still
same results.
SSSD Configuration:
[sssd] domains = DEF.XYZ.LOCAL services = nss, pam, sudo config_file_version = 2 debug_level = 10 [nss] [pam] [sudo] debug_level=10 [domain/def.xyz.local] debug_level=10 ad_server = AD-Server.def.xyz.local id_provider = ad auth_provider = ad access_provider = ad sudo_provider = ad ldap_use_tokengroups = False
Why exactly did you disable tokengroups?
krb5_realm = DEF.XYZ.LOCAL ldap_uri = ldap://<AD-Server>.def.xyz.local ldap_sudo_search_base = .........................
dc=abc,dc=xyz,dc=local
ldap_user_search_base = dc=xyz,dc=local ldap_group_search_base = ........................
dc=abc,dc=xyz,dc=local
ldap_access_order = filter, expire
Same here, can you test with a more vanilla configuration, removing anything that starts with ldap_ (unless you had a reason to set those) ?
Point being, the AD provider normally has the defaults set sensibly enough, so there shouldn't be any point in overriding the AD config..
ad_access_filter = ... cache_credentials = true override_homedir = /home/%d/%u default_shell = /bin/bash
krb5.conf:
[logging] default = FILE:/var/log/krb5libs.log kdc = FILE:/var/log/krb5kdc.log admin_server = FILE:/var/log/kadmind.log [libdefaults] default_realm = DEF.XYZ.LOCAL dns_lookup_realm = true dns_lookup_kdc = true ticket_lifetime = 24h renew_lifetime = 7d forwardable = yes [realms] DEF.XYZ.LOCAL = { kdc = AD-Server.def.xyz.local:88 admin_server = AD-Server.def.xyz.local:749 } [domain_realm] .def.xyz.local = DEF.XYZ.LOCAL def.xyz.local = DEF.XYZ.LOCAL
Here is sssd_domain log set to level 10. Captured during
authentication.
Thank you for the logs, but I don't think the logs are complete, is there anything after:
(Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]]
[krb5_auth_queue_send] (0x1000): Wait queue of user [first.last@abc.xyz.local] is empty, running request [0x1136800] immediately.
(Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [krb5_setup]
(0x4000): No mapping for: first.last@abc.xyz.local _______________________________________________ sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org
On (28/06/17 16:51), Abhijit Tikekar wrote:
Hi Jakub,
Thanks for the response.
After enabling ldap_use_tokengroups = true, "id" command is now able to retrieve all the group memberships for that user. But Authentication still doesn't work.
Also tried setting ad_gpo_access_control = permissive / access_provider = permit but that didn't help.
I am attaching both krb5_child.log and sssd_domain.log ( Both with Logon level 10) here. These were captures during the authentication attempt.
Logs are not from the same time. There is 8 minutes between authentication attempt an krb5_child.log.
But I smell a crash in krb5_child.log
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] [sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.720777: Requesting tickets for host/hostname.def.xyz.local@ABC.XYZ.LOCAL, +referrals on (Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] [sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.720845: Generated subkey for TGS request: aes256-cts/D868 (Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] [sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.720891: etypes requested in TGS request: aes256-cts, aes128-cts, +des3-cbc-sha1, rc4-hmac (Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] [sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.721078: Sending request (1750 bytes) to ABC.XYZ.LOCAL (Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [main] (0x0400): krb5_child started. (Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [unpack_buffer] (0x1000): total buffer size: [181]
Because I would expect different messages at the end "16:02:27" and we can see only that new child started.
LS
On Wed, Jun 28, 2017 at 11:09:38PM +0200, Lukas Slebodnik wrote:
On (28/06/17 16:51), Abhijit Tikekar wrote:
Hi Jakub,
Thanks for the response.
After enabling ldap_use_tokengroups = true, "id" command is now able to retrieve all the group memberships for that user. But Authentication still doesn't work.
Also tried setting ad_gpo_access_control = permissive / access_provider = permit but that didn't help.
I am attaching both krb5_child.log and sssd_domain.log ( Both with Logon level 10) here. These were captures during the authentication attempt.
Logs are not from the same time. There is 8 minutes between authentication attempt an krb5_child.log.
But I smell a crash in krb5_child.log
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] [sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.720777: Requesting tickets for host/hostname.def.xyz.local@ABC.XYZ.LOCAL, +referrals on (Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] [sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.720845: Generated subkey for TGS request: aes256-cts/D868 (Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] [sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.720891: etypes requested in TGS request: aes256-cts, aes128-cts, +des3-cbc-sha1, rc4-hmac (Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] [sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.721078: Sending request (1750 bytes) to ABC.XYZ.LOCAL (Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [main] (0x0400): krb5_child started. (Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [unpack_buffer] (0x1000): total buffer size: [181]
Because I would expect different messages at the end "16:02:27" and we can see only that new child started.
Yes, either a crash, or the back end killed the krb5_child because of a timeout. This could be seen in the matching domain log --either you would see that the child was killed by signal 6 or 11 or similar (=crash) or you would see that the child was killed by the back end due to a time out.
sssd-users@lists.fedorahosted.org