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@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 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@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@domain.net
(Fri May  8 15:10:10 2020) [sssd[be[domain.net]]] [sdap_save_user] (0x0400): Adding original memberOf attributes to [MY_USERNAME@domain.net].
(Fri May  8 15:10:10 2020) [sssd[be[domain.net]]] [sdap_save_user] (0x0400): Adding user principal [MY_USERNAME@DOMAIN.NET] to attributes of [MY_USERNAME@domain.net].
(Fri May  8 15:10:10 2020) [sssd[be[domain.net]]] [sdap_save_user] (0x0400): Storing info for user MY_USERNAME@domain.net
(Fri May  8 15:10:10 2020) [sssd[be[domain.net]]] [sysdb_set_entry_attr] (0x0200): Entry [name=MY_USERNAME@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@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@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@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@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@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@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@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@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@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@domain.net
(Fri May  8 15:10:10 2020) [sssd[pam]] [cache_req_search_ncache] (0x0400): CR #12: Checking negative cache for [my_username@domain.net]
(Fri May  8 15:10:10 2020) [sssd[pam]] [cache_req_search_ncache] (0x0400): CR #12: [my_username@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@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@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@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@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@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@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@domain.net
(Fri May  8 15:10:10 2020) [sssd[pam]] [cache_req_search_ncache] (0x0400): CR #13: Checking negative cache for [my_username@domain.net]
(Fri May  8 15:10:10 2020) [sssd[pam]] [cache_req_search_ncache] (0x0400): CR #13: [my_username@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@domain.net] in cache
(Fri May  8 15:10:10 2020) [sssd[pam]] [cache_req_search_send] (0x0400): CR #13: Returning [my_username@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@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@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!