8:35 a.m.
Hi all,
I'm encountering an issue after upgrading to Samba 4.12.2. I can no longer
login with an Active Directory account from a terminal or gnome. I'm
prompted with a "System error" message.
When I downgrade to samba 4.11.3 everything works fine. AD authentication
works OK with the same account from a Windows machine.
"getent passwd my_username" works well, as "getent passwd
<group>". kinit
my_username(a)DOMAIN.NET works OK too. Logging in in with "su <username>"
from a local account works too.
SSSD version: 2.2.3. This is from an Arch Linux package, that has been
patched
<https://git.archlinux.org/svntogit/community.git/tree/trunk?h=packages/ss...
by its maintainer for compatibility with Samba 4.12 (I also compiled sssd
from the current git source code, but encountered the same cryptic error.)
Samba version: 4.12.2
Operating system: Arch Linux (fully upgraded)
Any idea how I could fix this / investigate this further? Please find
sssd.conf and logs below - I couldn't find anything interesting in there
but I'm no expert :)
Thanks a lot!
=== sssd.conf ===
[sssd]
config_file_version = 2
domains = domain.net
services = nss, pam
debug_level = 6
[domain/domain.net]
ad_hostname = computer.domain.net
krb5_realm = DOMAIN.NET
cache_credentials = true
id_provider = ad
auth_provider = ad
access_provider = ad
chpass_provider = ad
ldap_schema = ad
default_shell = /bin/zsh
fallback_homedir = /home/DOMAIN/%u
dyndns_update = true
dyndns_refresh_interval = 43200
dyndns_update_ptr = true
dyndns_ttl = 3600
debug_level = 6
#enumerate = true
[pam]
debug_level = 6
[nss]
debug_level = 6
=== sssd_domain.net.log ===
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[dp_get_account_info_send] (0x0200): Got request for
[0x3][BE_REQ_INITGROUPS][name=my_username(a)domain.net]
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [dp_attach_req] (0x0400):
DP Request [Initgroups #17]: New request. Flags [0x0001].
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [dp_attach_req] (0x0400):
Number of active DP request: 1
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_initgr_next_base] (0x0400): Searching for users with base
[DC=domain,DC=net]
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
[(&(sAMAccountName=my_username)(objectclass=user)(objectSID=*))][DC=domain,DC=net].
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
errmsg set
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [sdap_save_user]
(0x0400): Save user
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [sdap_get_primary_name]
(0x0400): Processing object MY_USERNAME
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [sdap_save_user]
(0x0400): Processing user MY_USERNAME(a)domain.net
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [sdap_save_user]
(0x0400): Adding original memberOf attributes to [MY_USERNAME(a)domain.net].
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [sdap_save_user]
(0x0400): Adding user principal [MY_USERNAME(a)DOMAIN.NET] to attributes of [
MY_USERNAME(a)domain.net].
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [sdap_save_user]
(0x0400): Storing info for user MY_USERNAME(a)domain.net
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [sysdb_set_entry_attr]
(0x0200): Entry [name=MY_USERNAME(a)domain.net,cn=users,cn=domain.net,cn=sysdb]
has set [ts_cache] attrs.
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [sysdb_store_user]
(0x0400): User "MY_USERNAME(a)domain.net" has been stored
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [no
filter][CN=My Username,OU=Users,DC=domain,DC=net].
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
errmsg set
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [sdap_idmap_sid_to_unix]
(0x0400): Object SID [S-1-5-32-545] is a built-in one.
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_ad_save_group_membership_with_idmapping] (0x0400): Skipping built-in
object.
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [sdap_get_initgr_done]
(0x0400): Primary group already cached, nothing to do.
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [dp_req_done] (0x0400):
DP Request [Initgroups #17]: Request handler finished [0]: Success
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [_dp_req_recv] (0x0400):
DP Request [Initgroups #17]: Receiving request data.
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [dp_req_destructor]
(0x0400): DP Request [Initgroups #17]: Request removed.
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [dp_req_destructor]
(0x0400): Number of active DP request: 0
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[dp_get_account_info_initgroups_step] (0x0400): Ordering NSS responder to
update memory cache
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [sysdb_set_entry_attr]
(0x0200): Entry [name=MY_USERNAME(a)domain.net,cn=users,cn=domain.net,cn=sysdb]
has set [ts_cache] attrs.
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [sbus_issue_request_done]
(0x0400): sssd.dataprovider.getAccountInfo: Success
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [dp_pam_handler_send]
(0x0100): Got request with the following data
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): command: SSS_PAM_AUTHENTICATE
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): domain: domain.net
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): user: MY_USERNAME(a)domain.net
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): service: login
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): tty: tty4
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): ruser:
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): rhost:
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): authtok type: 1
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): newauthtok type: 0
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): priv: 1
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): cli_pid: 70306
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): logon name: not set
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): flags: 0
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [dp_attach_req] (0x0400):
DP Request [PAM Authenticate #18]: New request. Flags [0000].
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [dp_attach_req] (0x0400):
Number of active DP request: 1
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [krb5_auth_send]
(0x0100): Domain directory for user [MY_USERNAME(a)domain.net] not known.
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [fo_resolve_service_send]
(0x0100): Trying to resolve service 'AD'
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [resolve_srv_send]
(0x0200): The status of SRV lookup is resolved
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[be_resolve_server_process] (0x0200): Found address for server
ADDC.domain.net: [192.168.5.4] TTL 900
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [write_pipe_handler]
(0x0400): All data has been sent!
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [child_sig_handler]
(0x0100): child [71170] finished successfully.
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [read_pipe_handler]
(0x0400): EOF received, client finished
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [fo_set_port_status]
(0x0100): Marking port 389 of server 'ADDC.domain.net' as 'working'
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[set_server_common_status] (0x0100): Marking server 'ADDC.domain.net' as
'working'
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [fo_set_port_status]
(0x0400): Marking port 389 of duplicate server 'ADDC.domain.net' as
'working'
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [sysdb_set_entry_attr]
(0x0200): Entry [name=MY_USERNAME(a)domain.net,cn=users,cn=domain.net,cn=sysdb]
has set [cache, ts_cache] attrs.
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [sysdb_set_entry_attr]
(0x0200): Entry [name=MY_USERNAME(a)domain.net,cn=users,cn=domain.net,cn=sysdb]
has set [cache, ts_cache] attrs.
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [dp_req_done] (0x0400):
DP Request [PAM Authenticate #18]: Request handler finished [0]: Success
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [_dp_req_recv] (0x0400):
DP Request [PAM Authenticate #18]: Receiving request data.
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [dp_req_destructor]
(0x0400): DP Request [PAM Authenticate #18]: Request removed.
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [dp_req_destructor]
(0x0400): Number of active DP request: 0
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [dp_method_enabled]
(0x0400): Target selinux is not configured
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [sbus_issue_request_done]
(0x0400): sssd.dataprovider.pamHandler: Success
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [dp_pam_handler_send]
(0x0100): Got request with the following data
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): command: SSS_PAM_ACCT_MGMT
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): domain: domain.net
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): user: MY_USERNAME(a)domain.net
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): service: login
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): tty: tty4
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): ruser:
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): rhost:
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): authtok type: 0
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): newauthtok type: 0
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): priv: 1
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): cli_pid: 70306
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): logon name: not set
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [pam_print_data]
(0x0100): flags: 0
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [dp_attach_req] (0x0400):
DP Request [PAM Account #19]: New request. Flags [0000].
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [dp_attach_req] (0x0400):
Number of active DP request: 1
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [sdap_access_send]
(0x0400): Performing access check for user [MY_USERNAME(a)domain.net]
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [sdap_account_expired_ad]
(0x0400): Performing AD access check for user [MY_USERNAME(a)domain.net]
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [ad_gpo_access_send]
(0x0400): service login maps to Interactive
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [ad_gpo_connect_done]
(0x0400): sam_account_name is COMPUTER$
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
[(&(objectclass=user)(sAMAccountName=COMPUTER$))][dc=domain,dc=net].
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
errmsg set
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
[objectclass=domain][DC=domain,DC=net].
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
errmsg set
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[ad_master_domain_next_done] (0x0400): Found SID
[S-1-5-21-3635097336-3991203712-2063481127].
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
[(&(DnsDomain=domain.net)(NtVer=\14\00\00\00))][].
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
errmsg set
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[ad_master_domain_netlogon_done] (0x0400): Found flat name [DOMAIN].
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[ad_master_domain_netlogon_done] (0x0400): Found site [Domain].
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[ad_master_domain_netlogon_done] (0x0400): Found forest [domain.net].
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[ad_gpo_site_name_retrieval_done] (0x0400): Using AD site 'cn=Domain'.
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
[(objectclass=*)][].
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
errmsg set
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[ad_gpo_site_dn_retrieval_done] (0x0400): som_list[0]->som_dn is
OU=Computers,DC=domain,DC=net
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[ad_gpo_site_dn_retrieval_done] (0x0400): som_list[1]->som_dn is
DC=domain,DC=net
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[ad_gpo_site_dn_retrieval_done] (0x0400): som_list[2]->som_dn is
cn=Domain,cn=Sites,CN=Configuration,DC=domain,DC=net
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
[(objectclass=*)][OU=Computers,DC=domain,DC=net].
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
errmsg set
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[ad_gpo_populate_gplink_list] (0x0400): som_dn:
OU=Computers,DC=domain,DC=net
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
[(objectclass=*)][DC=domain,DC=net].
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
errmsg set
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[ad_gpo_populate_gplink_list] (0x0400): som_dn: DC=domain,DC=net
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
[(objectclass=*)][cn=Domain,cn=Sites,CN=Configuration,DC=domain,DC=net].
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
errmsg set
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[ad_gpo_get_som_attrs_done] (0x0040): no attrs found for SOM; try next SOM
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[ad_gpo_populate_candidate_gpos] (0x0400): candidate_gpos[0]->gpo_dn:
CN={31B2F340-016D-11D2-945F-00C04FB984F9},CN=Policies,CN=System,DC=domain,DC=net
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[ad_gpo_populate_candidate_gpos] (0x0400): candidate_gpos[1]->gpo_dn:
cn={6FF5E2F5-D491-45A1-9432-5AB497AEF031},cn=policies,cn=system,DC=domain,DC=net
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [sdap_sd_search_send]
(0x0400): Searching entry
[CN={31B2F340-016D-11D2-945F-00C04FB984F9},CN=Policies,CN=System,DC=domain,DC=net]
using SD
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_generic_ext_send] (0x0400): WARNING: Disabling paging because
scope is set to base.
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
[(objectclass=*)][CN={31B2F340-016D-11D2-945F-00C04FB984F9},CN=Policies,CN=System,DC=domain,DC=net].
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]]
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
errmsg set
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [ad_gpo_parse_sd]
(0x0020): Failed to pull security descriptor
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [ad_gpo_sd_process_attrs]
(0x0040): ad_gpo_parse_sd() failed
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [ad_gpo_process_gpo_done]
(0x0040): Unable to get GPO list: [22](Invalid argument)
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [ad_gpo_access_done]
(0x0040): GPO-based access control failed.
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [dp_req_done] (0x0400):
DP Request [PAM Account #19]: Request handler finished [0]: Success
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [_dp_req_recv] (0x0400):
DP Request [PAM Account #19]: Receiving request data.
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [dp_req_destructor]
(0x0400): DP Request [PAM Account #19]: Request removed.
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [dp_req_destructor]
(0x0400): Number of active DP request: 0
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [dp_method_enabled]
(0x0400): Target selinux is not configured
(Fri May 8 15:10:10 2020) [sssd[be[domain.net]]] [sbus_issue_request_done]
(0x0400): sssd.dataprovider.pamHandler: Success
=== sssd_pam.log ====
(Fri May 8 15:10:10 2020) [sssd[pam]] [get_client_cred] (0x0080): The
following failure is expected to happen in case SELinux is disabled:
SELINUX_getpeercon failed [95][Operation not supported].
Please, consider enabling SELinux in your system.
(Fri May 8 15:10:10 2020) [sssd[pam]] [accept_fd_handler] (0x0400): Client
[0x5606d6371860][19] connected to privileged pipe!
(Fri May 8 15:10:10 2020) [sssd[pam]] [sss_cmd_get_version] (0x0200):
Received client version [3].
(Fri May 8 15:10:10 2020) [sssd[pam]] [sss_cmd_get_version] (0x0200):
Offered version [3].
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_cmd_authenticate] (0x0100):
entering pam_cmd_authenticate
(Fri May 8 15:10:10 2020) [sssd[pam]] [sss_parse_name_for_domains]
(0x0200): name 'my_username' matched without domain, user is my_username
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): command:
SSS_PAM_AUTHENTICATE
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): domain:
not set
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): user:
my_username
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): service:
login
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): tty: tty4
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): ruser:
not set
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): rhost:
not set
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): authtok
type: 1
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100):
newauthtok type: 0
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): cli_pid:
70306
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): logon
name: my_username
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): flags: 0
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_send] (0x0400): CR #12:
New request 'Initgroups by name'
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_process_input] (0x0400):
CR #12: Parsing input name [my_username]
(Fri May 8 15:10:10 2020) [sssd[pam]] [sss_parse_name_for_domains]
(0x0200): name 'my_username' matched without domain, user is my_username
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_set_name] (0x0400): CR
#12: Setting name [my_username]
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_select_domains] (0x0400):
CR #12: Performing a multi-domain search
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_search_domains] (0x0400):
CR #12: Search will bypass the cache and check the data provider
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_set_domain] (0x0400): CR
#12: Using domain [domain.net]
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_prepare_domain_data]
(0x0400): CR #12: Preparing input data for domain [domain.net] rules
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_search_send] (0x0400): CR
#12: Looking up my_username(a)domain.net
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_search_ncache] (0x0400):
CR #12: Checking negative cache for [my_username(a)domain.net]
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_search_ncache] (0x0400):
CR #12: [my_username(a)domain.net] is not present in negative cache
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_search_dp] (0x0400): CR
#12: Looking up [my_username(a)domain.net] in data provider
(Fri May 8 15:10:10 2020) [sssd[pam]] [sss_dp_get_account_send] (0x0400):
Creating request for [domain.net
][0x3][BE_REQ_INITGROUPS][name=my_username@domain.net:-]
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_search_cache] (0x0400):
CR #12: Looking up [my_username(a)domain.net] in cache
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_search_ncache_filter]
(0x0400): CR #12: This request type does not support filtering result by
negative cache
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_search_done] (0x0400): CR
#12: Returning updated object [my_username(a)domain.net]
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_create_and_add_result]
(0x0400): CR #12: Found 4 entries in domain domain.net
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_done] (0x0400): CR #12:
Finished: Success
(Fri May 8 15:10:10 2020) [sssd[pam]] [pd_set_primary_name] (0x0400):
User's primary name is my_username(a)domain.net
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending
request with the following data:
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): command:
SSS_PAM_AUTHENTICATE
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): domain:
domain.net
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): user:
my_username(a)domain.net
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): service:
login
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): tty: tty4
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): ruser:
not set
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): rhost:
not set
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): authtok
type: 1
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100):
newauthtok type: 0
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): cli_pid:
70306
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): logon
name: my_username
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): flags: 0
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_dom_forwarder] (0x0100):
pam_dp_send_req returned 0
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_dp_send_req_done] (0x0200):
received: [0 (Success)][domain.net]
(Fri May 8 15:10:10 2020) [sssd[pam]] [sysdb_set_entry_attr] (0x0200):
Entry [name=my_username(a)domain.net,cn=users,cn=domain.net,cn=sysdb] has set
[cache, ts_cache] attrs.
(Fri May 8 15:10:10 2020) [sssd[pam]] [filter_responses] (0x0100):
[pam_response_filter] not available, not fatal.
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_reply] (0x0200): blen: 85
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_reply] (0x0200): Returning [0]:
Success to the client
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_cmd_acct_mgmt] (0x0100):
entering pam_cmd_acct_mgmt
(Fri May 8 15:10:10 2020) [sssd[pam]] [sss_parse_name_for_domains]
(0x0200): name 'my_username' matched without domain, user is my_username
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): command:
SSS_PAM_ACCT_MGMT
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): domain:
not set
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): user:
my_username
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): service:
login
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): tty: tty4
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): ruser:
not set
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): rhost:
not set
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): authtok
type: 0
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100):
newauthtok type: 0
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): cli_pid:
70306
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): logon
name: my_username
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): flags: 0
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_send] (0x0400): CR #13:
New request 'Initgroups by name'
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_process_input] (0x0400):
CR #13: Parsing input name [my_username]
(Fri May 8 15:10:10 2020) [sssd[pam]] [sss_parse_name_for_domains]
(0x0200): name 'my_username' matched without domain, user is my_username
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_set_name] (0x0400): CR
#13: Setting name [my_username]
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_select_domains] (0x0400):
CR #13: Performing a multi-domain search
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_search_domains] (0x0400):
CR #13: Search will check the cache and check the data provider
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_set_domain] (0x0400): CR
#13: Using domain [domain.net]
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_prepare_domain_data]
(0x0400): CR #13: Preparing input data for domain [domain.net] rules
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_search_send] (0x0400): CR
#13: Looking up my_username(a)domain.net
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_search_ncache] (0x0400):
CR #13: Checking negative cache for [my_username(a)domain.net]
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_search_ncache] (0x0400):
CR #13: [my_username(a)domain.net] is not present in negative cache
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_search_cache] (0x0400):
CR #13: Looking up [my_username(a)domain.net] in cache
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_search_send] (0x0400): CR
#13: Returning [my_username(a)domain.net] from cache
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_search_ncache_filter]
(0x0400): CR #13: This request type does not support filtering result by
negative cache
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_create_and_add_result]
(0x0400): CR #13: Found 4 entries in domain domain.net
(Fri May 8 15:10:10 2020) [sssd[pam]] [cache_req_done] (0x0400): CR #13:
Finished: Success
(Fri May 8 15:10:10 2020) [sssd[pam]] [pd_set_primary_name] (0x0400):
User's primary name is my_username(a)domain.net
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending
request with the following data:
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): command:
SSS_PAM_ACCT_MGMT
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): domain:
domain.net
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): user:
my_username(a)domain.net
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): service:
login
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): tty: tty4
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): ruser:
not set
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): rhost:
not set
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): authtok
type: 0
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100):
newauthtok type: 0
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): cli_pid:
70306
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): logon
name: my_username
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_print_data] (0x0100): flags: 0
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_dom_forwarder] (0x0100):
pam_dp_send_req returned 0
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_dp_send_req_done] (0x0200):
received: [4 (System error)][domain.net]
(Fri May 8 15:10:10 2020) [sssd[pam]] [filter_responses] (0x0100):
[pam_response_filter] not available, not fatal.
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_reply] (0x0200): blen: 31
(Fri May 8 15:10:10 2020) [sssd[pam]] [pam_reply] (0x0200): Returning [4]:
System error to the client
(Fri May 8 15:10:10 2020) [sssd[pam]] [client_recv] (0x0200): Client
disconnected!