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...