Attachment 827127 Details for Bug 1032983 – Domain log when the crash happens

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:

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]
>

Actions: View

Attachments on bug 1032983: 827127 | 827128