8:02 a.m.
Hello.
I've set up SSSD v.1.12.4 with 'ad' provider, enrolled PC into domain
with adcli, and everything seems to be working. I've got bothered with
two problems which I think are linked.
First one, is slow logins. It takes up to 1-2 minutes sometimes to get
access to machine, and commands like 'id user' and 'sudo' works slowly.
From 30 seconds to two minutes approx. After record goes to cache,
however, if works almost instantly.
Second is that SSSD does not resolve nested groups by default and some
users that are should be allowed, are not able to login. Possible
workaround is use of explict noting of
'memberOf:1.2.840.113556.1.4.1941:' rule, but it looks like a workaround
to me. Maybe I'm wrong, though.
But when I'm enabling 'ldap_groups_use_matching_rule_in_chain' and
'ldap_initgroups_use_matching_rule_in_chain', login process and commands
like 'id user' and 'sudo' takes up to 2-5 minutes to finish.
It shouldn't be the network issue, all servers are on the same virtual
host.
We've got rather big environment: one domain, several locations, many
services and groups. Therefore, I can't enable enumeration on the
machine.
As far as I understand, slow logins occuring because ad_filter needs to
know if the user in the valid group or not.
So, the main question is slow logins. Here's my sssd.conf:
[domain/domain.local]
debug_level = 2
id_provider = ad
auth_provider = ad
chpass_provider = ad
access_provider = ad
case_sensitive = false
cache_credentials = true
krb5_auth_timeout = 30
dns_resolver_timeout = 30
ad_domain = domain.local
ad_hostname = ServerTwo.domain.local
ad_server = loc01dc01.domain.local, _srv_, loc02dc02.domain.local
ad_backup_server = 192.168.0.1
ad_gpo_access_control = disabled
ad_access_filter = DOM:domain.local:(|(memberOf=CN=group1,
OU=something, DC=domain,
DC=local)(memberOf:1.2.840.113556.1.4.1941:=CN=grour2, OU=something,
DC=domain, DC=local))
ldap_search_timeout = 15
ldap_opt_timeout = 15
ldap_sasl_minssf = 56
[sssd]
debug_level = 2
domains = domain.local
services = nss,pam,ssh,pac
config_file_version = 2
[nss]
debug_level = 2
filter_users = root
filter_groups = root
[pam]
debug_level = 2
pam_id_timeout = 15
[ssh]
debug_level=2
[pac]
And here's what happens when I'm trying to log in with Kerberos (tried
also password and rsa auth):
[sssd[nss]] [nss_cmd_getbynam] (0x0100): Requesting info for [UserOne]
from [<ALL>]
[sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info for
[userone(a)domain.local]
[sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info for
[userone(a)domain.local]
[sssd[be[domain.local]]] [acctinfo_callback] (0x0100): Request
processed. Returned 0,0,Success
(waiting 1 sec.)
[sssd[be[domain.local]]] [fo_resolve_service_send] (0x0100): Trying to
resolve service 'AD_GC'
[sssd[be[domain.local]]] [ad_resolve_callback] (0x0100): Constructed uri
'ldap://loc01dc01.domain.local'
[sssd[be[domain.local]]] [ad_resolve_callback] (0x0100): Constructed GC
uri 'ldap://loc01dc01.domain.local:3268'
[sssd[be[domain.local]]] [sdap_get_server_opts_from_rootdse] (0x0100):
Setting AD compatibility level to [6]
[sssd[be[domain.local]]] [fo_resolve_service_send] (0x0100): Trying to
resolve service 'AD'
[sssd[be[domain.local]]] [ad_resolve_callback] (0x0100): Constructed uri
'ldap://loc01dc01.domain.local'
[sssd[be[domain.local]]] [ad_resolve_callback] (0x0100): Constructed GC
uri 'ldap://loc01dc01.domain.local'
[[sssd[ldap_child[18547]]]] [ldap_child_get_tgt_sync] (0x0100):
Principal name is: [LOC01DC01$(a)DOMAIN.LOCAL]
[[sssd[ldap_child[18547]]]] [ldap_child_get_tgt_sync] (0x0100): Using
keytab [MEMORY:/etc/krb5.keytab]
[sssd[be[domain.local]]] [child_sig_handler] (0x0100): child [18547]
finished successfully.
[sssd[be[domain.local]]] [sdap_cli_auth_step] (0x0100): expire timeout
is 900
[sssd[be[domain.local]]] [sasl_bind_send] (0x0100): Executing sasl bind
mech: gssapi, user: LOC01DC01$
(waiting 1 sec.)
[sssd[be[domain.local]]] [fo_set_port_status] (0x0100): Marking port 0
of server 'loc01dc01.domain.local' as 'working'
[sssd[be[domain.local]]] [set_server_common_status] (0x0100): Marking
server 'loc01dc01.domain.local' as 'working'
[sssd[be[domain.local]]] [sdap_fill_memberships] (0x0080): Member
[CN=group1,CN=something,DC=domain,DC=local] was not found in cache. Is
it out of scope?
[sssd[be[domain.local]]] [sdap_fill_memberships] (0x0080): Member
[CN=group2,OU=something,OU=something,OU=something,DC=domain,DC=local]
was not found in cache. Is it out of scope?
[sssd[be[domain.local]]] [acctinfo_callback] (0x0100): Request
processed. Returned 0,0,Success
[sssd[be[domain.local]]] [sdap_fill_memberships] (0x0080): Member
[CN=group3,OU=something,OU=something,OU=something,DC=domain,DC=local]
was not found in cache. Is it out of scope?
... (many many many more 'success' with few errors 'out of scope')
[sssd[nss]] [nss_cmd_getbynam] (0x0100): Requesting info for [UserOne]
from [<ALL>]
[sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info for
[userone(a)domain.local]
(repeated twice)
[sssd[pam]] [pam_cmd_acct_mgmt] (0x0100): entering pam_cmd_acct_mgmt
[sssd[pam]] [pam_print_data] (0x0100): command: PAM_ACCT_MGMT
[sssd[pam]] [pam_print_data] (0x0100): domain: not set
[sssd[pam]] [pam_print_data] (0x0100): user: UserOne
[sssd[pam]] [pam_print_data] (0x0100): service: sshd
[sssd[pam]] [pam_print_data] (0x0100): tty: ssh
[sssd[pam]] [pam_print_data] (0x0100): ruser: not set
[sssd[pam]] [pam_print_data] (0x0100): rhost: ServerOne.domain.local
[sssd[pam]] [pam_print_data] (0x0100): authtok type: 0
[sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
[sssd[pam]] [pam_print_data] (0x0100): priv: 1
[sssd[pam]] [pam_print_data] (0x0100): cli_pid: 18545
[sssd[pam]] [pam_print_data] (0x0100): logon name: UserOne
[sssd[be[domain.local]]] [acctinfo_callback] (0x0100): Request
processed. Returned 0,0,Success
[sssd[pam]] [pam_check_user_search] (0x0100): Requesting info for
[userone(a)domain.local]
[sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the
following data:
[sssd[pam]] [pam_print_data] (0x0100): command: PAM_ACCT_MGMT
[sssd[pam]] [pam_print_data] (0x0100): domain: domain.local
[sssd[pam]] [pam_print_data] (0x0100): user: UserOne
[sssd[pam]] [pam_print_data] (0x0100): service: sshd
[sssd[pam]] [pam_print_data] (0x0100): tty: ssh
[sssd[pam]] [pam_print_data] (0x0100): ruser: not set
[sssd[pam]] [pam_print_data] (0x0100): rhost: ServerOne.domain.local
[sssd[pam]] [pam_print_data] (0x0100): authtok type: 0
[sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
[sssd[pam]] [pam_print_data] (0x0100): priv: 1
[sssd[pam]] [pam_print_data] (0x0100): cli_pid: 18545
[sssd[pam]] [pam_print_data] (0x0100): logon name: UserOne
[sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0
[sssd[be[domain.local]]] [be_pam_handler] (0x0100): Got request with the
following data
[sssd[be[domain.local]]] [pam_print_data] (0x0100): command:
PAM_ACCT_MGMT
[sssd[be[domain.local]]] [pam_print_data] (0x0100): domain: domain.local
[sssd[be[domain.local]]] [pam_print_data] (0x0100): user: UserOne
[sssd[be[domain.local]]] [pam_print_data] (0x0100): service: sshd
[sssd[be[domain.local]]] [pam_print_data] (0x0100): tty: ssh
[sssd[be[domain.local]]] [pam_print_data] (0x0100): ruser:
[sssd[be[domain.local]]] [pam_print_data] (0x0100): rhost:
ServerOne.domain.local
[sssd[be[domain.local]]] [pam_print_data] (0x0100): authtok type: 0
[sssd[be[domain.local]]] [pam_print_data] (0x0100): newauthtok type: 0
[sssd[be[domain.local]]] [pam_print_data] (0x0100): priv: 1
[sssd[be[domain.local]]] [pam_print_data] (0x0100): cli_pid: 18545
[sssd[be[domain.local]]] [pam_print_data] (0x0100): logon name: not set
[sssd[be[domain.local]]] [be_pam_handler_callback] (0x0100): Backend
returned: (0, 0, <NULL>) [Success]
[sssd[be[domain.local]]] [be_pam_handler_callback] (0x0100): Sending
result [0][domain.local]
[sssd[pam]] [pam_dp_process_reply] (0x0100): received: [0][domain.local]
[sssd[be[domain.local]]] [be_pam_handler_callback] (0x0100): Sent result
[0][domain.local]
[sssd[nss]] [nss_cmd_getbynam] (0x0100): Requesting info for [userone]
from [<ALL>]
[sssd[nss]] [nss_cmd_initgroups_search] (0x0100): Requesting info for
[userone(a)domain.local]
(repeated 6 times)
[sssd[pam]] [pam_cmd_open_session] (0x0100): entering
pam_cmd_open_session
[sssd[pam]] [pam_print_data] (0x0100): command: PAM_OPEN_SESSION
[sssd[pam]] [pam_print_data] (0x0100): domain: not set
[sssd[pam]] [pam_print_data] (0x0100): user: UserOne
[sssd[pam]] [pam_print_data] (0x0100): service: sshd
[sssd[pam]] [pam_print_data] (0x0100): tty: ssh
[sssd[pam]] [pam_print_data] (0x0100): ruser: not set
[sssd[pam]] [pam_print_data] (0x0100): rhost: ServerOne.domain.local
[sssd[pam]] [pam_print_data] (0x0100): authtok type: 0
[sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
[sssd[pam]] [pam_print_data] (0x0100): priv: 1
[sssd[pam]] [pam_print_data] (0x0100): cli_pid: 18545
[sssd[pam]] [pam_print_data] (0x0100): logon name: UserOne
[sssd[pam]] [pam_check_user_search] (0x0100): Requesting info for
[userone(a)domain.local]
[sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the
following data:
[sssd[pam]] [pam_print_data] (0x0100): command: PAM_OPEN_SESSION
[sssd[pam]] [pam_print_data] (0x0100): domain: domain.local
[sssd[pam]] [pam_print_data] (0x0100): user: UserOne
[sssd[pam]] [pam_print_data] (0x0100): service: sshd
[sssd[pam]] [pam_print_data] (0x0100): tty: ssh
[sssd[pam]] [pam_print_data] (0x0100): ruser: not set
[sssd[pam]] [pam_print_data] (0x0100): rhost: ServerOne.domain.local
[sssd[pam]] [pam_print_data] (0x0100): authtok type: 0
[sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
[sssd[pam]] [pam_print_data] (0x0100): priv: 1
[sssd[pam]] [pam_print_data] (0x0100): cli_pid: 18545
[sssd[pam]] [pam_print_data] (0x0100): logon name: UserOne
[sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0
[sssd[be[domain.local]]] [be_pam_handler] (0x0100): Got request with the
following data
[sssd[be[domain.local]]] [pam_print_data] (0x0100): command:
PAM_OPEN_SESSION
[sssd[be[domain.local]]] [pam_print_data] (0x0100): domain: domain.local
[sssd[be[domain.local]]] [pam_print_data] (0x0100): user: UserOne
[sssd[be[domain.local]]] [pam_print_data] (0x0100): service: sshd
[sssd[be[domain.local]]] [pam_print_data] (0x0100): tty: ssh
[sssd[be[domain.local]]] [pam_print_data] (0x0100): ruser:
[sssd[be[domain.local]]] [pam_print_data] (0x0100): rhost:
ServerOne.domain.local
[sssd[be[domain.local]]] [pam_print_data] (0x0100): authtok type: 0
[sssd[be[domain.local]]] [pam_print_data] (0x0100): newauthtok type: 0
[sssd[be[domain.local]]] [pam_print_data] (0x0100): priv: 1
[sssd[be[domain.local]]] [pam_print_data] (0x0100): cli_pid: 18545
[sssd[be[domain.local]]] [pam_print_data] (0x0100): logon name: not set
[sssd[be[domain.local]]] [be_pam_handler] (0x0100): Sending result
[0][domain.local]
[sssd[pam]] [pam_dp_process_reply] (0x0100): received: [0][domain.local]
[sssd[nss]] [nss_cmd_getbynam] (0x0100): Requesting info for [userone]
from [<ALL>]
[sssd[nss]] [nss_cmd_initgroups_search] (0x0100): Requesting info for
[userone(a)domain.local]
[sssd[nss]] [nss_cmd_getbynam] (0x0100): Requesting info for [userone]
from [<ALL>]
[sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info for
[userone(a)domain.local]
[sssd[nss]] [nss_cmd_getgrgid_search] (0x0100): Requesting info for
[704943713(a)domain.local]
[sssd[nss]] [nss_cmd_getgrgid_search] (0x0080): No matching domain found
for [704943713]
It takes from about 30 secs to 2 minutes lo login.
Here what I see in logs when setting options
'ldap_groups_use_matching_rule_in_chain' and
'ldap_initgroups_use_matching_rule_in_chain' and running 'id user':
[sssd[be[domain.local]]] [acctinfo_callback] (0x0100): Request
processed. Returned 0,0,Success
[sssd[nss]] [nss_cmd_getgrgid_search] (0x0100): Requesting info for
[704754393(a)domain.local]
[sssd[nss]] [nss_cmd_getgrgid_search] (0x0080): No matching domain found
for [704754393]
[sssd[nss]] [nss_cmd_getgrgid_search] (0x0100): Requesting info for
[704754393(a)domain.local]
[sssd[nss]] [nss_cmd_getgrgid_search] (0x0080): No matching domain found
for [704754393]
... (many of these messages, about 1-3/sec)
And then I see these messages:
[sssd[be[domain.local]]] [sysdb_store_group] (0x0080): A group with the
same GID [704543591] was removed from the cache
[sssd[nss]] [nss_cmd_getgrgid_search] (0x0100): Requesting info for
[704543591(a)domain.local]
[sssd[nss]] [nss_cmd_getgrgid_search] (0x0080): No matching domain found
for [704543591]
[sssd[nss]] [nss_cmd_getgrgid_search] (0x0100): Requesting info for
[704432243(a)domain.local]
[sssd[nss]] [nss_cmd_getgrgid_search] (0x0080): No matching domain found
for [704432243]
[sssd[be[domain.local]]] [acctinfo_callback] (0x0100): Request
processed. Returned 0,0,Success
[sssd[be[domain.local]]] [sysdb_store_group] (0x0080): A group with the
same GID [704432243] was removed from the cache
... (not so many, but still a lot.)
In the output of 'id user' I see these strange groups:
704195244(groupname {fcc357ea-83ef-4645-17e9-1967bfe8a77f})
Is there anything I can do to speed up my login? Is there anything I've
messed up in my sssd.conf?
Any help appreciated. Thank you in advance.