On Wed, Aug 21, 2019 at 07:10:50PM -0000, Martijn Bakkes via FreeIPA-users wrote: ...
Hi,
here everything happened in 14:08:28, so there is no visible delay in the logs. Did you see a delay on the client for this attempt?
Can you try again and send new logs which "hopefully" show some delay?
bye, Sumit
(Wed Aug 21 14:08:43 2019) [sssd[nss]] [setup_client_idle_timer] (0x4000): Idle timer
re-set for client [0x559f771f0e20][21]
(Wed Aug 21 14:08:58 2019) [sssd[nss]] [setup_client_idle_timer] (0x4000): Idle timer
re-set for client [0x559f771e45f0][22]
(Wed Aug 21 14:09:13 2019) [sssd[nss]] [client_idle_handler] (0x2000): Terminating
idle client [0x559f771f0e20][21]
(Wed Aug 21 14:09:13 2019) [sssd[nss]] [client_close_fn] (0x2000): Terminated client
[0x559f771f0e20][21]
(Wed Aug 21 14:09:28 2019) [sssd[nss]] [setup_client_idle_timer] (0x4000): Idle timer
re-set for client [0x559f771e45f0][22]
(Wed Aug 21 14:09:58 2019) [sssd[nss]] [client_idle_handler] (0x2000): Terminating
idle client [0x559f771e45f0][22]
(Wed Aug 21 14:09:58 2019) [sssd[nss]] [client_close_fn] (0x2000): Terminated client
[0x559f771e45f0][22]
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [get_client_cred] (0x4000): Client creds:
euid[0] egid[0] pid[18338].
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [setup_client_idle_timer] (0x4000): Idle timer
re-set for client [0x559f771f0e20][21]
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [accept_fd_handler] (0x0400): Client
connected!
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [sss_cmd_get_version] (0x0200): Received
client version [1].
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [sss_cmd_get_version] (0x0200): Offered
version [1].
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [nss_getby_name] (0x0400): Input name: root (Wed Aug 21 14:10:01 2019) [sssd[nss]] [cache_req_set_plugin] (0x2000): CR #27:
Setting "Initgroups by name" plugin
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [cache_req_send] (0x0400): CR #27: New request
'Initgroups by name'
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [cache_req_process_input] (0x0400): CR #27:
Parsing input name [root]
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name
'root' matched without domain, user is root
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [cache_req_set_name] (0x0400): CR #27: Setting
name [root]
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #27:
Performing a multi-domain search
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #27:
Search will check the cache and check the data provider
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000):
Request type POSIX-only for domain <IPA DOMAIN> type POSIX is valid
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #27: Using
domain [<IPA DOMAIN>]
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR
#27: Preparing input data for domain [<IPA DOMAIN>] rules
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #27:
Looking up root@<IPA DOMAIN>
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #27:
Checking negative cache for [root@<IPA DOMAIN>]
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking
negative cache for [NCE/USER/<IPA DOMAIN>/root@<IPA DOMAIN>]
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #27:
[root@<IPA DOMAIN>] does not exist (negative cache)
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000):
Request type POSIX-only for domain <AD DOMAIN> type POSIX is valid
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [cache_req_process_result] (0x0400): CR #27:
Finished: Not found
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain <AD
DOMAIN> is Active
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [nss_protocol_done] (0x4000): Sending reply:
not found
(Wed Aug 21 14:10:01 2019) [sssd[nss]] [client_recv] (0x0200): Client disconnected! (Wed Aug 21 14:10:01 2019) [sssd[nss]] [client_close_fn] (0x2000): Terminated client
[0x559f771f0e20][21]
FreeIPA-users mailing list -- freeipa-users(a)lists.fedorahosted.org To unsubscribe send an email to freeipa-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/freeipa-users@lists.fedoraho...
So when I'm currently testing the NSS process starts and finishes right away after entering username at the prompt. Then it just sits there without a password prompt. Meanwhile on the server:
(Thu Aug 22 09:05:34 2019) [sssd[nss]] [cache_req_done] (0x0400): CR #69: Finished: Success (Thu Aug 22 09:05:34 2019) [sssd[nss]] [nss_protocol_done] (0x4000): Sending reply: success (Thu Aug 22 09:06:04 2019) [sssd[nss]] [setup_client_idle_timer] (0x4000): Idle timer re-set for client [0x5628cf451730][21] (Thu Aug 22 09:06:34 2019) [sssd[nss]] [setup_client_idle_timer] (0x4000): Idle timer re-set for client [0x5628cf451730][21] (Thu Aug 22 09:07:04 2019) [sssd[nss]] [client_idle_handler] (0x2000): Terminating idle client [0x5628cf451730][21] (Thu Aug 22 09:07:04 2019) [sssd[nss]] [client_close_fn] (0x2000): Terminated client [0x5628cf451730][21]
Sometimes the network connection gets reset, and you get an idle timeout like above. Sometimes the password prompt appears in time for me to enter a password, in which case /var/log/secure shows: 6 (Permission denied)
The slowness before the password prompt appearing happens only when using an AD account, but it happens on the server as well. However, on the server once the passw prompt appears you're able to successfully login with AD credentials...