Am Tue, Jan 25, 2022 at 04:30:10PM -0000 schrieb Rob Crittenden:
> Am Mon, Jan 24, 2022 at 01:36:28PM -0500 schrieb Rob
Crittenden:
>
> Hi,
>
> the PAM_PERM_DENIED error is returned from the backend. Please check the
> backend log and krb5_child.log. I agree that it looks a bit like a
> timeout issue since the default krb5_auth_timeout is 6s but I would
> expect a different return code in this case.
>
> It looks like currently PAM_PERM_DENIED is returned during
> authentication only if the KDC returns KRB5KDC_ERR_CLIENT_REVOKED, i.e.
> the account is locked or similar.
Looks like the backend is detected as offline.
Here is a hopefully not too-hacked representation from the backend log:
* (2022-01-24 16:11:50): [be[ipa.test]] [sbus_senders_lookup] (0x2000): Looking for
identity of sender [sssd.pam]
* (2022-01-24 16:11:50): [be[ipa.test]] [dp_pam_handler_send] (0x0100): Got request
with the following data
* (2022-01-24 16:11:50): [be[ipa.test]] [pam_print_data] (0x0100): [CID #2] command:
SSS_PAM_AUTHENTICATE
* (2022-01-24 16:11:50): [be[ipa.test]] [pam_print_data] (0x0100): [CID #2] domain:
ipa.test
* (2022-01-24 16:11:50): [be[ipa.test]] [pam_print_data] (0x0100): [CID #2] user:
user19client003.ipa.test(a)ipa.test
* (2022-01-24 16:11:50): [be[ipa.test]] [pam_print_data] (0x0100): [CID #2] service:
login
[snip but it's a password auth]
* (2022-01-24 16:11:50): [be[ipa.test]] [dp_attach_req] (0x0400): [RID#171] DP
Request [PAM Authenticate #171]: REQ_TRACE: New request. [sssd.pam CID #2] Flags [0000].
* (2022-01-24 16:11:50): [be[ipa.test]] [dp_attach_req] (0x0400): [RID#171] Number of
active DP request: 1
* (2022-01-24 16:11:50): [be[ipa.test]] [sss_domain_get_state] (0x1000): [RID#171]
Domain ipa.test is Active
* (2022-01-24 16:11:50): [be[ipa.test]] [sss_domain_get_state] (0x1000): [RID#171]
Domain ipa.test is Active
* (2022-01-24 16:11:50): [be[ipa.test]] [krb5_auth_queue_send] (0x1000): [RID#171]
Wait queue of user [user19client003.ipa.test(a)ipa.test] is empty, running request
[0x5614e40a64d0] immediately.
* (2022-01-24 16:11:50): [be[ipa.test]] [krb5_setup] (0x4000): [RID#171] No mapping
for: user19client003.ipa.test(a)ipa.test
* (2022-01-24 16:11:50): [be[ipa.test]] [krb5_auth_prepare_ccache_name] (0x1000):
[RID#171] No ccache file for user [user19client003.ipa.test(a)ipa.test] found.
* (2022-01-24 16:11:50): [be[ipa.test]] [fo_resolve_service_send] (0x0100): [RID#171]
Trying to resolve service 'IPA'
* (2022-01-24 16:11:50): [be[ipa.test]] [get_server_status] (0x1000): [RID#171]
Status of server 'server.ipa.test' is 'working'
* (2022-01-24 16:11:50): [be[ipa.test]] [get_port_status] (0x1000): [RID#171] Port
status of port 0 for server 'server.ipa.test' is 'working'
* (2022-01-24 16:11:50): [be[ipa.test]] [fo_resolve_service_activate_timeout]
(0x2000): [RID#171] Resolve timeout [dns_resolver_timeout] set to 6 seconds
* (2022-01-24 16:11:50): [be[ipa.test]] [get_server_status] (0x1000): [RID#171]
Status of server 'server.ipa.test' is 'working'
* (2022-01-24 16:11:50): [be[ipa.test]] [be_resolve_server_process] (0x1000):
[RID#171] Saving the first resolved server
* (2022-01-24 16:11:50): [be[ipa.test]] [be_resolve_server_process] (0x0200):
[RID#171] Found address for server server.ipa.test: [192.168.193.244] TTL 7200
* (2022-01-24 16:11:50): [be[ipa.test]] [ipa_resolve_callback] (0x0400): [RID#171]
Constructed uri 'ldap://server.ipa.test'
* (2022-01-24 16:11:50): [be[ipa.test]] [krb5_add_krb5info_offline_callback]
(0x4000): [RID#171] Removal callback already available for service [IPA].
* (2022-01-24 16:11:50): [be[ipa.test]] [unlink_dbg] (0x2000): [RID#171] File already
removed: [/var/lib/sss/pubconf/.krb5info_dummy_hY7Urp]
* (2022-01-24 16:11:50): [be[ipa.test]] [sss_domain_get_state] (0x1000): [RID#171]
Domain ipa.test is Active
* (2022-01-24 16:11:50): [be[ipa.test]] [child_handler_setup] (0x2000): [RID#171]
Setting up signal handler up for pid [4444]
* (2022-01-24 16:11:50): [be[ipa.test]] [child_handler_setup] (0x2000): [RID#171]
Signal handler set up for pid [4444]
* (2022-01-24 16:11:50): [be[ipa.test]] [write_pipe_handler] (0x0400): [RID#171] All
data has been sent!
* (2022-01-24 16:11:56): [be[ipa.test]] [krb5_auth_done] (0x0020): [RID#171] child
timed out!
********************** BACKTRACE DUMP ENDS HERE *********************************
(2022-01-24 16:11:56): [be[ipa.test]] [fo_resolve_service_send] (0x0020): [RID#171] No
available servers for service 'IPA'
and subsequent backtraces:
********************** PREVIOUS MESSAGE WAS TRIGGERED BY THE FOLLOWING BACKTRACE:
* (2022-01-24 16:11:56): [be[ipa.test]] [_be_fo_set_port_status] (0x8000): [RID#171]
Setting status: PORT_NOT_WORKING. Called from: src/providers/krb5/krb5_auth.c:
krb5_auth_done: 862
and all the expected ports not available, etc. and no available servers for IPA (single
server install).
The child is eventually killed leading to:
(2022-01-24 16:11:57): [be[ipa.test]] [krb5_auth_cache_creds] (0x0020): [RID#171] Offline
authentication failed
Which makes sense since this is the first login for the user so there are no stored
creds.
Hi,
yes, PAM_PERM_DENIED is returned if there is no cached password for the
current user and I guess you are using 'cache_credentials=False' (or not
even set it since it is the default) to make sure every authentication
is hitting the server.
bye,
Sumit
So if this is indeed a timeout, it is good for me. I'm explicitly trying to find the
limit of how many users/clients can authenticate at more or less the same time. It seems
like I've managed to push the server enough that it isn't responsive to the
default sssd timeouts (and 6 seconds feels like forever if you're just trying to log
in). The interesting bit is that the server isn't really stressing at all, using maybe
25% of CPU. So it must be something else that is restrictive: # of threads, connections,
etc.
I'll preserve these client and server logs in case we want to do further analysis but
I'll try decreasing the number of logins to continue my search for the sweet spot.
_______________________________________________
sssd-users mailing list -- sssd-users(a)lists.fedorahosted.org
To unsubscribe send an email to sssd-users-leave(a)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/sssd-users@lists.fedorahoste...
Do not reply to spam on the list, report it:
https://pagure.io/fedora-infrastructure