Login
[x]
Log in using an account from:
Fedora Account System
Red Hat Associate
Red Hat Customer
Or login using a Red Hat Bugzilla account
Forgot Password
Login:
Hide Forgot
Create an Account
Red Hat Bugzilla – Attachment 851732 Details for
Bug 1054899
explicitly suggest krb5_auth_timeout in a loud DEBUG message in case Kerberos authentication times out
[?]
New
Simple Search
Advanced Search
My Links
Browse
Requests
Reports
Current State
Search
Tabular reports
Graphical reports
Duplicates
Other Reports
User Changes
Plotly Reports
Bug Status
Bug Severity
Non-Defaults
|
Product Dashboard
Help
Page Help!
Bug Writing Guidelines
What's new
Browser Support Policy
5.0.4.rh83 Release notes
FAQ
Guides index
User guide
Web Services
Contact
Legal
This site requires JavaScript to be enabled to function correctly, please enable it.
domain log for non-primary(user1_dom3) user login
user1_dom3_sssd_sssdad.com.log (text/plain), 139.45 KB, created by
Kaushik Banerjee
on 2014-01-17 17:39:58 UTC
(
hide
)
Description:
domain log for non-primary(user1_dom3) user login
Filename:
MIME Type:
Creator:
Kaushik Banerjee
Created:
2014-01-17 17:39:58 UTC
Size:
139.45 KB
patch
obsolete
>(Fri Jan 17 06:39:25 2014) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x7ff269f0e640 >(Fri Jan 17 06:39:25 2014) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): Dispatching. >(Fri Jan 17 06:39:25 2014) [sssd[be[sssdad.com]]] [sbus_message_handler] (0x4000): Received SBUS method [ping] >(Fri Jan 17 06:39:35 2014) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x7ff269f0e640 >(Fri Jan 17 06:39:35 2014) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): Dispatching. >(Fri Jan 17 06:39:35 2014) [sssd[be[sssdad.com]]] [sbus_message_handler] (0x4000): Received SBUS method [ping] >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x7ff269f3a7a0 >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): Dispatching. >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [sbus_message_handler] (0x4000): Received SBUS method [getAccountInfo] >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [be_get_account_info] (0x0100): Got request for [4097][1][name=user1_dom3] >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [be_req_set_domain] (0x0400): Changing request domain from [sssdad.com] to [child1.sssdad.com] >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [sdap_idmap_add_domain] (0x1000): Adding domain [S-1-5-21-2153326666-2176343378-3404031434] as slice [3853] >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [sysdb_idmap_dn] (0x4000): objectSID=S-1-5-21-2153326666-2176343378-3404031434,cn=id_mappings,cn=sssdad.com,cn=sysdb >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 0) >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f52550 > >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f50a20 > >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f52550 "ltdb_callback" > >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f50a20 "ltdb_timeout" > >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f52550 "ltdb_callback" > >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [sysdb_idmap_store_mapping] (0x0100): Adding new ID mapping [sssdad.com][S-1-5-21-2153326666-2176343378-3404031434][3853] >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 1) >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f3ff50 > >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f40080 > >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f3ff50 "ltdb_callback" > >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f40080 "ltdb_timeout" > >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f3ff50 "ltdb_callback" > >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 1) >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 0) >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [sdap_id_op_connect_step] (0x4000): beginning to connect >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD_GC' >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [get_port_status] (0x1000): Port status of port 0 for server '(no name)' is 'neutral' >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [resolve_srv_send] (0x0200): The status of SRV lookup is neutral >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [ad_srv_plugin_send] (0x0400): About to find domain controllers >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [ad_get_dc_servers_send] (0x0400): Looking up domain controllers in domain sssdad.com >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'ldap'. Will use DNS discovery domain 'sssdad.com' >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_ldap._tcp.sssdad.com' >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [request_watch_destructor] (0x0400): Deleting request watch >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got 1 servers >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [ad_get_dc_servers_done] (0x0400): Found 1 domain controllers in domain sssdad.com >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [ad_srv_plugin_dcs_done] (0x0400): About to locate suitable site >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [sdap_connect_host_send] (0x0400): Resolving host pluto.sssdad.com >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [resolv_is_address] (0x4000): [pluto.sssdad.com] does not look like an IP address >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying files >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'pluto.sssdad.com' in files >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying files >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'pluto.sssdad.com' in files >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying DNS >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'pluto.sssdad.com' in DNS >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds >(Fri Jan 17 06:39:37 2014) [sssd[be[sssdad.com]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [request_watch_destructor] (0x0400): Deleting request watch >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [sdap_connect_host_resolv_done] (0x0400): Connecting to ldap://pluto.sssdad.com:389 >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [sss_ldap_init_send] (0x4000): Using file descriptor [23] for LDAP connection. >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://pluto.sssdad.com:389/??base] with fd [23]. >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [sdap_connect_host_done] (0x0400): Successful connection to ldap://pluto.sssdad.com:389 >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(DnsDomain=sssdad.com)(NtVer=\14\00\00\00))][]. >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [netlogon] >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f40010], connected[1], ops[0x7ff269f62d50], ldap[0x7ff269f59f60] >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [sdap_parse_entry] (0x4000): OriginalDN: []. >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [netlogon] >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f40010], connected[1], ops[0x7ff269f62d50], ldap[0x7ff269f59f60] >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [sdap_handle_release] (0x2000): Trace: sh[0x7ff269f40010], connected[1], ops[(nil)], ldap[0x7ff269f59f60], destructor_lock[0], release_memory[0] >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [remove_connection_callback] (0x4000): Successfully removed connection callback. >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [ad_get_client_site_done] (0x0400): Found site: Default-First-Site-Name >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [ad_srv_plugin_site_done] (0x0400): About to discover primary and backup servers >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [fo_discover_servers_send] (0x0400): Looking up primary servers >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'gc'. Will use DNS discovery domain 'Default-First-Site-Name._sites.sssdad.com' >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_gc._tcp.Default-First-Site-Name._sites.sssdad.com' >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds >(Fri Jan 17 06:39:38 2014) [sssd[be[sssdad.com]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [request_watch_destructor] (0x0400): Deleting request watch >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got 3 servers >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [fo_discover_servers_primary_done] (0x0400): Looking up backup servers >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'gc'. Will use DNS discovery domain 'sssdad.com' >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_gc._tcp.sssdad.com' >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [request_watch_destructor] (0x0400): Deleting request watch >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got 3 servers >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [ad_srv_plugin_servers_done] (0x0400): Got 3 primary and 3 backup servers >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'pluto.sssdad.com:3268' to service 'AD_GC' >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'longhaul.child1.sssdad.com:3268' to service 'AD_GC' >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'eagle.sssdad_tree.com:3268' to service 'AD_GC' >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing GC with GC >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing GC with GC >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [fo_add_server_to_list] (0x0400): Server 'longhaul.child1.sssdad.com:3268' for service 'AD_GC' is already present >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing GC with GC >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [fo_add_server_to_list] (0x0400): Server 'pluto.sssdad.com:3268' for service 'AD_GC' is already present >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing GC with GC >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing GC with GC >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing GC with GC >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [fo_add_server_to_list] (0x0400): Server 'eagle.sssdad_tree.com:3268' for service 'AD_GC' is already present >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [set_srv_data_status] (0x0100): Marking SRV lookup of service 'AD_GC' as 'resolved' >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'pluto.sssdad.com' is 'working' >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x0200): Found address for server pluto.sssdad.com: [10.65.206.100] TTL 3600 >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://pluto.sssdad.com' >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [ad_resolve_callback] (0x0100): Constructed GC uri 'ldap://pluto.sssdad.com:3268' >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sss_ldap_init_send] (0x4000): Using file descriptor [23] for LDAP connection. >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://pluto.sssdad.com:3268/??base] with fd [23]. >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_get_rootdse_send] (0x4000): Getting rootdse >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f71490], connected[1], ops[0x7ff269f71640], ldap[0x7ff269f724d0] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f71490], connected[1], ops[0x7ff269f71640], ldap[0x7ff269f724d0] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_entry] (0x4000): OriginalDN: []. >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [currentTime] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [subschemaSubentry] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [dsServiceName] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [namingContexts] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [defaultNamingContext] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [schemaNamingContext] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [configurationNamingContext] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [rootDomainNamingContext] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedControl] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPVersion] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPPolicies] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [highestCommittedUSN] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedSASLMechanisms] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [dnsHostName] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [ldapServiceName] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [serverName] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedCapabilities] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [isSynchronized] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [isGlobalCatalogReady] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedExtension] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainFunctionality] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [forestFunctionality] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainControllerFunctionality] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f71490], connected[1], ops[0x7ff269f71640], ldap[0x7ff269f724d0] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_get_rootdse_done] (0x2000): Got rootdse >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_get_server_opts_from_rootdse] (0x4000): USN value: 672395 (int: 672395) >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [4] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, AMD-PIKE-05$, SSSDAD.COM, 86400) >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service AD >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'pluto.sssdad.com' is 'working' >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [get_port_status] (0x1000): Port status of port 389 for server 'pluto.sssdad.com' is 'working' >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'pluto.sssdad.com' is 'working' >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x0200): Found address for server pluto.sssdad.com: [10.65.206.100] TTL 3600 >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://pluto.sssdad.com' >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [ad_resolve_callback] (0x0100): Constructed GC uri 'ldap://pluto.sssdad.com' >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 38 >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [896] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [child_handler_setup] (0x2000): Signal handler set up for pid [896] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f71490], connected[1], ops[(nil)], ldap[0x7ff269f724d0] >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! >(Fri Jan 17 06:39:39 2014) [sssd[be[sssdad.com]]] [write_pipe_handler] (0x0400): All data has been sent! >(Fri Jan 17 06:39:40 2014) [sssd[be[sssdad.com]]] [child_sig_handler] (0x1000): Waiting for child [896]. >(Fri Jan 17 06:39:40 2014) [sssd[be[sssdad.com]]] [child_sig_handler] (0x0100): child [896] finished successfully. >(Fri Jan 17 06:39:40 2014) [sssd[be[sssdad.com]]] [read_pipe_handler] (0x0400): EOF received, client finished >(Fri Jan 17 06:39:40 2014) [sssd[be[sssdad.com]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_SSSDAD.COM], expired on [1389994780] >(Fri Jan 17 06:39:40 2014) [sssd[be[sssdad.com]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 >(Fri Jan 17 06:39:40 2014) [sssd[be[sssdad.com]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1389959680 >(Fri Jan 17 06:39:40 2014) [sssd[be[sssdad.com]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: AMD-PIKE-05$ >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [fo_set_port_status] (0x0100): Marking port 3268 of server 'pluto.sssdad.com' as 'working' >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [set_server_common_status] (0x0100): Marking server 'pluto.sssdad.com' as 'working' >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing GC with GC >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [fo_set_port_status] (0x0400): Marking port 3268 of duplicate server 'pluto.sssdad.com' as 'working' >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing GC with GC >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing GC with GC >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_id_op_connect_done] (0x2000): Old USN: 672384, New USN: 672395 >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_id_op_connect_done] (0x4000): notify connected to op #1 >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_search_user_next_base] (0x0400): Searching for users with base [dc=child1,dc=sssdad,dc=com] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(sAMAccountName=user1_dom3)(objectclass=user)(sAMAccountName=*)(objectSID=*))][dc=child1,dc=sssdad,dc=com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 5 >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_id_op_connect_done] (0x4000): caching successful connection after 1 notifies >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [be_run_unconditional_online_cb] (0x4000): List of unconditional online callbacks is empty, nothing to do. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [be_run_online_cb] (0x0080): Going online. Running callbacks. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ad_online_cb] (0x0400): The AD provider is online >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ad_online_cb] (0x0400): The AD provider is online >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [objectclass=domain][DC=sssdad,DC=com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 11 >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [delayed_online_authentication_callback] (0x0200): Backend is online, starting delayed online authentication. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [be_nsupdate_timer_schedule] (0x0200): Timer already scheduled >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ad_dyndns_update_send] (0x0400): Performing update >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ad_dyndns_update_send] (0x0200): Last periodic update ran recently or timerin progress, not scheduling another update >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ad_dyndns_nsupdate_done] (0x0040): DNS update finished >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ad_online_cb] (0x0400): The AD provider is online >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f71490], connected[1], ops[0x7ff269f7f150], ldap[0x7ff269f724d0] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_parse_entry] (0x4000): OriginalDN: [CN=user1_dom3,CN=Users,DC=child1,DC=sssdad,DC=com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectClass] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [whenChanged] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [uSNChanged] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [name] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectGUID] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [userAccountControl] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [primaryGroupID] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectSid] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [sAMAccountName] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [userPrincipalName] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f71490], connected[1], ops[0x7ff269f7f150], ldap[0x7ff269f724d0] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_search_user_process] (0x0400): Search for users, returned 1 results. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_search_user_process] (0x4000): Retrieved total 1 users >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 0) >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_save_user] (0x0400): Save user >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_primary_name] (0x0400): Processing object user1_dom3@child1.sssdad.com >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_save_user] (0x0400): Processing user user1_dom3@child1.sssdad.com >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_save_user] (0x1000): Mapping user [user1_dom3@child1.sssdad.com] objectSID [S-1-5-21-3406858696-2348136156-2230084869-1380] to unix ID >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_save_user] (0x2000): Adding originalDN [CN=user1_dom3,CN=Users,DC=child1,DC=sssdad,DC=com] to attributes of [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_save_user] (0x0400): Original memberOf is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding original mod-Timestamp [20140117112925.0Z] to attributes of [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_save_user] (0x0400): Adding user principal [user1_dom3@CHILD1.SSSDAD.COM] to attributes of [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowLastChange is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMin is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMax is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowWarning is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowInactive is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowExpire is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowFlag is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): krbLastPwdChange is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): krbPasswordExpiration is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): pwdAttribute is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedService is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): adAccountExpires is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding adUserAccountControl [512] to attributes of [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): nsAccountLock is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedHost is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginDisabled is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginExpirationTime is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginAllowedTimeMap is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): sshPublicKey is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sysdb_attrs_get_aliases] (0x2000): Domain is case-insensitive; will add lowercased aliases >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_save_user] (0x0400): Storing info for user user1_dom3@child1.sssdad.com >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 1) >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f8f850 > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f8f910 > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f8f850 "ltdb_callback" > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f8f910 "ltdb_timeout" > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f8f850 "ltdb_callback" > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sysdb_search_user_by_name] (0x0400): No such entry >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 2) >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f8ea00 > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f8eb30 > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f8ea00 "ltdb_callback" > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f8eb30 "ltdb_timeout" > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f8ea00 "ltdb_callback" > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sysdb_search_group_by_name] (0x0400): No such entry >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f900b0 > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f90170 > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f900b0 "ltdb_callback" > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f90170 "ltdb_timeout" > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f900b0 "ltdb_callback" > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sysdb_search_user_by_uid] (0x0400): No such entry >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 3) >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f922d0 > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f92400 > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f922d0 "ltdb_callback" > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f92400 "ltdb_timeout" > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f922d0 "ltdb_callback" > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 3) >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 3) >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f83420 > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f9a7b0 > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f83420 "ltdb_callback" > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f9a7b0 "ltdb_timeout" > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f83420 "ltdb_callback" > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 3) >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f9b260 > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f9ce20 > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f9b260 "ltdb_callback" > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f9ce20 "ltdb_timeout" > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f9b260 "ltdb_callback" > >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 2) >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 1) >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_save_users] (0x4000): User 0 processed! >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 0) >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_users_done] (0x4000): Saving 1 Users - Done >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_id_op_done] (0x4000): releasing operation connection >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f71490], connected[1], ops[(nil)], ldap[0x7ff269f724d0] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f41170], connected[1], ops[0x7ff269f7e2d0], ldap[0x7ff269f3a970] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_parse_entry] (0x4000): OriginalDN: [DC=sssdad,DC=com]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectSid] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f41170], connected[1], ops[0x7ff269f7e2d0], ldap[0x7ff269f3a970] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [ad_master_domain_next_done] (0x0400): Found SID [S-1-5-21-2153326666-2176343378-3404031434]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(DnsDomain=sssdad.com)(NtVer=\14\00\00\00))][]. >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [netlogon] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 12 >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f41170], connected[1], ops[0x7ff269f53e20], ldap[0x7ff269f3a970] >(Fri Jan 17 06:39:42 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f41170], connected[1], ops[0x7ff269f53e20], ldap[0x7ff269f3a970] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_parse_entry] (0x4000): OriginalDN: []. >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [netlogon] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f41170], connected[1], ops[0x7ff269f53e20], ldap[0x7ff269f3a970] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [ad_master_domain_netlogon_done] (0x0400): Found flat name [SSSDAD]. >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectclass=trustedDomain)(trustType=2)(!(msDS-TrustForestTrustInfo=*)))][DC=sssdad,DC=com]. >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [flatName] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [trustPartner] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [securityIdentifier] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [trustType] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [trustAttributes] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 13 >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f41170], connected[1], ops[0x7ff269f717a0], ldap[0x7ff269f3a970] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f41170], connected[1], ops[0x7ff269f717a0], ldap[0x7ff269f3a970] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_parse_entry] (0x4000): OriginalDN: [CN=sssdad_tree.com,CN=System,DC=sssdad,DC=com]. >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [securityIdentifier] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [trustPartner] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [trustType] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [trustAttributes] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [flatName] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f41170], connected[1], ops[0x7ff269f717a0], ldap[0x7ff269f3a970] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_parse_entry] (0x4000): OriginalDN: [CN=child1.sssdad.com,CN=System,DC=sssdad,DC=com]. >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [securityIdentifier] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [trustPartner] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [trustType] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [trustAttributes] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [flatName] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f41170], connected[1], ops[0x7ff269f717a0], ldap[0x7ff269f3a970] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f41170], connected[1], ops[0x7ff269f717a0], ldap[0x7ff269f3a970] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f41170], connected[1], ops[0x7ff269f717a0], ldap[0x7ff269f3a970] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f41170], connected[1], ops[0x7ff269f717a0], ldap[0x7ff269f3a970] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f41170], connected[1], ops[0x7ff269f717a0], ldap[0x7ff269f3a970] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f5c240 > >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f7d210 > >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f5c240 "ltdb_callback" > >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f7d210 "ltdb_timeout" > >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f5c240 "ltdb_callback" > >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f7ee40 > >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f7d590 > >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f7ee40 "ltdb_callback" > >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f7d590 "ltdb_timeout" > >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f7ee40 "ltdb_callback" > >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [ad_subdomains_get_slave_domain_done] (0x1000): There are no changes >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_id_op_destroy] (0x4000): releasing operation connection >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f41170], connected[1], ops[(nil)], ldap[0x7ff269f3a970] >(Fri Jan 17 06:39:43 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! >(Fri Jan 17 06:39:45 2014) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x7ff269f0e640 >(Fri Jan 17 06:39:45 2014) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): Dispatching. >(Fri Jan 17 06:39:45 2014) [sssd[be[sssdad.com]]] [sbus_message_handler] (0x4000): Received SBUS method [ping] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x7ff269f3b160 >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): Dispatching. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sbus_message_handler] (0x4000): Received SBUS method [getAccountInfo] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [be_get_account_info] (0x0100): Got request for [3][1][name=user1_dom3] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [be_req_set_domain] (0x0400): Changing request domain from [sssdad.com] to [child1.sssdad.com] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f529d0 > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f5c3b0 > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f529d0 "ltdb_callback" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f5c3b0 "ltdb_timeout" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f529d0 "ltdb_callback" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_initgr_send] (0x4000): Retrieving info for initgroups call >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_initgr_next_base] (0x0400): Searching for users with base [dc=child1,dc=sssdad,dc=com] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(sAMAccountName=user1_dom3)(objectclass=user)(objectSID=*))][dc=child1,dc=sssdad,dc=com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 6 >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f71490], connected[1], ops[0x7ff269f7f150], ldap[0x7ff269f724d0] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_parse_entry] (0x4000): OriginalDN: [CN=user1_dom3,CN=Users,DC=child1,DC=sssdad,DC=com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectClass] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [whenChanged] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [uSNChanged] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [name] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectGUID] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [userAccountControl] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [primaryGroupID] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectSid] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [sAMAccountName] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [userPrincipalName] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f71490], connected[1], ops[0x7ff269f7f150], ldap[0x7ff269f724d0] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_initgr_user] (0x4000): Receiving info for the user >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 0) >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_initgr_user] (0x4000): Storing the user >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_save_user] (0x0400): Save user >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_primary_name] (0x0400): Processing object user1_dom3@child1.sssdad.com >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_save_user] (0x0400): Processing user user1_dom3@child1.sssdad.com >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_save_user] (0x1000): Mapping user [user1_dom3@child1.sssdad.com] objectSID [S-1-5-21-3406858696-2348136156-2230084869-1380] to unix ID >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_save_user] (0x2000): Adding originalDN [CN=user1_dom3,CN=Users,DC=child1,DC=sssdad,DC=com] to attributes of [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_save_user] (0x0400): Original memberOf is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding original mod-Timestamp [20140117112925.0Z] to attributes of [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_save_user] (0x0400): Adding user principal [user1_dom3@CHILD1.SSSDAD.COM] to attributes of [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowLastChange is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMin is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMax is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowWarning is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowInactive is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowExpire is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowFlag is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): krbLastPwdChange is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): krbPasswordExpiration is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): pwdAttribute is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedService is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): adAccountExpires is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding adUserAccountControl [512] to attributes of [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): nsAccountLock is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedHost is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginDisabled is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginExpirationTime is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginAllowedTimeMap is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): sshPublicKey is not available for [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sysdb_attrs_get_aliases] (0x2000): Domain is case-insensitive; will add lowercased aliases >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_save_user] (0x0400): Storing info for user user1_dom3@child1.sssdad.com >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 1) >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f8f4f0 > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f8f5b0 > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f8f4f0 "ltdb_callback" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f8f5b0 "ltdb_timeout" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f8f4f0 "ltdb_callback" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 2) >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f8eb40 > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f8ec00 > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f8eb40 "ltdb_callback" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f8ec00 "ltdb_timeout" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f8eb40 "ltdb_callback" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 2) >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 2) >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sysdb_remove_attrs] (0x2000): Removing attribute [userPassword] from [user1_dom3@child1.sssdad.com] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 3) >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f94e60 > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f94f20 > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f94e60 "ltdb_callback" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f94f20 "ltdb_timeout" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f94e60 "ltdb_callback" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sysdb_remove_attrs] (0x2000): Removing attribute [homeDirectory] from [user1_dom3@child1.sssdad.com] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 3) >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f94e60 > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f94f20 > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f94e60 "ltdb_callback" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f94f20 "ltdb_timeout" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f94e60 "ltdb_callback" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sysdb_remove_attrs] (0x2000): Removing attribute [loginShell] from [user1_dom3@child1.sssdad.com] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 3) >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f94e60 > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f94f20 > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f94e60 "ltdb_callback" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f94f20 "ltdb_timeout" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f94e60 "ltdb_callback" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sysdb_remove_attrs] (0x2000): Removing attribute [adAccountExpires] from [user1_dom3@child1.sssdad.com] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 3) >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f94e60 > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f94f20 > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f94e60 "ltdb_callback" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f94f20 "ltdb_timeout" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f94e60 "ltdb_callback" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 2) >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 1) >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_initgr_user] (0x4000): Commit change >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 0) >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f8e9f0 > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f8eb20 > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f8e9f0 "ltdb_callback" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f8eb20 "ltdb_timeout" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f8e9f0 "ltdb_callback" > >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_get_initgr_user] (0x4000): Process user's groups >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_id_op_connect_step] (0x4000): beginning to connect >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'child1.sssdad.com' >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [get_port_status] (0x1000): Port status of port 0 for server '(no name)' is 'neutral' >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [resolve_srv_send] (0x0200): The status of SRV lookup is neutral >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ad_srv_plugin_send] (0x0400): About to find domain controllers >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [ad_get_dc_servers_send] (0x0400): Looking up domain controllers in domain child1.sssdad.com >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'ldap'. Will use DNS discovery domain 'child1.sssdad.com' >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_ldap._tcp.child1.sssdad.com' >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f71490], connected[1], ops[(nil)], ldap[0x7ff269f724d0] >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds >(Fri Jan 17 06:39:46 2014) [sssd[be[sssdad.com]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher >(Fri Jan 17 06:39:47 2014) [sssd[be[sssdad.com]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher >(Fri Jan 17 06:39:47 2014) [sssd[be[sssdad.com]]] [request_watch_destructor] (0x0400): Deleting request watch >(Fri Jan 17 06:39:47 2014) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... >(Fri Jan 17 06:39:47 2014) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got 1 servers >(Fri Jan 17 06:39:47 2014) [sssd[be[sssdad.com]]] [ad_get_dc_servers_done] (0x0400): Found 1 domain controllers in domain child1.sssdad.com >(Fri Jan 17 06:39:47 2014) [sssd[be[sssdad.com]]] [ad_srv_plugin_dcs_done] (0x0400): About to locate suitable site >(Fri Jan 17 06:39:47 2014) [sssd[be[sssdad.com]]] [sdap_connect_host_send] (0x0400): Resolving host longhaul.child1.sssdad.com >(Fri Jan 17 06:39:47 2014) [sssd[be[sssdad.com]]] [resolv_is_address] (0x4000): [longhaul.child1.sssdad.com] does not look like an IP address >(Fri Jan 17 06:39:47 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying files >(Fri Jan 17 06:39:47 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'longhaul.child1.sssdad.com' in files >(Fri Jan 17 06:39:47 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying files >(Fri Jan 17 06:39:47 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'longhaul.child1.sssdad.com' in files >(Fri Jan 17 06:39:47 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry >(Fri Jan 17 06:39:47 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying DNS >(Fri Jan 17 06:39:47 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'longhaul.child1.sssdad.com' in DNS >(Fri Jan 17 06:39:47 2014) [sssd[be[sssdad.com]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds >(Fri Jan 17 06:39:47 2014) [sssd[be[sssdad.com]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher >(Fri Jan 17 06:39:48 2014) [sssd[be[sssdad.com]]] [check_fd_timeouts] (0x4000): Checking for DNS timeouts >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [check_fd_timeouts] (0x4000): Checking for DNS timeouts >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [request_watch_destructor] (0x0400): Deleting request watch >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_done] (0x0040): querying hosts database failed [5]: Input/output error >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [sdap_connect_host_resolv_done] (0x0040): Failed to resolve host longhaul.child1.sssdad.com: Timeout while contacting DNS servers >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [ad_get_client_site_connect_done] (0x0080): Unable to connect to domain controller [longhaul.child1.sssdad.com:389] >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [ad_srv_plugin_site_done] (0x0400): About to discover primary and backup servers >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [fo_discover_servers_send] (0x0400): Looking up primary servers >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'ldap'. Will use DNS discovery domain 'child1.sssdad.com' >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_ldap._tcp.child1.sssdad.com' >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [request_watch_destructor] (0x0400): Deleting request watch >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got 1 servers >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [fo_discover_servers_primary_done] (0x0400): No backup domain specified >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [ad_srv_plugin_servers_done] (0x0400): Got 1 primary and 0 backup servers >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'longhaul.child1.sssdad.com:389' to service 'child1.sssdad.com' >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [set_srv_data_status] (0x0100): Marking SRV lookup of service 'child1.sssdad.com' as 'resolved' >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'longhaul.child1.sssdad.com' is 'name not resolved' >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [resolv_is_address] (0x4000): [longhaul.child1.sssdad.com] does not look like an IP address >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying files >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'longhaul.child1.sssdad.com' in files >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [set_server_common_status] (0x0100): Marking server 'longhaul.child1.sssdad.com' as 'resolving name' >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying files >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'longhaul.child1.sssdad.com' in files >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying DNS >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'longhaul.child1.sssdad.com' in DNS >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [request_watch_destructor] (0x0400): Deleting request watch >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [set_server_common_status] (0x0100): Marking server 'longhaul.child1.sssdad.com' as 'name resolved' >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x0200): Found address for server longhaul.child1.sssdad.com: [10.65.206.54] TTL 3600 >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://longhaul.child1.sssdad.com' >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [ad_resolve_callback] (0x0100): Constructed GC uri 'ldap://longhaul.child1.sssdad.com' >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [sss_ldap_init_send] (0x4000): Using file descriptor [24] for LDAP connection. >(Fri Jan 17 06:39:49 2014) [sssd[be[sssdad.com]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://longhaul.child1.sssdad.com:389/??base] with fd [24]. >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_get_rootdse_send] (0x4000): Getting rootdse >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f8f540], connected[1], ops[0x7ff269f8f460], ldap[0x7ff269f8e7a0] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f8f540], connected[1], ops[0x7ff269f8f460], ldap[0x7ff269f8e7a0] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_entry] (0x4000): OriginalDN: []. >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [currentTime] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [subschemaSubentry] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [dsServiceName] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [namingContexts] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [defaultNamingContext] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [schemaNamingContext] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [configurationNamingContext] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [rootDomainNamingContext] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedControl] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPVersion] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPPolicies] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [highestCommittedUSN] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedSASLMechanisms] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [dnsHostName] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [ldapServiceName] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [serverName] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedCapabilities] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [isSynchronized] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [isGlobalCatalogReady] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedExtension] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainFunctionality] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [forestFunctionality] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainControllerFunctionality] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f8f540], connected[1], ops[0x7ff269f8f460], ldap[0x7ff269f8e7a0] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_get_rootdse_done] (0x2000): Got rootdse >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_get_server_opts_from_rootdse] (0x4000): USN value: 264785 (int: 264785) >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [4] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, AMD-PIKE-05$, SSSDAD.COM, 86400) >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service child1.sssdad.com >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'child1.sssdad.com' >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'longhaul.child1.sssdad.com' is 'name resolved' >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'longhaul.child1.sssdad.com' is 'name resolved' >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x0200): Found address for server longhaul.child1.sssdad.com: [10.65.206.54] TTL 3600 >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 38 >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [897] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [child_handler_setup] (0x2000): Signal handler set up for pid [897] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f8f540], connected[1], ops[(nil)], ldap[0x7ff269f8e7a0] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [write_pipe_handler] (0x0400): All data has been sent! >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [child_sig_handler] (0x1000): Waiting for child [897]. >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [child_sig_handler] (0x0100): child [897] finished successfully. >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [read_pipe_handler] (0x0400): EOF received, client finished >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_SSSDAD.COM], expired on [1389994790] >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1389959690 >(Fri Jan 17 06:39:50 2014) [sssd[be[sssdad.com]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: AMD-PIKE-05$ >(Fri Jan 17 06:39:54 2014) [sssd[be[sssdad.com]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'longhaul.child1.sssdad.com' as 'working' >(Fri Jan 17 06:39:54 2014) [sssd[be[sssdad.com]]] [set_server_common_status] (0x0100): Marking server 'longhaul.child1.sssdad.com' as 'working' >(Fri Jan 17 06:39:54 2014) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing LDAP with LDAP >(Fri Jan 17 06:39:54 2014) [sssd[be[sssdad.com]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'longhaul.child1.sssdad.com' as 'working' >(Fri Jan 17 06:39:54 2014) [sssd[be[sssdad.com]]] [sdap_id_op_connect_done] (0x4000): notify connected to op #1 >(Fri Jan 17 06:39:54 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [no filter][CN=user1_dom3,CN=Users,DC=child1,DC=sssdad,DC=com]. >(Fri Jan 17 06:39:54 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [tokenGroups] >(Fri Jan 17 06:39:54 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 5 >(Fri Jan 17 06:39:54 2014) [sssd[be[sssdad.com]]] [sdap_id_op_connect_done] (0x4000): caching successful connection after 1 notifies >(Fri Jan 17 06:39:54 2014) [sssd[be[sssdad.com]]] [be_run_unconditional_online_cb] (0x4000): List of unconditional online callbacks is empty, nothing to do. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x7ff269f0e640 >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): Dispatching. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sbus_message_handler] (0x4000): Received SBUS method [ping] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f8f540], connected[1], ops[0x7ff269f96530], ldap[0x7ff269f8e7a0] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_parse_entry] (0x4000): OriginalDN: [CN=user1_dom3,CN=Users,DC=child1,DC=sssdad,DC=com]. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [tokenGroups] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f8f540], connected[1], ops[0x7ff269f96530], ldap[0x7ff269f8e7a0] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_ad_tokengroups_initgr_posix_tg_done] (0x1000): Processing membership SID [S-1-5-32-545] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_ad_tokengroups_initgr_posix_tg_done] (0x0080): Domain not found for SID S-1-5-32-545 >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_ad_tokengroups_initgr_posix_tg_done] (0x1000): Processing membership SID [S-1-5-21-3406858696-2348136156-2230084869-513] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f937a0 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f95590 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f937a0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f95590 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f937a0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sysdb_search_entry_by_sid_str] (0x0400): No such entry >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_ad_tokengroups_initgr_posix_tg_done] (0x0400): Missing SID S-1-5-21-3406858696-2348136156-2230084869-513 will be downloaded >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_ad_tokengroups_initgr_posix_tg_done] (0x1000): Processing membership SID [S-1-5-21-3406858696-2348136156-2230084869-1383] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f95320 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f99a10 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f95320 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f99a10 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f95320 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sysdb_search_entry_by_sid_str] (0x0400): No such entry >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_ad_tokengroups_initgr_posix_tg_done] (0x0400): Missing SID S-1-5-21-3406858696-2348136156-2230084869-1383 will be downloaded >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f90220 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f907e0 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f90220 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f907e0 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f90220 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_ad_tokengroups_update_members] (0x1000): Updating memberships for [user1_dom3@child1.sssdad.com] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 0) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 0) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_groups_next_base] (0x0400): Searching for groups with base [dc=child1,dc=sssdad,dc=com] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectSID=S-1-5-21-3406858696-2348136156-2230084869-513)(objectclass=group)(name=*))][dc=child1,dc=sssdad,dc=com]. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [member] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [groupType] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 6 >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f8f540], connected[1], ops[0x7ff269f94570], ldap[0x7ff269f8e7a0] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f8f540], connected[1], ops[0x7ff269f94570], ldap[0x7ff269f8e7a0] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_parse_entry] (0x4000): OriginalDN: [CN=Domain Users,CN=Users,DC=child1,DC=sssdad,DC=com]. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectClass] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [whenChanged] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [uSNChanged] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [name] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectGUID] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectSid] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [groupType] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f8f540], connected[1], ops[0x7ff269f94570], ldap[0x7ff269f8e7a0] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f8f540], connected[1], ops[0x7ff269f94570], ldap[0x7ff269f8e7a0] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_groups_process] (0x0400): Search for groups, returned 1 results. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_has_deref_support] (0x0400): The server supports deref method ASQ >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_nested_group_hash_group] (0x4000): AD group has type flags 0x80000002. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_nested_group_hash_group] (0x4000): The group's gid was missing >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_nested_group_hash_group] (0x2000): Marking group as non-posix and setting GID=0! >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_nested_group_hash_entry] (0x4000): Inserting [CN=Domain Users,CN=Users,DC=child1,DC=sssdad,DC=com] into hash table [groups] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_nested_group_process_send] (0x2000): About to process group [CN=Domain Users,CN=Users,DC=child1,DC=sssdad,DC=com] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_nested_group_process_send] (0x2000): Looking up 0/0 members of group [CN=Domain Users,CN=Users,DC=child1,DC=sssdad,DC=com] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_nested_group_recv] (0x0400): 0 users found in the hash table >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_nested_group_recv] (0x0400): 1 groups found in the hash table >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 0) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 1) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_primary_name] (0x0400): Processing object Domain Users@child1.sssdad.com >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_save_group] (0x0400): Processing group Domain Users@child1.sssdad.com >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_save_group] (0x4000): AD group [Domain Users@child1.sssdad.com] has type flags 0x80000002.(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_save_group] (0x1000): Mapping group [Domain Users@child1.sssdad.com] objectSID [S-1-5-21-3406858696-2348136156-2230084869-513] to unix ID >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding original DN [CN=Domain Users,CN=Users,DC=child1,DC=sssdad,DC=com] to attributes of [Domain Users@child1.sssdad.com]. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding original mod-Timestamp [20130821104743.0Z] to attributes of [Domain Users@child1.sssdad.com]. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_ghost_members] (0x0400): The group has 0 members >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_ghost_members] (0x0400): Group has 0 members >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sysdb_attrs_get_aliases] (0x2000): Domain is case-insensitive; will add lowercased aliases >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_save_group] (0x0400): Storing info for group Domain Users@child1.sssdad.com >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f96810 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f96940 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f96810 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f96940 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f96810 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sysdb_search_group_by_name] (0x0400): No such entry >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 2) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f97d40 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f97e00 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f97d40 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f97e00 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f97d40 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sysdb_search_user_by_name] (0x0400): No such entry >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269fa61f0 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f93c80 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269fa61f0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f93c80 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269fa61f0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sysdb_search_group_by_gid] (0x0400): No such entry >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 3) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f9bc10 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f97b90 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f9bc10 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f97b90 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f9bc10 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 3) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 3) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f98810 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f96880 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f98810 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269fa7660 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f98dd0 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f96880 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f98810 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269fa7660 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f98dd0 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269fa7660 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 3) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 2) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_save_groups] (0x4000): Group 0 processed! >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_primary_name] (0x0400): Processing object Domain Users@child1.sssdad.com >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_save_grpmem] (0x0400): Processing group Domain Users@child1.sssdad.com >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sysdb_search_users] (0x2000): Search users with filter: (&(objectclass=user)(gidNumber=1290800513)) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f97e10 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f99170 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f97e10 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f99170 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f97e10 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sysdb_search_users] (0x2000): No such entry >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_save_grpmem] (0x0400): No members for group [Domain Users@child1.sssdad.com] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f99170 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f97e10 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f99170 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f97e10 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f99170 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 2) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269fb1a10 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f97b90 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269fb1a10 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f97b90 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269fb1a10 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 2) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_save_groups] (0x4000): Group 0 members processed! >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 1) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 0) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_id_op_destroy] (0x4000): releasing operation connection >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_id_op_done] (0x4000): releasing operation connection >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_groups_next_base] (0x0400): Searching for groups with base [dc=child1,dc=sssdad,dc=com] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectSID=S-1-5-21-3406858696-2348136156-2230084869-1383)(objectclass=group)(name=*))][dc=child1,dc=sssdad,dc=com]. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [member] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [groupType] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 7 >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f8f540], connected[1], ops[0x7ff269f8eef0], ldap[0x7ff269f8e7a0] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f8f540], connected[1], ops[0x7ff269f8eef0], ldap[0x7ff269f8e7a0] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_parse_entry] (0x4000): OriginalDN: [CN=group1_dom3,CN=Users,DC=child1,DC=sssdad,DC=com]. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectClass] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [member] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [whenChanged] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [uSNChanged] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [name] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectGUID] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectSid] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [groupType] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f8f540], connected[1], ops[0x7ff269f8eef0], ldap[0x7ff269f8e7a0] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f8f540], connected[1], ops[0x7ff269f8eef0], ldap[0x7ff269f8e7a0] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_groups_process] (0x0400): Search for groups, returned 1 results. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_has_deref_support] (0x0400): The server supports deref method ASQ >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_nested_group_hash_group] (0x4000): AD group has type flags 0x80000002. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_nested_group_hash_group] (0x4000): The group's gid was missing >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_nested_group_hash_group] (0x2000): Marking group as non-posix and setting GID=0! >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_nested_group_hash_entry] (0x4000): Inserting [CN=group1_dom3,CN=Users,DC=child1,DC=sssdad,DC=com] into hash table [groups] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_nested_group_process_send] (0x2000): About to process group [CN=group1_dom3,CN=Users,DC=child1,DC=sssdad,DC=com] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sysdb_search_users] (0x2000): Search users with filter: (&(objectclass=user)(originalDN=CN=user1_dom3,CN=Users,DC=child1,DC=sssdad,DC=com)) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f9a290 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f9a3c0 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f9a290 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f9a3c0 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f9a290 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_nested_group_split_members] (0x4000): [CN=user1_dom3,CN=Users,DC=child1,DC=sssdad,DC=com] found in cache, skipping >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_nested_group_process_send] (0x2000): Looking up 0/1 members of group [CN=group1_dom3,CN=Users,DC=child1,DC=sssdad,DC=com] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_nested_group_recv] (0x0400): 0 users found in the hash table >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_nested_group_recv] (0x0400): 1 groups found in the hash table >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 0) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 1) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_primary_name] (0x0400): Processing object group1_dom3@child1.sssdad.com >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_save_group] (0x0400): Processing group group1_dom3@child1.sssdad.com >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_save_group] (0x4000): AD group [group1_dom3@child1.sssdad.com] has type flags 0x80000002.(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_save_group] (0x1000): Mapping group [group1_dom3@child1.sssdad.com] objectSID [S-1-5-21-3406858696-2348136156-2230084869-1383] to unix ID >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding original DN [CN=group1_dom3,CN=Users,DC=child1,DC=sssdad,DC=com] to attributes of [group1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding original mod-Timestamp [20140117112214.0Z] to attributes of [group1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_ghost_members] (0x0400): The group has 1 members >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_ghost_members] (0x0400): Group has 1 members >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sysdb_attrs_get_aliases] (0x2000): Domain is case-insensitive; will add lowercased aliases >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_save_group] (0x0400): Storing info for group group1_dom3@child1.sssdad.com >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f9a1b0 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f9a2e0 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f9a1b0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f9a2e0 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f9a1b0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sysdb_search_group_by_name] (0x0400): No such entry >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 2) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f982e0 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f983a0 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f982e0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f983a0 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f982e0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sysdb_search_user_by_name] (0x0400): No such entry >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f97bc0 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f98590 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f97bc0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f98590 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f97bc0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sysdb_search_group_by_gid] (0x0400): No such entry >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 3) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f98f30 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f98ff0 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f98f30 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f98ff0 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f98f30 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 3) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 3) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f981f0 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f982b0 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f981f0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f98d10 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269fa77b0 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f982b0 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f981f0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f98d10 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269fa77b0 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f98d10 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 3) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 2) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_save_groups] (0x4000): Group 0 processed! >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_primary_name] (0x0400): Processing object group1_dom3@child1.sssdad.com >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_save_grpmem] (0x0400): Processing group group1_dom3@child1.sssdad.com >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sysdb_search_users] (0x2000): Search users with filter: (&(objectclass=user)(gidNumber=1290801383)) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f8e540 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269fb1fc0 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f8e540 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269fb1fc0 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f8e540 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sysdb_search_users] (0x2000): No such entry >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_save_grpmem] (0x0400): Adding member users to group [group1_dom3@child1.sssdad.com] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_find_entry_by_origDN] (0x4000): Searching cache for [CN=user1_dom3,CN=Users,DC=child1,DC=sssdad,DC=com]. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f8e540 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269fb0b30 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f8e540 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269fb0b30 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f8e540 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_fill_memberships] (0x1000): member #0 (CN=user1_dom3,CN=Users,DC=child1,DC=sssdad,DC=com): [name=user1_dom3@child1.sssdad.com,cn=users,cn=child1.sssdad.com,cn=sysdb] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269fa77b0 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f8e540 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269fa77b0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f8e540 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269fa77b0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 2) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f98620 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f9bb60 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f98620 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269fb1bd0 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f98990 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f9bb60 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f98620 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269fb1bd0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269fb4d20 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f98e80 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f98990 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269fb1bd0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269fb4d20 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269fb5cc0 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269fb5d80 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f98e80 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269fb4d20 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269fb5cc0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f981f0 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269fb4c70 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269fb5d80 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269fb5cc0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f981f0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269fb4c70 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f981f0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 2) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_save_groups] (0x4000): Group 0 members processed! >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 1) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 0) >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_id_op_destroy] (0x4000): releasing operation connection >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_id_op_done] (0x4000): releasing operation connection >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_id_op_destroy] (0x4000): releasing operation connection >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_initgr_done] (0x4000): Initgroups done >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_get_initgr_done] (0x1000): Mapping primary group to unix ID >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_id_op_destroy] (0x4000): releasing operation connection >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_id_op_done] (0x4000): releasing operation connection >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7ff269f8f540], connected[1], ops[(nil)], ldap[0x7ff269f8e7a0] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x7ff269f3b160 >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): Dispatching. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [be_req_set_domain] (0x0400): Changing request domain from [sssdad.com] to [child1.sssdad.com] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [be_pam_handler] (0x0100): Got request with the following data >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): command: PAM_AUTHENTICATE >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): domain: child1.sssdad.com >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): user: user1_dom3@child1.sssdad.com >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): service: sshd >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): tty: ssh >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): ruser: >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): rhost: localhost >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): authtok type: 1 >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): newauthtok type: 0 >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): priv: 1 >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): cli_pid: 894 >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [krb5_pam_handler] (0x1000): Wait queue of user [user1_dom3@child1.sssdad.com] is empty, running request immediately. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f41fd0 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f52550 > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f41fd0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f52550 "ltdb_timeout" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f41fd0 "ltdb_callback" > >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [krb5_auth_send] (0x0100): Home directory for user [user1_dom3@child1.sssdad.com] not known. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [krb5_auth_send] (0x0100): No ccache file for user [user1_dom3@child1.sssdad.com] found. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [krb5_auth_send] (0x4000): Ccache_file is [not set] and is not active and TGT is not valid. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'pluto.sssdad.com' is 'working' >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [get_port_status] (0x1000): Port status of port 389 for server 'pluto.sssdad.com' is 'working' >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'pluto.sssdad.com' is 'working' >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x0200): Found address for server pluto.sssdad.com: [10.65.206.100] TTL 3600 >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://pluto.sssdad.com' >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [ad_resolve_callback] (0x0100): Constructed GC uri 'ldap://pluto.sssdad.com' >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [krb5_auth_prepare_ccache_name] (0x4000): Recreating ccache file. >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [898] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [child_handler_setup] (0x2000): Signal handler set up for pid [898] >(Fri Jan 17 06:39:55 2014) [sssd[be[sssdad.com]]] [write_pipe_handler] (0x0400): All data has been sent! >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [krb5_child_timeout] (0x4000): timeout for child [898] reached. >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [krb5_auth_done] (0x0020): child timed out! >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'pluto.sssdad.com' as 'not working' >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing LDAP with LDAP >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'pluto.sssdad.com' as 'not working' >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'pluto.sssdad.com' is 'working' >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [get_port_status] (0x1000): Port status of port 389 for server 'pluto.sssdad.com' is 'not working' >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'pluto.sssdad.com' is 'working' >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [get_port_status] (0x1000): Port status of port 389 for server 'pluto.sssdad.com' is 'not working' >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [fo_resolve_service_send] (0x0020): No available servers for service 'AD' >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [be_resolve_server_done] (0x1000): Server resolution failed: 5 >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [be_mark_offline] (0x2000): Going offline! >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [be_run_offline_cb] (0x0080): Going offline. Running callbacks. >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [krb5_auth_prepare_ccache_name] (0x4000): Recreating ccache file. >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [krb5_auth_resolve_done] (0x4000): Preparing for offline operation. >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [899] >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [child_handler_setup] (0x2000): Signal handler set up for pid [899] >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [child_sig_handler] (0x1000): Waiting for child [899]. >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [become_user] (0x0200): (Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [child_sig_handler] (0x0020): Trying to become user [1290801380][1290801380]. >waitpid did not found a child with changed status. >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [child_sig_handler] (0x1000): Waiting for child [898]. >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [child_sig_handler] (0x0020): child [898] was terminated by signal [9]. >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [write_pipe_handler] (0x0400): All data has been sent! >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [child_sig_handler] (0x1000): Waiting for child [899]. >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [child_sig_handler] (0x0100): child [899] finished successfully. >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [read_pipe_handler] (0x0400): EOF received, client finished >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [parse_krb5_child_response] (0x1000): child response [0][3][41]. >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'pluto.sssdad.com' as 'working' >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [set_server_common_status] (0x0100): Marking server 'pluto.sssdad.com' as 'working' >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing LDAP with LDAP >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'pluto.sssdad.com' as 'working' >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [switch_creds] (0x0200): Switch user to [1290801380][1290801380]. >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [sss_krb5_check_ccache_princ] (0x2000): Searching for [user1_dom3@CHILD1.SSSDAD.COM] in cache of type [KEYRING] >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [switch_creds] (0x0200): Switch user to [0][0]. >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [krb5_mod_ccname] (0x4000): Save ccname [KEYRING:persistent:1290801380] for user [user1_dom3@child1.sssdad.com]. >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 0) >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 1) >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f519f0 > >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f7bbe0 > >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f519f0 "ltdb_callback" > >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f7bbe0 "ltdb_timeout" > >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f519f0 "ltdb_callback" > >(Fri Jan 17 06:40:01 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 1) >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 0) >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 0) >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7ff269f7ecd0 > >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7ff269f519f0 > >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7ff269f7ecd0 "ltdb_callback" > >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7ff269f519f0 "ltdb_timeout" > >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7ff269f7ecd0 "ltdb_callback" > >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [sysdb_cache_auth] (0x4000): Offline credentials expiration is [0] days. >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [check_failed_login_attempts] (0x4000): Failed login attempts [0], allowed failed login attempts [0], failed login delay [5]. >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [sysdb_cache_auth] (0x0100): Cached credentials not available. >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [ldb] (0x4000): cancel ldb transaction (nesting: 0) >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [krb5_auth_cache_creds] (0x0020): Offline authentication failed >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [check_wait_queue] (0x1000): Wait queue for user [user1_dom3@child1.sssdad.com] is empty. >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 6, <NULL>) [Success] >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [be_pam_handler_callback] (0x0100): Sending result [6][child1.sssdad.com] >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [be_pam_handler_callback] (0x0100): Sent result [6][child1.sssdad.com] >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [sdap_id_release_conn_data] (0x4000): releasing unused connection >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [sdap_handle_release] (0x2000): Trace: sh[0x7ff269f8f540], connected[1], ops[(nil)], ldap[0x7ff269f8e7a0], destructor_lock[0], release_memory[0] >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [remove_connection_callback] (0x4000): Successfully removed connection callback. >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [remove_krb5_info_files] (0x0200): Could not remove [/var/lib/sss/pubconf/kpasswdinfo.SSSDAD.COM], [2][No such file or directory] >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [sdap_id_release_conn_data] (0x4000): releasing unused connection >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [sdap_handle_release] (0x2000): Trace: sh[0x7ff269f71490], connected[1], ops[(nil)], ldap[0x7ff269f724d0], destructor_lock[0], release_memory[0] >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [remove_connection_callback] (0x4000): Successfully removed connection callback. >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [sdap_id_release_conn_data] (0x4000): releasing unused connection >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [sdap_handle_release] (0x2000): Trace: sh[0x7ff269f41170], connected[1], ops[(nil)], ldap[0x7ff269f3a970], destructor_lock[0], release_memory[0] >(Fri Jan 17 06:40:02 2014) [sssd[be[sssdad.com]]] [remove_connection_callback] (0x4000): Successfully removed connection callback. >(Fri Jan 17 06:40:05 2014) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x7ff269f0e640 >(Fri Jan 17 06:40:05 2014) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): Dispatching. >(Fri Jan 17 06:40:05 2014) [sssd[be[sssdad.com]]] [sbus_message_handler] (0x4000): Received SBUS method [ping] >(Fri Jan 17 06:40:15 2014) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x7ff269f0e640 >(Fri Jan 17 06:40:15 2014) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): Dispatching. >(Fri Jan 17 06:40:15 2014) [sssd[be[sssdad.com]]] [sbus_message_handler] (0x4000): Received SBUS method [ping]
You cannot view the attachment while viewing its details because your browser does not support IFRAMEs.
View the attachment on a separate page
.
View Attachment As Raw
Actions:
View
Attachments on
bug 1054899
: 851732