8:44 a.m.
All,
I have a somewhat weird issue with user authentication, with a pure LDAP
SSSD backend. A user was created in LDAP, and that user could be used, via
SSSD, for login, etc., just fine. Then, the LDAP databases were rebuilt
(this is a test environment) and the user was re-created, in LDAP, and can
be seen there.
HOWEVER, only hosts created SINCE the LDAP rebuild allow this user to
authenticate. Hosts that predate the rebuild respond with "user unknown".
I've gone through all the caches that I know (nscd, PAM), and haven't
managed to solve the problem.
Here is a log of what SSSD reports, when trying to authenticate the user,
from a host that predated the LDAP rebuild:
(Thu Apr 17 13:35:51 2014) [sssd[nss]] [nss_cmd_getpwnam] (4): Requesting
info for [baduser] from [<ALL>]
(Thu Apr 17 13:35:51 2014) [sssd[nss]] [nss_cmd_getpwnam_search] (4):
Requesting info for [baduser@default]
(Thu Apr 17 13:35:51 2014) [sssd[nss]] [sss_dp_send_acct_req_create] (4):
Sending request for [default][4097][1][name=baduser]
(Thu Apr 17 13:35:51 2014) [sssd[nss]] [sss_dp_get_reply] (4): Got reply
(0, 0, Success) from Data Provider
(Thu Apr 17 13:35:51 2014) [sssd[nss]] [nss_cmd_getpwnam_search] (4):
Requesting info for [baduser@default]
(Thu Apr 17 13:35:51 2014) [sssd[nss]] [nss_cmd_getpwnam_search] (2): No
results for getpwnam call
(Thu Apr 17 13:35:51 2014) [sssd[nss]] [nss_cmd_getpwnam] (4): Requesting
info for [baduser] from [<ALL>]
(Thu Apr 17 13:35:51 2014) [sssd[nss]] [nss_cmd_getpwnam_search] (2): User
[baduser] does not exist in [default]! (negative cache)
(Thu Apr 17 13:35:51 2014) [sssd[nss]] [nss_cmd_getpwnam_search] (2): No
matching domain found for [baduser], fail!
(Thu Apr 17 13:35:51 2014) [sssd[nss]] [nss_cmd_getpwnam] (4): Requesting
info for [baduser] from [<ALL>]
(Thu Apr 17 13:35:51 2014) [sssd[nss]] [nss_cmd_getpwnam_search] (2): User
[baduser] does not exist in [default]! (negative cache)
(Thu Apr 17 13:35:51 2014) [sssd[nss]] [nss_cmd_getpwnam_search] (2): No
matching domain found for [baduser], fail!
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [sss_cmd_get_version] (5): Received
client version [3].
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [sss_cmd_get_version] (5): Offered
version [3].
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [pam_cmd_authenticate] (4): entering
pam_cmd_authenticate
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [pam_print_data] (4): command:
PAM_AUTHENTICATE
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [pam_print_data] (4): domain: (null)
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [pam_print_data] (4): user: baduser
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [pam_print_data] (4): service: sshd
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [pam_print_data] (4): tty: ssh
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [pam_print_data] (4): ruser: (null)
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [pam_print_data] (4): rhost: 1.2.3.4
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [pam_print_data] (4): authtok type: 1
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [pam_print_data] (4): authtok size:
13
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [pam_print_data] (4): newauthtok
type: 0
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [pam_print_data] (4): newauthtok
size: 0
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [pam_print_data] (4): priv: 1
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [pam_print_data] (4): cli_pid: 3919
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [sss_dp_send_acct_req_create] (4):
Sending request for [default][3][1][name=baduser]
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [sss_dp_get_reply] (4): Got reply
(3, 17, Init Groups Failed) from Data Provider
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [pam_check_user_dp_callback] (2):
Unable to get information from Data Provider
Error: 3, 17, Init Groups Failed
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [pam_check_user_search] (4):
Requesting info for [baduser@default]
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [pam_check_user_search] (2): No
matching domain found for [baduser], fail!
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [pam_reply] (4): pam_reply get
called.
(Thu Apr 17 13:35:51 2014) [sssd[pam]] [pam_reply] (4): blen: 8
(Thu Apr 17 13:35:51 2014) [sssd[be[default]]] [be_get_account_info] (4):
Got request for [4097][1][name=baduser]
(Thu Apr 17 13:35:51 2014) [sssd[be[default]]] [sdap_save_user] (2): Failed
to save user [baduser]
(Thu Apr 17 13:35:51 2014) [sssd[be[default]]] [sdap_save_users] (2):
Failed to store user 0. Ignoring.
(Thu Apr 17 13:35:51 2014) [sssd[be[default]]] [acctinfo_callback] (4):
Request processed. Returned 0,0,Success
(Thu Apr 17 13:35:51 2014) [sssd[be[default]]] [be_get_account_info] (4):
Got request for [3][1][name=baduser]
(Thu Apr 17 13:35:51 2014) [sssd[be[default]]] [sdap_save_user] (2): Failed
to save user [baduser]
(Thu Apr 17 13:35:51 2014) [sssd[be[default]]] [acctinfo_callback] (4):
Request processed. Returned 3,17,Init Groups Failed
(Thu Apr 17 13:35:53 2014) [sssd[nss]] [client_recv] (5): Client
disconnected!
(Thu Apr 17 13:35:53 2014) [sssd[pam]] [client_recv] (5): Client
disconnected!
Any thoughts, based on this?
Thanks!
- Alex