On 01/06/2015 05:06 PM, Orion Poplawski wrote:
We're having some trouble with sssd on centos 7 under load on a
VPS. 389ds
ldap server for id/auth. Part may be an issue with the VPS, but I'm trying to
track down all possible issues.
Some updated logs with debug_level=4
Looks like some hiccups again overnight. What seem odd here is that the
service is maked as working, but then also failed?
(Thu Jan 8 08:45:24 2015) [sssd[be[default]]] [fo_resolve_service_send]
(0x0100): Trying to resolve service 'LDAP'
(Thu Jan 8 08:45:24 2015) [sssd[be[default]]] [fo_set_port_status] (0x0100):
Marking port 636 of server 'server.com' as 'working'
(Thu Jan 8 08:45:24 2015) [sssd[be[default]]] [set_server_common_status]
(0x0100): Marking server 'server.com' as 'working'
(Thu Jan 8 08:45:24 2015) [sssd[be[default]]] [simple_bind_send] (0x0100):
Executing simple bind as: uid=XXX,ou=People,dc=server,dc=com
(Thu Jan 8 08:45:24 2015) [sssd[be[default]]] [fo_set_port_status] (0x0100):
Marking port 636 of server 'server.com' as 'working'
(Thu Jan 8 08:45:24 2015) [sssd[be[default]]] [set_server_common_status]
(0x0100): Marking server 'server.com' as 'working'
(Thu Jan 8 08:45:24 2015) [sssd[be[default]]] [simple_bind_send] (0x0100):
Executing simple bind as: uid=XXX,ou=People,dc=server,dc=com
(Thu Jan 8 08:45:24 2015) [sssd[be[default]]] [acctinfo_callback] (0x0100):
Request processed. Returned 0,0,Success
(Thu Jan 8 08:45:24 2015) [sssd[be[default]]] [acctinfo_callback] (0x0100):
Request processed. Returned 0,0,Success
(Thu Jan 8 08:45:25 2015) [sssd[be[default]]] [fo_set_port_status] (0x0100):
Marking port 636 of server 'server.com' as 'working'
(Thu Jan 8 08:45:25 2015) [sssd[be[default]]] [set_server_common_status]
(0x0100): Marking server 'server.com' as 'working'
(Thu Jan 8 08:45:25 2015) [sssd[be[default]]] [simple_bind_send] (0x0100):
Executing simple bind as: uid=XXX,ou=People,dc=server,dc=com
(Thu Jan 8 08:45:31 2015) [sssd[be[default]]] [sdap_pam_auth_done] (0x0100):
Password successfully cached for XXX
(Thu Jan 8 08:45:31 2015) [sssd[be[default]]] [be_pam_handler_callback]
(0x0100): Backend returned: (0, 0, <NULL>) [Success]
(Thu Jan 8 08:45:31 2015) [sssd[be[default]]] [be_pam_handler_callback]
(0x0100): Sending result [0][default]
(Thu Jan 8 08:45:31 2015) [sssd[be[default]]] [be_pam_handler_callback]
(0x0100): Sent result [0][default]
(Thu Jan 8 08:45:31 2015) [sssd[be[default]]] [fo_resolve_service_send]
(0x0100): Trying to resolve service 'LDAP'
(Thu Jan 8 08:45:31 2015) [sssd[be[default]]] [fo_resolve_service_send]
(0x0100): Trying to resolve service 'LDAP'
(Thu Jan 8 08:45:31 2015) [sssd[be[default]]] [be_resolve_server_process]
(0x0040): The fail over cycled through all available servers
(Thu Jan 8 08:45:31 2015) [sssd[be[default]]] [be_run_offline_cb] (0x0080):
Going offline. Running callbacks.
(Thu Jan 8 08:45:31 2015) [sssd[be[default]]] [be_pam_handler_callback]
(0x0100): Backend returned: (1, 9, <NULL>) [Provider is Offline
(Authentication service cannot retrieve authentication info)]
(Thu Jan 8 08:45:31 2015) [sssd[be[default]]] [be_pam_handler_callback]
(0x0100): Sending result [9][default]
(Thu Jan 8 08:45:31 2015) [sssd[be[default]]] [be_pam_handler_callback]
(0x0100): Sent result [9][default]
(Thu Jan 8 08:45:31 2015) [sssd[be[default]]] [fo_set_port_status] (0x0100):
Marking port 636 of server 'server.com' as 'working'
(Thu Jan 8 08:45:31 2015) [sssd[be[default]]] [set_server_common_status]
(0x0100): Marking server 'server.com' as 'working'
(Thu Jan 8 08:45:33 2015) [sssd[be[default]]] [simple_bind_send] (0x0100):
Executing simple bind as: uid=XXX,ou=People,dc=server,dc=com
(Thu Jan 8 08:45:33 2015) [sssd[be[default]]] [be_get_account_info] (0x0100):
Got request for [3][1][name=XXX]
(Thu Jan 8 08:45:33 2015) [sssd[be[default]]] [be_get_account_info] (0x0100):
Got request for [3][1][name=XXX]
(Thu Jan 8 08:45:33 2015) [sssd[be[default]]] [acctinfo_callback] (0x0100):
Request processed. Returned 1,11,Offline
We're finally working again:
(Thu Jan 8 08:46:51 2015) [sssd[be[default]]] [fo_resolve_service_send]
(0x0100): Trying to resolve service 'LDAP'
(Thu Jan 8 08:46:51 2015) [sssd[be[default]]] [get_single_value_as_string]
(0x0080): More than one value found.
(Thu Jan 8 08:46:51 2015) [sssd[be[default]]]
[sdap_set_config_options_with_rootdse] (0x0020): get_naming_context failed.
(Thu Jan 8 08:46:51 2015) [sssd[be[default]]] [sdap_cli_auth_step] (0x0100):
expire timeout is 900
(Thu Jan 8 08:46:51 2015) [sssd[be[default]]] [fo_set_port_status] (0x0100):
Marking port 636 of server 'server.com' as 'working'
(Thu Jan 8 08:46:51 2015) [sssd[be[default]]] [set_server_common_status]
(0x0100): Marking server 'server.com' as 'working'
(Thu Jan 8 08:46:51 2015) [sssd[be[default]]] [sdap_attrs_get_sid_str]
(0x0080): No [objectSID] attribute while id-mapping. [0][Success]
(Thu Jan 8 08:46:51 2015) [sssd[be[default]]] [acctinfo_callback] (0x0100):
Request processed. Returned 0,0,Success
(Thu Jan 8 08:46:51 2015) [sssd[be[default]]] [fo_resolve_service_send]
(0x0100): Trying to resolve service 'LDAP'
(Thu Jan 8 08:46:52 2015) [sssd[be[default]]] [fo_set_port_status] (0x0100):
Marking port 636 of server 'server.com' as 'working'
(Thu Jan 8 08:46:52 2015) [sssd[be[default]]] [set_server_common_status]
(0x0100): Marking server 'server.com' as 'working'
(Thu Jan 8 08:46:52 2015) [sssd[be[default]]] [simple_bind_send] (0x0100):
Executing simple bind as: uid=XXX,ou=People,dc=server,dc=com
(Thu Jan 8 08:46:52 2015) [sssd[be[default]]] [sdap_pam_auth_done] (0x0100):
Password successfully cached for XXX
(Thu Jan 8 08:46:52 2015) [sssd[be[default]]] [be_pam_handler_callback]
(0x0100): Backend returned: (0, 0, <NULL>) [Success]
(Thu Jan 8 08:46:52 2015) [sssd[be[default]]] [be_pam_handler_callback]
(0x0100): Sending result [0][default]
(Thu Jan 8 08:46:52 2015) [sssd[be[default]]] [be_pam_handler_callback]
(0x0100): Sent result [0][default]
(Thu Jan 8 08:46:52 2015) [sssd[be[default]]] [fo_resolve_service_send]
(0x0100): Trying to resolve service 'LDAP'
(Thu Jan 8 08:46:52 2015) [sssd[be[default]]] [fo_set_port_status] (0x0100):
Marking port 636 of server 'server.com' as 'working'
(Thu Jan 8 08:46:52 2015) [sssd[be[default]]] [set_server_common_status]
(0x0100): Marking server 'server.com' as 'working'
(Thu Jan 8 08:46:52 2015) [sssd[be[default]]] [simple_bind_send] (0x0100):
Executing simple bind as: uid=XXX,ou=People,dc=server,dc=com
(Thu Jan 8 08:46:52 2015) [sssd[be[default]]] [sdap_pam_auth_done] (0x0100):
Password successfully cached for XXX
--
Orion Poplawski
Technical Manager 303-415-9701 x222
NWRA, Boulder/CoRA Office FAX: 303-415-9702
3380 Mitchell Lane orion(a)nwra.com
Boulder, CO 80301
http://www.nwra.com