Hi Jakub,

Thanks for the response.

After enabling ldap_use_tokengroups = true, "id" command is now able to
retrieve all the group memberships for that user. But Authentication still
doesn't work.

Also tried setting   ad_gpo_access_control = permissive / access_provider =
permit but that didn't help.

I am attaching both krb5_child.log and sssd_domain.log ( Both with Logon
level 10) here. These were captures during the authentication attempt.

Thanks,

~ Abhi


On Tue, Jun 27, 2017 at 2:39 PM, Jakub Hrozek <[email protected]> wrote:

> On Tue, Jun 27, 2017 at 01:35:18PM -0400, Abhijit Tikekar wrote:
> >
> > >
> > > Hi,
> > >
> > > We are running into some SSSD authentication issues and would really
> appreciate any advice. Here’s some background:
> > >
> > > Until now, all CentOS machines which use SSSD were joined to the same
> domain that also holds all user’s along with their respective groups.
> Let’s call this abc.xyz.local. Now, due to some compliance issue, we cannot
> have these Linux computer accounts in “abc” domain, and need to be moved to
> another domain called “def.xyz.local”. User’s / Groups who would be
> accessing these servers  are unchanged and continue to be part of
> abc.xyz.local.
> > >
> > > “xyz.local” is the forest whereas both “abc” & “def” are child domains
> with bi-directional trust. Was able to successfully join this machine to
> “def” domain. ad_access_filter and other SSSD configurations are kept the
> same except domains, ad_server, krb5_realm, ldap_uri which all point to the
> “DEF” domain now.
> > >
> > > But when trying to authenticate, we get the following under
> /var/log/secure:
> > >
> > > Jun 27 12:58:48 sshd[15716]: pam_sss(sshd:auth): authentication
> failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=
> [email protected]
> > > Jun 27 12:58:48 sshd[15716]: pam_sss(sshd:auth): received for user
> [email protected]: 6 (Permission denied)
>
> This sounds like GPO access control prevented you from logging in.
>
> Can you (just for a test!) please set either:
>     ad_gpo_access_control = permissive
> or even:
>     access_provider = permit
>
> and see if the issue persists?
>
>
> > >
> > > From the logs, it looks like SSSD was able to change request domain
> from “def” to “abc” and was able to locate the OU where the user’s reside,
> but could not get any further.
> > >
> > > Also, “id” commands returns only a default group of “domain users”
> instead of all the groups this user is member of in “ABC” domain.
> > > [root@]# id [email protected]
> > > Uid=xxxxxxxxx([email protected]) 
> > > gid=yyyyyyyyy([email protected])
> groups=yyyyyyyyy([email protected]),xxxxxxxxx(domain
> [email protected])
> > >
> > > Tried changing the ldap_user_search_base to dc=xyz,dc=local but still
> same results.
> > >
> > > SSSD Configuration:
> > >
> > >
> > > [sssd]
> > > domains = DEF.XYZ.LOCAL
> > > services = nss, pam, sudo
> > > config_file_version = 2
> > > debug_level = 10
> > > [nss]
> > > [pam]
> > > [sudo]
> > > debug_level=10
> > > [domain/def.xyz.local]
> > > debug_level=10
> > > ad_server = AD-Server.def.xyz.local
> > > id_provider = ad
> > > auth_provider = ad
> > > access_provider = ad
> > > sudo_provider = ad
> > > ldap_use_tokengroups = False
>
> Why exactly did you disable tokengroups?
>
> > > krb5_realm = DEF.XYZ.LOCAL
> > > ldap_uri = ldap://<AD-Server>.def.xyz.local
> > > ldap_sudo_search_base = .........................
>  dc=abc,dc=xyz,dc=local
> > > ldap_user_search_base = dc=xyz,dc=local
> > > ldap_group_search_base = ........................
> dc=abc,dc=xyz,dc=local
> > > ldap_access_order = filter, expire
>
> Same here, can you test with a more vanilla configuration, removing
> anything that starts with ldap_ (unless you had a reason to set those) ?
>
> Point being, the AD provider normally has the defaults set sensibly
> enough, so there shouldn't be any point in overriding the AD config..
>
> > > ad_access_filter =  ...
> > > cache_credentials = true
> > > override_homedir = /home/%d/%u
> > > default_shell = /bin/bash
> > >
> > >
> > >
> > > krb5.conf:
> > >
> > > [logging]
> > > default = FILE:/var/log/krb5libs.log
> > > kdc = FILE:/var/log/krb5kdc.log
> > > admin_server = FILE:/var/log/kadmind.log
> > > [libdefaults]
> > > default_realm = DEF.XYZ.LOCAL
> > > dns_lookup_realm = true
> > > dns_lookup_kdc = true
> > > ticket_lifetime = 24h
> > > renew_lifetime = 7d
> > > forwardable = yes
> > > [realms]
> > > DEF.XYZ.LOCAL = {
> > > kdc = AD-Server.def.xyz.local:88
> > > admin_server = AD-Server.def.xyz.local:749
> > > }
> > > [domain_realm]
> > > .def.xyz.local = DEF.XYZ.LOCAL
> > > def.xyz.local = DEF.XYZ.LOCAL
> > >
> > >
> > >
> > >
> > >
> > > Here is sssd_domain log set to level 10. Captured during
> authentication.
>
> Thank you for the logs, but I don't think the logs are complete, is
> there anything after:
>
> > > (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]]
> [krb5_auth_queue_send] (0x1000): Wait queue of user
> [[email protected]] is empty, running request [0x1136800]
> immediately.
> > > (Tue Jun 27 10:41:00 2017) [sssd[be[def.xyz.local]]] [krb5_setup]
> (0x4000): No mapping for: [email protected]
> _______________________________________________
> sssd-users mailing list -- [email protected]
> To unsubscribe send an email to [email protected]
>
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] [main] (0x0400): 
krb5_child started.
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] [unpack_buffer] 
(0x1000): total buffer size: [181]
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] [unpack_buffer] 
(0x0100): cmd [241] uid [xxxxx6683] gid [xxxxx6683] validate [true] enterprise 
principal [true] offline [false] UPN [[email protected]]
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] [unpack_buffer] 
(0x0100): ccname: [FILE:/tmp/krb5cc_xxxxx6683_XXXXXX] old_ccname: 
[FILE:/tmp/krb5cc_xxxxx6683_9sctMM] keytab: [/etc/krb5.keytab]
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] [check_use_fast] 
(0x0100): Not using FAST.
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] [switch_creds] (0x0200): 
Switch user to [xxxxx6683][xxxxx6683].
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[sss_krb5_cc_verify_ccache] (0x2000): TGT not found or expired.
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] [switch_creds] (0x0200): 
Switch user to [0][0].
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] [k5c_check_old_ccache] 
(0x4000): Ccache_file is [FILE:/tmp/krb5cc_xxxxx6683_9sctMM] and is not active 
and TGT is  valid.
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] [k5c_precreate_ccache] 
(0x4000): Recreating ccache
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] [privileged_krb5_setup] 
(0x0080): Cannot open the PAC responder socket
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] [become_user] (0x0200): 
Trying to become user [xxxxx6683][xxxxx6683].
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] [main] (0x2000): Running 
as [xxxxx6683][xxxxx6683].
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] [k5c_setup] (0x2000): 
Running as [xxxxx6683][xxxxx6683].
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] [set_lifetime_options] 
(0x0100): Cannot read [SSSD_KRB5_RENEWABLE_LIFETIME] from environment.
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] [set_lifetime_options] 
(0x0100): Cannot read [SSSD_KRB5_LIFETIME] from environment.
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[set_canonicalize_option] (0x0100): SSSD_KRB5_CANONICALIZE is set to [true]
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] [main] (0x0400): Will 
perform online auth
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] [tgt_req_child] 
(0x1000): Attempting to get a TGT
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] [get_and_save_tgt] 
(0x0400): Attempting kinit for realm [DEF.XYZ.LOCAL]
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680143.556973: Getting initial 
credentials for first.last\@[email protected]
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680143.557229: Sending request 
(232 bytes) to DEF.XYZ.LOCAL
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680143.557638: Sending initial 
UDP request to dgram X.X.37.26:88
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680143.558913: Received answer 
from dgram X.X.37.26:88
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680143.559056: Response was 
from master KDC
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680143.559125: Received error 
from KDC: -1765328316/Realm not local to KDC
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680143.559168: Following 
referral to realm ABC.XYZ.LOCAL
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680143.559265: Sending request 
(232 bytes) to ABC.XYZ.LOCAL
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680143.560829: Resolving 
hostname corpdc001.abc.xyz.local.
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680143.567441: Sending initial 
UDP request to dgram X.X.20.66:88
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680143.576718: Received answer 
from dgram X.X.20.66:88
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680143.577431: Response was not 
from master KDC
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680143.577536: Received error 
from KDC: -1765328359/Additional pre-authentication required
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680143.577632: Processing 
preauth types: 16, 15, 19, 2
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680143.577690: Selected etype 
info: etype aes256-cts, salt "ABC.XYZ.LOCALfirst.last", params ""
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680143.602166: AS key obtained 
for encrypted timestamp: aes256-cts/11B0
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680143.602300: Encrypted 
timestamp (for 1498680143.602216): plain 
301AA011180F32303137303632383230303232335AA1050203093068, encrypted 
4D4749AB8C7E0A2FB61738C2C5EE07AC4B187DED86846052BF8906B43C111AB61F4E12CD2DE777261BC82943D415B97E80E0103A2C1C4F58
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680143.602386: Preauth module 
encrypted_timestamp (2) (flags=1) returned: 0/Success
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680143.602448: Produced preauth 
for next request: 2
(Wed Jun 28 16:02:23 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680143.602553: Sending request 
(312 bytes) to ABC.XYZ.LOCAL
(Wed Jun 28 16:02:24 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680144.689654: Response was not 
from master KDC
(Wed Jun 28 16:02:24 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680144.689738: Received error 
from KDC: -1765328332/Response too big for UDP, retry with TCP
(Wed Jun 28 16:02:24 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680144.689775: Request or 
response is too big for UDP; retrying with TCP
(Wed Jun 28 16:02:24 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680144.689805: Sending request 
(312 bytes) to ABC.XYZ.LOCAL (tcp only)
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.719737: Processing 
preauth types: 19
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.719780: Selected etype 
info: etype aes256-cts, salt "ABC.XYZ.LOCALfirst.last", params ""
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.719814: Produced preauth 
for next request: (empty)
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.719850: AS key 
determined by preauth: aes256-cts/11B0
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.719981: Decrypted AS 
reply; session key is: aes256-cts/20C6
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.720051: FAST 
negotiation: unavailable
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] 
[sss_krb5_expire_callback_func] (0x2000): exp_time: [923071]
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] [validate_tgt] (0x2000): 
Found keytab entry with the realm of the credential.
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.720284: Retrieving 
host/[email protected] from MEMORY:/etc/krb5.keytab (vno 0, 
enctype 0) with result: 0/Success
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.720344: Resolving unique 
ccache of type MEMORY
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.720395: Initializing 
MEMORY:ctHHOo4 with default princ [email protected]
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.720437: Removing 
[email protected] -> krbtgt/[email protected] from 
MEMORY:ctHHOo4
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.720473: Storing 
[email protected] -> krbtgt/[email protected] in MEMORY:ctHHOo4
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.720532: Getting 
credentials [email protected] -> 
host/[email protected] using ccache MEMORY:ctHHOo4
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.720614: Retrieving 
[email protected] -> host/[email protected] from 
MEMORY:ctHHOo4 with result: -1765328243/Matching credential not found
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.720691: Retrieving 
[email protected] -> krbtgt/[email protected] from 
MEMORY:ctHHOo4 with result: 0/Success
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.720737: Found cached TGT 
for service realm: [email protected] -> 
krbtgt/[email protected]
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.720777: Requesting 
tickets for host/[email protected], referrals on
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.720845: Generated subkey 
for TGS request: aes256-cts/D868
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.720891: etypes requested 
in TGS request: aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac
(Wed Jun 28 16:02:27 2017) [[sssd[krb5_child[23140]]]] 
[sss_child_krb5_trace_cb] (0x4000): [23140] 1498680147.721078: Sending request 
(1750 bytes) to ABC.XYZ.LOCAL
(Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [main] (0x0400): 
krb5_child started.
(Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [unpack_buffer] 
(0x1000): total buffer size: [181]
(Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [unpack_buffer] 
(0x0100): cmd [241] uid [xxxxx6683] gid [xxxxx6683] validate [true] enterprise 
principal [false] offline [true] UPN [[email protected]]
(Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [unpack_buffer] 
(0x0100): ccname: [FILE:/tmp/krb5cc_xxxxx6683_XXXXXX] old_ccname: 
[FILE:/tmp/krb5cc_xxxxx6683_9sctMM] keytab: [/etc/krb5.keytab]
(Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [check_use_fast] 
(0x0100): Not using FAST.
(Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [switch_creds] (0x0200): 
Switch user to [xxxxx6683][xxxxx6683].
(Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] 
[sss_krb5_cc_verify_ccache] (0x2000): TGT not found or expired.
(Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [switch_creds] (0x0200): 
Switch user to [0][0].
(Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [k5c_check_old_ccache] 
(0x4000): Ccache_file is [FILE:/tmp/krb5cc_xxxxx6683_9sctMM] and is not active 
and TGT is  valid.
(Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [privileged_krb5_setup] 
(0x0080): Cannot open the PAC responder socket
(Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [become_user] (0x0200): 
Trying to become user [xxxxx6683][xxxxx6683].
(Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [main] (0x2000): Running 
as [xxxxx6683][xxxxx6683].
(Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [become_user] (0x0200): 
Trying to become user [xxxxx6683][xxxxx6683].
(Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [become_user] (0x0200): 
Already user [xxxxx6683].
(Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [k5c_setup] (0x2000): 
Running as [xxxxx6683][xxxxx6683].
(Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [set_lifetime_options] 
(0x0100): Cannot read [SSSD_KRB5_RENEWABLE_LIFETIME] from environment.
(Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [set_lifetime_options] 
(0x0100): Cannot read [SSSD_KRB5_LIFETIME] from environment.
(Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [main] (0x0400): Will 
perform offline auth
(Wed Jun 28 16:02:29 2017) [[sssd[krb5_child[23141]]]] [create_empty_ccache] 
(0x1000): Existing ccache still valid, reusing
(Wed Jun 28 16:10:33 2017) [sssd[be[def.xyz.local]]] [sbus_dispatch] (0x4000): 
dbus conn: 0x10f5170
(Wed Jun 28 16:10:33 2017) [sssd[be[def.xyz.local]]] [sbus_dispatch] (0x4000): 
Dispatching.
(Wed Jun 28 16:10:33 2017) [sssd[be[def.xyz.local]]] [sbus_message_handler] 
(0x2000): Received SBUS method org.freedesktop.sssd.service.ping on path 
/org/freedesktop/sssd/service
(Wed Jun 28 16:10:33 2017) [sssd[be[def.xyz.local]]] [sbus_get_sender_id_send] 
(0x2000): Not a sysbus message, quit
(Wed Jun 28 16:10:43 2017) [sssd[be[def.xyz.local]]] [sbus_dispatch] (0x4000): 
dbus conn: 0x10f5170
(Wed Jun 28 16:10:43 2017) [sssd[be[def.xyz.local]]] [sbus_dispatch] (0x4000): 
Dispatching.
(Wed Jun 28 16:10:43 2017) [sssd[be[def.xyz.local]]] [sbus_message_handler] 
(0x2000): Received SBUS method org.freedesktop.sssd.service.ping on path 
/org/freedesktop/sssd/service
(Wed Jun 28 16:10:43 2017) [sssd[be[def.xyz.local]]] [sbus_get_sender_id_send] 
(0x2000): Not a sysbus message, quit
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sbus_dispatch] (0x4000): 
dbus conn: 0x114da80
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sbus_dispatch] (0x4000): 
Dispatching.
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sbus_message_handler] 
(0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo 
on path /org/freedesktop/sssd/dataprovider
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sbus_get_sender_id_send] 
(0x2000): Not a sysbus message, quit
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [be_get_account_info] 
(0x0200): Got request for [0x3][BE_REQ_INITGROUPS][1][name=first.last]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [be_req_set_domain] 
(0x0400): Changing request domain from [def.xyz.local] to [abc.xyz.local]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x118e2b0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11a0060
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x118e2b0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11a0060 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x118e2b0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_id_op_connect_step] 
(0x4000): reusing cached connection
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_get_initgr_send] 
(0x4000): Retrieving info for initgroups call
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_initgr_next_base] (0x0400): Searching for users with base 
[dc=abc,dc=xyz,dc=local]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_print_server] 
(0x2000): Searching X.X.37.26
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with 
[(&(sAMAccountName=first.last)(objectclass=user)(objectSID=*))][dc=abc,dc=xyz,dc=local].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 7
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_op_add] (0x2000): 
New operation 7 timeout 6
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] 
(0x2000): Trace: sh[0x1160ae0], connected[1], ops[0x11a0400], ldap[0x1161d90]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_message] 
(0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_entry] 
(0x1000): OriginalDN: [CN=First 
Last,OU=Users,OU=Dept,OU=Team,OU=Location,OU=Country,OU=Company,DC=abc,DC=xyz,DC=local].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_range] 
(0x2000): No sub-attributes for [objectClass]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_range] 
(0x2000): No sub-attributes for [whenChanged]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_range] 
(0x2000): No sub-attributes for [memberOf]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_range] 
(0x2000): No sub-attributes for [uSNChanged]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_range] 
(0x2000): No sub-attributes for [name]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_range] 
(0x2000): No sub-attributes for [objectGUID]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_range] 
(0x2000): No sub-attributes for [userAccountControl]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_range] 
(0x2000): No sub-attributes for [primaryGroupID]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_range] 
(0x2000): No sub-attributes for [objectSid]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_range] 
(0x2000): No sub-attributes for [sAMAccountName]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_range] 
(0x2000): No sub-attributes for [userPrincipalName]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] 
(0x2000): Trace: sh[0x1160ae0], connected[1], ops[0x11a0400], ldap[0x1161d90]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_message] 
(0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg 
set
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_op_destructor] 
(0x2000): Operation 7 finished
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_get_initgr_user] 
(0x4000): Receiving info for the user
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): start ldb 
transaction (nesting: 0)
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_get_initgr_user] 
(0x4000): Storing the user
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_save_user] (0x0400): 
Save user
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_get_primary_name] 
(0x0400): Processing object [email protected]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_save_user] (0x0400): 
Processing user [email protected]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_save_user] (0x1000): 
Mapping user [[email protected]] objectSID [SID String-6683] to unix ID
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_save_user] (0x2000): 
Adding originalDN [CN=First 
Last,OU=Users,OU=Dept,OU=Team,OU=Location,OU=Country,OU=Company,DC=abc,DC=xyz,DC=local]
 to attributes of [[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_save_user] (0x0400): 
Adding original memberOf attributes to [[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): Adding original mod-Timestamp [20170622141237.0Z] to attributes of 
[[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_save_user] (0x0400): 
Adding user principal [[email protected]] to attributes of 
[[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): shadowLastChange is not available for [[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): shadowMin is not available for [[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): shadowMax is not available for [[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): shadowWarning is not available for [[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): shadowInactive is not available for [[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): shadowExpire is not available for [[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): shadowFlag is not available for [[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): krbLastPwdChange is not available for [[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): krbPasswordExpiration is not available for [[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): pwdAttribute is not available for [[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): authorizedService is not available for [[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): adAccountExpires is not available for [[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): Adding adUserAccountControl [512] to attributes of 
[[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): nsAccountLock is not available for [[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): authorizedHost is not available for [[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): ndsLoginDisabled is not available for [[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): ndsLoginExpirationTime is not available for 
[[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): ndsLoginAllowedTimeMap is not available for 
[[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): sshPublicKey is not available for [[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): authType is not available for [[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_attrs_add_ldap_attr] 
(0x2000): userCertificate is not available for [[email protected]].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sysdb_attrs_get_aliases] 
(0x2000): Domain is case-insensitive; will add lowercased aliases
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_save_user] (0x0400): 
Storing info for user [email protected]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): start ldb 
transaction (nesting: 1)
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x1174320
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x118cc40
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x1174320 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x118cc40 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x1174320 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): start ldb 
transaction (nesting: 2)
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11a7820
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x118b9a0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11a7820 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x118b9a0 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11a7820 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): commit ldb 
transaction (nesting: 2)
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): start ldb 
transaction (nesting: 2)
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sysdb_remove_attrs] 
(0x2000): Removing attribute [userPassword] from [[email protected]]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): start ldb 
transaction (nesting: 3)
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11a7b40
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11a7d30
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11a7b40 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11a7d30 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11a7b40 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): cancel ldb 
transaction (nesting: 3)
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sysdb_remove_attrs] 
(0x2000): Removing attribute [homeDirectory] from [[email protected]]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): start ldb 
transaction (nesting: 3)
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x119f980
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11a3d80
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x119f980 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11a3d80 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x119f980 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): cancel ldb 
transaction (nesting: 3)
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sysdb_remove_attrs] 
(0x2000): Removing attribute [loginShell] from [[email protected]]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): start ldb 
transaction (nesting: 3)
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x119f980
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11a1d70
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x119f980 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11a1d70 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x119f980 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): cancel ldb 
transaction (nesting: 3)
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sysdb_remove_attrs] 
(0x2000): Removing attribute [adAccountExpires] from [[email protected]]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): start ldb 
transaction (nesting: 3)
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11a3d80
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11a63e0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11a3d80 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11a63e0 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11a3d80 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): cancel ldb 
transaction (nesting: 3)
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): commit ldb 
transaction (nesting: 2)
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): commit ldb 
transaction (nesting: 1)
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_get_initgr_user] 
(0x4000): Commit change
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): commit ldb 
transaction (nesting: 0)
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x119f890
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x119f950
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x119f890 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x119f950 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x119f890 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_get_initgr_user] 
(0x4000): Process user's groups
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_id_op_connect_step] 
(0x4000): reusing cached connection
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_print_server] 
(0x2000): Searching X.X.20.166
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [no 
filter][CN=First 
Last,OU=Users,OU=Dept,OU=Team,OU=Location,OU=Country,OU=Company,DC=abc,DC=xyz,DC=local].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [tokenGroups]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 9
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_op_add] (0x2000): 
New operation 9 timeout 6
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] 
(0x2000): Trace: sh[0x1160ae0], connected[1], ops[(nil)], ldap[0x1161d90]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] 
(0x2000): Trace: ldap_result found nothing!
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] 
(0x2000): Trace: sh[0x1182d40], connected[1], ops[0x118b4e0], ldap[0x1191ab0]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_message] 
(0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_entry] 
(0x1000): OriginalDN: [CN=First 
Last,OU=Users,OU=Dept,OU=Team,OU=Location,OU=Country,OU=Company,DC=abc,DC=xyz,DC=local].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_range] 
(0x2000): No sub-attributes for [tokenGroups]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] 
(0x2000): Trace: sh[0x1182d40], connected[1], ops[0x118b4e0], ldap[0x1191ab0]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_message] 
(0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg 
set
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_op_destructor] 
(0x2000): Operation 9 finished
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[S-1-5-32-545]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x0080): Domain not found for SID 
S-1-5-32-545
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-18872]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11a7270
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11a73a0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11a7270 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11a73a0 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11a7270 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-18726]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11adfb0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11ae070
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11adfb0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11ae070 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11adfb0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-18871]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11a9d30
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11aabf0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11a9d30 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11aabf0 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11a9d30 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-18870]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11a9c90
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11aa880
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11a9c90 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11aa880 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11a9c90 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-5299]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11a9c90
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11ad900
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11a9c90 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11ad900 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11a9c90 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-106610]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11a46b0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11aa880
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11a46b0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11aa880 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11a46b0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-2931]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11b0090
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11a3090
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11b0090 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11a3090 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11b0090 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-25159]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11aefb0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11ae2d0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11aefb0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11ae2d0 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11aefb0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-27107]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11aefb0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11ae960
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11aefb0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11ae960 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11aefb0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sysdb_search_entry_by_sid_str] (0x0400): No such entry
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x0400): Missing SID SID String-27107 
will be downloaded
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-24225]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11aefb0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11ae960
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11aefb0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11ae960 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11aefb0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-42327]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11ae960
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11a9040
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11ae960 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11a9040 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11ae960 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-21851]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11a8420
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11ae960
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11a8420 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11ae960 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11a8420 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-21664]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11a8420
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11ae960
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11a8420 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11ae960 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11a8420 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-21927]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11aefb0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11ae2d0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11aefb0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11ae2d0 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11aefb0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-21830]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11ae800
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11aefb0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11ae800 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11aefb0 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11ae800 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-21666]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11aefb0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11ae2d0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11aefb0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11ae2d0 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11aefb0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-42358]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11ae2d0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11aefb0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11ae2d0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11aefb0 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11ae2d0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-25819]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11ae2d0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11b23c0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11ae2d0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11b23c0 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11ae2d0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-25856]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11b33c0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11a9040
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11b33c0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11a9040 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11b33c0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-24129]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11b23c0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11ad900
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11b23c0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11ad900 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11b23c0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-25614]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11b37d0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11aefb0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11b37d0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11aefb0 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11b37d0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-25648]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11aefb0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11b37d0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11aefb0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11b37d0 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11aefb0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-9618]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11b37d0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11aefb0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11b37d0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11aefb0 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11b37d0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-25164]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11aefb0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11b37d0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11aefb0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11b37d0 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11aefb0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-513]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11b23c0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x120ad60
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11b23c0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x120ad60 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11b23c0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-20958]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11b23c0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11b4cc0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11b23c0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11b4cc0 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11b23c0 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_id_op_connect_step] 
(0x4000): reusing cached connection
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_id_op_connect_step] 
(0x4000): reusing cached connection
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_groups_next_base] (0x0400): Searching for groups with base 
[dc=abc,dc=xyz,dc=local]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_print_server] 
(0x2000): Searching X.X.20.166
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with 
[(&(objectSID=SID 
String-27107)(objectClass=group)(sAMAccountName=*))][dc=abc,dc=xyz,dc=local].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [groupType]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 10
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_op_add] (0x2000): 
New operation 10 timeout 6
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] 
(0x2000): Trace: sh[0x1182d40], connected[1], ops[0x118b4e0], ldap[0x1191ab0]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] 
(0x2000): Trace: ldap_result found nothing!
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] 
(0x2000): Trace: sh[0x1182d40], connected[1], ops[0x118b4e0], ldap[0x1191ab0]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_message] 
(0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_entry] 
(0x1000): OriginalDN: [CN=dddddddd,CN=Users,DC=abc,DC=xyz,DC=local].
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_range] 
(0x2000): No sub-attributes for [objectClass]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_range] 
(0x2000): No sub-attributes for [whenChanged]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_range] 
(0x2000): No sub-attributes for [uSNChanged]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_range] 
(0x2000): No sub-attributes for [objectGUID]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_range] 
(0x2000): No sub-attributes for [objectSid]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_range] 
(0x2000): No sub-attributes for [sAMAccountName]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_parse_range] 
(0x2000): No sub-attributes for [groupType]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] 
(0x2000): Trace: sh[0x1182d40], connected[1], ops[0x118b4e0], ldap[0x1191ab0]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_message] 
(0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_add_references] (0x1000): Additional References: 
ldap://DomainDnsZones.abc.xyz.local/DC=DomainDnsZones,DC=abc,DC=xyz,DC=local
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] 
(0x2000): Trace: sh[0x1182d40], connected[1], ops[0x118b4e0], ldap[0x1191ab0]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_message] 
(0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_add_references] (0x1000): Additional References: 
ldap://remotedomain1.abc.xyz.local/DC=remotedomain1,DC=abc,DC=xyz,DC=local
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] 
(0x2000): Trace: sh[0x1182d40], connected[1], ops[0x118b4e0], ldap[0x1191ab0]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_message] 
(0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_ext_add_references] (0x1000): Additional References: 
ldap://remotedomain2.abc.xyz.local/DC=remotedomain2,DC=abc,DC=xyz,DC=local
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] 
(0x2000): Trace: sh[0x1182d40], connected[1], ops[0x118b4e0], ldap[0x1191ab0]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_message] 
(0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg 
set
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_op_destructor] 
(0x2000): Operation 10 finished
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[generic_ext_search_handler] (0x4000): Request included referrals which were 
ignored.
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[generic_ext_search_handler] (0x4000):     Ref: 
ldap://DomainDnsZones.abc.xyz.local/DC=DomainDnsZones,DC=abc,DC=xyz,DC=local
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[generic_ext_search_handler] (0x4000):     Ref: 
ldap://remotedomain1.abc.xyz.local/DC=remotedomain1,DC=abc,DC=xyz,DC=local
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[generic_ext_search_handler] (0x4000):     Ref: 
ldap://remotedomain2.abc.xyz.local/DC=remotedomain2,DC=abc,DC=xyz,DC=local
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_get_groups_process] 
(0x0400): Search for groups, returned 1 results.
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_id_op_destroy] 
(0x4000): releasing operation connection
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_id_op_done] 
(0x4000): releasing operation connection
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_resolve_sids_done] (0x0020): Unable to resolve SID SID String-27107 - 
will try next sid.
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID 
[SID String-27107]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11b3300
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11a9d50
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11b3300 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11a9d50 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11b3300 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sysdb_search_entry_by_sid_str] (0x0400): No such entry
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11b3200
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11b32c0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11b3200 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11b32c0 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11b3200 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[sdap_ad_tokengroups_update_members] (0x1000): Updating memberships for 
[[email protected]]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): start ldb 
transaction (nesting: 0)
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): commit ldb 
transaction (nesting: 0)
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_id_op_destroy] 
(0x4000): releasing operation connection
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_get_initgr_done] 
(0x4000): Initgroups done
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_get_initgr_done] 
(0x1000): Mapping primary group to unix ID
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11a5950
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11a5a80
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11a5950 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11a5a80 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11a5950 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_get_initgr_done] 
(0x0400): Primary group already cached, nothing to do.
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_id_op_done] 
(0x4000): releasing operation connection
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x1177650
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x1182a90
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x1177650 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x1182a90 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x1177650 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): start ldb 
transaction (nesting: 0)
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x11a0400
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x11a2140
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x11a0400 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x11a2140 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x11a0400 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): commit ldb 
transaction (nesting: 0)
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [acctinfo_callback] 
(0x0100): Request processed. Returned 0,0,Success
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] 
(0x2000): Trace: sh[0x1182d40], connected[1], ops[(nil)], ldap[0x1191ab0]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sdap_process_result] 
(0x2000): Trace: ldap_result found nothing!
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sbus_dispatch] (0x4000): 
dbus conn: 0x114da80
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sbus_dispatch] (0x4000): 
Dispatching.
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sbus_message_handler] 
(0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.pamHandler on 
path /org/freedesktop/sssd/dataprovider
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [sbus_get_sender_id_send] 
(0x2000): Not a sysbus message, quit
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [be_req_set_domain] 
(0x0400): Changing request domain from [def.xyz.local] to [abc.xyz.local]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [be_pam_handler] (0x0100): 
Got request with the following data
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [pam_print_data] (0x0100): 
command: SSS_PAM_AUTHENTICATE
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [pam_print_data] (0x0100): 
domain: abc.xyz.local
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [pam_print_data] (0x0100): 
user: [email protected]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [pam_print_data] (0x0100): 
service: sshd
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [pam_print_data] (0x0100): 
tty: ssh
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [pam_print_data] (0x0100): 
ruser: 
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [pam_print_data] (0x0100): 
rhost: remote-host.abc.xyz.local
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [pam_print_data] (0x0100): 
authtok type: 1
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [pam_print_data] (0x0100): 
newauthtok type: 0
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [pam_print_data] (0x0100): 
priv: 1
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [pam_print_data] (0x0100): 
cli_pid: 23205
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [pam_print_data] (0x0100): 
logon name: not set
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [krb5_auth_queue_send] 
(0x1000): Wait queue of user [[email protected]] is empty, running 
request [0x11762e0] immediately.
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [krb5_setup] (0x4000): No 
mapping for: [email protected]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_callback": 0x119e510
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Added 
timed event "ltdb_timeout": 0x1182a90
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Running 
timer event 0x119e510 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Destroying 
timer event 0x1182a90 "ltdb_timeout"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ldb] (0x4000): Ending 
timer event 0x119e510 "ltdb_callback"
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [krb5_auth_send] (0x0100): 
Home directory for user [[email protected]] not known.
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [fo_resolve_service_send] 
(0x0100): Trying to resolve service 'AD'
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [get_server_status] 
(0x1000): Status of server 'AD_Server.def.xyz.local' is 'working'
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [get_port_status] 
(0x1000): Port status of port 0 for server 'AD_Server.def.xyz.local' is 
'working'
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [get_server_status] 
(0x1000): Status of server 'AD_Server.def.xyz.local' is 'working'
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[be_resolve_server_process] (0x1000): Saving the first resolved server
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[be_resolve_server_process] (0x0200): Found address for server 
AD_Server.def.xyz.local: [X.X.37.26] TTL 3600
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ad_resolve_callback] 
(0x0100): Constructed uri 'ldap://AD_Server.def.xyz.local'
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [ad_resolve_callback] 
(0x0100): Constructed GC uri 'ldap://AD_Server.def.xyz.local'
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] 
[unique_filename_destructor] (0x2000): Unlinking 
[/var/lib/sss/pubconf/.krb5info_dummy_jY69Pr]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [unlink_dbg] (0x2000): 
File already removed: [/var/lib/sss/pubconf/.krb5info_dummy_jY69Pr]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [child_handler_setup] 
(0x2000): Setting up signal handler up for pid [23206]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [child_handler_setup] 
(0x2000): Signal handler set up for pid [23206]
(Wed Jun 28 16:10:46 2017) [sssd[be[def.xyz.local]]] [write_pipe_handler] 
(0x0400): All data has been sent!
(Wed Jun 28 16:10:50 2017) [sssd[be[def.xyz.local]]] [child_sig_handler] 
(0x1000): Waiting for child [23206].
(Wed Jun 28 16:10:50 2017) [sssd[be[def.xyz.local]]] [child_sig_handler] 
(0x0100): child [23206] finished successfully.
(Wed Jun 28 16:10:50 2017) [sssd[be[def.xyz.local]]] [read_pipe_handler] 
(0x0400): EOF received, client finished
(Wed Jun 28 16:10:50 2017) [sssd[be[def.xyz.local]]] 
[parse_krb5_child_response] (0x1000): child response [1432158209][6][8].
(Wed Jun 28 16:10:50 2017) [sssd[be[def.xyz.local]]] [check_wait_queue] 
(0x1000): Wait queue for user [[email protected]] is empty.
(Wed Jun 28 16:10:50 2017) [sssd[be[def.xyz.local]]] [krb5_auth_queue_done] 
(0x1000): krb5_auth_queue request [0x11762e0] done.
(Wed Jun 28 16:10:50 2017) [sssd[be[def.xyz.local]]] [be_pam_handler_callback] 
(0x0100): Backend returned: (0, 4, <NULL>) [Success]
(Wed Jun 28 16:10:50 2017) [sssd[be[def.xyz.local]]] [be_pam_handler_callback] 
(0x0100): Sending result [4][abc.xyz.local]
(Wed Jun 28 16:10:50 2017) [sssd[be[def.xyz.local]]] [be_pam_handler_callback] 
(0x0100): Sent result [4][abc.xyz.local]
(Wed Jun 28 16:10:53 2017) [sssd[be[def.xyz.local]]] [sbus_dispatch] (0x4000): 
dbus conn: 0x10f5170
(Wed Jun 28 16:10:53 2017) [sssd[be[def.xyz.local]]] [sbus_dispatch] (0x4000): 
Dispatching.
(Wed Jun 28 16:10:53 2017) [sssd[be[def.xyz.local]]] [sbus_message_handler] 
(0x2000): Received SBUS method org.freedesktop.sssd.service.ping on path 
/org/freedesktop/sssd/service
(Wed Jun 28 16:10:53 2017) [sssd[be[def.xyz.local]]] [sbus_get_sender_id_send] 
(0x2000): Not a sysbus message, quit
_______________________________________________
sssd-users mailing list -- [email protected]
To unsubscribe send an email to [email protected]

Reply via email to