sssd-users January 2018

sssd-users@lists.fedorahosted.org

13 participants
16 discussions

sssd performance on large domains
by zfnoctis＠gmail.com 03 Feb '22

03 Feb '22

Hi, I'm wondering if there are any plans to improve sssd performance on large active directory domains (100k+ users, 40k+ groups), or if there are settings I am not aware of that can greatly improve performance, specifically for workstation use cases. Currently if I do not set "ignore_group_members = True" in sssd.conf, logins can take upwards of 6 minutes and "sssd_be" will max the CPU for up to 20 minutes after logon, which makes it a non-starter. The reason I want to allow group members to be seen is that I want certain domain groups to be able to perform elevated actions using polkit. If I ignore group members, polkit reports that the group is empty and so no one can elevate in the graphical environment. Ultimately this means that Linux workstations are at a severe disadvantage since they cannot be bound to the domain and have the normal set of access features users and IT expect from macOS or Windows. Distributions used: Ubuntu 16.04 (sssd 1.13.4-1ubuntu1.1), Ubuntu 16.10 (sssd 1.13.4-3) and Fedora 24 (sssd-1.13.4-3.fc24). All exhibit the same problems. I've also tried "ldap_group_nesting_level = 1" without seeing any noticeable improvement with respect to performance. Putting the database on /tmp isn't viable as these are workstations that will reboot semi-frequently, and I don't believe this is an I/O bound performance issue anyways. Thanks for your time.

6 29

Enumerate users from external group from AD trust
by Bolke de Bruin 29 Nov '19

29 Nov '19

Hello, I have sssd 1.13.00 working against FreeIPA 4.2 domain. This domain has a trust relationship with a active directory domain. One of the systems we are using requires to enumerate all users in groups by (unfortunate) design (Apache Ranger). This is done by using “getent group”. During this enumeration the full user list for a group that has a nested external member group* is not always returned so we thought to add “getent group mygroup” in order to get more details. Unfortunately this does not seem to work consistently: sometimes this gives information sometimes it does not: [root@master centos]# getent group ad_users ad_users:*:1950000004: [root@master centos]# id bolke(a)ad.local UID=1796201107(bolke(a)ad.local) GID=1796201107(bolke(a)ad.local) groepen=1796201107(bolke(a)ad.local),1796200513(domain users@ad.local),1796201108(test@ad.local) [root@master centos]# getent group ad_users ad_users:*:1950000004:bolke@ad.local <mailto:bolke@ad.local> If I clear the cache (sss_cache -E) the entry is gone again: [root@master centos]# getent group ad_users ad_users:*:1950000004: My question is how do I get sssd to enumerate *all users* in a group consistently? Thanks! Bolke * https://docs.fedoraproject.org/en-US/Fedora/18/html/FreeIPA_Guide/trust-gro…

3 15

SSSD for one-way trusted AD domain
by Ondrej Valousek 15 May '18

15 May '18

Hi List, Question, we have joined machine into AD domain B. This domain has one way trust to domain A. No direct connection from domain B network to DCs in domain A is possible. Can we use SSSD to authenticate members in domain A. In windows, this works - but can't get it working in Linux via SSSD (Fedora 25, used realmd for AD join). Thanks, Ondrej ----- The information contained in this e-mail and in any attachments is confidential and is designated solely for the attention of the intended recipient(s). If you are not an intended recipient, you must not use, disclose, copy, distribute or retain this e-mail or any part thereof. If you have received this e-mail in error, please notify the sender by return e-mail and delete all copies of this e-mail from your computer system(s). Please direct any additional queries to: communications(a)s3group.com. Thank You. Silicon and Software Systems Limited (S3 Group). Registered in Ireland no. 378073. Registered Office: South County Business Park, Leopardstown, Dublin 18.

3 2

SSSD/AD Issues After 1.14 to 1.15 upgrade in CentOS 7
by Simon Engelbert 02 Feb '18

02 Feb '18

Hello, We are having issues with SSSD and SSHD after upgrading our package versions of SSSD from 1.14.0 to 1.15.2. The configurations are the same. From what we can tell the issue revolves around the keys returned by the /usr/bin/sss_ssh_authorizedkeys toolset. Our server that still has 1.14.0 returns the keys with all different permutations of the command below: /usr/bin/sss_ssh_authorizedkeys user -d DOMAIN.AD Returns keys /usr/bin/sss_ssh_authorizedkeys user Returns keys /usr/bin/sss_ssh_authorizedkeys user(a)DOMAIN.AD -d DOMAIN.AD Returns keys /usr/bin/sss_ssh_authorizedkeys user(a)DOMAIN.AD Returns keys However, our server with 1.15.2 returns keys for 2 of the permutations and fails for the other 2, and those are the 2 we believe need to function. Below are the commands and logs (redacted/altered). We have tried altering various configs around the domain and other areas but nothing seems to help. The ones that are failing seem to be finding a new domain and searching through it (PRD.AD), this is not happening in 1.14.0. Is there a way to blacklist domains? Is there a way to tell it to not search for new domains? No auto-dscovery? /usr/bin/sss_ssh_authorizedkeys user -d DOMAIN.AD Returns keys /usr/bin/sss_ssh_authorizedkeys user Returns keys (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path /org/freedesktop/sssd/dataprovider (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [dp_get_account_info_handler] (0x0200): Got request for [0x1][BE_REQ_USER][name=user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [dp_attach_req] (0x0400): DP Request [Account #1403]: New request. Flags [0x0001]. (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [dp_attach_req] (0x0400): Number of active DP request: 1 (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sss_domain_get_state] (0x1000): Domain DOMAIN.AD is Active (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sss_domain_get_state] (0x1000): Domain DOMAIN.AD is Active (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_search_user_next_base] (0x0400): Searching for users with base [DC=DOMAIN,DC=AD] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_print_server] (0x2000): Searching 170.0.0.2:389 (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(sAMAccountName=user)(objectclass=user)(sAMAccountName=*)(objectSID=*))][DC=DOMAIN,DC=AD]. (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shawUser-sshPublicKey] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userCertificate;binary] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [mail] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shawUser-sshPublicKey] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 12 (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_add] (0x2000): New operation 12 timeout 6 (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7eb7160], connected[1], ops[0x5622d7ebef10], ldap[0x5622d6c9a790] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_entry] (0x1000): OriginalDN: [CN=Simon Engelbert,OU=Non-VIP,OU=Users,OU=Accounts,OU=Corp,DC=DOMAIN,DC=AD]. (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectClass] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [whenChanged] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [memberOf] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [uSNChanged] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [name] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectGUID] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [userAccountControl] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [primaryGroupID] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectSid] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [accountExpires] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [sAMAccountName] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [mail] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [shawUser-sshPublicKey] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7eb7160], connected[1], ops[0x5622d7ebef10], ldap[0x5622d6c9a790] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_add_references] (0x1000): Additional References: ldap://DomainDnsZones.DOMAIN.AD/DC=DomainDnsZones,DC=DOMAIN,DC=AD (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7eb7160], connected[1], ops[0x5622d7ebef10], ldap[0x5622d6c9a790] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_destructor] (0x2000): Operation 12 finished (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_search_user_process] (0x0400): Search for users, returned 1 results. (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_search_user_process] (0x2000): Retrieved total 1 users (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_save_user] (0x0400): Save user (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sss_domain_get_state] (0x1000): Domain DOMAIN.AD is Active (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_primary_name] (0x0400): Processing object user (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_save_user] (0x0400): Processing user user(a)DOMAIN.ad (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_save_user] (0x1000): Mapping user [user(a)DOMAIN.ad] objectSID [S-1-5-21-1916243804-2947104764-1996252313-179441] to unix ID (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_save_user] (0x2000): Adding originalDN [CN=Simon Engelbert,OU=Non-VIP,OU=Users,OU=Accounts,OU=Corp,DC=DOMAIN,DC=AD] to attributes of [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_save_user] (0x0400): Adding original memberOf attributes to [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding original mod-Timestamp [20180122182213.0Z] to attributes of [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_save_user] (0x0400): Adding user principal [user] to attributes of [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowLastChange is not available for [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMin is not available for [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMax is not available for [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowWarning is not available for [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowInactive is not available for [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowExpire is not available for [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowFlag is not available for [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): krbLastPwdChange is not available for [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): krbPasswordExpiration is not available for [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): pwdAttribute is not available for [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedService is not available for [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding adAccountExpires [9223372036854775807] to attributes of [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding adUserAccountControl [512] to attributes of [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): nsAccountLock is not available for [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedHost is not available for [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginDisabled is not available for [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginExpirationTime is not available for [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginAllowedTimeMap is not available for [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding sshPublicKey [<redacted>] to attributes of [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding sshPublicKey [<redacted>] to attributes of [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): authType is not available for [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): userCertificate is not available for [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding mail [Simon.Engelbert(a)DOMAIN.ca] to attributes of [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding shawUser-sshPublicKey [<redacted>] to attributes of [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding shawUser-sshPublicKey [<redacted>] to attributes of [user(a)DOMAIN.ad] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sysdb_attrs_get_aliases] (0x2000): Domain is case-insensitive; will add lowercased aliases (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_save_user] (0x0400): Storing info for user user(a)DOMAIN.ad (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sysdb_search_by_name] (0x0400): No such entry (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sysdb_store_user] (0x1000): User user(a)DOMAIN.ad does not exist. (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sysdb_search_user_by_uid] (0x0400): No such entry (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sysdb_ldb_msg_difference] (0x2000): Added attr [objectSIDString] to entry [name=user(a)DOMAIN.ad,cn=users,cn=DOMAIN.AD,cn=sysdb] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sysdb_set_entry_attr] (0x0200): Entry [name=user(a)DOMAIN.ad,cn=users,cn=DOMAIN.AD,cn=sysdb] has set [cache, ts_cache] attrs. (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [dp_req_done] (0x0400): DP Request [Account #1403]: Request handler finished [0]: Success (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [_dp_req_recv] (0x0400): DP Request [Account #1403]: Receiving request data. (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [dp_req_reply_list_success] (0x0400): DP Request [Account #1403]: Finished. Success. (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [dp_req_reply_std] (0x1000): DP Request [Account #1403]: Returning [Success]: 0,0,Success (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:1::DOMAIN.AD:name=user@DOMAIN.ad] from reply table (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [dp_req_destructor] (0x0400): DP Request [Account #1403]: Request removed. (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7eb7160], connected[1], ops[(nil)], ldap[0x5622d6c9a790] (Wed Jan 31 18:26:46 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list /usr/bin/sss_ssh_authorizedkeys user(a)DOMAIN.AD -d DOMAIN.AD Error looking up public keys /usr/bin/sss_ssh_authorizedkeys user(a)DOMAIN.AD Error looking up public keys (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path /org/freedesktop/sssd/dataprovider (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_get_account_info_handler] (0x0200): Got request for [0x1][BE_REQ_USER][name=user@DOMAIN.ad@DOMAIN.ad] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_attach_req] (0x0400): DP Request [Account #1409]: New request. Flags [0x0001]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_attach_req] (0x0400): Number of active DP request: 1 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sss_domain_get_state] (0x1000): Domain DOMAIN.AD is Active (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sss_domain_get_state] (0x1000): Domain DOMAIN.AD is Active (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'ADSERVER.DOMAIN.ad' is 'working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 0 for server 'ADSERVER.DOMAIN.ad' is 'working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'ADSERVER.DOMAIN.ad' is 'working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x0200): Found address for server ADSERVER.DOMAIN.ad: [170.0.0.2] TTL 3600 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sssd_async_socket_init_send] (0x0400): Setting 6 seconds timeout for connecting (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://ADSERVER.DOMAIN.ad:389/??base] with fd [19]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_print_server] (0x2000): Searching 170.0.0.2:389 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_add] (0x2000): New operation 1 timeout 6 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7e94550], connected[1], ops[0x5622d7ebef10], ldap[0x5622d6c9a790] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_entry] (0x1000): OriginalDN: []. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [currentTime] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [subschemaSubentry] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [dsServiceName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [namingContexts] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [defaultNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [schemaNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [configurationNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [rootDomainNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedControl] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPVersion] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPPolicies] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [highestCommittedUSN] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedSASLMechanisms] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [dnsHostName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [ldapServiceName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [serverName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedCapabilities] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [isSynchronized] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [isGlobalCatalogReady] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedExtension] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [forestFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainControllerFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7e94550], connected[1], ops[0x5622d7ebef10], ldap[0x5622d6c9a790] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_destructor] (0x2000): Operation 1 finished (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_rootdse_done] (0x2000): Got rootdse (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [6] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, host/server.DOMAIN.ad, DOMAIN.AD, 86400) (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service AD (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'ADSERVER.DOMAIN.ad' is 'working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 0 for server 'ADSERVER.DOMAIN.ad' is 'working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'ADSERVER.DOMAIN.ad' is 'working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x0200): Found address for server ADSERVER.DOMAIN.ad: [170.0.0.2] TTL 3600 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 55 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [19453] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_handler_setup] (0x2000): Signal handler set up for pid [19453] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7e94550], connected[1], ops[(nil)], ldap[0x5622d6c9a790] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [write_pipe_handler] (0x0400): All data has been sent! (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [read_pipe_handler] (0x0400): EOF received, client finished (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_DOMAIN.AD], expired on [1517459477] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1517424377 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: host/server.DOMAIN.ad (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_sig_handler] (0x1000): Waiting for child [19453]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_sig_handler] (0x0100): child [19453] finished successfully. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_cli_connect_recv] (0x0400): Connection established. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'ADSERVER.DOMAIN.ad' as 'working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [set_server_common_status] (0x0100): Marking server 'ADSERVER.DOMAIN.ad' as 'working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_set_port_status] (0x0400): Marking port 0 of duplicate server 'ADSERVER.DOMAIN.ad' as 'working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_id_op_connect_done] (0x2000): Old USN: 75028237, New USN: 75031468 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_search_user_next_base] (0x0400): Searching for users with base [DC=DOMAIN,DC=AD] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_print_server] (0x2000): Searching 170.0.0.2:389 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(sAMAccountName=user@DOMAIN.ad)(objectclass=user)(sAMAccountName=*)(objectSID=*))][DC=DOMAIN,DC=AD]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shawUser-sshPublicKey] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userCertificate;binary] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [mail] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shawUser-sshPublicKey] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 5 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_add] (0x2000): New operation 5 timeout 6 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7e94550], connected[1], ops[0x5622d7e96670], ldap[0x5622d6c9a790] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_add_references] (0x1000): Additional References: ldap://DomainDnsZones.DOMAIN.AD/DC=DomainDnsZones,DC=DOMAIN,DC=AD (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7e94550], connected[1], ops[0x5622d7e96670], ldap[0x5622d6c9a790] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_destructor] (0x2000): Operation 5 finished (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_search_user_process] (0x0400): Search for users, returned 0 results. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_search_user_process] (0x2000): Retrieved total 0 users (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sysdb_search_by_name] (0x0400): No such entry (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sysdb_cache_search_groups] (0x2000): Search groups with filter: (&(objectclass=group)(ghost=user@DOMAIN.ad@DOMAIN.ad)) (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sysdb_cache_search_groups] (0x2000): No such entry (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sysdb_delete_user] (0x0400): Error: 2 (No such file or directory) (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_req_done] (0x0400): DP Request [Account #1409]: Request handler finished [0]: Success (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [_dp_req_recv] (0x0400): DP Request [Account #1409]: Receiving request data. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_req_reply_list_success] (0x0400): DP Request [Account #1409]: Finished. Success. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_req_reply_std] (0x1000): DP Request [Account #1409]: Returning [Success]: 0,0,Success (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:1::DOMAIN.AD:name=user@DOMAIN.ad@DOMAIN.ad] from reply table (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_req_destructor] (0x0400): DP Request [Account #1409]: Request removed. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7e94550], connected[1], ops[(nil)], ldap[0x5622d6c9a790] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path /org/freedesktop/sssd/dataprovider (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_get_account_info_handler] (0x0200): Got request for [0x1][BE_REQ_USER][name=user(a)DOMAIN.AD] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_attach_req] (0x0400): DP Request [Account #1410]: New request. Flags [0x0001]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_attach_req] (0x0400): Number of active DP request: 1 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sss_domain_get_state] (0x1000): Domain DOMAIN.AD is Active (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sss_domain_get_state] (0x1000): Domain DOMAIN.AD is Active (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_search_user_next_base] (0x0400): Searching for users with base [DC=DOMAIN,DC=AD] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_print_server] (0x2000): Searching 170.0.0.2:389 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(|(sAMAccountName=user@DOMAIN.AD)(mail=user@DOMAIN.AD)(sAMAccountName=user\\@DOMAIN.AD@DOMAIN.AD))(objectclass=user)(sAMAccountName=*)(objectSID=*))][DC=DOMAIN,DC=AD]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shawUser-sshPublicKey] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userCertificate;binary] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [mail] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shawUser-sshPublicKey] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 6 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_add] (0x2000): New operation 6 timeout 6 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7e94550], connected[1], ops[0x5622d7e96670], ldap[0x5622d6c9a790] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_add_references] (0x1000): Additional References: ldap://DomainDnsZones.DOMAIN.AD/DC=DomainDnsZones,DC=DOMAIN,DC=AD (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7e94550], connected[1], ops[0x5622d7e96670], ldap[0x5622d6c9a790] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_destructor] (0x2000): Operation 6 finished (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_search_user_process] (0x0400): Search for users, returned 0 results. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_search_user_process] (0x2000): Retrieved total 0 users (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_req_done] (0x0400): DP Request [Account #1410]: Request handler finished [0]: Success (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [_dp_req_recv] (0x0400): DP Request [Account #1410]: Receiving request data. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_req_reply_list_success] (0x0400): DP Request [Account #1410]: Finished. Success. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_req_reply_std] (0x1000): DP Request [Account #1410]: Returning [Success]: 0,0,Success (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:1:U:DOMAIN.AD:name=user@DOMAIN.AD] from reply table (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_req_destructor] (0x0400): DP Request [Account #1410]: Request removed. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7e94550], connected[1], ops[(nil)], ldap[0x5622d6c9a790] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path /org/freedesktop/sssd/dataprovider (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_get_account_info_handler] (0x0200): Got request for [0x1][BE_REQ_USER][name=user(a)DOMAIN.AD] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_attach_req] (0x0400): DP Request [Account #1411]: New request. Flags [0x0001]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_attach_req] (0x0400): Number of active DP request: 1 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sss_domain_get_state] (0x1000): Domain DOMAIN.AD is Active (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sss_domain_get_state] (0x1000): Domain PRD.AD is Active (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sss_domain_get_state] (0x1000): Domain DOMAIN.AD is Active (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sss_domain_get_state] (0x1000): Domain PRD.AD is Active (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sss_domain_get_state] (0x1000): Domain PRD.AD is Active (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD_GC' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'ADSERVER.DOMAIN.ad' is 'working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 0 for server 'ADSERVER.DOMAIN.ad' is 'working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'ADSERVER.DOMAIN.ad' is 'working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x0200): Found address for server ADSERVER.DOMAIN.ad: [170.0.0.2] TTL 3600 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://ADSERVER.DOMAIN.ad' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_resolve_callback] (0x0100): Constructed GC uri 'ldap://ADSERVER.DOMAIN.ad:3268' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sssd_async_socket_init_send] (0x0400): Setting 6 seconds timeout for connecting (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://ADSERVER.DOMAIN.ad:3268/??base] with fd [25]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_print_server] (0x2000): Searching 170.0.0.2:3268 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_add] (0x2000): New operation 1 timeout 6 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7e7a9a0], connected[1], ops[0x5622d7d32e90], ldap[0x5622d7d76f00] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_entry] (0x1000): OriginalDN: []. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [currentTime] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [subschemaSubentry] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [dsServiceName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [namingContexts] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [defaultNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [schemaNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [configurationNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [rootDomainNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedControl] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPVersion] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPPolicies] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [highestCommittedUSN] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedSASLMechanisms] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [dnsHostName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [ldapServiceName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [serverName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedCapabilities] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [isSynchronized] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [isGlobalCatalogReady] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedExtension] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [forestFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainControllerFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7e7a9a0], connected[1], ops[0x5622d7d32e90], ldap[0x5622d7d76f00] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_destructor] (0x2000): Operation 1 finished (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_rootdse_done] (0x2000): Got rootdse (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [6] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, host/server.DOMAIN.ad, DOMAIN.AD, 86400) (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service AD (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'ADSERVER.DOMAIN.ad' is 'working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 0 for server 'ADSERVER.DOMAIN.ad' is 'working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'ADSERVER.DOMAIN.ad' is 'working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x0200): Found address for server ADSERVER.DOMAIN.ad: [170.0.0.2] TTL 3600 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://ADSERVER.DOMAIN.ad' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_resolve_callback] (0x0100): Constructed GC uri 'ldap://ADSERVER.DOMAIN.ad' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [unique_filename_destructor] (0x2000): Unlinking [/var/lib/sss/pubconf/.krb5info_dummy_IYm1jO] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [unlink_dbg] (0x2000): File already removed: [/var/lib/sss/pubconf/.krb5info_dummy_IYm1jO] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 55 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [19454] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_handler_setup] (0x2000): Signal handler set up for pid [19454] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7e7a9a0], connected[1], ops[(nil)], ldap[0x5622d7d76f00] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [write_pipe_handler] (0x0400): All data has been sent! (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_sig_handler] (0x1000): Waiting for child [19454]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_sig_handler] (0x0100): child [19454] finished successfully. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [read_pipe_handler] (0x0400): EOF received, client finished (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_DOMAIN.AD], expired on [1517459477] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1517424377 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: host/server.DOMAIN.ad (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_cli_connect_recv] (0x0400): Connection established. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'ADSERVER.DOMAIN.ad' as 'working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [set_server_common_status] (0x0100): Marking server 'ADSERVER.DOMAIN.ad' as 'working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_set_port_status] (0x0400): Marking port 0 of duplicate server 'ADSERVER.DOMAIN.ad' as 'working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_id_op_connect_done] (0x2000): Old USN: 75028237, New USN: 75031469 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_search_user_next_base] (0x0400): Searching for users with base [dc=prd,dc=ad] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_print_server] (0x2000): Searching 170.0.0.2:3268 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(|(sAMAccountName=user@DOMAIN.AD)(mail=user@DOMAIN.AD)(sAMAccountName=user\\@DOMAIN.AD@DOMAIN.AD))(objectclass=user)(sAMAccountName=*)(objectSID=*))][dc=prd,dc=ad]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shawUser-sshPublicKey] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userCertificate;binary] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [mail] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shawUser-sshPublicKey] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 5 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_add] (0x2000): New operation 5 timeout 6 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7e7a9a0], connected[1], ops[0x5622d7e96670], ldap[0x5622d7d76f00] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_destructor] (0x2000): Operation 5 finished (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_search_user_process] (0x0400): Search for users, returned 0 results. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_search_user_process] (0x2000): Retrieved total 0 users (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'sd_PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc02.PRD.AD' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x0100): Hostname resolution expired, resetting the server status of 'dc02.PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [set_server_common_status] (0x0100): Marking server 'dc02.PRD.AD' as 'name not resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolve_srv_send] (0x0200): The status of SRV lookup is expired (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [collapse_srv_lookup] (0x0100): Need to refresh SRV lookup for domain AWS._sites.PRD.AD (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_srv_plugin_send] (0x0400): About to find domain controllers (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_get_dc_servers_send] (0x0400): Looking up domain controllers in domain PRD.AD (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'ldap'. Will use DNS discovery domain 'PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_ldap._tcp.PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7e7a9a0], connected[1], ops[(nil)], ldap[0x5622d7d76f00] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_getsrv_done] (0x1000): Using TTL [600] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [request_watch_destructor] (0x0400): Deleting request watch (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_discover_srv_done] (0x0400): Got 7 servers (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_get_dc_servers_done] (0x0400): Found 7 domain controllers in domain PRD.AD (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_srv_plugin_dcs_done] (0x0400): About to locate suitable site (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_connect_host_send] (0x0400): Resolving host dc02.prd.ad (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_step] (0x2000): Querying files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'dc02.prd.ad' in files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_step] (0x2000): Querying files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'dc02.prd.ad' in files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_step] (0x2000): Querying DNS (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'dc02.prd.ad' in DNS (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [request_watch_destructor] (0x0400): Deleting request watch (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_connect_host_resolv_done] (0x0400): Connecting to ldap://dc02.prd.ad:389 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sssd_async_socket_init_send] (0x0400): Setting 6 seconds timeout for connecting (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://dc02.prd.ad:389/??base] with fd [27]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_connect_host_done] (0x0400): Successful connection to ldap://dc02.prd.ad:389 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_print_server] (0x2000): Searching 10.0.0.2:389 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(DnsDomain=PRD.AD)(NtVer=\14\00\00\00))][]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [netlogon] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_add] (0x2000): New operation 1 timeout 6 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7edd820], connected[1], ops[0x5622d7ece270], ldap[0x5622d7cebd40] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_entry] (0x1000): OriginalDN: []. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [netlogon] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7edd820], connected[1], ops[0x5622d7ece270], ldap[0x5622d7cebd40] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_destructor] (0x2000): Operation 1 finished (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_handle_release] (0x2000): Trace: sh[0x5622d7edd820], connected[1], ops[(nil)], ldap[0x5622d7cebd40], destructor_lock[0], release_memory[0] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_get_client_site_done] (0x0400): Found site: AWS (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_get_client_site_done] (0x0400): Found forest: PRD.AD (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_srv_plugin_site_done] (0x0400): About to discover primary and backup servers (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_discover_servers_send] (0x0400): Looking up primary servers (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'ldap'. Will use DNS discovery domain 'AWS._sites.PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_ldap._tcp.AWS._sites.PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_getsrv_done] (0x1000): Using TTL [600] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [request_watch_destructor] (0x0400): Deleting request watch (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_discover_srv_done] (0x0400): Got 6 servers (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_discover_servers_primary_done] (0x0400): Looking up backup servers (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'ldap'. Will use DNS discovery domain 'PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_ldap._tcp.PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_getsrv_done] (0x1000): Using TTL [600] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [request_watch_destructor] (0x0400): Deleting request watch (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_discover_srv_done] (0x0400): Got 7 servers (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_srv_plugin_servers_done] (0x0400): Got 6 primary and 7 backup servers (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'dc02.PRD.AD:389' to service 'sd_PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'dc11.PRD.AD:389' to service 'sd_PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'dc11.PRD.AD:389' to service 'sd_PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'dc02.PRD.AD:389' to service 'sd_PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'dc05.prd.ad:389' to service 'sd_PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'dc06.prd.ad:389' to service 'sd_PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_add_server_to_list] (0x0400): Server 'dc02.PRD.AD:389' for service 'sd_PRD.AD' is already present (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_add_server_to_list] (0x0400): Server 'dc11.PRD.AD:389' for service 'sd_PRD.AD' is already present (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_add_server_to_list] (0x0400): Server 'dc05.prd.ad:389' for service 'sd_PRD.AD' is already present (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_add_server_to_list] (0x0400): Server 'dc11.PRD.AD:389' for service 'sd_PRD.AD' is already present (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_add_server_to_list] (0x0400): Server 'dc02.PRD.AD:389' for service 'sd_PRD.AD' is already present (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_add_server_to_list] (0x0400): Server 'dc06.prd.ad:389' for service 'sd_PRD.AD' is already present (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_add_server_to_list] (0x0400): Inserted backup server 'dc07.prd.ad:389' to service 'sd_PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [set_srv_data_status] (0x0100): Marking SRV lookup of service 'sd_PRD.AD' as 'resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc02.PRD.AD' is 'name not resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_step] (0x2000): Querying files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'dc02.PRD.AD' in files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [set_server_common_status] (0x0100): Marking server 'dc02.PRD.AD' as 'resolving name' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_step] (0x2000): Querying files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'dc02.PRD.AD' in files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_step] (0x2000): Querying DNS (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'dc02.PRD.AD' in DNS (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [request_watch_destructor] (0x0400): Deleting request watch (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [set_server_common_status] (0x0100): Marking server 'dc02.PRD.AD' as 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x0200): Found address for server dc02.PRD.AD: [10.0.0.2] TTL 3600 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://dc02.PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_resolve_callback] (0x0100): Constructed GC uri 'ldap://dc02.PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sssd_async_socket_init_send] (0x0400): Setting 6 seconds timeout for connecting (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://dc02.PRD.AD:389/??base] with fd [26]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_print_server] (0x2000): Searching 10.0.0.2:389 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_add] (0x2000): New operation 1 timeout 6 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7edd820], connected[1], ops[0x5622d7e8ae00], ldap[0x5622d7cebd40] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_entry] (0x1000): OriginalDN: []. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [currentTime] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [subschemaSubentry] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [dsServiceName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [namingContexts] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [defaultNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [schemaNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [configurationNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [rootDomainNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedControl] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPVersion] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPPolicies] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [highestCommittedUSN] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedSASLMechanisms] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [dnsHostName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [ldapServiceName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [serverName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedCapabilities] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [isSynchronized] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [isGlobalCatalogReady] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedExtension] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [forestFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainControllerFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7edd820], connected[1], ops[0x5622d7e8ae00], ldap[0x5622d7cebd40] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_destructor] (0x2000): Operation 1 finished (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_rootdse_done] (0x2000): Got rootdse (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [6] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, server$, DOMAIN.AD, 86400) (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service sd_PRD.AD (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'sd_PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc02.PRD.AD' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc02.PRD.AD' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x0200): Found address for server dc02.PRD.AD: [10.0.0.2] TTL 3600 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 43 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [19455] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_handler_setup] (0x2000): Signal handler set up for pid [19455] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7edd820], connected[1], ops[(nil)], ldap[0x5622d7cebd40] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [write_pipe_handler] (0x0400): All data has been sent! (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [read_pipe_handler] (0x0400): EOF received, client finished (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_DOMAIN.AD], expired on [1517459477] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1517424377 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: server$ (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_sasl_log] (0x0040): SASL: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Cannot find KDC for realm "PRD.AD") (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sasl_bind_send] (0x0020): ldap_sasl_bind failed (-2)[Local error] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sasl_bind_send] (0x0080): Extended failure message: [SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Cannot find KDC for realm "PRD.AD")] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_sig_handler] (0x1000): Waiting for child [19455]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_sig_handler] (0x0100): child [19455] finished successfully. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_cli_connect_recv] (0x0040): Unable to establish connection [1432158226]: Authentication Failed (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'dc02.PRD.AD' as 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'dc02.PRD.AD' as 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'dc02.PRD.AD' as 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_handle_release] (0x2000): Trace: sh[0x5622d7edd820], connected[1], ops[(nil)], ldap[0x5622d7cebd40], destructor_lock[0], release_memory[0] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'sd_PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc11.PRD.AD' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x0100): Hostname resolution expired, resetting the server status of 'dc11.PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [set_server_common_status] (0x0100): Marking server 'dc11.PRD.AD' as 'name not resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc11.PRD.AD' is 'neutral' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc11.PRD.AD' is 'name not resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_step] (0x2000): Querying files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'dc11.PRD.AD' in files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [set_server_common_status] (0x0100): Marking server 'dc11.PRD.AD' as 'resolving name' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_step] (0x2000): Querying files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'dc11.PRD.AD' in files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_step] (0x2000): Querying DNS (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'dc11.PRD.AD' in DNS (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [request_watch_destructor] (0x0400): Deleting request watch (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [set_server_common_status] (0x0100): Marking server 'dc11.PRD.AD' as 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x0200): Found address for server dc11.PRD.AD: [10.0.0.3] TTL 3600 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://dc11.PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_resolve_callback] (0x0100): Constructed GC uri 'ldap://dc11.PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sssd_async_socket_init_send] (0x0400): Setting 6 seconds timeout for connecting (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://dc11.PRD.AD:389/??base] with fd [26]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_print_server] (0x2000): Searching 10.0.0.3:389 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_add] (0x2000): New operation 1 timeout 6 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7edd820], connected[1], ops[0x5622d7e96670], ldap[0x5622d7e7b5c0] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_entry] (0x1000): OriginalDN: []. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [currentTime] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [subschemaSubentry] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [dsServiceName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [namingContexts] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [defaultNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [schemaNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [configurationNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [rootDomainNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedControl] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPVersion] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPPolicies] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [highestCommittedUSN] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedSASLMechanisms] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [dnsHostName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [ldapServiceName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [serverName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedCapabilities] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [isSynchronized] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [isGlobalCatalogReady] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedExtension] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [forestFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainControllerFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7edd820], connected[1], ops[0x5622d7e96670], ldap[0x5622d7e7b5c0] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_destructor] (0x2000): Operation 1 finished (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_rootdse_done] (0x2000): Got rootdse (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [7] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, server$, DOMAIN.AD, 86400) (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service sd_PRD.AD (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'sd_PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc11.PRD.AD' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc11.PRD.AD' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x0200): Found address for server dc11.PRD.AD: [10.0.0.3] TTL 3600 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 43 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [19456] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_handler_setup] (0x2000): Signal handler set up for pid [19456] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7edd820], connected[1], ops[(nil)], ldap[0x5622d7e7b5c0] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [write_pipe_handler] (0x0400): All data has been sent! (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [read_pipe_handler] (0x0400): EOF received, client finished (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_DOMAIN.AD], expired on [1517459477] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1517424377 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: server$ (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_sasl_log] (0x0040): SASL: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Cannot find KDC for realm "PRD.AD") (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sasl_bind_send] (0x0020): ldap_sasl_bind failed (-2)[Local error] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sasl_bind_send] (0x0080): Extended failure message: [SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Cannot find KDC for realm "PRD.AD")] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_sig_handler] (0x1000): Waiting for child [19456]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_sig_handler] (0x0100): child [19456] finished successfully. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_cli_connect_recv] (0x0040): Unable to establish connection [1432158226]: Authentication Failed (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'dc11.PRD.AD' as 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'dc11.PRD.AD' as 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'dc11.PRD.AD' as 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_handle_release] (0x2000): Trace: sh[0x5622d7edd820], connected[1], ops[(nil)], ldap[0x5622d7e7b5c0], destructor_lock[0], release_memory[0] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'sd_PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc11.PRD.AD' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc11.PRD.AD' is 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x0080): SSSD is unable to complete the full connection request, this internal status does not necessarily indicate network port issues. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc02.PRD.AD' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc02.PRD.AD' is 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x0080): SSSD is unable to complete the full connection request, this internal status does not necessarily indicate network port issues. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc05.prd.ad' is 'name not resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc05.prd.ad' is 'neutral' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc05.prd.ad' is 'name not resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_step] (0x2000): Querying files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'dc05.prd.ad' in files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [set_server_common_status] (0x0100): Marking server 'dc05.prd.ad' as 'resolving name' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_step] (0x2000): Querying files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'dc05.prd.ad' in files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_step] (0x2000): Querying DNS (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'dc05.prd.ad' in DNS (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [request_watch_destructor] (0x0400): Deleting request watch (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [set_server_common_status] (0x0100): Marking server 'dc05.prd.ad' as 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x0200): Found address for server dc05.prd.ad: [10.0.0.1] TTL 3600 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://dc05.prd.ad' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_resolve_callback] (0x0100): Constructed GC uri 'ldap://dc05.prd.ad' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sssd_async_socket_init_send] (0x0400): Setting 6 seconds timeout for connecting (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://dc05.prd.ad:389/??base] with fd [26]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_print_server] (0x2000): Searching 10.0.0.1:389 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_add] (0x2000): New operation 1 timeout 6 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7edd820], connected[1], ops[0x5622d7e96670], ldap[0x5622d8cb2600] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7edd820], connected[1], ops[0x5622d7e96670], ldap[0x5622d8cb2600] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_entry] (0x1000): OriginalDN: []. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [currentTime] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [subschemaSubentry] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [dsServiceName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [namingContexts] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [defaultNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [schemaNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [configurationNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [rootDomainNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedControl] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPVersion] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPPolicies] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [highestCommittedUSN] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedSASLMechanisms] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [dnsHostName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [ldapServiceName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [serverName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedCapabilities] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [isSynchronized] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [isGlobalCatalogReady] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedExtension] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [forestFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainControllerFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7edd820], connected[1], ops[0x5622d7e96670], ldap[0x5622d8cb2600] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_destructor] (0x2000): Operation 1 finished (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_rootdse_done] (0x2000): Got rootdse (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [6] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, server$, DOMAIN.AD, 86400) (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service sd_PRD.AD (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'sd_PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc05.prd.ad' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc05.prd.ad' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x0200): Found address for server dc05.prd.ad: [10.0.0.1] TTL 3600 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 43 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [19457] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_handler_setup] (0x2000): Signal handler set up for pid [19457] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7edd820], connected[1], ops[(nil)], ldap[0x5622d8cb2600] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [write_pipe_handler] (0x0400): All data has been sent! (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [read_pipe_handler] (0x0400): EOF received, client finished (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_DOMAIN.AD], expired on [1517459477] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1517424377 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: server$ (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_sasl_log] (0x0040): SASL: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Cannot find KDC for realm "PRD.AD") (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sasl_bind_send] (0x0020): ldap_sasl_bind failed (-2)[Local error] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sasl_bind_send] (0x0080): Extended failure message: [SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Cannot find KDC for realm "PRD.AD")] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_sig_handler] (0x1000): Waiting for child [19457]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_sig_handler] (0x0100): child [19457] finished successfully. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_cli_connect_recv] (0x0040): Unable to establish connection [1432158226]: Authentication Failed (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'dc05.prd.ad' as 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'dc05.prd.ad' as 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_handle_release] (0x2000): Trace: sh[0x5622d7edd820], connected[1], ops[(nil)], ldap[0x5622d8cb2600], destructor_lock[0], release_memory[0] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'sd_PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc06.prd.ad' is 'name not resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc06.prd.ad' is 'neutral' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc06.prd.ad' is 'name not resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_step] (0x2000): Querying files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'dc06.prd.ad' in files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [set_server_common_status] (0x0100): Marking server 'dc06.prd.ad' as 'resolving name' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_step] (0x2000): Querying files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'dc06.prd.ad' in files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_step] (0x2000): Querying DNS (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'dc06.prd.ad' in DNS (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [request_watch_destructor] (0x0400): Deleting request watch (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [set_server_common_status] (0x0100): Marking server 'dc06.prd.ad' as 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x0200): Found address for server dc06.prd.ad: [10.0.0.4] TTL 3600 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://dc06.prd.ad' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_resolve_callback] (0x0100): Constructed GC uri 'ldap://dc06.prd.ad' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sssd_async_socket_init_send] (0x0400): Setting 6 seconds timeout for connecting (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://dc06.prd.ad:389/??base] with fd [26]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_print_server] (0x2000): Searching 10.0.0.4:389 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_add] (0x2000): New operation 1 timeout 6 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7edd820], connected[1], ops[0x5622d7e96670], ldap[0x5622d8cc07b0] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_entry] (0x1000): OriginalDN: []. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [currentTime] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [subschemaSubentry] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [dsServiceName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [namingContexts] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [defaultNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [schemaNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [configurationNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [rootDomainNamingContext] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedControl] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPVersion] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPPolicies] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [highestCommittedUSN] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedSASLMechanisms] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [dnsHostName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [ldapServiceName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [serverName] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedCapabilities] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [isSynchronized] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [isGlobalCatalogReady] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedExtension] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [forestFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainControllerFunctionality] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7edd820], connected[1], ops[0x5622d7e96670], ldap[0x5622d8cc07b0] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_op_destructor] (0x2000): Operation 1 finished (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_rootdse_done] (0x2000): Got rootdse (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [6] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, server$, DOMAIN.AD, 86400) (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service sd_PRD.AD (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'sd_PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc06.prd.ad' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc06.prd.ad' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x0200): Found address for server dc06.prd.ad: [10.0.0.4] TTL 3600 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 43 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [19458] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_handler_setup] (0x2000): Signal handler set up for pid [19458] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: sh[0x5622d7edd820], connected[1], ops[(nil)], ldap[0x5622d8cc07b0] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [write_pipe_handler] (0x0400): All data has been sent! (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [read_pipe_handler] (0x0400): EOF received, client finished (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_DOMAIN.AD], expired on [1517459477] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1517424377 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: server$ (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_sasl_log] (0x0040): SASL: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Cannot find KDC for realm "PRD.AD") (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sasl_bind_send] (0x0020): ldap_sasl_bind failed (-2)[Local error] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sasl_bind_send] (0x0080): Extended failure message: [SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Cannot find KDC for realm "PRD.AD")] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_sig_handler] (0x1000): Waiting for child [19458]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [child_sig_handler] (0x0100): child [19458] finished successfully. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_cli_connect_recv] (0x0040): Unable to establish connection [1432158226]: Authentication Failed (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'dc06.prd.ad' as 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'dc06.prd.ad' as 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_handle_release] (0x2000): Trace: sh[0x5622d7edd820], connected[1], ops[(nil)], ldap[0x5622d8cc07b0], destructor_lock[0], release_memory[0] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'sd_PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc02.PRD.AD' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc02.PRD.AD' is 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x0080): SSSD is unable to complete the full connection request, this internal status does not necessarily indicate network port issues. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc11.PRD.AD' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc11.PRD.AD' is 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x0080): SSSD is unable to complete the full connection request, this internal status does not necessarily indicate network port issues. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc11.PRD.AD' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc11.PRD.AD' is 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x0080): SSSD is unable to complete the full connection request, this internal status does not necessarily indicate network port issues. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc02.PRD.AD' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc02.PRD.AD' is 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x0080): SSSD is unable to complete the full connection request, this internal status does not necessarily indicate network port issues. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc05.prd.ad' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc05.prd.ad' is 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x0080): SSSD is unable to complete the full connection request, this internal status does not necessarily indicate network port issues. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc06.prd.ad' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc06.prd.ad' is 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x0080): SSSD is unable to complete the full connection request, this internal status does not necessarily indicate network port issues. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc07.prd.ad' is 'name not resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc07.prd.ad' is 'neutral' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc07.prd.ad' is 'name not resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_step] (0x2000): Querying files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'dc07.prd.ad' in files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [set_server_common_status] (0x0100): Marking server 'dc07.prd.ad' as 'resolving name' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_step] (0x2000): Querying files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'dc07.prd.ad' in files (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_step] (0x2000): Querying DNS (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'dc07.prd.ad' in DNS (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [request_watch_destructor] (0x0400): Deleting request watch (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [set_server_common_status] (0x0100): Marking server 'dc07.prd.ad' as 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_process] (0x0200): Found address for server dc07.prd.ad: [10.200.80.12] TTL 3600 (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://dc07.prd.ad' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [ad_resolve_callback] (0x0100): Constructed GC uri 'ldap://dc07.prd.ad' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_primary_server_timeout_activate] (0x2000): Primary server reactivation timeout set to 31 seconds (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sssd_async_socket_init_send] (0x0400): Setting 6 seconds timeout for connecting (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sssd_async_connect_done] (0x0020): connect failed [113][No route to host]. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sssd_async_socket_init_done] (0x0020): sdap_async_sys_connect request failed: [113]: No route to host. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sssd_async_socket_state_destructor] (0x0400): closing socket [26] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sss_ldap_init_sys_connect_done] (0x0020): sssd_async_socket_init request failed: [113]: No route to host. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_sys_connect_done] (0x0020): sdap_async_connect_call request failed: [113]: No route to host. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_handle_release] (0x2000): Trace: sh[0x5622d7edd820], connected[0], ops[(nil)], ldap[(nil)], destructor_lock[0], release_memory[0] (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'dc07.prd.ad' as 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'dc07.prd.ad' as 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'sd_PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc02.PRD.AD' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc02.PRD.AD' is 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x0080): SSSD is unable to complete the full connection request, this internal status does not necessarily indicate network port issues. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc11.PRD.AD' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc11.PRD.AD' is 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x0080): SSSD is unable to complete the full connection request, this internal status does not necessarily indicate network port issues. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc11.PRD.AD' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc11.PRD.AD' is 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x0080): SSSD is unable to complete the full connection request, this internal status does not necessarily indicate network port issues. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc02.PRD.AD' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc02.PRD.AD' is 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x0080): SSSD is unable to complete the full connection request, this internal status does not necessarily indicate network port issues. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc05.prd.ad' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc05.prd.ad' is 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x0080): SSSD is unable to complete the full connection request, this internal status does not necessarily indicate network port issues. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc06.prd.ad' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc06.prd.ad' is 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x0080): SSSD is unable to complete the full connection request, this internal status does not necessarily indicate network port issues. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_server_status] (0x1000): Status of server 'dc07.prd.ad' is 'name resolved' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc07.prd.ad' is 'not working' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [get_port_status] (0x0080): SSSD is unable to complete the full connection request, this internal status does not necessarily indicate network port issues. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [fo_resolve_service_send] (0x0020): No available servers for service 'sd_PRD.AD' (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [be_resolve_server_done] (0x1000): Server resolution failed: [5]: Input/output error (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [sdap_id_op_connect_done] (0x0400): Failed to connect to server, but ignore mark offline is enabled. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_req_done] (0x0400): DP Request [Account #1411]: Request handler finished [0]: Success (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [_dp_req_recv] (0x0400): DP Request [Account #1411]: Receiving request data. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_req_reply_list_success] (0x0400): DP Request [Account #1411]: Finished. Success. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_req_reply_std] (0x1000): DP Request [Account #1411]: Returning [Internal Error]: 3,1432158272,User lookup failed (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:1:U:PRD.AD:name=user@DOMAIN.AD] from reply table (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_req_destructor] (0x0400): DP Request [Account #1411]: Request removed. (Wed Jan 31 18:31:17 2018) [sssd[be[DOMAIN.AD]]] [dp_req_destructor] (0x0400): Number of active DP request: 0

3 6

FreeIPA/SSSD sssd_nss error: The Data Provider returned an error [org.freedesktop.sssd.Error.DataProvider.Fatal]
by Anthony Joseph Messina 31 Jan '18

31 Jan '18

In a Fedora 27 FreeIPA-4.6 domain with the following sssd.conf, I regularly get the followin error: sssd_nss[2603]: The Data Provider returned an error [org.freedesktop.sssd.Error.DataProvider.Fatal] Increasing the sssd debug level reveals that the fatal error seems to be raised by the lookup in the implicit_files domain which doesn't contain this GID. While this happens on all my FreeIPA clients, this particular host is a mailserver postfix and cyrus-imap with saslsuthd/pam authentication so the number of user lookups is far higher and the error occurs with considerable frequency. Do I have a misconfiguration here or is there a problem with implicit_domain and GID lookups? It doesn't seem like this should be a fatal error when the GID exists in the example.com FreeIPA/SSSD domain. # /etc/nsswitch.conf (snippet) passwd: sss files mymachines systemd shadow: files sss group: sss files mymachines systemd # /etc/sssd/sssd.conf [domain/example.com] cache_credentials = True krb5_store_password_if_offline = True ipa_domain = example.com id_provider = ipa auth_provider = ipa access_provider = ipa ipa_hostname = host.example.com chpass_provider = ipa ipa_server = _srv_, ipa-master.ipa.example.com ldap_tls_cacert = /etc/ipa/ca.crt [sssd] services = nss, sudo, pam, ssh, ifp domains = example.com [nss] homedir_substring = /home [pam] [sudo] [autofs] [ssh] [pac] [ifp] allowed_uids = apache, root [secrets] # Relevant sssd_nss debug logs Jan 30 18:22:48 sssd_nss[2603]: Input ID: 1111100001 Jan 30 18:22:48 sssd_nss[2603]: CR #134773: New request 'Group by ID' Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Performing a multi-domain search Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Search will check the cache and check the data provider Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Using domain [implicit_files] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up GID:1111100001@implicit_files Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Checking negative cache for [GID:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: [GID:1111100001@implicit_files] is not present in negative cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up [GID:1111100001@implicit_files] in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Object [GID:1111100001@implicit_files] was not found in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up [GID:1111100001@implicit_files] in data provider Jan 30 18:22:48 sssd_nss[2603]: Issuing request for [0x56200cc04250:2:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: Creating request for [implicit_files][0x2][BE_REQ_GROUP][idnumber=1111100001:-] Jan 30 18:22:48 sssd_nss[2603]: Entering request [0x56200cc04250:2:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: Input ID: 1111100001 Jan 30 18:22:48 sssd_nss[2603]: CR #134774: New request 'Group by ID' Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Performing a multi-domain search Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Search will check the cache and check the data provider Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Using domain [implicit_files] Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Looking up GID:1111100001@implicit_files Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Checking negative cache for [GID:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: CR #134774: [GID:1111100001@implicit_files] is not present in negative cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Looking up [GID:1111100001@implicit_files] in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Object [GID:1111100001@implicit_files] was not found in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Looking up [GID:1111100001@implicit_files] in data provider Jan 30 18:22:48 sssd_nss[2603]: Issuing request for [0x56200cc04250:2:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: Identical request in progress: [0x56200cc04250:2:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: The Data Provider returned an error [org.freedesktop.sssd.Error.DataProvider.Fatal] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Data Provider Error: 3, 5, Failed to get reply from Data Provider Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Due to an error we will return cached data Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up [GID:1111100001@implicit_files] in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Object [GID:1111100001@implicit_files] was not found in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Using domain [example.com] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up GID:1111100001@example.com Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Checking negative cache for [GID:1111100001@example.com] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: [GID:1111100001@example.com] is not present in negative cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up [GID:1111100001@example.com] in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Returning [GID:1111100001@example.com] from cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Filtering out results by negative cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Data Provider Error: 3, 5, Failed to get reply from Data Provider Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Due to an error we will return cached data Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Looking up [GID:1111100001@implicit_files] in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Object [GID:1111100001@implicit_files] was not found in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Using domain [example.com] Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Looking up GID:1111100001@example.com Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Checking negative cache for [GID:1111100001@example.com] Jan 30 18:22:48 sssd_nss[2603]: CR #134774: [GID:1111100001@example.com] is not present in negative cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Looking up [GID:1111100001@example.com] in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Returning [GID:1111100001@example.com] from cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Filtering out results by negative cache Jan 30 18:22:48 sssd_nss[2603]: Deleting request: [0x56200cc04250:2:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Found 1 entries in domain example.com Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Found 1 entries in domain example.com Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Finished: Success Jan 30 18:22:48 sssd_nss[2603]: Domain example.com is Active Jan 30 18:22:48 sssd_nss[2603]: Domain implicit_files is Active Jan 30 18:22:48 sssd_nss[2603]: Domain example.com is Active Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Finished: Success -- Anthony - https://messinet.com/ - https://messinet.com/~amessina/gallery F9B6 560E 68EA 037D 8C3D D1C9 FF31 3BDB D9D8 99B6

2 3

Strange pam configuration help needed
by Orion Poplawski 31 Jan '18

31 Jan '18

This may not be entirely sssd related, but hopefully I can tap some PAM expertise. I'm trying to work out a pam configuration that will always require a OTP via google_authenticator in combination with any other auth method - gssapi, key, or password. I've tried to this with this sshd config: # Kerberos / Public Key + PAM AuthenticationMethods gssapi-with-mic,keyboard-interactive:pam publickey,keyboard-interactive:pam password,keyboard-interactive:pam and pam: auth [success=done new_authtok_reqd=done default=ok] pam_google_authenticator.so auth substack password-auth The idea being that if ga prompts for a token, we're done, and sshd's password auth handles the password case. But with this config, sshd fails with: sshd[23879]: pam_sss(sshd:auth): authentication success; logname= uid=0 euid=0 tty=ssh ruser= rhost= user=USER sshd[23879]: debug1: PAM: password authentication failed for USER: The return value should be ignored by PAM dispatch Which may be a bug/limitation in sshd, but I don't think I'm able to fix that. At this point I'm think of something like: auth [success=done new_authtok_reqd=done] pam_google_authenticator.so auth sufficient "return success if no auth token is given" auth substack password-auth But how to achieve it? Thanks. -- Orion Poplawski Manager of NWRA Technical Systems 720-772-5637 NWRA, Boulder/CoRA Office FAX: 303-415-9702 3380 Mitchell Lane orion(a)nwra.com Boulder, CO 80301 https://www.nwra.com/

1 0

Re: [Freeipa-users] Getting DP Request [Account #4]: Returning [Internal Error]: 3,5,Group lookup failed
by TomK 31 Jan '18

31 Jan '18

On 1/31/2018 3:18 AM, TomK via FreeIPA-users wrote: My bad, did not include sssd-users earlier. :( > Hey All, > > I'm wondering if anyone came across this error below. We have two RHEL > 7.4 servers with SSSD 1.15.2: http-srv01 and http-srv02 > > Both connect to the same AD DC host below: addc-srv03.addom.com. > Verified krb5.conf and sssd.conf both are identical. We can login on > the http-srv01 and can list all groups for an AD account. > > On http-srv02 we cannot login and any group listing from the CLI result > only in the user's local groups. No AD groups. > > Logs give us the output below. Short of adding in the entire log which > I might not be able to do till the end of the week, what could we look > at to resolve this? > > There's very little available online on this error. The RH solution > doesn't make sense since the first host connects and authenticates users > just fine so it's definitely GC enabled. > -- Cheers, Tom K. ------------------------------------------------------------------------------------- Living on earth is expensive, but it includes a free trip around the sun. samba-libs-4.6.2-12.el7_4.x86_64 samba-client-libs-4.6.2-12.el7_4.x86_64 sssd-1.15.2-50.el7_4.6.x86_64 openldap-2.4.44-5.el7.x86_64 sssd-ldap-1.15.2-50.el7_4.6.x86_64 sssd-common-pac-1.15.2-50.el7_4.6.x86_64 samba-winbind-clients-4.6.2-12.el7_4.x86_64 samba-common-4.6.2-12.el7_4.noarch sssd-client-1.15.2-50.el7_4.6.x86_64 sssd-proxy-1.15.2-50.el7_4.6.x86_64 samba-winbind-modules-4.6.2-12.el7_4.x86_64 python-sssdconfig-1.15.2-50.el7_4.6.noarch sssd-ipa-1.15.2-50.el7_4.6.x86_64 samba-common-libs-4.6.2-12.el7_4.x86_64 sssd-krb5-common-1.15.2-50.el7_4.6.x86_64 samba-winbind-4.6.2-12.el7_4.x86_64 sssd-krb5-1.15.2-50.el7_4.6.x86_64 sssd-ad-1.15.2-50.el7_4.6.x86_64 sssd-common-1.15.2-50.el7_4.6.x86_64 samba-common-tools-4.6.2-12.el7_4.x86_64 (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [sbus_dispatch] (0x4000): dbus conn: 0x55b2e22e8700 (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [sbus_dispatch] (0x4000): Dispatching. (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path /org/freedesktop/sssd/dataprovider (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [dp_get_account_info_handler] (0x0200): Got request for [0x2][BE_REQ_GROUP][name=unix-admin-group@addom] (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [dp_attach_req] (0x0400): DP Request [Account #4]: New request. Flags [0x0001]. (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [dp_attach_req] (0x0400): Number of active DP request: 1 (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [sss_domain_get_state] (0x1000): Domain ADDOM is Active (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [sss_domain_get_state] (0x1000): Domain ADDOM is Active (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [sdap_id_op_connect_step] (0x4000): beginning to connect (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD_GC' (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [get_server_status] (0x1000): Status of server 'addc-srv03.addom.com' is 'working' (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [get_port_status] (0x1000): Port status of port 0 for server 'addc-srv03.addom.com' is 'not working' (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [get_port_status] (0x0080): SSSD is unable to complete the full connection request, this internal status does not necessarily indicate network port issues. (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [fo_resolve_service_send] (0x0020): No available servers for service 'AD_GC' (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [be_resolve_server_done] (0x1000): Server resolution failed: [5]: Input/output error (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [sdap_id_op_connect_done] (0x0400): Failed to connect to server, but ignore mark offline is enabled. (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [sdap_id_op_connect_done] (0x4000): notify error to op #1: 5 [Input/output error] (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [dp_req_done] (0x0400): DP Request [Account #4]: Request handler finished [0]: Success (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [_dp_req_recv] (0x0400): DP Request [Account #4]: Receiving request data. (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [dp_req_reply_list_success] (0x0400): DP Request [Account #4]: Finished. Success. (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [dp_req_reply_std] (0x1000): DP Request [Account #4]: Returning [Internal Error]: 3,5,Group lookup failed (Tue Jan 30 19:00:01 2018) [sssd[be[ADDOM]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:2::ADDOM:name=unix-admin-group@addom] from reply

2 3

Weird Timeout Problem
by Amichai Rotman 29 Jan '18

29 Jan '18

Hello all, I am having a very annoying problem with SSSD and AD: I have a lab with 5 Ubuntu 16.04 LTS Desktops clients that I configured to authenticate with the University's Active Directory. SSSD is configured with Samba and Kerberos 5. All was working well when we used Ubuntu 14.04. The Problem: If one of the students never logged in before, or was away for more than a week - LightDM claims the password is incorrect - even if we know for sure it is correct. We have two Active Directory domains, sometimes the same user succeeds in logging in, other times - not... I am guessing it has to do with the credential cache (GPO Cache?) 1. Is there a way to check which domains SSSD authenticates against, not read it from the local configuration? 2. Is there a command to manually force an enumeration - I mean, refresh the cache from the AD to enable a student to log in at that given time? This problem is bugging me for more than a month! It is really frustrating.... Thanks! Amichai. [1502369097122_erez6.png] �� - ��

2 1

System Error (4) for passwd users
by goehle＠gmail.com 24 Jan '18

24 Jan '18

Hi, The troubleshooting guide in the docs said to email the list if the System Error (4) shows up, so I figured I bring this issue up. I'm running sssd version 1.16.0 on Debian testing and recently encountered a new behavior. We set up sssd with active directory based authentication on an already established system. For various reasons there are still local passwd users, some of whom also have ad accounts. What used to happen is that the pam/nsswitch stack was set up so that those users would end up with their passwd id. If they had an ad account they could log in with either their shadow password or their ad password. Right after we upgraded from 1.16.0-1 to 1.16.0-2 any local user generated a System Error (4) in the logs and and local users with ad accounts could no longer use their ad passwords (although they could still use their local passwords). There isn't a lot of information in the logs. auth.log: Jan 23 19:02:27 spoon su[28320]: pam_unix(su:auth): authentication failure; logname=goehle uid=1000 euid=0 tty=/dev/pts/0 ruser=goehle rhost= user=picard Jan 23 19:02:27 spoon su[28320]: pam_sss(su:auth): authentication failure; logname=goehle uid=1000 euid=0 tty=/dev/pts/0 ruser=goehle rhost= user=picard Jan 23 19:02:27 spoon su[28320]: pam_sss(su:auth): received for user picard: 4 (System error) sssd_pam.log (full version below): (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_AUTHENTICATE (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): domain: implicit_files (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): user: picard@implicit_files (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): service: su (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): tty: /dev/pts/0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): ruser: goehle (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 1 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): priv: 0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 28320 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): logon name: picard (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x55bc08045290 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x55bc08045290 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_dp_process_reply] (0x0010): Reply error. (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [4]: System error. (Tue Jan 23 19:02:27 2018) [sssd[pam]] [filter_responses] (0x0100): [pam_response_filter] not available, not fatal. (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_reply] (0x0200): blen: 31 There aren't any other log entries with this time stamp. In particular there aren't any entries in the domain log, the pam_nss log or the krb5_child log. I am able to authenticate manually with kinit, however. I would really appreciate it if someone could point me to the right logs, or even just tell me that mixing local and sss users in this way is not supported. Thanks for your time. Geoff Goehle. (Tue Jan 23 19:02:27 2018) [sssd[pam]] [accept_fd_handler] (0x0400): Client connected! (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_cmd_get_version] (0x0200): Received client version [3]. (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_cmd_get_version] (0x0200): Offered version [3]. (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_cmd_authenticate] (0x0100): entering pam_cmd_authenticate (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_domain_get_state] (0x1000): Domain wcu.edu is Active (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'picard' matched without domain, user is picard (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_AUTHENTICATE (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): domain: not set (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): user: picard (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): service: su (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): tty: /dev/pts/0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): ruser: goehle (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 1 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): priv: 0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 28320 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): logon name: picard (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_set_plugin] (0x2000): CR #12: Setting "Initgroups by name" plugin (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_send] (0x0400): CR #12: New request 'Initgroups by name' (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_process_input] (0x0400): CR #12: Parsing input name [picard] (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_domain_get_state] (0x1000): Domain wcu.edu is Active (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'picard' matched without domain, user is picard (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_set_name] (0x0400): CR #12: Setting name [picard] (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_select_domains] (0x0400): CR #12: Performing a multi-domain search (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_search_domains] (0x0400): CR #12: Search will bypass the cache and check the data provider (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain implicit_files type POSIX is valid (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_set_domain] (0x0400): CR #12: Using domain [implicit_files] (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_prepare_domain_data] (0x0400): CR #12: Preparing input data for domain [implicit_files] rules (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_search_send] (0x0400): CR #12: Looking up picard@implicit_files (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_search_ncache] (0x0400): CR #12: Checking negative cache for [picard@implicit_files] (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/implicit_files/picard@implicit_files] (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_search_ncache] (0x0400): CR #12: [picard@implicit_files] is not present in negative cache (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_search_dp] (0x0400): CR #12: Looking up [picard@implicit_files] in data provider (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_dp_account_files_params] (0x2000): Domain files is not consistent, issuing update (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_dp_issue_request] (0x0400): Issuing request for [0x55bc077c6930:3:files_initgr_request@implicit_files] (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_dp_get_account_msg] (0x0400): Creating request for [implicit_files][0x3][BE_REQ_INITGROUPS][name=files_initgr_request:-] (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x55bc08045290 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_dp_internal_get_send] (0x0400): Entering request [0x55bc077c6930:3:files_initgr_request@implicit_files] (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x55bc08045290 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 0 errno: 0 error message: Success (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_search_cache] (0x0400): CR #12: Looking up [picard@implicit_files] in cache (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_search_ncache_filter] (0x0400) : CR #12: This request type does not support filtering result by negative cache (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_search_done] (0x0400): CR #12: Returning updated object [picard@implicit_files] (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_create_and_add_result] (0x0400): CR #12: Found 3 entries in domain implicit_files (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x55bc077c6930:3:files_initgr_request@implicit_files] (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_done] (0x0400): CR #12: Finished: Success (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pd_set_primary_name] (0x0400): User's primary name is picard@implicit_files (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_initgr_cache_set] (0x2000): [picard] added to PAM initgroup cache (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data: (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_AUTHENTICATE (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): domain: implicit_files (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): user: picard@implicit_files (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): service: su (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): tty: /dev/pts/0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): ruser: goehle (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 1 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): priv: 0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 28320 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): logon name: picard (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x55bc08045290 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x55bc08045290 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_dp_process_reply] (0x0010): Reply error. (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [4]: System error. (Tue Jan 23 19:02:27 2018) [sssd[pam]] [filter_responses] (0x0100): [pam_response_filter] not available, not fatal. (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_reply] (0x0200): blen: 31

5 11

max_id no longer working
by Franky Van Liedekerke 24 Jan '18

24 Jan '18

Hi, we saw a lot of queries for uidnumber=4294967295 in our ldap backend logs (from sssd), so we did as suggested by https://access.redhat.com/solutions/2963401 and added max_id=4294967294 in our sssd domain config. But this seems to be ignored (at least in version 1.15.2-50.el7_4.8.x86_64), as the queries continue to arrive in ldap. Adding ldap_max_id with the same value resulted in an "numerical out of range" error and sssd refuses to start then (seems to be 16-bit ...). And of course I read the nfsnobody discussions where the uid=65534 :-) As a workaround, I added an entry in /etc/passwd for uid 4294967295 so the problem went away, but this still leaves the max_id and ldap_max_id issues that should be working fine ... Any hints? Franky

2 1

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

sssd-users January 2018