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 827127 Details for
Bug 1032983
sssd_be crashes when ad_access_filter uses FOREST keyword.
[?]
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 when the crash happens
sssd_domain_log (text/plain), 132.67 KB, created by
Kaushik Banerjee
on 2013-11-21 10:55:19 UTC
(
hide
)
Description:
Domain log when the crash happens
Filename:
MIME Type:
Creator:
Kaushik Banerjee
Created:
2013-11-21 10:55:19 UTC
Size:
132.67 KB
patch
obsolete
>(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sbus_message_handler] (0x4000): Received SBUS method [getAccountInfo] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_get_account_info] (0x0100): Got request for [3][1][name=user1_dom1] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_req_set_domain] (0x0400): Changing request domain from [sssdad.com] to [sssdad.com] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7fdf4bdaf4d0 > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7fdf4bdaf600 > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7fdf4bdaf4d0 "ltdb_callback" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7fdf4bdaf600 "ltdb_timeout" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7fdf4bdaf4d0 "ltdb_callback" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7fdf4bdb3210 > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7fdf4bdaf420 > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7fdf4bdb3210 "ltdb_callback" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7fdf4bdb5190 > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7fdf4bdb5250 > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7fdf4bdaf420 "ltdb_timeout" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7fdf4bdb3210 "ltdb_callback" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7fdf4bdb5190 "ltdb_callback" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7fdf4bdaf420 > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7fdf4bdb5de0 > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7fdf4bdb5250 "ltdb_timeout" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7fdf4bdb5190 "ltdb_callback" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7fdf4bdaf420 "ltdb_callback" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7fdf4bdb5de0 "ltdb_timeout" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7fdf4bdaf420 "ltdb_callback" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_connect_step] (0x4000): beginning to connect >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD_GC' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [get_port_status] (0x1000): Port status of port 0 for server '(no name)' is 'neutral' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolve_srv_send] (0x0200): The status of SRV lookup is neutral >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_srv_plugin_send] (0x0400): About to find domain controllers >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_get_dc_servers_send] (0x0400): Looking up domain controllers in domain sssdad.com >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'ldap'. Will use DNS discovery domain 'sssdad.com' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_ldap._tcp.sssdad.com' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [request_watch_destructor] (0x0400): Deleting request watch >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got 1 servers >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_get_dc_servers_done] (0x0400): Found 1 domain controllers in domain sssdad.com >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_srv_plugin_dcs_done] (0x0400): About to locate suitable site >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_connect_host_send] (0x0400): Resolving host pluto.sssdad.com >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_is_address] (0x4000): [pluto.sssdad.com] does not look like an IP address >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying files >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'pluto.sssdad.com' in files >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying files >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'pluto.sssdad.com' in files >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying DNS >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'pluto.sssdad.com' in DNS >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [request_watch_destructor] (0x0400): Deleting request watch >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_connect_host_resolv_done] (0x0400): Connecting to ldap://pluto.sssdad.com:389 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sss_ldap_init_send] (0x4000): Using file descriptor [21] for LDAP connection. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://pluto.sssdad.com:389/??base] with fd [21]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_connect_host_done] (0x0400): Successful connection to ldap://pluto.sssdad.com:389 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(DnsDomain=sssdad.com)(NtVer=\14\00\00\00))][]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [netlogon] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7fdf4bdb0af0], connected[1], ops[0x7fdf4bdae490], ldap[0x7fdf4bd9e910] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_entry] (0x4000): OriginalDN: []. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [netlogon] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7fdf4bdb0af0], connected[1], ops[0x7fdf4bdae490], ldap[0x7fdf4bd9e910] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_handle_release] (0x2000): Trace: sh[0x7fdf4bdb0af0], connected[1], ops[(nil)], ldap[0x7fdf4bd9e910], destructor_lock[0], release_memory[0] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [remove_connection_callback] (0x4000): Successfully removed connection callback. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_get_client_site_done] (0x0400): Found site: Default-First-Site-Name >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_srv_plugin_site_done] (0x0400): About to discover primary and backup servers >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_discover_servers_send] (0x0400): Looking up primary servers >(Thu Nov 21 14:22:07 2013) [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' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_gc._tcp.Default-First-Site-Name._sites.sssdad.com' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [request_watch_destructor] (0x0400): Deleting request watch >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got 3 servers >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_discover_servers_primary_done] (0x0400): Looking up backup servers >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'gc'. Will use DNS discovery domain 'sssdad.com' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_gc._tcp.sssdad.com' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [request_watch_destructor] (0x0400): Deleting request watch >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got 3 servers >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_srv_plugin_servers_done] (0x0400): Got 3 primary and 3 backup servers >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'longhaul.child1.sssdad.com:3268' to service 'AD_GC' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'pluto.sssdad.com:3268' to service 'AD_GC' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'eagle.sssdad_tree.com:3268' to service 'AD_GC' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing GC with GC >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_add_server_to_list] (0x0400): Server 'longhaul.child1.sssdad.com:3268' for service 'AD_GC' is already present >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing GC with GC >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing GC with GC >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_add_server_to_list] (0x0400): Server 'pluto.sssdad.com:3268' for service 'AD_GC' is already present >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing GC with GC >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing GC with GC >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing GC with GC >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_add_server_to_list] (0x0400): Server 'eagle.sssdad_tree.com:3268' for service 'AD_GC' is already present >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [set_srv_data_status] (0x0100): Marking SRV lookup of service 'AD_GC' as 'resolved' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'longhaul.child1.sssdad.com' is 'name not resolved' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_is_address] (0x4000): [longhaul.child1.sssdad.com] does not look like an IP address >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying files >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'longhaul.child1.sssdad.com' in files >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [set_server_common_status] (0x0100): Marking server 'longhaul.child1.sssdad.com' as 'resolving name' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying files >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'longhaul.child1.sssdad.com' in files >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying DNS >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'longhaul.child1.sssdad.com' in DNS >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [request_watch_destructor] (0x0400): Deleting request watch >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [set_server_common_status] (0x0100): Marking server 'longhaul.child1.sssdad.com' as 'name resolved' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x0200): Found address for server longhaul.child1.sssdad.com: [10.65.206.54] TTL 3600 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://longhaul.child1.sssdad.com' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_resolve_callback] (0x0100): Constructed GC uri 'ldap://longhaul.child1.sssdad.com:3268' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sss_ldap_init_send] (0x4000): Using file descriptor [21] for LDAP connection. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://longhaul.child1.sssdad.com:3268/??base] with fd [21]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_rootdse_send] (0x4000): Getting rootdse >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7fdf4bdaf6c0], connected[1], ops[0x7fdf4bdb5d90], ldap[0x7fdf4bdac840] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_entry] (0x4000): OriginalDN: []. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [currentTime] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [subschemaSubentry] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [dsServiceName] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [namingContexts] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [defaultNamingContext] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [schemaNamingContext] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [configurationNamingContext] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [rootDomainNamingContext] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedControl] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPVersion] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPPolicies] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [highestCommittedUSN] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedSASLMechanisms] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [dnsHostName] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [ldapServiceName] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [serverName] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedCapabilities] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [isSynchronized] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [isGlobalCatalogReady] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedExtension] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainFunctionality] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [forestFunctionality] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainControllerFunctionality] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7fdf4bdaf6c0], connected[1], ops[0x7fdf4bdb5d90], ldap[0x7fdf4bdac840] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_rootdse_done] (0x2000): Got rootdse >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [get_naming_context] (0x0200): Using value from [defaultNamingContext] as naming context. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_set_search_base] (0x0100): Setting option [ldap_search_base] to [DC=child1,DC=sssdad,DC=com]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [common_parse_search_base] (0x0100): Search base added: [DEFAULT][DC=child1,DC=sssdad,DC=com][SUBTREE][] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_set_search_base] (0x0100): Setting option [ldap_user_search_base] to [DC=child1,DC=sssdad,DC=com]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [common_parse_search_base] (0x0100): Search base added: [USER][DC=child1,DC=sssdad,DC=com][SUBTREE][] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_set_search_base] (0x0100): Setting option [ldap_group_search_base] to [DC=child1,DC=sssdad,DC=com]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [common_parse_search_base] (0x0100): Search base added: [GROUP][DC=child1,DC=sssdad,DC=com][SUBTREE][] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_set_search_base] (0x0100): Setting option [ldap_netgroup_search_base] to [DC=child1,DC=sssdad,DC=com]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [common_parse_search_base] (0x0100): Search base added: [NETGROUP][DC=child1,DC=sssdad,DC=com][SUBTREE][] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_set_search_base] (0x0100): Setting option [ldap_sudo_search_base] to [DC=child1,DC=sssdad,DC=com]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [common_parse_search_base] (0x0100): Search base added: [SUDO][DC=child1,DC=sssdad,DC=com][SUBTREE][] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_set_search_base] (0x0100): Setting option [ldap_service_search_base] to [DC=child1,DC=sssdad,DC=com]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [common_parse_search_base] (0x0100): Search base added: [SERVICE][DC=child1,DC=sssdad,DC=com][SUBTREE][] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_set_search_base] (0x0100): Setting option [ldap_autofs_search_base] to [DC=child1,DC=sssdad,DC=com]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [common_parse_search_base] (0x0100): Search base added: [AUTOFS][DC=child1,DC=sssdad,DC=com][SUBTREE][] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_server_opts_from_rootdse] (0x4000): USN value: 170123 (int: 170123) >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [4] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, DHCP207-191$, SSSDAD.COM, 86400) >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service AD >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [get_port_status] (0x1000): Port status of port 0 for server '(no name)' is 'neutral' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolve_srv_send] (0x0200): The status of SRV lookup is neutral >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_srv_plugin_send] (0x0400): About to find domain controllers >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_get_dc_servers_send] (0x0400): Looking up domain controllers in domain sssdad.com >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'ldap'. Will use DNS discovery domain 'sssdad.com' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_ldap._tcp.sssdad.com' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7fdf4bdaf6c0], connected[1], ops[(nil)], ldap[0x7fdf4bdac840] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [request_watch_destructor] (0x0400): Deleting request watch >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got 1 servers >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_get_dc_servers_done] (0x0400): Found 1 domain controllers in domain sssdad.com >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_srv_plugin_dcs_done] (0x0400): About to locate suitable site >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_connect_host_send] (0x0400): Resolving host pluto.sssdad.com >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_is_address] (0x4000): [pluto.sssdad.com] does not look like an IP address >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying files >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'pluto.sssdad.com' in files >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying files >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'pluto.sssdad.com' in files >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying DNS >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'pluto.sssdad.com' in DNS >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [request_watch_destructor] (0x0400): Deleting request watch >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_connect_host_resolv_done] (0x0400): Connecting to ldap://pluto.sssdad.com:389 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sss_ldap_init_send] (0x4000): Using file descriptor [22] for LDAP connection. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://pluto.sssdad.com:389/??base] with fd [22]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_connect_host_done] (0x0400): Successful connection to ldap://pluto.sssdad.com:389 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(DnsDomain=sssdad.com)(NtVer=\14\00\00\00))][]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [netlogon] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7fdf4bdc26a0], connected[1], ops[0x7fdf4bdc2280], ldap[0x7fdf4bdb0340] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_entry] (0x4000): OriginalDN: []. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [netlogon] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7fdf4bdc26a0], connected[1], ops[0x7fdf4bdc2280], ldap[0x7fdf4bdb0340] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_handle_release] (0x2000): Trace: sh[0x7fdf4bdc26a0], connected[1], ops[(nil)], ldap[0x7fdf4bdb0340], destructor_lock[0], release_memory[0] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [remove_connection_callback] (0x4000): Successfully removed connection callback. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_get_client_site_done] (0x0400): Found site: Default-First-Site-Name >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_srv_plugin_site_done] (0x0400): About to discover primary and backup servers >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_discover_servers_send] (0x0400): Looking up primary servers >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'ldap'. Will use DNS discovery domain 'Default-First-Site-Name._sites.sssdad.com' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_ldap._tcp.Default-First-Site-Name._sites.sssdad.com' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [request_watch_destructor] (0x0400): Deleting request watch >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got 1 servers >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_discover_servers_primary_done] (0x0400): Looking up backup servers >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'ldap'. Will use DNS discovery domain 'sssdad.com' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_ldap._tcp.sssdad.com' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [request_watch_destructor] (0x0400): Deleting request watch >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_discover_srv_done] (0x0400): Got 1 servers >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_srv_plugin_servers_done] (0x0400): Got 1 primary and 1 backup servers >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'pluto.sssdad.com:389' to service 'AD' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing LDAP with LDAP >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_add_server_to_list] (0x0400): Server 'pluto.sssdad.com:389' for service 'AD' is already present >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [set_srv_data_status] (0x0100): Marking SRV lookup of service 'AD' as 'resolved' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'pluto.sssdad.com' is 'name not resolved' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_is_address] (0x4000): [pluto.sssdad.com] does not look like an IP address >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying files >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'pluto.sssdad.com' in files >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [set_server_common_status] (0x0100): Marking server 'pluto.sssdad.com' as 'resolving name' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying files >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'pluto.sssdad.com' in files >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying DNS >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'pluto.sssdad.com' in DNS >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [request_watch_destructor] (0x0400): Deleting request watch >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [set_server_common_status] (0x0100): Marking server 'pluto.sssdad.com' as 'name resolved' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x0200): Found address for server pluto.sssdad.com: [10.65.206.100] TTL 3600 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://pluto.sssdad.com' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_resolve_callback] (0x0100): Constructed GC uri 'ldap://pluto.sssdad.com' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 38 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [5806] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [child_handler_setup] (0x2000): Signal handler set up for pid [5806] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [write_pipe_handler] (0x0400): All data has been sent! >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [read_pipe_handler] (0x0400): EOF received, client finished >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_SSSDAD.COM], expired on [1385059927] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1385024827 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: DHCP207-191$ >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [child_sig_handler] (0x1000): Waiting for child [5806]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [child_sig_handler] (0x0100): child [5806] finished successfully. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_set_port_status] (0x0100): Marking port 3268 of server 'longhaul.child1.sssdad.com' as 'working' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [set_server_common_status] (0x0100): Marking server 'longhaul.child1.sssdad.com' as 'working' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing GC with GC >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_set_port_status] (0x0400): Marking port 3268 of duplicate server 'longhaul.child1.sssdad.com' as 'working' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing GC with GC >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing GC with GC >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_connect_done] (0x4000): notify connected to op #1 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_initgr_send] (0x4000): Retrieving info for initgroups call >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_initgr_next_base] (0x0400): Searching for users with base [DC=child1,DC=sssdad,DC=com] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(sAMAccountName=user1_dom1)(objectclass=user)(&(uidNumber=*)(!(uidNumber=0))))][DC=child1,DC=sssdad,DC=com]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 5 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_connect_done] (0x4000): caching successful connection after 1 notifies >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_run_unconditional_online_cb] (0x4000): List of unconditional online callbacks is empty, nothing to do. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_run_online_cb] (0x0080): Going online. Running callbacks. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7fdf4bdaf6c0], connected[1], ops[0x7fdf4bdc1030], ldap[0x7fdf4bdac840] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_initgr_user] (0x4000): Receiving info for the user >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_done] (0x4000): releasing operation connection >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_connect_step] (0x4000): beginning to connect >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'pluto.sssdad.com' is 'name resolved' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'pluto.sssdad.com' is 'name resolved' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x0200): Found address for server pluto.sssdad.com: [10.65.206.100] TTL 3600 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sss_ldap_init_send] (0x4000): Using file descriptor [22] for LDAP connection. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7fdf4bdaf6c0], connected[1], ops[(nil)], ldap[0x7fdf4bdac840] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://pluto.sssdad.com:389/??base] with fd [22]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_rootdse_send] (0x4000): Getting rootdse >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7fdf4bdc0420], connected[1], ops[0x7fdf4bdbf150], ldap[0x7fdf4bdbe770] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_entry] (0x4000): OriginalDN: []. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [currentTime] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [subschemaSubentry] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [dsServiceName] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [namingContexts] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [defaultNamingContext] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [schemaNamingContext] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [configurationNamingContext] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [rootDomainNamingContext] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedControl] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPVersion] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPPolicies] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [highestCommittedUSN] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedSASLMechanisms] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [dnsHostName] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [ldapServiceName] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [serverName] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedCapabilities] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [isSynchronized] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [isGlobalCatalogReady] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedExtension] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainFunctionality] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [forestFunctionality] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainControllerFunctionality] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7fdf4bdc0420], connected[1], ops[0x7fdf4bdbf150], ldap[0x7fdf4bdbe770] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_rootdse_done] (0x2000): Got rootdse >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_server_opts_from_rootdse] (0x4000): USN value: 586057 (int: 586057) >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [4] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, DHCP207-191$, SSSDAD.COM, 86400) >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service AD >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'pluto.sssdad.com' is 'name resolved' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'pluto.sssdad.com' is 'name resolved' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x0200): Found address for server pluto.sssdad.com: [10.65.206.100] TTL 3600 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 38 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [5807] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [child_handler_setup] (0x2000): Signal handler set up for pid [5807] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7fdf4bdc0420], connected[1], ops[(nil)], ldap[0x7fdf4bdbe770] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [write_pipe_handler] (0x0400): All data has been sent! >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_connect_step] (0x4000): waiting for connection to complete >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [delayed_online_authentication_callback] (0x0200): Backend is online, starting delayed online authentication. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [read_pipe_handler] (0x0400): EOF received, client finished >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_SSSDAD.COM], expired on [1385059927] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1385024827 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: DHCP207-191$ >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [child_sig_handler] (0x1000): Waiting for child [5807]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [child_sig_handler] (0x0100): child [5807] finished successfully. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'pluto.sssdad.com' as 'working' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [set_server_common_status] (0x0100): Marking server 'pluto.sssdad.com' as 'working' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing LDAP with LDAP >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'pluto.sssdad.com' as 'working' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_connect_done] (0x2000): Old USN: 170123, New USN: 586057 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_connect_done] (0x4000): notify connected to op #1 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_initgr_send] (0x4000): Retrieving info for initgroups call >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_initgr_next_base] (0x0400): Searching for users with base [DC=child1,DC=sssdad,DC=com] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(sAMAccountName=user1_dom1)(objectclass=user)(&(uidNumber=*)(!(uidNumber=0))))][DC=child1,DC=sssdad,DC=com]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 5 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_connect_done] (0x4000): notify connected to op #2 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [objectclass=domain][DC=child1,DC=sssdad,DC=com]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 6 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_connect_done] (0x4000): caching successful connection after 2 notifies >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_run_unconditional_online_cb] (0x4000): List of unconditional online callbacks is empty, nothing to do. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7fdf4bdc0420], connected[1], ops[0x7fdf4bdd4570], ldap[0x7fdf4bdbe770] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Referral(10), 0000202B: RefErr: DSID-03100742, data 0, 1 access points > ref 1: 'child1.sssdad.com' > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0040): Unexpected result from ldap: Referral(10), 0000202B: RefErr: DSID-03100742, data 0, 1 access points > ref 1: 'child1.sssdad.com' > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_done] (0x0100): sdap_get_generic_ext_recv failed [5]: Input/output error >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_initgr_user] (0x4000): Receiving info for the user >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_done] (0x0200): communication error on cached connection, moving to next server >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_done] (0x4000): advising for connection retry #1 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_done] (0x4000): releasing operation connection >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_connect_step] (0x4000): beginning to connect >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'pluto.sssdad.com' is 'working' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'pluto.sssdad.com' is 'working' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x0200): Found address for server pluto.sssdad.com: [10.65.206.100] TTL 3600 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sss_ldap_init_send] (0x4000): Using file descriptor [23] for LDAP connection. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7fdf4bdc0420], connected[1], ops[0x7fdf4bdd4570], ldap[0x7fdf4bdbe770] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Referral(10), 0000202B: RefErr: DSID-03100742, data 0, 1 access points > ref 1: 'child1.sssdad.com' > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0040): Unexpected result from ldap: Referral(10), 0000202B: RefErr: DSID-03100742, data 0, 1 access points > ref 1: 'child1.sssdad.com' > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_done] (0x0100): sdap_get_generic_ext_recv failed [5]: Input/output error >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_master_domain_next_done] (0x0040): sdap_get_generic_send request failed. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_subdomains_master_dom_done] (0x0040): Cannot retrieve master domain info >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_destroy] (0x4000): releasing operation connection >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_release_conn_data] (0x4000): releasing unused connection >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_handle_release] (0x2000): Trace: sh[0x7fdf4bdc0420], connected[1], ops[(nil)], ldap[0x7fdf4bdbe770], destructor_lock[0], release_memory[0] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [remove_connection_callback] (0x4000): Successfully removed connection callback. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_nsupdate_timer_schedule] (0x0200): Timer already scheduled >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_dyndns_update_send] (0x0400): Performing update >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_connect_step] (0x4000): waiting for connection to complete >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://pluto.sssdad.com:389/??base] with fd [23]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_rootdse_send] (0x4000): Getting rootdse >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7fdf4bddbd40], connected[1], ops[0x7fdf4bdbe860], ldap[0x7fdf4bdbe770] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_entry] (0x4000): OriginalDN: []. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [currentTime] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [subschemaSubentry] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [dsServiceName] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [namingContexts] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [defaultNamingContext] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [schemaNamingContext] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [configurationNamingContext] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [rootDomainNamingContext] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedControl] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPVersion] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPPolicies] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [highestCommittedUSN] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedSASLMechanisms] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [dnsHostName] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [ldapServiceName] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [serverName] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedCapabilities] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [isSynchronized] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [isGlobalCatalogReady] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedExtension] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainFunctionality] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [forestFunctionality] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainControllerFunctionality] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7fdf4bddbd40], connected[1], ops[0x7fdf4bdbe860], ldap[0x7fdf4bdbe770] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_rootdse_done] (0x2000): Got rootdse >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_server_opts_from_rootdse] (0x4000): USN value: 586058 (int: 586058) >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [4] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, DHCP207-191$, SSSDAD.COM, 86400) >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service AD >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'pluto.sssdad.com' is 'working' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'pluto.sssdad.com' is 'working' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x0200): Found address for server pluto.sssdad.com: [10.65.206.100] TTL 3600 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 38 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [5808] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [child_handler_setup] (0x2000): Signal handler set up for pid [5808] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7fdf4bddbd40], connected[1], ops[(nil)], ldap[0x7fdf4bdbe770] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [write_pipe_handler] (0x0400): All data has been sent! >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_online_cb] (0x0400): The AD provider is online >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [read_pipe_handler] (0x0400): EOF received, client finished >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_SSSDAD.COM], expired on [1385059927] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1385024827 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: DHCP207-191$ >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [child_sig_handler] (0x1000): Waiting for child [5808]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [child_sig_handler] (0x0100): child [5808] finished successfully. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'pluto.sssdad.com' as 'working' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [set_server_common_status] (0x0100): Marking server 'pluto.sssdad.com' as 'working' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing LDAP with LDAP >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'pluto.sssdad.com' as 'working' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_connect_done] (0x2000): Old USN: 586057, New USN: 586058 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_connect_done] (0x4000): notify connected to op #1 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_initgr_send] (0x4000): Retrieving info for initgroups call >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_initgr_next_base] (0x0400): Searching for users with base [DC=child1,DC=sssdad,DC=com] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(sAMAccountName=user1_dom1)(objectclass=user)(&(uidNumber=*)(!(uidNumber=0))))][DC=child1,DC=sssdad,DC=com]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 5 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_connect_done] (0x4000): notify connected to op #2 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_is_address] (0x4000): [dhcp207-191.lab.eng.pnq.redhat.com] does not look like an IP address >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying DNS >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_connect_done] (0x4000): caching successful connection after 2 notifies >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_run_unconditional_online_cb] (0x4000): List of unconditional online callbacks is empty, nothing to do. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'dhcp207-191.lab.eng.pnq.redhat.com' in DNS >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7fdf4bddbd40], connected[1], ops[0x7fdf4bdd5da0], ldap[0x7fdf4bdbe770] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Referral(10), 0000202B: RefErr: DSID-03100742, data 0, 1 access points > ref 1: 'child1.sssdad.com' > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_ext_done] (0x0040): Unexpected result from ldap: Referral(10), 0000202B: RefErr: DSID-03100742, data 0, 1 access points > ref 1: 'child1.sssdad.com' > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_generic_done] (0x0100): sdap_get_generic_ext_recv failed [5]: Input/output error >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_get_initgr_user] (0x4000): Receiving info for the user >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_done] (0x0200): communication error on cached connection, moving to next server >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_done] (0x4000): too many communication failures, giving up... >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_id_op_done] (0x4000): releasing operation connection >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_account_info_complete] (0x0010): Bug: dp_error is OK on failed request(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sbus_add_timeout] (0x2000): 0x7fdf4bdc84d0 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: sh[0x7fdf4bddbd40], connected[1], ops[(nil)], ldap[0x7fdf4bdbe770] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sbus_remove_timeout] (0x2000): 0x7fdf4bdc84d0 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x7fdf4bda8200 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): Dispatching. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [acctinfo_callback] (0x0100): Request processed. Returned 3,5,Internal Error (Memory buffer error) >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [request_watch_destructor] (0x0400): Deleting request watch >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_step] (0x2000): Querying DNS >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve AAAA record of 'dhcp207-191.lab.eng.pnq.redhat.com' in DNS >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x7fdf4bdab530 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): Dispatching. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_req_set_domain] (0x0400): Changing request domain from [sssdad.com] to [sssdad.com] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_pam_handler] (0x0100): Got request with the following data >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): command: PAM_AUTHENTICATE >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): domain: sssdad.com >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): user: user1_dom1 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): service: sshd >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): tty: ssh >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): ruser: >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): rhost: localhost >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): authtok type: 1 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): newauthtok type: 0 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): priv: 1 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): cli_pid: 5804 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [krb5_pam_handler] (0x1000): Wait queue of user [user1_dom1] is empty, running request immediately. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7fdf4bdc2660 > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7fdf4bddbb30 > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7fdf4bdc2660 "ltdb_callback" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7fdf4bddbb30 "ltdb_timeout" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7fdf4bdc2660 "ltdb_callback" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [krb5_auth_send] (0x0100): Home directory for user [user1_dom1] not known. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [switch_creds] (0x0200): Switch user to [770843748][770800513]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [switch_creds] (0x0200): Switch user to [0][0]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [krb5_auth_send] (0x4000): Ccache_file is [DIR:/run/user/770843748/krb5cc] and is active and TGT is valid. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'pluto.sssdad.com' is 'working' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [get_server_status] (0x1000): Status of server 'pluto.sssdad.com' is 'working' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_resolve_server_process] (0x0200): Found address for server pluto.sssdad.com: [10.65.206.100] TTL 3600 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [5809] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [child_handler_setup] (0x2000): Signal handler set up for pid [5809] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [write_pipe_handler] (0x0400): All data has been sent! >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [read_pipe_handler] (0x0400): EOF received, client finished >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [parse_krb5_child_response] (0x1000): child response [0][3][42]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [parse_krb5_child_response] (0x1000): child response [0][-1073741822][22]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [parse_krb5_child_response] (0x1000): child response [0][-1073741823][32]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [parse_krb5_child_response] (0x1000): TGT times are [1385023707][1385023707][1385059707][1385628507]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [parse_krb5_child_response] (0x1000): child response [0][6][8]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'pluto.sssdad.com' as 'working' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [set_server_common_status] (0x0100): Marking server 'pluto.sssdad.com' as 'working' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ad_user_data_cmp] (0x1000): Comparing LDAP with LDAP >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'pluto.sssdad.com' as 'working' >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [switch_creds] (0x0200): Switch user to [770843748][770800513]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sss_krb5_check_ccache_princ] (0x2000): Searching for [user1_dom1@SSSDAD.COM] in cache of type [DIR] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [switch_creds] (0x0200): Switch user to [0][0]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [safe_remove_old_ccache_file] (0x0400): New and old ccache file are the same, none will be deleted. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [krb5_mod_ccname] (0x4000): Save ccname [DIR:/run/user/770843748/krb5cc] for user [user1_dom1]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 0) >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 1) >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7fdf4bdc3800 > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7fdf4bdc2810 > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7fdf4bdc3800 "ltdb_callback" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7fdf4bdc2810 "ltdb_timeout" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7fdf4bdc3800 "ltdb_callback" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 1) >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 0) >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 0) >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7fdf4cdfca00 > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7fdf4cdfcb30 > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7fdf4cdfca00 "ltdb_callback" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7fdf4cdfcb30 "ltdb_timeout" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7fdf4cdfca00 "ltdb_callback" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 0) >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [check_wait_queue] (0x1000): Wait queue for user [user1_dom1] is empty. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 0, <NULL>) [Success] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_pam_handler_callback] (0x0100): Sending result [0][sssdad.com] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_pam_handler_callback] (0x0100): Sent result [0][sssdad.com] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [child_sig_handler] (0x1000): Waiting for child [5809]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [child_sig_handler] (0x0100): child [5809] finished successfully. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x7fdf4bdab530 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): Dispatching. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_req_set_domain] (0x0400): Changing request domain from [sssdad.com] to [sssdad.com] >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_pam_handler] (0x0100): Got request with the following data >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): command: PAM_ACCT_MGMT >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): domain: sssdad.com >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): user: user1_dom1 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): service: sshd >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): tty: ssh >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): ruser: >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): rhost: localhost >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): authtok type: 0 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): newauthtok type: 0 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): priv: 1 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [pam_print_data] (0x0100): cli_pid: 5804 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [server_setup] (0x0400): CONFDB: /var/lib/sss/db/config.ldb >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option lookup_family_order has value ipv4_first >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option dns_resolver_timeout has value 6 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option dns_resolver_op_timeout has value 6 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option dns_discovery_domain has no value >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [be_res_get_opts] (0x0100): Lookup order: ipv4_first >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [recreate_ares_channel] (0x0100): Initializing new c-ares channel >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [fo_context_init] (0x0400): Created new fail over context, retry timeout is 30 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [confdb_get_domain_internal] (0x0400): No enumeration for [sssdad.com]! >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [confdb_get_domain_internal] (0x1000): pwd_expiration_warning is -1 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sysdb_domain_init_internal] (0x0200): DB File for sssdad.com: /var/lib/sss/db/cache_sssdad.com.ldb >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7fe0ac0ac8c0 > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7fe0ac0c24d0 > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7fe0ac0ac8c0 "ltdb_callback" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7fe0ac0c24d0 "ltdb_timeout" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7fe0ac0ac8c0 "ltdb_callback" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x0400): asq: Unable to register control with rootdse! >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7fe0ac0c25a0 > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7fe0ac0c2660 > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7fe0ac0c25a0 "ltdb_callback" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7fe0ac0c2660 "ltdb_timeout" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7fe0ac0c25a0 "ltdb_callback" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7fe0ac0c2820 > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7fe0ac0c28e0 > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7fe0ac0c2820 "ltdb_callback" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7fe0ac0c28e0 "ltdb_timeout" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7fe0ac0c2820 "ltdb_callback" > >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sbus_init_connection] (0x0400): Adding connection 0x7fe0ac0ac7b0 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sbus_add_watch] (0x2000): 0x7fe0ac0c2980/0x7fe0ac0c02c0 (14), -/W (enabled) >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0c2980/0x7fe0ac0c1a00 (14), R/- (disabled) >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [monitor_common_send_id] (0x0100): Sending ID: (%BE_sssdad.com,1) >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sbus_add_timeout] (0x2000): 0x7fe0ac0bffe0 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0c2980/0x7fe0ac0c1a00 (14), R/- (enabled) >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0c2980/0x7fe0ac0c02c0 (14), -/W (disabled) >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sss_names_init_from_args] (0x0100): Using re [(((?P<domain>[^\\]+)\\(?P<name>.+$))|((?P<name>[^@]+)@(?P<domain>.+$))|(^(?P<name>[^@\\]+)$))]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sss_fqnames_init] (0x0100): Using fq format [%1$s@%2$s]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sss_fqnames_init] (0x0100): Found the pattern for domain name >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [create_socket_symlink] (0x1000): Symlinking the dbus path /var/lib/sss/pipes/private/sbus-dp_sssdad.com.5810 to a link /var/lib/sss/pipes/private/sbus-dp_sssdad.com >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sbus_new_server] (0x0400): D-BUS Server listening on unix:path=/var/lib/sss/pipes/private/sbus-dp_sssdad.com.5810,guid=5d0a117f186a3fed5a9d8bbb528dc9b7 >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [sbus_add_watch] (0x2000): 0x7fe0ac0c3200/0x7fe0ac0c0040 (15), R/- (enabled) >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [load_backend_module] (0x1000): Loading backend [ad] with path [/usr/lib64/sssd/libsss_ad.so]. >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ad_domain has value sssdad.com >(Thu Nov 21 14:22:07 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ad_server has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ad_backup_server has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ad_hostname has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_keytab has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_realm has value SSSDAD.COM >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ad_enable_dns_sites is TRUE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ad_access_filter has value FOREST:SSSDAD.COM:(memberOf=cn=group1_dom1,cn=Users,dc=sssdad,dc=com) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ad_get_common_options] (0x0100): No AD server set, will use service discovery! >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ad_get_common_options] (0x0100): Setting ad_hostname to [dhcp207-191.lab.eng.pnq.redhat.com]. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 0) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): commit ldb transaction (nesting: 0) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ad_get_common_options] (0x0100): Setting domain case-insensitive >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [fo_new_service] (0x0400): Creating new service 'AD' >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [fo_new_service] (0x0400): Creating new service 'AD_GC' >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ad_failover_init] (0x0100): No primary servers defined, using service discovery >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [fo_add_srv_server] (0x0400): Adding new SRV server to service 'AD_GC' using 'tcp'. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [fo_add_srv_server] (0x0400): Adding new SRV server to service 'AD' using 'tcp'. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [_ad_servers_init] (0x0100): Added service discovery for AD >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option dyndns_update is TRUE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option dyndns_refresh_interval has value 86400 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option dyndns_iface has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option dyndns_ttl has value 3600 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option dyndns_update_ptr is TRUE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option dyndns_force_tcp is FALSE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option dyndns_auth has value gss-tsig >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ad_dyndns_init] (0x0100): Dynamic DNS updates are on. Checking for nsupdate.. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [be_nsupdate_timer_schedule] (0x0200): Scheduling timer in 86400 seconds >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_uri has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_backup_uri has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_search_base has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_default_bind_dn has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_default_authtok_type has value password >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_default_authtok has no binary value. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_search_timeout has value 6 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_network_timeout has value 6 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_opt_timeout has value 6 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_tls_reqcert has value hard >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_user_search_base has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_user_search_scope has value sub >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_user_search_filter has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_group_search_base has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_group_search_scope has value sub >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_group_search_filter has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_service_search_base has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_sudo_search_base has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_sudo_full_refresh_interval has value 21600 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_sudo_smart_refresh_interval has value 900 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_sudo_use_host_filter is TRUE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_sudo_hostnames has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_sudo_ip has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_sudo_include_netgroups is TRUE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_sudo_include_regexp is TRUE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_autofs_search_base has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_schema has value ad >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_offline_timeout has value 60 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_force_upper_case_realm is TRUE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_enumeration_refresh_timeout has value 300 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_purge_cache_timeout has value 10800 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_tls_cacert has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_tls_cacertdir has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_tls_cert has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_tls_key has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_tls_cipher_suite has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_id_use_start_tls is FALSE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_id_mapping is TRUE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_sasl_mech has value gssapi >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_sasl_authid has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_sasl_realm has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_sasl_minssf has value -1 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_krb5_keytab has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_krb5_init_creds is TRUE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_server has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_backup_server has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_realm has value SSSDAD.COM >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_canonicalize is FALSE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_use_kdcinfo is TRUE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_pwd_policy has value none >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_referrals is FALSE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option account_cache_expiration has value 0 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_dns_service_name has value ldap >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_krb5_ticket_lifetime has value 86400 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_access_filter has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_netgroup_search_base has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_group_nesting_level has value 2 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_deref has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_account_expire_policy has value ad >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_access_order has value filter >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_chpass_uri has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_chpass_backup_uri has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_chpass_dns_service_name has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_chpass_update_last_change is FALSE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_enumeration_search_timeout has value 60 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_auth_disable_tls_never_use_in_production is FALSE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_page_size has value 1000 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_deref_threshold has value 10 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_sasl_canonicalize is FALSE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_connection_expire_timeout has value 900 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_disable_paging is FALSE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_idmap_range_min has value 200000 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_idmap_range_max has value 2000200000 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_idmap_range_size has value 200000 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_idmap_autorid_compat is FALSE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_idmap_default_domain has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_idmap_default_domain_sid has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_groups_use_matching_rule_in_chain is FALSE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_initgroups_use_matching_rule_in_chain is FALSE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_rfc2307_fallback_to_local_users is FALSE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_disable_range_retrieval is FALSE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_min_id has value 0 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option ldap_max_id has value 0 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_entry_usn has value uSNChanged >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_rootdse_last_usn has value highestCommittedUSN >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_object_class has value user >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_name has value sAMAccountName >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_pwd has value unixUserPassword >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_uid_number has value uidNumber >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_gid_number has value gidNumber >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_gecos has value gecos >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_home_directory has value unixHomeDirectory >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_shell has value loginShell >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_principal has value userPrincipalName >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_fullname has value name >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_member_of has value memberOf >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_uuid has value objectGUID >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_objectsid has value objectSID >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_primary_group has value primaryGroupID >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_modify_timestamp has value whenChanged >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_entry_usn has value uSNChanged >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_shadow_last_change has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_shadow_min has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_shadow_max has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_shadow_warning has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_shadow_inactive has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_shadow_expire has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_shadow_flag has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_krb_last_pwd_change has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_krb_password_expiration has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_pwd_attribute has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_authorized_service has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_ad_account_expires has value accountExpires >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_ad_user_account_control has value userAccountControl >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_ns_account_lock has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_authorized_host has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_nds_login_disabled has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_nds_login_expiration_time has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_nds_login_allowed_time_map has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_user_ssh_public_key has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_group_object_class has value group >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_group_name has value name >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_group_pwd has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_group_gid_number has value gidNumber >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_group_member has value member >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_group_uuid has value objectGUID >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_group_objectsid has value objectSID >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_group_modify_timestamp has value whenChanged >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_group_entry_usn has value uSNChanged >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_netgroup_object_class has value nisNetgroup >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_netgroup_name has value cn >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_netgroup_member has value memberNisNetgroup >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_netgroup_triple has value nisNetgroupTriple >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_netgroup_uuid has value nsUniqueId >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_netgroup_modify_timestamp has value modifyTimestamp >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_service_object_class has value ipService >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_service_name has value cn >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_service_port has value ipServicePort >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_service_proto has value ipServiceProtocol >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_get_map] (0x0400): Option ldap_service_entry_usn has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ad_set_ad_id_options] (0x0100): Option krb5_realm set to SSSDAD.COM >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_set_sasl_options] (0x0100): Will look for dhcp207-191.lab.eng.pnq.redhat.com@SSSDAD.COM in default keytab >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [select_principal_from_keytab] (0x0200): trying to select the most appropriate principal from keytab >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [find_principal_in_keytab] (0x4000): Trying to find principal dhcp207-191.lab.eng.pnq.redhat.com@SSSDAD.COM in keytab. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [find_principal_in_keytab] (0x0400): No principal matching dhcp207-191.lab.eng.pnq.redhat.com@SSSDAD.COM found in keytab. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [find_principal_in_keytab] (0x4000): Trying to find principal DHCP207-191$@SSSDAD.COM in keytab. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [match_principal] (0x1000): Principal matched to the sample (DHCP207-191$@SSSDAD.COM). >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [select_principal_from_keytab] (0x0200): Selected primary: DHCP207-191$ >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [select_principal_from_keytab] (0x0200): Selected realm: SSSDAD.COM >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_set_sasl_options] (0x0100): Option ldap_sasl_authid set to DHCP207-191$ >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_set_sasl_options] (0x0100): Option ldap_sasl_realm set to SSSDAD.COM >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ad_set_search_bases] (0x0100): Search base not set. SSSD will attempt to discover it later, when connecting to the LDAP server. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_id_setup_tasks] (0x0400): Setting up cleanup task for sssdad.com >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [be_ptask_create] (0x0400): Periodic task [Cleanup of sssdad.com] was created >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [be_ptask_schedule] (0x0400): Task [Cleanup of sssdad.com]: scheduling task 10 seconds from now [1385023938] >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sysdb_idmap_get_mappings] (0x4000): cn=id_mappings,cn=sssdad.com,cn=sysdb >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7fe0ac0d34d0 > >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7fe0ac0d3600 > >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7fe0ac0d34d0 "ltdb_callback" > >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7fe0ac0d3600 "ltdb_timeout" > >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7fe0ac0d34d0 "ltdb_callback" > >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_idmap_init] (0x0100): Initializing [3] domains for ID-mapping >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_idmap_add_domain] (0x1000): Adding domain [S-1-5-21-2153326666-2176343378-3404031434] as slice [3853] >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sysdb_idmap_dn] (0x4000): objectSID=S-1-5-21-2153326666-2176343378-3404031434,cn=id_mappings,cn=sssdad.com,cn=sysdb >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 0) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7fe0ac0d0fb0 > >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7fe0ac0d9840 > >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7fe0ac0d0fb0 "ltdb_callback" > >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7fe0ac0d9840 "ltdb_timeout" > >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7fe0ac0d0fb0 "ltdb_callback" > >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sysdb_idmap_store_mapping] (0x1000): No changes needed, canceling transaction >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): cancel ldb transaction (nesting: 0) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_idmap_add_domain] (0x1000): Adding domain [S-1-5-21-3406858696-2348136156-2230084869] as slice [6453] >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sysdb_idmap_dn] (0x4000): objectSID=S-1-5-21-3406858696-2348136156-2230084869,cn=id_mappings,cn=sssdad.com,cn=sysdb >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 0) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7fe0ac0d9940 > >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7fe0ac0d1620 > >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7fe0ac0d9940 "ltdb_callback" > >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7fe0ac0d1620 "ltdb_timeout" > >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7fe0ac0d9940 "ltdb_callback" > >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sysdb_idmap_store_mapping] (0x1000): No changes needed, canceling transaction >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): cancel ldb transaction (nesting: 0) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sdap_idmap_add_domain] (0x1000): Adding domain [S-1-5-21-2244127252-722905755-257600389] as slice [1475] >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sysdb_idmap_dn] (0x4000): objectSID=S-1-5-21-2244127252-722905755-257600389,cn=id_mappings,cn=sssdad.com,cn=sysdb >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): start ldb transaction (nesting: 0) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7fe0ac0d3430 > >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7fe0ac0d18a0 > >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Running timer event 0x7fe0ac0d3430 "ltdb_callback" > >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Destroying timer event 0x7fe0ac0d18a0 "ltdb_timeout" > >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): Ending timer event 0x7fe0ac0d3430 "ltdb_callback" > >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sysdb_idmap_store_mapping] (0x1000): No changes needed, canceling transaction >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ldb] (0x4000): cancel ldb transaction (nesting: 0) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [be_fo_set_srv_lookup_plugin] (0x0400): Trying to set SRV lookup plugin to AD >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [be_fo_set_srv_lookup_plugin] (0x0400): SRV lookup plugin is now AD >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [be_process_init] (0x2000): ID backend target successfully loaded from provider [ad]. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [load_backend_module] (0x0200): no module name found in confdb, using [ad]. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [load_backend_module] (0x1000): Backend [ad] already loaded. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_server has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_backup_server has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_realm has value SSSDAD.COM >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_ccachedir has value /tmp >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_ccname_template has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_auth_timeout has value 6 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_keytab has value /etc/krb5.keytab >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_validate is TRUE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_kpasswd has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_backup_kpasswd has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_store_password_if_offline is TRUE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_renewable_lifetime has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_lifetime has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_renew_interval has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_use_fast has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_fast_principal has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_canonicalize is FALSE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_use_enterprise_principal is TRUE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_get_options] (0x0400): Option krb5_use_kdcinfo is TRUE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ad_get_auth_options] (0x0100): Option krb5_server set to (null) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ad_get_auth_options] (0x0100): Option krb5_realm set to SSSDAD.COM >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [ad_get_auth_options] (0x0100): Option krb5_use_kdcinfo set to true >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [check_and_export_lifetime] (0x0200): No lifetime configured. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [check_and_export_lifetime] (0x0200): No lifetime configured. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [check_and_export_options] (0x0100): No KDC explicitly configured, using defaults. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [check_and_export_options] (0x0100): No kpasswd server explicitly configured, using the KDC or defaults. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [be_process_init] (0x2000): AUTH backend target successfully loaded from provider [ad]. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [load_backend_module] (0x1000): Backend [ad] already loaded. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_copy_options] (0x0400): Option ad_domain has value sssdad.com >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_copy_options] (0x0400): Option ad_server has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_copy_options] (0x0400): Option ad_backup_server has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_copy_options] (0x0400): Option ad_hostname has value dhcp207-191.lab.eng.pnq.redhat.com >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_copy_options] (0x0400): Option krb5_keytab has no value >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_copy_options] (0x0400): Option krb5_realm has value SSSDAD.COM >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_copy_options] (0x0400): Option ad_enable_dns_sites is TRUE >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [dp_copy_options] (0x0400): Option ad_access_filter has value FOREST:SSSDAD.COM:(memberOf=cn=group1_dom1,cn=Users,dc=sssdad,dc=com) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [be_process_init] (0x2000): ACCESS backend target successfully loaded from provider [ad]. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [load_backend_module] (0x0200): no module name found in confdb, using [ad]. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [load_backend_module] (0x1000): Backend [ad] already loaded. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [be_process_init] (0x2000): CHPASS backend target successfully loaded from provider [ad]. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [be_process_init_sudo] (0x0400): SUDO is not listed in services, disabling SUDO module. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [be_process_init] (0x0080): No SUDO module provided for [sssdad.com] !! >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [load_backend_module] (0x0200): no module name found in confdb, using [ad]. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [load_backend_module] (0x1000): Backend [ad] already loaded. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [be_process_init] (0x0080): No autofs module provided for [sssdad.com] !! >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [load_backend_module] (0x0200): no module name found in confdb, using [ad]. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [load_backend_module] (0x1000): Backend [ad] already loaded. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [be_process_init] (0x0020): No selinux module provided for [sssdad.com] !! >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [load_backend_module] (0x0200): no module name found in confdb, using [ad]. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [load_backend_module] (0x1000): Backend [ad] already loaded. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [be_process_init] (0x0020): No host info module provided for [sssdad.com] !! >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [load_backend_module] (0x0200): no module name found in confdb, using [ad]. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [load_backend_module] (0x1000): Backend [ad] already loaded. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [be_process_init] (0x4000): Get-Subdomains backend target successfully loaded from provider [ad]. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [main] (0x0400): Backend provider (sssdad.com) started! >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x7fe0ac0ac7b0 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x7fe0ac0ac7b0 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0c2980/0x7fe0ac0c1a00 (14), R/- (disabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0c2980/0x7fe0ac0c02c0 (14), -/W (enabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0c2980/0x7fe0ac0c1a00 (14), R/- (enabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0c2980/0x7fe0ac0c02c0 (14), -/W (disabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0c2980/0x7fe0ac0c1a00 (14), R/- (disabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0c2980/0x7fe0ac0c02c0 (14), -/W (enabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0c2980/0x7fe0ac0c1a00 (14), R/- (enabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0c2980/0x7fe0ac0c02c0 (14), -/W (disabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_remove_timeout] (0x2000): 0x7fe0ac0bffe0 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x7fe0ac0ac7b0 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): Dispatching. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [id_callback] (0x0100): Got id ack and version (1) from Monitor >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_server_init_new_connection] (0x0200): Entering. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x7fe0ac0dd200. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_init_connection] (0x0400): Adding connection 0x7fe0ac0dd200 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_add_watch] (0x2000): 0x7fe0ac0d9540/0x7fe0ac0ac4f0 (18), -/W (disabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0d9540/0x7fe0ac0ab660 (18), R/- (enabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_server_init_new_connection] (0x0200): Got a connection >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [be_client_init] (0x0100): Set-up Backend ID timeout [0x7fe0ac0dea60] >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x7fe0ac0dd200 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0d9540/0x7fe0ac0ab660 (18), R/- (disabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0d9540/0x7fe0ac0ac4f0 (18), -/W (enabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0d9540/0x7fe0ac0ab660 (18), R/- (enabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0d9540/0x7fe0ac0ac4f0 (18), -/W (disabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0d9540/0x7fe0ac0ab660 (18), R/- (disabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0d9540/0x7fe0ac0ac4f0 (18), -/W (enabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0d9540/0x7fe0ac0ab660 (18), R/- (enabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0d9540/0x7fe0ac0ac4f0 (18), -/W (disabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x7fe0ac0dd200 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): Dispatching. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_message_handler] (0x4000): Received SBUS method [RegisterService] >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [client_registration] (0x0100): Cancel DP ID timeout [0x7fe0ac0dea60] >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [client_registration] (0x0100): Added Frontend client [NSS] >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_server_init_new_connection] (0x0200): Entering. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x7fe0ac0e0530. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_init_connection] (0x0400): Adding connection 0x7fe0ac0e0530 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_add_watch] (0x2000): 0x7fe0ac0e0be0/0x7fe0ac0dd0b0 (19), -/W (disabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0e0be0/0x7fe0ac0ddaf0 (19), R/- (enabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_server_init_new_connection] (0x0200): Got a connection >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [be_client_init] (0x0100): Set-up Backend ID timeout [0x7fe0ac0e0e90] >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x7fe0ac0e0530 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0e0be0/0x7fe0ac0ddaf0 (19), R/- (disabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0e0be0/0x7fe0ac0dd0b0 (19), -/W (enabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0e0be0/0x7fe0ac0ddaf0 (19), R/- (enabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0e0be0/0x7fe0ac0dd0b0 (19), -/W (disabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0e0be0/0x7fe0ac0ddaf0 (19), R/- (disabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0e0be0/0x7fe0ac0dd0b0 (19), -/W (enabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0e0be0/0x7fe0ac0ddaf0 (19), R/- (enabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_toggle_watch] (0x4000): 0x7fe0ac0e0be0/0x7fe0ac0dd0b0 (19), -/W (disabled) >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x7fe0ac0e0530 >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_dispatch] (0x4000): Dispatching. >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [sbus_message_handler] (0x4000): Received SBUS method [RegisterService] >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [client_registration] (0x0100): Cancel DP ID timeout [0x7fe0ac0e0e90] >(Thu Nov 21 14:22:08 2013) [sssd[be[sssdad.com]]] [client_registration] (0x0100): Added Frontend client [PAM] >
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 1032983
: 827127 |
827128