Hello!
I am currently troubleshooting a very mysterious and difficult to tack down
issue with SSSD running on RHEL/CentOS 7.x and 8.x (SSSD ver. 1.16.5
and 2.2.3). The EL 7.x and 8.x systems are attached to a Windows Active
Directory domain using 'adcli'. We used this guide (
https://access.redhat.com/solutions/2653771), with some minor tweaks
appropriate for our Active Directory environment and security requirements
to set this up.
The vast majority of the time, the configuration works as expected.
However, occasionally, we experience sporadic and temporary issues where
users attempting to authenticate using valid Active Directory credentials
(via SSH) are unable to login.
When the issue presents itself, if we leave an affected system alone and do
nothing, the issue will eventually self-correct and users are able to
authenticate as expected. We have also discovered that we can manually
"fix" the issue by either (1) restarting SSSD with 'sudo systemctl restart
sssd' or (2) by running a 'kdestroy'/'kinit' sequence as the
'root' user on
the affected system like so:
# kdestroy -A ; kinit -k 'MYSERVER$(a)MYDOMAIN.EXAMPLE.COM'
At times when the issue is occurring, we observe the following messages in
'/var/log/sssd/sssd_MYDOMAIN.example.com.log' (debug_level 9):
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[dp_get_account_info_handler] (0x0200): Got request for
[0x1][BE_REQ_USER][name=someuser(a)mydomain.example.com]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]] [dp_attach_req] (0x0400):
DP Request [Account #6104]: New request. Flags [0x0001].
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]] [dp_attach_req] (0x0400):
Number of active DP request: 1
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]] [sss_domain_get_state]
(0x1000): Domain
MYDOMAIN.example.com is Active
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]] [sss_domain_get_state]
(0x1000): Domain
MYDOMAIN.example.com is Active
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]] [sdap_id_op_connect_step]
(0x4000): reusing cached connection
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_search_user_next_base] (0x0400): Searching for users with base
[DC=MYDOMAIN,DC=example,DC=com]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]] [sdap_print_server]
(0x2000): Searching 192.168.1.4:389
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
[(&(sAMAccountName=someuser)(objectclass=user)(sAMAccountName=*)(objectSID=*))][DC=MYDOMAIN,DC=example,DC=com].
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs:
[userCertificate;binary]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [mail]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 26
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]] [sdap_op_add] (0x2000):
New operation 26 timeout 6
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]] [sdap_process_result]
(0x2000): Trace: sh[0x55ca2802d840], connected[1], ops[0x55ca28028ef0],
ldap[0x55ca27fe0610]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]] [sdap_process_message]
(0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_op_finished] (0x0400): Search result: Referral(10),
0000202B: RefErr: DSID-0310074A, data 0, 1 access points
ref 1: 'MYDOMAIN.example.com'
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_get_generic_ext_add_references] (0x1000): Additional References:
ldap://MYDOMAIN.example.com/DC=MYDOMAIN,DC=example,DC=com
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]] [sdap_op_destructor]
(0x2000): Operation 26 finished
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[generic_ext_search_handler] (0x4000): Request included referrals which
were ignored.
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[generic_ext_search_handler] (0x4000): Ref: ldap://
MYDOMAIN.example.com/DC=MYDOMAIN,DC=example,DC=com
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_search_user_process] (0x0400): Search for users, returned 0 results.
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sdap_search_user_process] (0x2000): Retrieved total 0 users
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]] [sdap_id_op_done]
(0x4000): releasing operation connection
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]] [sysdb_search_by_name]
(0x0400): No such entry
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sysdb_cache_search_groups] (0x2000): Search groups with filter:
(&(objectCategory=group)(ghost=someuser(a)mydomain.example.com))
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[sysdb_cache_search_groups] (0x2000): No such entry
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]] [sysdb_delete_user]
(0x0400): Error: 2 (No such file or directory)
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]] [dp_req_done] (0x0400):
DP Request [Account #6104]: Request handler finished [0]: Success
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]] [_dp_req_recv] (0x0400):
DP Request [Account #6104]: Receiving request data.
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[dp_req_reply_list_success] (0x0400): DP Request [Account #6104]: Finished.
Success.
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]] [dp_req_reply_std]
(0x1000): DP Request [Account #6104]: Returning [Success]: 0,0,Success
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]]
[dp_table_value_destructor] (0x0400): Removing
[0:1:0x0001:1::MYDOMAIN.example.com:name=someuser@mydomain.example.com]
from reply table
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]] [dp_req_destructor]
(0x0400): DP Request [Account #6104]: Request removed.
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]] [dp_req_destructor]
(0x0400): Number of active DP request: 0
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]] [sdap_process_result]
(0x2000): Trace: sh[0x55ca2802d840], connected[1], ops[(nil)],
ldap[0x55ca27fe0610]
(2020-11-10 7:40:57): [be[MYDOMAIN.example.com]] [sdap_process_result]
(0x2000): Trace: end of ldap_result list
And the following corresponding messages in '/var/log/secure':
Nov 10 07:40:57 myserver sshd[755]: pam_unix(sshd:auth): check pass; user
unknown
Nov 10 07:40:57 myserver sshd[755]: pam_unix(sshd:auth): authentication
failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.1.123
Nov 10 07:40:57 myserver sshd[755]: pam_sss(sshd:auth): authentication
failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.1.123
user=someuser
Nov 10 07:40:57 myserver sshd[755]: pam_sss(sshd:auth): received for user
someuser: 10 (User not known to the underlying authentication module)
Nov 10 07:40:59 myserver sshd[735]: error: PAM: User not known to the
underlying authentication module for illegal user someuser from
192.168.1.123
Nov 10 07:40:59 myserver sshd[735]: Failed keyboard-interactive/pam for
invalid user someuser from 192.168.1.123 port 53300 ssh2
Nov 10 07:40:59 myserver sshd[735]: Connection closed by 192.168.1.123 port
53300 [preauth]
The effective '/etc/sssd/sssd.conf' file is as follows:
[sssd]
domains =
MYDOMAIN.example.com
config_file_version = 2
services = nss, pam
debug_level = 9
[
domain/MYDOMAIN.example.com]
ad_domain =
MYDOMAIN.example.com
krb5_realm =
MYDOMAIN.EXAMPLE.COM
krb5_lifetime = 10h
subdomain_inherit = ignore_group_members, ldap_purge_cache_timeout
ignore_group_members = true
ldap_purge_cache_timeout = 0
realmd_tags = joined-with-adcli, manages-system
cache_credentials = false
id_provider = ad
krb5_store_password_if_offline = true
default_shell = /bin/bash
ldap_id_mapping = true
ldap_sasl_authid = MYSERVER$(a)MYDOMAIN.EXAMPLE.COM
ldap_use_tokengroups = true
use_fully_qualified_names = false
fallback_homedir = /home/%d/%u
access_provider = simple
simple_allow_groups = linux_admins
simple_allow_users = someuser, someuser2, someuser3
debug_level = 9
Running either of the following commands appears to correct the issue
(until it presents again at an unpredictable time):
# systemctl restart sssd
or
# kdestroy -A ; kinit -k 'MYSERVER$(a)MYDOMAIN.EXAMPLE.COM'
Any assistance or insight you can offer would be greatly appreciated. We
have run countless internet searches over recent weeks, as well as
consulted with Red Hat Support without breakthroughs, so I decided to take
this straight to the experts!
Best,
*J. Adam Craig*
Lead Unix Operating Systems Analyst
VCU Computer Center <
https://www.ucc.vcu.edu/>
804.828.4886
jacraig(a)vcu.edu
<
https://adminmicro2.questionpro.com/?t_340030260=J.%20Adam%20Craig&u_...
*Don't be a phishing victim -- VCU and other reputable organisations will
never use email to request that you reply with your password, social
security number or confidential personal information. For more details,
visit
**https://ts.vcu.edu/about-us/information-security/common-questions/what-is-phishing
<
https://ts.vcu.edu/about-us/information-security/common-questions/what-is...