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
On Thu, Apr 17, 2014 at 09:44:22AM -0400, J. Alexander Jacocks wrote:
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
Did you remove the SSSD cache on the 'old' clients? I would first try that: rm -f /var/lib/sss/db/cache_*
Please note that the cache may contain cached credentials, so removing the cache would purge them..but it sounds like your clients can access the LDAP server, so offline case shouldn't be the issue for you.
On Thu, Apr 17, 2014 at 9:48 AM, Jakub Hrozek jhrozek@redhat.com wrote:
On Thu, Apr 17, 2014 at 09:44:22AM -0400, J. Alexander Jacocks wrote:
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
Did you remove the SSSD cache on the 'old' clients? I would first try that: rm -f /var/lib/sss/db/cache_*
Please note that the cache may contain cached credentials, so removing the cache would purge them..but it sounds like your clients can access the LDAP server, so offline case shouldn't be the issue for you.
Jakub,
Yep, that was it. I should have thought of that!
How long does it take for SSSD to invalidate its cache? Or, is this just something that I'll have to make a note of, in the unlikely case that we blow away our backend, again?
Many thanks! - Alex
On Thu, Apr 17, 2014 at 09:56:31AM -0400, J. Alexander Jacocks wrote:
Did you remove the SSSD cache on the 'old' clients? I would first try that: rm -f /var/lib/sss/db/cache_*
Please note that the cache may contain cached credentials, so removing the cache would purge them..but it sounds like your clients can access the LDAP server, so offline case shouldn't be the issue for you.
Jakub,
Yep, that was it. I should have thought of that!
How long does it take for SSSD to invalidate its cache? Or, is this just something that I'll have to make a note of, in the unlikely case that we blow away our backend, again?
Many thanks!
- Alex
Normally the cache expiration time is 5400 seconds (entry_cache_timeout). But the catch is that currently SSSD is not able to change the ID of a user if it was already cached. This is a planned enhancement for a future release: https://fedorahosted.org/sssd/ticket/2244
So if your test LDAP had different UIDs than the production LDAP, we might have errored out saving the entry.
Changing other attributes on updating the entry should be supported.
sssd-users@lists.fedorahosted.org