My setup includes a set of FreeIPA servers running on 4.9.2 version and a OpenVPN configured for the users to connect to VPN. Previously I was using IPA version 4.6.8 on CentOS7 and now installed IPA replica on 4.9.2 on OL8 and decommissioned the old one.
I am using openvpn-plugin-auth-pam.so with login pam file to authenticate the IPA users logging in to OpenVPN.
when I am resetting the password of users now, then users are not able to login to OpenVPN with 2FA (password+otp) whereas, with otp disabled it is working
for old users for whom password is not resetted recently after change in IPA cluster, their authentication is working through OpenVPN with/without OTP both.
All users(old + users whose password is resetted recently) are able to login to linux servers using password and OTP both combination, its just not authenticating in OpenVPN.
I have tried multiple things but still couldn't able to get it work.
Hoping if someone can help with this!!
On Аўт, 09 ліп 2024, Tinku Goyal via FreeIPA-users wrote:
My setup includes a set of FreeIPA servers running on 4.9.2 version and a OpenVPN configured for the users to connect to VPN. Previously I was using IPA version 4.6.8 on CentOS7 and now installed IPA replica on 4.9.2 on OL8 and decommissioned the old one.
I am using openvpn-plugin-auth-pam.so with login pam file to authenticate the IPA users logging in to OpenVPN.
when I am resetting the password of users now, then users are not able to login to OpenVPN with 2FA (password+otp) whereas, with otp disabled it is working
for old users for whom password is not resetted recently after change in IPA cluster, their authentication is working through OpenVPN with/without OTP both.
All users(old + users whose password is resetted recently) are able to login to linux servers using password and OTP both combination, its just not authenticating in OpenVPN.
I have tried multiple things but still couldn't able to get it work.
I don't see in openvpn auth-pam.c plugin code any handling of a password change request during authentication.
Debug logs from SSSD and probably LDAP server for an attempt where a password change is requested would be needed. Please look at https://sssd.io/troubleshooting/basics.html for basics on how to configure debug logs in SSSD.
The password is being changed using the IPA server UI for the IPA users. Post password change users are able to login to the IPA portal and linux servers as well but not able to authenticate with the OpenVPN via the plugin.
Also, same is happening for the new users, if I create a new user in IPA and try login to the OpenVPN with that user with 2FA enabled, it is not working.
While authentication, it is going for Pre-authentication and I found these in kerberos logs for a user for both attempts (with 2FA enabled and without). This users password was resetted recently and post that it started having issues.
Without OTP it is working and with OTP it is failing.
Without OTP
Jul 10 02:34:24 newvpn1 krb5kdc[1446773](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required Jul 10 02:34:25 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required Jul 10 02:34:25 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required Jul 10 02:34:26 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required Jul 10 02:34:26 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: ISSUE: authtime 1720559066, etypes {rep=aes256-cts-hmac-sha1-96(18), tkt=aes256-cts-hmac-sha1-96(18), ses=aes256-cts-hmac-sha1-96(18)}, asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL Jul 10 02:34:27 newvpn1 krb5kdc[1446774](info): TGS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: ISSUE: authtime 1720559066, etypes {rep=aes256-cts-hmac-sha1-96(18), tkt=aes256-cts-hmac-sha1-96(18), ses=aes256-cts-hmac-sha1-96(18)}, asingh@TINKU.LOCAL for host/newvpn.TINKU.local@TINKU.LOCAL
With OTP Failure
Jul 10 02:33:25 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required Jul 10 02:33:25 newvpn1 krb5kdc[1446773](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required Jul 10 02:33:26 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required Jul 10 02:33:26 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required Jul 10 02:33:27 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: PREAUTH_FAILED: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Preauthentication failed
On Срд, 10 ліп 2024, Tinku Goyal via FreeIPA-users wrote:
The password is being changed using the IPA server UI for the IPA users. Post password change users are able to login to the IPA portal and linux servers as well but not able to authenticate with the OpenVPN via the plugin.
Also, same is happening for the new users, if I create a new user in IPA and try login to the OpenVPN with that user with 2FA enabled, it is not working.
While authentication, it is going for Pre-authentication and I found these in kerberos logs for a user for both attempts (with 2FA enabled and without). This users password was resetted recently and post that it started having issues.
Without OTP it is working and with OTP it is failing.
Can you provide debug SSSD logs from the openvpn host?
Without OTP
Jul 10 02:34:24 newvpn1 krb5kdc[1446773](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required Jul 10 02:34:25 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required Jul 10 02:34:25 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required Jul 10 02:34:26 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required Jul 10 02:34:26 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: ISSUE: authtime 1720559066, etypes {rep=aes256-cts-hmac-sha1-96(18), tkt=aes256-cts-hmac-sha1-96(18), ses=aes256-cts-hmac-sha1-96(18)}, asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL Jul 10 02:34:27 newvpn1 krb5kdc[1446774](info): TGS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: ISSUE: authtime 1720559066, etypes {rep=aes256-cts-hmac-sha1-96(18), tkt=aes256-cts-hmac-sha1-96(18), ses=aes256-cts-hmac-sha1-96(18)}, asingh@TINKU.LOCAL for host/newvpn.TINKU.local@TINKU.LOCAL
With OTP Failure
Jul 10 02:33:25 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required Jul 10 02:33:25 newvpn1 krb5kdc[1446773](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required Jul 10 02:33:26 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required Jul 10 02:33:26 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required Jul 10 02:33:27 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: PREAUTH_FAILED: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Preauthentication failed -- _______________________________________________ FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org To unsubscribe send an email to freeipa-users-leave@lists.fedorahosted.org Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/ List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines List Archives: https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedorahoste... Do not reply to spam, report it: https://pagure.io/fedora-infrastructure/new_issue
In sssd logs, it didn't printed anything for the logon attempt through openvpn with 2FA enabled.
However, this is what I found in sssd_pam logs. Please confirm if any specific worker logs are needed.
(2024-07-10 23:32:38): [pam] [get_client_cred] (0x0080): The following failure is expected to happen in case SELinux is disabled: SELINUX_getpeercon failed [92][Protocol not available]. Please, consider enabling SELinux in your system. (2024-07-10 23:32:38): [pam] [accept_fd_handler] (0x0400): Client [CID #2][cmd /usr/sbin/openvpn][0x55c575eebfd0][24] connected to privileged pipe! (2024-07-10 23:32:38): [pam] [sss_cmd_get_version] (0x0200): Received client version [3]. (2024-07-10 23:32:38): [pam] [sss_cmd_get_version] (0x0200): Offered version [3]. (2024-07-10 23:32:38): [pam] [pam_cmd_preauth] (0x0100): entering pam_cmd_preauth (2024-07-10 23:32:38): [pam] [sss_domain_get_state] (0x1000): Domain tinku.local is Active (2024-07-10 23:32:38): [pam] [sss_parse_name] (0x0100): Domain not provided! (2024-07-10 23:32:38): [pam] [sss_parse_name_for_domains] (0x0200): name 'asingh' matched without domain, user is asingh (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] command: SSS_PAM_PREAUTH (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] domain: not set (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] user: asingh (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] service: login (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] tty: not set (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] ruser: not set (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] rhost: not set (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] authtok type: 0 (No authentication token available) (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] newauthtok type: 0 (No authentication token available) (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] priv: 1 (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] cli_pid: 335493 (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] logon name: asingh (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] flags: 2 (2024-07-10 23:32:38): [pam] [cache_req_send] (0x0400): CR #3: REQ_TRACE: New request [CID #2] 'Initgroups by name' (2024-07-10 23:32:38): [pam] [cache_req_process_input] (0x0400): CR #3: Parsing input name [asingh] (2024-07-10 23:32:38): [pam] [sss_domain_get_state] (0x1000): Domain tinku.local is Active (2024-07-10 23:32:38): [pam] [sss_parse_name] (0x0100): Domain not provided! (2024-07-10 23:32:38): [pam] [sss_parse_name_for_domains] (0x0200): name 'asingh' matched without domain, user is asingh (2024-07-10 23:32:38): [pam] [cache_req_set_name] (0x0400): CR #3: Setting name [asingh] (2024-07-10 23:32:38): [pam] [cache_req_select_domains] (0x0400): CR #3: Performing a multi-domain search (2024-07-10 23:32:38): [pam] [cache_req_search_domains] (0x0400): CR #3: Search will check the cache and bypass the data provider (2024-07-10 23:32:38): [pam] [cache_req_set_domain] (0x0400): CR #3: Using domain [implicit_files] (2024-07-10 23:32:38): [pam] [cache_req_prepare_domain_data] (0x0400): CR #3: Preparing input data for domain [implicit_files] rules (2024-07-10 23:32:38): [pam] [cache_req_search_send] (0x0400): CR #3: Looking up asingh@implicit_files (2024-07-10 23:32:38): [pam] [cache_req_search_ncache] (0x0400): CR #3: Checking negative cache for [asingh@implicit_files] (2024-07-10 23:32:38): [pam] [cache_req_search_ncache] (0x0400): CR #3: [asingh@implicit_files] is not present in negative cache (2024-07-10 23:32:38): [pam] [cache_req_search_cache] (0x0400): CR #3: Looking up [asingh@implicit_files] in cache (2024-07-10 23:32:38): [pam] [cache_req_search_cache] (0x0400): CR #3: Object [asingh@implicit_files] was not found in cache (2024-07-10 23:32:38): [pam] [cache_req_set_domain] (0x0400): CR #3: Using domain [tinku.local] (2024-07-10 23:32:38): [pam] [cache_req_prepare_domain_data] (0x0400): CR #3: Preparing input data for domain [tinku.local] rules (2024-07-10 23:32:38): [pam] [cache_req_search_send] (0x0400): CR #3: Looking up asingh@tinku.local (2024-07-10 23:32:38): [pam] [cache_req_search_ncache] (0x0400): CR #3: Checking negative cache for [asingh@tinku.local] (2024-07-10 23:32:38): [pam] [cache_req_search_ncache] (0x0400): CR #3: [asingh@tinku.local] is not present in negative cache (2024-07-10 23:32:38): [pam] [cache_req_search_cache] (0x0400): CR #3: Looking up [asingh@tinku.local] in cache (2024-07-10 23:32:38): [pam] [cache_req_search_send] (0x0400): CR #3: Returning [asingh@tinku.local] from cache (2024-07-10 23:32:38): [pam] [cache_req_search_ncache_filter] (0x0400): CR #3: This request type does not support filtering result by negative cache (2024-07-10 23:32:38): [pam] [cache_req_create_and_add_result] (0x0400): CR #3: Found 3 entries in domain tinku.local (2024-07-10 23:32:38): [pam] [cache_req_done] (0x0400): CR #3: Finished: Success (2024-07-10 23:32:38): [pam] [cache_req_send] (0x0400): CR #4: REQ_TRACE: New request [CID #2] 'Initgroups by name' (2024-07-10 23:32:38): [pam] [cache_req_process_input] (0x0400): CR #4: Parsing input name [asingh] (2024-07-10 23:32:38): [pam] [sss_domain_get_state] (0x1000): Domain tinku.local is Active (2024-07-10 23:32:38): [pam] [sss_parse_name] (0x0100): Domain not provided! (2024-07-10 23:32:38): [pam] [sss_parse_name_for_domains] (0x0200): name 'asingh' matched without domain, user is asingh (2024-07-10 23:32:38): [pam] [cache_req_set_name] (0x0400): CR #4: Setting name [asingh] (2024-07-10 23:32:38): [pam] [cache_req_select_domains] (0x0400): CR #4: Performing a multi-domain search (2024-07-10 23:32:38): [pam] [cache_req_search_domains] (0x0400): CR #4: Search will bypass the cache and check the data provider (2024-07-10 23:32:38): [pam] [cache_req_set_domain] (0x0400): CR #4: Using domain [implicit_files] (2024-07-10 23:32:38): [pam] [cache_req_prepare_domain_data] (0x0400): CR #4: Preparing input data for domain [implicit_files] rules (2024-07-10 23:32:38): [pam] [cache_req_search_send] (0x0400): CR #4: Looking up asingh@implicit_files (2024-07-10 23:32:38): [pam] [cache_req_search_ncache] (0x0400): CR #4: Checking negative cache for [asingh@implicit_files] (2024-07-10 23:32:38): [pam] [cache_req_search_ncache] (0x0400): CR #4: [asingh@implicit_files] is not present in negative cache (2024-07-10 23:32:38): [pam] [cache_req_search_dp] (0x0400): CR #4: Looking up [asingh@implicit_files] in data provider (2024-07-10 23:32:38): [pam] [sss_domain_get_state] (0x1000): Domain implicit_files is Active (2024-07-10 23:32:38): [pam] [sss_domain_get_state] (0x1000): Domain implicit_files is Active (2024-07-10 23:32:38): [pam] [cache_req_search_cache] (0x0400): CR #4: Looking up [asingh@implicit_files] in cache (2024-07-10 23:32:38): [pam] [cache_req_search_cache] (0x0400): CR #4: Object [asingh@implicit_files] was not found in cache (2024-07-10 23:32:38): [pam] [cache_req_search_ncache_add_to_domain] (0x0400): CR #4: Adding [asingh@implicit_files] to negative cache (2024-07-10 23:32:38): [pam] [sss_ncache_set_str] (0x0400): Adding [NCE/USER/implicit_files/asingh@implicit_files] to negative cache (2024-07-10 23:32:38): [pam] [cache_req_set_domain] (0x0400): CR #4: Using domain [tinku.local] (2024-07-10 23:32:38): [pam] [cache_req_prepare_domain_data] (0x0400): CR #4: Preparing input data for domain [tinku.local] rules (2024-07-10 23:32:38): [pam] [cache_req_search_send] (0x0400): CR #4: Looking up asingh@tinku.local (2024-07-10 23:32:38): [pam] [cache_req_search_ncache] (0x0400): CR #4: Checking negative cache for [asingh@tinku.local] (2024-07-10 23:32:38): [pam] [cache_req_search_ncache] (0x0400): CR #4: [asingh@tinku.local] is not present in negative cache (2024-07-10 23:32:38): [pam] [cache_req_search_dp] (0x0400): CR #4: Looking up [asingh@tinku.local] in data provider (2024-07-10 23:32:38): [pam] [sss_dp_get_account_send] (0x0400): Creating request for [tinku.local][0x3][BE_REQ_INITGROUPS][name=asingh@tinku.local:-] (2024-07-10 23:32:38): [pam] [sss_domain_get_state] (0x1000): Domain tinku.local is Active (2024-07-10 23:32:38): [pam] [cache_req_search_cache] (0x0400): CR #4: Looking up [asingh@tinku.local] in cache (2024-07-10 23:32:38): [pam] [cache_req_search_ncache_filter] (0x0400): CR #4: This request type does not support filtering result by negative cache (2024-07-10 23:32:38): [pam] [cache_req_search_done] (0x0400): CR #4: Returning updated object [asingh@tinku.local] (2024-07-10 23:32:38): [pam] [cache_req_create_and_add_result] (0x0400): CR #4: Found 3 entries in domain tinku.local (2024-07-10 23:32:38): [pam] [cache_req_done] (0x0400): CR #4: Finished: Success (2024-07-10 23:32:38): [pam] [pd_set_primary_name] (0x0400): User's primary name is asingh@tinku.local (2024-07-10 23:32:38): [pam] [pam_dp_send_req] (0x0100): Sending request [CID #2] with the following data: (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] command: SSS_PAM_PREAUTH (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] domain: tinku.local (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] user: asingh@tinku.local (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] service: login (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] tty: not set (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] ruser: not set (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] rhost: not set (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] authtok type: 0 (No authentication token available) (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] newauthtok type: 0 (No authentication token available) (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] priv: 1 (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] cli_pid: 335493 (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] logon name: asingh (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] flags: 2 (2024-07-10 23:32:38): [pam] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0 (2024-07-10 23:32:39): [pam] [pam_dp_send_req_done] (0x0200): received: [0 (Success)][tinku.local][CID #2] (2024-07-10 23:32:39): [pam] [pam_reply] (0x0200): blen: 47 (2024-07-10 23:32:39): [pam] [pam_reply] (0x0200): Returning [0]: Success to the client [CID #2] (2024-07-10 23:32:39): [pam] [pam_cmd_authenticate] (0x0100): entering pam_cmd_authenticate (2024-07-10 23:32:39): [pam] [sss_domain_get_state] (0x1000): Domain tinku.local is Active (2024-07-10 23:32:39): [pam] [sss_parse_name] (0x0100): Domain not provided! (2024-07-10 23:32:39): [pam] [sss_parse_name_for_domains] (0x0200): name 'asingh' matched without domain, user is asingh (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] command: SSS_PAM_AUTHENTICATE (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] domain: not set (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] user: asingh (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] service: login (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] tty: not set (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] ruser: not set (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] rhost: not set (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] authtok type: 3 (Two factors) (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] newauthtok type: 0 (No authentication token available) (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] priv: 1 (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] cli_pid: 335493 (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] logon name: asingh (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] flags: 2 (2024-07-10 23:32:39): [pam] [cache_req_send] (0x0400): CR #5: REQ_TRACE: New request [CID #2] 'Initgroups by name' (2024-07-10 23:32:39): [pam] [cache_req_process_input] (0x0400): CR #5: Parsing input name [asingh] (2024-07-10 23:32:39): [pam] [sss_domain_get_state] (0x1000): Domain tinku.local is Active (2024-07-10 23:32:39): [pam] [sss_parse_name] (0x0100): Domain not provided! (2024-07-10 23:32:39): [pam] [sss_parse_name_for_domains] (0x0200): name 'asingh' matched without domain, user is asingh (2024-07-10 23:32:39): [pam] [cache_req_set_name] (0x0400): CR #5: Setting name [asingh] (2024-07-10 23:32:39): [pam] [cache_req_select_domains] (0x0400): CR #5: Performing a multi-domain search (2024-07-10 23:32:39): [pam] [cache_req_search_domains] (0x0400): CR #5: Search will check the cache and bypass the data provider (2024-07-10 23:32:39): [pam] [cache_req_set_domain] (0x0400): CR #5: Using domain [implicit_files] (2024-07-10 23:32:39): [pam] [cache_req_prepare_domain_data] (0x0400): CR #5: Preparing input data for domain [implicit_files] rules (2024-07-10 23:32:39): [pam] [cache_req_search_send] (0x0400): CR #5: Looking up asingh@implicit_files (2024-07-10 23:32:39): [pam] [cache_req_search_ncache] (0x0400): CR #5: Checking negative cache for [asingh@implicit_files] (2024-07-10 23:32:39): [pam] [cache_req_search_ncache] (0x0400): CR #5: [asingh@implicit_files] does not exist (negative cache) (2024-07-10 23:32:39): [pam] [cache_req_set_domain] (0x0400): CR #5: Using domain [tinku.local] (2024-07-10 23:32:39): [pam] [cache_req_prepare_domain_data] (0x0400): CR #5: Preparing input data for domain [tinku.local] rules (2024-07-10 23:32:39): [pam] [cache_req_search_send] (0x0400): CR #5: Looking up asingh@tinku.local (2024-07-10 23:32:39): [pam] [cache_req_search_ncache] (0x0400): CR #5: Checking negative cache for [asingh@tinku.local] (2024-07-10 23:32:39): [pam] [cache_req_search_ncache] (0x0400): CR #5: [asingh@tinku.local] is not present in negative cache (2024-07-10 23:32:39): [pam] [cache_req_search_cache] (0x0400): CR #5: Looking up [asingh@tinku.local] in cache (2024-07-10 23:32:39): [pam] [cache_req_search_send] (0x0400): CR #5: Returning [asingh@tinku.local] from cache (2024-07-10 23:32:39): [pam] [cache_req_search_ncache_filter] (0x0400): CR #5: This request type does not support filtering result by negative cache (2024-07-10 23:32:39): [pam] [cache_req_create_and_add_result] (0x0400): CR #5: Found 3 entries in domain tinku.local (2024-07-10 23:32:39): [pam] [cache_req_done] (0x0400): CR #5: Finished: Success (2024-07-10 23:32:39): [pam] [pd_set_primary_name] (0x0400): User's primary name is asingh@tinku.local (2024-07-10 23:32:39): [pam] [pam_dp_send_req] (0x0100): Sending request [CID #2] with the following data: (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] command: SSS_PAM_AUTHENTICATE (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] domain: tinku.local (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] user: asingh@tinku.local (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] service: login (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] tty: not set (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] ruser: not set (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] rhost: not set (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] authtok type: 3 (Two factors) (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] newauthtok type: 0 (No authentication token available) (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] priv: 1 (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] cli_pid: 335493 (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] logon name: asingh (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] flags: 2 (2024-07-10 23:32:39): [pam] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0 (2024-07-10 23:32:41): [pam] [pam_dp_send_req_done] (0x0200): received: [7 (Authentication failure)][tinku.local][CID #2] (2024-07-10 23:32:41): [pam] [pam_reply] (0x0200): blen: 28 (2024-07-10 23:32:41): [pam] [pam_reply] (0x0200): Returning [7]: Authentication failure to the client [CID #2] (2024-07-10 23:32:43): [pam] [client_recv] (0x0200): Client disconnected!
In sssd logs, it didn't printed anything for the logon attempt through openvpn with 2FA enabled.
However, this is what I found in sssd_pam logs. Please confirm if any specific worker logs are needed.
(2024-07-10 23:32:38): [pam] [get_client_cred] (0x0080): The following failure is expected to happen in case SELinux is disabled: SELINUX_getpeercon failed [92][Protocol not available]. Please, consider enabling SELinux in your system. (2024-07-10 23:32:38): [pam] [accept_fd_handler] (0x0400): Client [CID #2][cmd /usr/sbin/openvpn][0x55c575eebfd0][24] connected to privileged pipe! (2024-07-10 23:32:38): [pam] [sss_cmd_get_version] (0x0200): Received client version [3]. (2024-07-10 23:32:38): [pam] [sss_cmd_get_version] (0x0200): Offered version [3]. (2024-07-10 23:32:38): [pam] [pam_cmd_preauth] (0x0100): entering pam_cmd_preauth (2024-07-10 23:32:38): [pam] [sss_domain_get_state] (0x1000): Domain tinku.local is Active (2024-07-10 23:32:38): [pam] [sss_parse_name] (0x0100): Domain not provided! (2024-07-10 23:32:38): [pam] [sss_parse_name_for_domains] (0x0200): name 'asingh' matched without domain, user is asingh (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] command: SSS_PAM_PREAUTH (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] domain: not set (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] user: asingh (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] service: login (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] tty: not set (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] ruser: not set (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] rhost: not set (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] authtok type: 0 (No authentication token available) (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] newauthtok type: 0 (No authentication token available) (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] priv: 1 (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] cli_pid: 335493 (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] logon name: asingh (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] flags: 2 (2024-07-10 23:32:38): [pam] [cache_req_send] (0x0400): CR #3: REQ_TRACE: New request [CID #2] 'Initgroups by name' (2024-07-10 23:32:38): [pam] [cache_req_process_input] (0x0400): CR #3: Parsing input name [asingh] (2024-07-10 23:32:38): [pam] [sss_domain_get_state] (0x1000): Domain tinku.local is Active (2024-07-10 23:32:38): [pam] [sss_parse_name] (0x0100): Domain not provided! (2024-07-10 23:32:38): [pam] [sss_parse_name_for_domains] (0x0200): name 'asingh' matched without domain, user is asingh (2024-07-10 23:32:38): [pam] [cache_req_set_name] (0x0400): CR #3: Setting name [asingh] (2024-07-10 23:32:38): [pam] [cache_req_select_domains] (0x0400): CR #3: Performing a multi-domain search (2024-07-10 23:32:38): [pam] [cache_req_search_domains] (0x0400): CR #3: Search will check the cache and bypass the data provider (2024-07-10 23:32:38): [pam] [cache_req_set_domain] (0x0400): CR #3: Using domain [implicit_files] (2024-07-10 23:32:38): [pam] [cache_req_prepare_domain_data] (0x0400): CR #3: Preparing input data for domain [implicit_files] rules (2024-07-10 23:32:38): [pam] [cache_req_search_send] (0x0400): CR #3: Looking up asingh@implicit_files (2024-07-10 23:32:38): [pam] [cache_req_search_ncache] (0x0400): CR #3: Checking negative cache for [asingh@implicit_files] (2024-07-10 23:32:38): [pam] [cache_req_search_ncache] (0x0400): CR #3: [asingh@implicit_files] is not present in negative cache (2024-07-10 23:32:38): [pam] [cache_req_search_cache] (0x0400): CR #3: Looking up [asingh@implicit_files] in cache (2024-07-10 23:32:38): [pam] [cache_req_search_cache] (0x0400): CR #3: Object [asingh@implicit_files] was not found in cache (2024-07-10 23:32:38): [pam] [cache_req_set_domain] (0x0400): CR #3: Using domain [tinku.local] (2024-07-10 23:32:38): [pam] [cache_req_prepare_domain_data] (0x0400): CR #3: Preparing input data for domain [tinku.local] rules (2024-07-10 23:32:38): [pam] [cache_req_search_send] (0x0400): CR #3: Looking up asingh@tinku.local (2024-07-10 23:32:38): [pam] [cache_req_search_ncache] (0x0400): CR #3: Checking negative cache for [asingh@tinku.local] (2024-07-10 23:32:38): [pam] [cache_req_search_ncache] (0x0400): CR #3: [asingh@tinku.local] is not present in negative cache (2024-07-10 23:32:38): [pam] [cache_req_search_cache] (0x0400): CR #3: Looking up [asingh@tinku.local] in cache (2024-07-10 23:32:38): [pam] [cache_req_search_send] (0x0400): CR #3: Returning [asingh@tinku.local] from cache (2024-07-10 23:32:38): [pam] [cache_req_search_ncache_filter] (0x0400): CR #3: This request type does not support filtering result by negative cache (2024-07-10 23:32:38): [pam] [cache_req_create_and_add_result] (0x0400): CR #3: Found 3 entries in domain tinku.local (2024-07-10 23:32:38): [pam] [cache_req_done] (0x0400): CR #3: Finished: Success (2024-07-10 23:32:38): [pam] [cache_req_send] (0x0400): CR #4: REQ_TRACE: New request [CID #2] 'Initgroups by name' (2024-07-10 23:32:38): [pam] [cache_req_process_input] (0x0400): CR #4: Parsing input name [asingh] (2024-07-10 23:32:38): [pam] [sss_domain_get_state] (0x1000): Domain tinku.local is Active (2024-07-10 23:32:38): [pam] [sss_parse_name] (0x0100): Domain not provided! (2024-07-10 23:32:38): [pam] [sss_parse_name_for_domains] (0x0200): name 'asingh' matched without domain, user is asingh (2024-07-10 23:32:38): [pam] [cache_req_set_name] (0x0400): CR #4: Setting name [asingh] (2024-07-10 23:32:38): [pam] [cache_req_select_domains] (0x0400): CR #4: Performing a multi-domain search (2024-07-10 23:32:38): [pam] [cache_req_search_domains] (0x0400): CR #4: Search will bypass the cache and check the data provider (2024-07-10 23:32:38): [pam] [cache_req_set_domain] (0x0400): CR #4: Using domain [implicit_files] (2024-07-10 23:32:38): [pam] [cache_req_prepare_domain_data] (0x0400): CR #4: Preparing input data for domain [implicit_files] rules (2024-07-10 23:32:38): [pam] [cache_req_search_send] (0x0400): CR #4: Looking up asingh@implicit_files (2024-07-10 23:32:38): [pam] [cache_req_search_ncache] (0x0400): CR #4: Checking negative cache for [asingh@implicit_files] (2024-07-10 23:32:38): [pam] [cache_req_search_ncache] (0x0400): CR #4: [asingh@implicit_files] is not present in negative cache (2024-07-10 23:32:38): [pam] [cache_req_search_dp] (0x0400): CR #4: Looking up [asingh@implicit_files] in data provider (2024-07-10 23:32:38): [pam] [sss_domain_get_state] (0x1000): Domain implicit_files is Active (2024-07-10 23:32:38): [pam] [sss_domain_get_state] (0x1000): Domain implicit_files is Active (2024-07-10 23:32:38): [pam] [cache_req_search_cache] (0x0400): CR #4: Looking up [asingh@implicit_files] in cache (2024-07-10 23:32:38): [pam] [cache_req_search_cache] (0x0400): CR #4: Object [asingh@implicit_files] was not found in cache (2024-07-10 23:32:38): [pam] [cache_req_search_ncache_add_to_domain] (0x0400): CR #4: Adding [asingh@implicit_files] to negative cache (2024-07-10 23:32:38): [pam] [sss_ncache_set_str] (0x0400): Adding [NCE/USER/implicit_files/asingh@implicit_files] to negative cache (2024-07-10 23:32:38): [pam] [cache_req_set_domain] (0x0400): CR #4: Using domain [tinku.local] (2024-07-10 23:32:38): [pam] [cache_req_prepare_domain_data] (0x0400): CR #4: Preparing input data for domain [tinku.local] rules (2024-07-10 23:32:38): [pam] [cache_req_search_send] (0x0400): CR #4: Looking up asingh@tinku.local (2024-07-10 23:32:38): [pam] [cache_req_search_ncache] (0x0400): CR #4: Checking negative cache for [asingh@tinku.local] (2024-07-10 23:32:38): [pam] [cache_req_search_ncache] (0x0400): CR #4: [asingh@tinku.local] is not present in negative cache (2024-07-10 23:32:38): [pam] [cache_req_search_dp] (0x0400): CR #4: Looking up [asingh@tinku.local] in data provider (2024-07-10 23:32:38): [pam] [sss_dp_get_account_send] (0x0400): Creating request for [tinku.local][0x3][BE_REQ_INITGROUPS][name=asingh@tinku.local:-] (2024-07-10 23:32:38): [pam] [sss_domain_get_state] (0x1000): Domain tinku.local is Active (2024-07-10 23:32:38): [pam] [cache_req_search_cache] (0x0400): CR #4: Looking up [asingh@tinku.local] in cache (2024-07-10 23:32:38): [pam] [cache_req_search_ncache_filter] (0x0400): CR #4: This request type does not support filtering result by negative cache (2024-07-10 23:32:38): [pam] [cache_req_search_done] (0x0400): CR #4: Returning updated object [asingh@tinku.local] (2024-07-10 23:32:38): [pam] [cache_req_create_and_add_result] (0x0400): CR #4: Found 3 entries in domain tinku.local (2024-07-10 23:32:38): [pam] [cache_req_done] (0x0400): CR #4: Finished: Success (2024-07-10 23:32:38): [pam] [pd_set_primary_name] (0x0400): User's primary name is asingh@tinku.local (2024-07-10 23:32:38): [pam] [pam_dp_send_req] (0x0100): Sending request [CID #2] with the following data: (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] command: SSS_PAM_PREAUTH (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] domain: tinku.local (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] user: asingh@tinku.local (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] service: login (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] tty: not set (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] ruser: not set (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] rhost: not set (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] authtok type: 0 (No authentication token available) (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] newauthtok type: 0 (No authentication token available) (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] priv: 1 (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] cli_pid: 335493 (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] logon name: asingh (2024-07-10 23:32:38): [pam] [pam_print_data] (0x0100): [CID #2] flags: 2 (2024-07-10 23:32:38): [pam] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0 (2024-07-10 23:32:39): [pam] [pam_dp_send_req_done] (0x0200): received: [0 (Success)][tinku.local][CID #2] (2024-07-10 23:32:39): [pam] [pam_reply] (0x0200): blen: 47 (2024-07-10 23:32:39): [pam] [pam_reply] (0x0200): Returning [0]: Success to the client [CID #2] (2024-07-10 23:32:39): [pam] [pam_cmd_authenticate] (0x0100): entering pam_cmd_authenticate (2024-07-10 23:32:39): [pam] [sss_domain_get_state] (0x1000): Domain tinku.local is Active (2024-07-10 23:32:39): [pam] [sss_parse_name] (0x0100): Domain not provided! (2024-07-10 23:32:39): [pam] [sss_parse_name_for_domains] (0x0200): name 'asingh' matched without domain, user is asingh (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] command: SSS_PAM_AUTHENTICATE (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] domain: not set (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] user: asingh (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] service: login (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] tty: not set (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] ruser: not set (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] rhost: not set (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] authtok type: 3 (Two factors) (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] newauthtok type: 0 (No authentication token available) (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] priv: 1 (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] cli_pid: 335493 (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] logon name: asingh (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] flags: 2 (2024-07-10 23:32:39): [pam] [cache_req_send] (0x0400): CR #5: REQ_TRACE: New request [CID #2] 'Initgroups by name' (2024-07-10 23:32:39): [pam] [cache_req_process_input] (0x0400): CR #5: Parsing input name [asingh] (2024-07-10 23:32:39): [pam] [sss_domain_get_state] (0x1000): Domain tinku.local is Active (2024-07-10 23:32:39): [pam] [sss_parse_name] (0x0100): Domain not provided! (2024-07-10 23:32:39): [pam] [sss_parse_name_for_domains] (0x0200): name 'asingh' matched without domain, user is asingh (2024-07-10 23:32:39): [pam] [cache_req_set_name] (0x0400): CR #5: Setting name [asingh] (2024-07-10 23:32:39): [pam] [cache_req_select_domains] (0x0400): CR #5: Performing a multi-domain search (2024-07-10 23:32:39): [pam] [cache_req_search_domains] (0x0400): CR #5: Search will check the cache and bypass the data provider (2024-07-10 23:32:39): [pam] [cache_req_set_domain] (0x0400): CR #5: Using domain [implicit_files] (2024-07-10 23:32:39): [pam] [cache_req_prepare_domain_data] (0x0400): CR #5: Preparing input data for domain [implicit_files] rules (2024-07-10 23:32:39): [pam] [cache_req_search_send] (0x0400): CR #5: Looking up asingh@implicit_files (2024-07-10 23:32:39): [pam] [cache_req_search_ncache] (0x0400): CR #5: Checking negative cache for [asingh@implicit_files] (2024-07-10 23:32:39): [pam] [cache_req_search_ncache] (0x0400): CR #5: [asingh@implicit_files] does not exist (negative cache) (2024-07-10 23:32:39): [pam] [cache_req_set_domain] (0x0400): CR #5: Using domain [tinku.local] (2024-07-10 23:32:39): [pam] [cache_req_prepare_domain_data] (0x0400): CR #5: Preparing input data for domain [tinku.local] rules (2024-07-10 23:32:39): [pam] [cache_req_search_send] (0x0400): CR #5: Looking up asingh@tinku.local (2024-07-10 23:32:39): [pam] [cache_req_search_ncache] (0x0400): CR #5: Checking negative cache for [asingh@tinku.local] (2024-07-10 23:32:39): [pam] [cache_req_search_ncache] (0x0400): CR #5: [asingh@tinku.local] is not present in negative cache (2024-07-10 23:32:39): [pam] [cache_req_search_cache] (0x0400): CR #5: Looking up [asingh@tinku.local] in cache (2024-07-10 23:32:39): [pam] [cache_req_search_send] (0x0400): CR #5: Returning [asingh@tinku.local] from cache (2024-07-10 23:32:39): [pam] [cache_req_search_ncache_filter] (0x0400): CR #5: This request type does not support filtering result by negative cache (2024-07-10 23:32:39): [pam] [cache_req_create_and_add_result] (0x0400): CR #5: Found 3 entries in domain tinku.local (2024-07-10 23:32:39): [pam] [cache_req_done] (0x0400): CR #5: Finished: Success (2024-07-10 23:32:39): [pam] [pd_set_primary_name] (0x0400): User's primary name is asingh@tinku.local (2024-07-10 23:32:39): [pam] [pam_dp_send_req] (0x0100): Sending request [CID #2] with the following data: (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] command: SSS_PAM_AUTHENTICATE (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] domain: tinku.local (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] user: asingh@tinku.local (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] service: login (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] tty: not set (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] ruser: not set (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] rhost: not set (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] authtok type: 3 (Two factors) (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] newauthtok type: 0 (No authentication token available) (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] priv: 1 (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] cli_pid: 335493 (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] logon name: asingh (2024-07-10 23:32:39): [pam] [pam_print_data] (0x0100): [CID #2] flags: 2 (2024-07-10 23:32:39): [pam] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0 (2024-07-10 23:32:41): [pam] [pam_dp_send_req_done] (0x0200): received: [7 (Authentication failure)][tinku.local][CID #2] (2024-07-10 23:32:41): [pam] [pam_reply] (0x0200): blen: 28 (2024-07-10 23:32:41): [pam] [pam_reply] (0x0200): Returning [7]: Authentication failure to the client [CID #2] (2024-07-10 23:32:43): [pam] [client_recv] (0x0200): Client disconnected!
Hi Alex/Everyone,
Please look at this and help in this matter to provide any insights. Please let me know if any other information is required to get this resolved.
Thanks Tinku
Hi Alexander/Team,
Requiring your guidance in solving this problem. I have tried multiple possibilities but couldn't get this right.
I am writing down the entire setup which I have right now.
My FreeIPA cluster was earlier on 4.6.8 running on CentOS 7 and OpenVPN server authentication being done by plugin /usr/lib64/openvpn/plugins/openvpn-plugin-auth-pam.so login along with 2FA successfully.
When I migrated this setup to Oracle Linux 8 and updated the IPA version to 4.9.13 the OpenVPN authentication is not working with 2FA when I reset any user password or on-board any new user. For old users, 2FA is working successfully unless I/they reset their IPA passwords. 2FA is working fine when I login to the servers, it's just not working with OpenVPN pam plugin. I am using the same plugin which was being used earlier with same pam file.
Request you to please assist in this. Please let me know if any other details are needed.
Thanks Tinku
On Wed, 10 Jul 2024 at 17:24, Alexander Bokovoy abokovoy@redhat.com wrote:
On Срд, 10 ліп 2024, Tinku Goyal via FreeIPA-users wrote:
The password is being changed using the IPA server UI for the IPA users. Post password change users are able to login to the IPA portal and linux servers as well but not able to authenticate with the OpenVPN via the plugin.
Also, same is happening for the new users, if I create a new user in IPA and try login to the OpenVPN with that user with 2FA enabled, it is not working.
While authentication, it is going for Pre-authentication and I found these in kerberos logs for a user for both attempts (with 2FA enabled and without). This users password was resetted recently and post that it started having issues.
Without OTP it is working and with OTP it is failing.
Can you provide debug SSSD logs from the openvpn host?
Without OTP
Jul 10 02:34:24 newvpn1 krb5kdc[1446773](info): AS_REQ (6 etypes
{aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required
Jul 10 02:34:25 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes
{aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required
Jul 10 02:34:25 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes
{aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required
Jul 10 02:34:26 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes
{aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required
Jul 10 02:34:26 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes
{aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: ISSUE: authtime 1720559066, etypes {rep=aes256-cts-hmac-sha1-96(18), tkt=aes256-cts-hmac-sha1-96(18), ses=aes256-cts-hmac-sha1-96(18)}, asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL
Jul 10 02:34:27 newvpn1 krb5kdc[1446774](info): TGS_REQ (6 etypes
{aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: ISSUE: authtime 1720559066, etypes {rep=aes256-cts-hmac-sha1-96(18), tkt=aes256-cts-hmac-sha1-96(18), ses=aes256-cts-hmac-sha1-96(18)}, asingh@TINKU.LOCAL for host/newvpn.TINKU.local@TINKU.LOCAL
With OTP Failure
Jul 10 02:33:25 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes
{aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required
Jul 10 02:33:25 newvpn1 krb5kdc[1446773](info): AS_REQ (6 etypes
{aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required
Jul 10 02:33:26 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes
{aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required
Jul 10 02:33:26 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes
{aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: NEEDED_PREAUTH: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Additional pre-authentication required
Jul 10 02:33:27 newvpn1 krb5kdc[1446774](info): AS_REQ (6 etypes
{aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 10.18.20.5: PREAUTH_FAILED: asingh@TINKU.LOCAL for krbtgt/TINKU.LOCAL@TINKU.LOCAL, Preauthentication failed
-- _______________________________________________ FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org To unsubscribe send an email to
freeipa-users-leave@lists.fedorahosted.org
Fedora Code of Conduct:
https://docs.fedoraproject.org/en-US/project/code-of-conduct/
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines List Archives:
https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedorahoste...
Do not reply to spam, report it:
https://pagure.io/fedora-infrastructure/new_issue
-- / Alexander Bokovoy Sr. Principal Software Engineer Security / Identity Management Engineering Red Hat Limited, Finland
freeipa-users@lists.fedorahosted.org
-
Alexander Bokovoy -
Tinku -
Tinku Goyal