After some further digging I tend to agree that its in the LDAP arena where the issue lies .. but there is nothing in the ldap_child log thats helping out .. (btw the other replica IPA servers dont seem to encounter this issue just the master (ie the server with CA responsibility) ...

Also more logs (sigh) dont understand though how a server can be marked as working and in the same second fail ... or what call is causing an input/output error ... :(


(Tue Nov 26 09:14:58 2013) [sssd[be[ipa.server-noc.com]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: GSSAPI, user: host/tardis.ipa.server-noc.com (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [sasl_bind_send] (0x0020): ldap_sasl_bind failed (-5)[Timed out] (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [sasl_bind_send] (0x0080): Extended failure message: [unknown error] (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'tardis.ipa.server-noc.com' as 'not working' (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [sdap_handle_release] (0x2000): Trace: sh[0x17dcf50], connected[1], ops[(nil)], ldap[0x17d6920], destructor_lock[0], release_memory[0] (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [remove_connection_callback] (0x4000): Successfully removed connection callback. (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [sdap_id_op_connect_done] (0x4000): notify error to op #1: 5 [Input/output error] (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [acctinfo_callback] (0x0100): Request processed. Returned 3,5,User lookup failed (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [sdap_id_release_conn_data] (0x4000): releasing unused connection (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [sbus_dispatch] (0x4000): dbus conn: 174A470 (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [sbus_dispatch] (0x4000): Dispatching. (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [sbus_message_handler] (0x4000): Received SBUS method [getAccountInfo] (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [be_get_account_info] (0x0100): Got request for [4097][1][name=nobody] (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [sdap_id_op_connect_step] (0x4000): beginning to connect (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [get_server_status] (0x1000): Status of server 'tardis.ipa.server-noc.com' is 'working' (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [get_port_status] (0x1000): Port status of port 0 for server 'tardis.ipa.server-noc.com' is 'not working' (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [fo_resolve_service_send] (0x0020): No available servers for service 'IPA' (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [be_resolve_server_done] (0x1000): Server resolution failed: 5 (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [sdap_id_op_connect_done] (0x0020): Failed to connect, going offline (5 [Input/output error]) (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [be_mark_offline] (0x2000): Going offline! (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [be_run_offline_cb] (0x0080): Going offline. Running callbacks. (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [sdap_id_op_connect_done] (0x4000): notify offline to op #1 (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [acctinfo_callback] (0x0100): Request processed. Returned 1,11,Offline (Tue Nov 26 09:15:04 2013) [sssd[be[ipa.server-noc.com]]] [sdap_id_release_conn_data] (0x4000): releasing unused connection
...
...
(Tue Nov 26 09:16:12 2013) [sssd[be[ipa.server-noc.com]]] [sbus_dispatch] (0x4000): dbus conn: 171FDB0 (Tue Nov 26 09:16:12 2013) [sssd[be[ipa.server-noc.com]]] [sbus_dispatch] (0x4000): Dispatching. (Tue Nov 26 09:16:12 2013) [sssd[be[ipa.server-noc.com]]] [sbus_message_handler] (0x4000): Received SBUS method [ping] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sbus_dispatch] (0x4000): dbus conn: 174A470 (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sbus_dispatch] (0x4000): Dispatching. (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sbus_message_handler] (0x4000): Received SBUS method [getAccountInfo] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [be_get_account_info] (0x0100): Got request for [4097][1][idnumber=493] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [be_get_account_info] (0x0100): Request processed. Returned 1,11,Fast reply - offline (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_id_op_connect_step] (0x4000): beginning to connect (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [get_server_status] (0x1000): Status of server 'tardis.ipa.server-noc.com' is 'working' (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [get_port_status] (0x1000): Port status of port 0 for server 'tardis.ipa.server-noc.com' is 'not working' (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [get_port_status] (0x0100): Reseting the status of port 0 for server 'tardis.ipa.server-noc.com' (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 10 seconds (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [get_server_status] (0x1000): Status of server 'tardis.ipa.server-noc.com' is 'working' (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [be_resolve_server_process] (0x0200): Found address for server tardis.ipa.server-noc.com: [203.147.190.30] TTL 7200 (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [ipa_resolve_callback] (0x0400): Constructed uri 'ldap://tardis.ipa.server-noc.com' (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sss_ldap_init_send] (0x4000): Using file descriptor [19] for LDAP connection. (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sss_ldap_init_send] (0x0400): Setting 10 seconds timeout for connecting (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://tardis.ipa.server-noc.com:389/??base] with fd [19]. (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_rootdse_send] (0x4000): Getting rootdse (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sbus_dispatch] (0x4000): dbus conn: 174A470 (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sbus_dispatch] (0x4000): Dispatching. (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sbus_message_handler] (0x4000): Received SBUS method [getAccountInfo] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [be_get_account_info] (0x0100): Got request for [4097][1][*] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_process_result] (0x2000): Trace: sh[0x171e770], connected[1], ops[0x17dded0], ldap[0x17378e0] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_parse_entry] (0x4000): OriginalDN: []. (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectClass] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [namingContexts] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [defaultnamingcontext] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedExtension] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedControl] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedSASLMechanisms] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPVersion] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [vendorName] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [vendorVersion] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [dataversion] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [netscapemdsuffix] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_parse_range] (0x2000): No sub-attributes for [lastusn] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_process_result] (0x2000): Trace: sh[0x171e770], connected[1], ops[0x17dded0], ldap[0x17378e0] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_rootdse_done] (0x2000): Got rootdse (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_server_opts_from_rootdse] (0x4000): USN value: 7097911 (int: 7097911) (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, host/tardis.ipa.server-noc.com, SERVER-IPA, 86400) (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service IPA (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [get_server_status] (0x1000): Status of server 'tardis.ipa.server-noc.com' is 'working' (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 10 seconds (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [get_server_status] (0x1000): Status of server 'tardis.ipa.server-noc.com' is 'working' (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [be_resolve_server_process] (0x0200): Found address for server tardis.ipa.server-noc.com: [203.147.190.30] TTL 7200 (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [create_tgt_req_send_buffer] (0x1000): buffer size: 56 (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [26046] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [child_handler_setup] (0x2000): Signal handler set up for pid [26046] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_process_result] (0x2000): Trace: sh[0x171e770], connected[1], ops[(nil)], ldap[0x17378e0] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [write_pipe_handler] (0x0400): All data has been sent! (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sbus_dispatch] (0x4000): dbus conn: 174A470 (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sbus_dispatch] (0x4000): Dispatching. (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sbus_message_handler] (0x4000): Received SBUS method [getAccountInfo] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [be_get_account_info] (0x0100): Got request for [4098][1][*] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sbus_dispatch] (0x4000): dbus conn: 174A470 (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sbus_dispatch] (0x4000): Dispatching. (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sbus_message_handler] (0x4000): Received SBUS method [getAccountInfo] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [be_get_account_info] (0x0100): Got request for [4097][1][idnumber=493] (Tue Nov 26 09:16:21 2013) [sssd[be[ipa.server-noc.com]]] [sdap_id_op_connect_step] (0x4000): waiting for connection to complete (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sbus_dispatch] (0x4000): dbus conn: 171FDB0 (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sbus_dispatch] (0x4000): Dispatching. (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sbus_message_handler] (0x4000): Received SBUS method [ping] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [child_sig_handler] (0x1000): Waiting for child [26046]. (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [child_sig_handler] (0x0100): child [26046] finished successfully. (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sss_child_handler] (0x2000): waitpid failed [10]: No child processes (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [read_pipe_handler] (0x0400): EOF received, client finished (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_SERVER-IPA], expired on [1385507781] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1385422282 (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: GSSAPI, user: host/tardis.ipa.server-noc.com (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'tardis.ipa.server-noc.com' as 'working' (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [set_server_common_status] (0x0100): Marking server 'tardis.ipa.server-noc.com' as 'working' (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_id_op_connect_done] (0x2000): Old USN: 7097881, New USN: 7097911 (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_id_op_connect_done] (0x4000): notify connected to op #1 (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_users_next_base] (0x0400): Searching for users with base [cn=accounts,dc=server-ipa] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(uidNumber=493)(objectclass=posixAccount))][cn=accounts,dc=server-ipa]. (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uid] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPassword] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [homeDirectory] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbPrincipalName] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [cn] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [nsUniqueId] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [modifyTimestamp] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [entryUSN] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowLastChange] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMin] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMax] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowWarning] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowInactive] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowExpire] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowFlag] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbLastPwdChange] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbPasswordExpiration] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [pwdAttribute] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [authorizedService] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [nsAccountLock] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [host] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginDisabled] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginExpirationTime] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginAllowedTimeMap] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [ipaSshPubKey] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 5 (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_id_op_connect_done] (0x4000): notify connected to op #2 (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_users_next_base] (0x0400): Searching for users with base [cn=accounts,dc=server-ipa] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(uidNumber=493)(objectclass=posixAccount))][cn=accounts,dc=server-ipa]. (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uid] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPassword] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [homeDirectory] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbPrincipalName] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [cn] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [nsUniqueId] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [modifyTimestamp] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [entryUSN] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowLastChange] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMin] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMax] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowWarning] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowInactive] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowExpire] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowFlag] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbLastPwdChange] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbPasswordExpiration] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [pwdAttribute] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [authorizedService] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [nsAccountLock] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [host] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginDisabled] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginExpirationTime] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginAllowedTimeMap] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [ipaSshPubKey] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 6 (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_id_op_connect_done] (0x4000): caching successful connection after 2 notifies (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [be_run_online_cb] (0x0080): Going online. Running callbacks. (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sbus_dispatch] (0x4000): dbus conn: 174A470 (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sbus_dispatch] (0x4000): Dispatching. (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sbus_message_handler] (0x4000): Received SBUS method [getAccountInfo] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [be_get_account_info] (0x0100): Got request for [4097][1][idnumber=495] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_users_next_base] (0x0400): Searching for users with base [cn=accounts,dc=server-ipa] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(uidNumber=495)(objectclass=posixAccount))][cn=accounts,dc=server-ipa]. (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uid] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPassword] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [homeDirectory] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbPrincipalName] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [cn] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [nsUniqueId] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [modifyTimestamp] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [entryUSN] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowLastChange] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMin] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMax] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowWarning] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowInactive] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowExpire] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowFlag] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbLastPwdChange] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbPasswordExpiration] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [pwdAttribute] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [authorizedService] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [nsAccountLock] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [host] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginDisabled] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginExpirationTime] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginAllowedTimeMap] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [ipaSshPubKey] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 7 (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [objectclass=ipaNTTrustedDomain][cn=trusts,dc=server-ipa]. (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [cn] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [ipaNTFlatName] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [ipaNTTrustedDomainSID] (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 8 (Tue Nov 26 09:16:22 2013) [sssd[be[ipa.server-noc.com]]] [delayed_online_authentication_callback] (0x0200): Backend is online, starting delayed online authentication.

also seeing these errors ...

Tue Nov 26 09:42:02 2013) [sssd[be[ipa.server-noc.com]]] [ldb] (0x4000): start ldb transaction (nesting: 0) (Tue Nov 26 09:42:02 2013) [sssd[be[ipa.server-noc.com]]] [sysdb_update_ranges] (0x0400): Adding range [SERVER-IPA_id_range]. (Tue Nov 26 09:42:02 2013) [sssd[be[ipa.server-noc.com]]] [sysdb_range_create] (0x0040): Invalid range, expected that either the secondary base rid or the SID of the trusted domain is set, but not both or none of them. (Tue Nov 26 09:42:02 2013) [sssd[be[ipa.server-noc.com]]] [sysdb_range_create] (0x0400): Error: 22 (Invalid argument) (Tue Nov 26 09:42:02 2013) [sssd[be[ipa.server-noc.com]]] [sysdb_update_ranges] (0x0040): sysdb_range_create failed. (Tue Nov 26 09:42:02 2013) [sssd[be[ipa.server-noc.com]]] [ldb] (0x4000): cancel ldb transaction (nesting: 0) (Tue Nov 26 09:42:02 2013) [sssd[be[ipa.server-noc.com]]] [ipa_subdomains_handler_ranges_done] (0x0040): sysdb_update_ranges failed.

Have not setup any AD trusts etc ...

rgds

Matt B.

On 11/25/2013 06:49 PM, Sumit Bose wrote:
On Mon, Nov 25, 2013 at 09:23:22AM +1000, Matt Bryant wrote:
All,

Was wondering if anyone can help out or point us the in right
direction. Ever since we updated from IPA v2.1 to IPA v3.0 have been
seeing some intermittent errors when trying to change passwords etc.
Getting the error cannot change password since system offline.

Have increased the logging and found that quite frequently the
sasl_bind using the host principle is timing out and failing ...
(whether this is red herring or not dont know but cant be good
anyhow)

(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[sdap_kinit_send] (0x0400): Attempting kinit (default,
host/tardis.ipa.server-noc.com, SERVER-IPA, 86400)
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service IPA
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[get_server_status] (0x1000): Status of server
'tardis.ipa.server-noc.com' is 'working'
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set
to 10 seconds
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[get_server_status] (0x1000): Status of server
'tardis.ipa.server-noc.com' is 'working'
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[be_resolve_server_process] (0x1000): Saving the first resolved
server
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[be_resolve_server_process] (0x0200): Found address for server
tardis.ipa.server-noc.com: [203.147.190.30] TTL 7200
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get
TGT...
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[create_tgt_req_send_buffer] (0x1000): buffer size: 56
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[child_handler_setup] (0x2000): Setting up signal handler up for pid
[3734]
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[child_handler_setup] (0x2000): Signal handler set up for pid [3734]
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt
child
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[sdap_process_result] (0x2000): Trace: sh[0xa45960], connected[1],
ops[(nil)], ldap[0xa12200]
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[sdap_process_result] (0x2000): Trace: ldap_result found nothing!
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[write_pipe_handler] (0x0400): All data has been sent!
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[child_sig_handler] (0x1000): Waiting for child [3734].
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[child_sig_handler] (0x0100): child [3734] finished successfully.
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[sss_child_handler] (0x2000): waitpid failed [10]: No child
processes
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[read_pipe_handler] (0x0400): EOF received, client finished
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[sdap_get_tgt_recv] (0x0400): Child responded: 0
[FILE:/var/lib/sss/db/ccache_SERVER-IPA], expired on [1385420045]
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[sdap_cli_auth_step] (0x0100): expire timeout is 900
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[sdap_cli_auth_step] (0x1000): the connection will expire at
1385334545
(Mon Nov 25 08:54:05 2013) [sssd[be[ipa.server-noc.com]]]
[sasl_bind_send] (0x0100): Executing sasl bind mech: GSSAPI, user:
host/tardis.ipa.server-noc.com
(Mon Nov 25 08:54:11 2013) [sssd[be[ipa.server-noc.com]]]
[sasl_bind_send] (0x0020): ldap_sasl_bind failed (-5)[Timed out]
(Mon Nov 25 08:54:11 2013) [sssd[be[ipa.server-noc.com]]]
[sasl_bind_send] (0x0080): Extended failure message: [unknown error]
(Mon Nov 25 08:54:11 2013) [sssd[be[ipa.server-noc.com]]]
[fo_set_port_status] (0x0100): Marking port 0 of server
'tardis.ipa.server-noc.com' as 'not working'
(Mon Nov 25 08:54:11 2013) [sssd[be[ipa.server-noc.com]]]
[sdap_handle_release] (0x2000): Trace: sh[0xa45960], connected[1],
ops[(nil)], ldap[0xa12200], destructor_lock[0], release_memory[0]
..
..

it then goes on to connect to fail over server and succeed and
shortly after the master server is tested and marked as working
again ... works for a couple of times then time out again .. any
pointers gratefully received.
According to the logs I would say that this timeout happens on the
LDAP server side. Do you have a chance to check the server logs to see
what happens at this time on the server?

You can increase the timeout value on the client by setting
ldap_opt_timeout to a larger value then 6 (the default). But please note
that the operation might take longer then letting SSSD fail over to the
next server.

HTH

bye,
Sumit


packages used ...

ipa-server-3.0.0-25.el6.x86_64
sssd-1.9.2-82.11.el6_4.x86_64

rgds

Matt Bryant

_______________________________________________
Freeipa-users mailing list
Freeipa-users@redhat.com
https://www.redhat.com/mailman/listinfo/freeipa-users
_______________________________________________
Freeipa-users mailing list
Freeipa-users@redhat.com
https://www.redhat.com/mailman/listinfo/freeipa-users

_______________________________________________
Freeipa-users mailing list
Freeipa-users@redhat.com
https://www.redhat.com/mailman/listinfo/freeipa-users

Reply via email to