Thanks. Can someone give me a hint what I need to look at on the IPA
server?
I checked krb5kdc.log but it does not have anything interesting.
Qing
On 04/15/2015 02:50 AM, Jakub Hrozek wrote:
On Tue, Apr 14, 2015 at 03:15:15PM -0400, tmpchq wrote:
> started with level 6 and went up to 10 with pretty much the same logs.
>
> Look at the lines around the gap from 13:05:06 to 13:05:08. That's when the
> delay happened. Responders other than nss and pam did not log anything
> within
> that time span.
>
> It is this line that was waiting for response:
> (Tue Apr 14 13:05:06 2015) [sssd[pam]] [pam_dom_forwarder] (0x0100):
> pam_dp_send_req returned 0
>
> ----- sssd_nss.log -----
> (Tue Apr 14 13:05:06 2015) [sssd[nss]] [check_cache] (0x0400): Cached entry
> is valid, returning..
> (Tue Apr 14 13:05:06 2015) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0400):
> Returning info for user [qchang(a)mr.ric]
> (Tue Apr 14 13:05:06 2015) [sssd[nss]] [reset_idle_timer] (0x4000): Idle
> timer re-set for client [0x7f8a5b56cc60][20]
> (Tue Apr 14 13:05:06 2015) [sssd[nss]] [reset_idle_timer] (0x4000): Idle
> timer re-set for client [0x7f8a5b56cc60][20]
> (Tue Apr 14 13:05:06 2015) [sssd[nss]] [nss_cmd_getbynam] (0x0400): Running
> command [17] with input [qchang].
> (Tue Apr 14 13:05:06 2015) [sssd[nss]] [sss_parse_name_for_domains]
> (0x0200): name 'qchang' matched without domain, user is qchang
> (Tue Apr 14 13:05:06 2015) [sssd[nss]] [nss_cmd_getbynam] (0x0100):
> Requesting info for [qchang] from [<ALL>]
> (Tue Apr 14 13:05:06 2015) [sssd[nss]] [sss_ncache_check_str] (0x2000):
> Checking negative cache for [NCE/USER/mr.ric/qchang]
> (Tue Apr 14 13:05:06 2015) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100):
> Requesting info for [qchang(a)mr.ric]
> (Tue Apr 14 13:05:06 2015) [sssd[nss]] [ldb] (0x4000): Added timed event
> "ltdb_callback": 0x7f8a5b56c920
>
> (Tue Apr 14 13:05:06 2015) [sssd[nss]] [ldb] (0x4000): Added timed event
> "ltdb_timeout": 0x7f8a5b574840
>
> (Tue Apr 14 13:05:06 2015) [sssd[nss]] [ldb] (0x4000): Running timer event
> 0x7f8a5b56c920 "ltdb_callback"
>
> (Tue Apr 14 13:05:06 2015) [sssd[nss]] [ldb] (0x4000): Destroying timer
> event 0x7f8a5b574840 "ltdb_timeout"
>
> (Tue Apr 14 13:05:06 2015) [sssd[nss]] [ldb] (0x4000): Ending timer event
> 0x7f8a5b56c920 "ltdb_callback"
>
> (Tue Apr 14 13:05:06 2015) [sssd[nss]] [check_cache] (0x0400): Cached entry
> is valid, returning..
> (Tue Apr 14 13:05:06 2015) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0400):
> Returning info for user [qchang(a)mr.ric]
> (Tue Apr 14 13:05:06 2015) [sssd[nss]] [reset_idle_timer] (0x4000): Idle
> timer re-set for client [0x7f8a5b56cc60][20]
> (Tue Apr 14 13:05:08 2015) [sssd[nss]] [get_client_cred] (0x4000): Client
> creds: euid[81] egid[81] pid[503].
> (Tue Apr 14 13:05:08 2015) [sssd[nss]] [reset_idle_timer] (0x4000): Idle
> timer re-set for client [0x7f8a5b574840][21]
> (Tue Apr 14 13:05:08 2015) [sssd[nss]] [accept_fd_handler] (0x0400): Client
> connected!
> (Tue Apr 14 13:05:08 2015) [sssd[nss]] [reset_idle_timer] (0x4000): Idle
> timer re-set for client [0x7f8a5b574840][21]
> (Tue Apr 14 13:05:08 2015) [sssd[nss]] [sss_cmd_get_version] (0x0200):
> Received client version [1].
> (Tue Apr 14 13:05:08 2015) [sssd[nss]] [sss_cmd_get_version] (0x0200):
> Offered version [1].
> (Tue Apr 14 13:05:08 2015) [sssd[nss]] [reset_idle_timer] (0x4000): Idle
> timer re-set for client [0x7f8a5b574840][21]
> (Tue Apr 14 13:05:08 2015) [sssd[nss]] [reset_idle_timer] (0x4000): Idle
> timer re-set for client [0x7f8a5b574840][21]
> (Tue Apr 14 13:05:08 2015) [sssd[nss]] [nss_cmd_getbynam] (0x0400): Running
> command [38] with input [root].
> (Tue Apr 14 13:05:08 2015) [sssd[nss]] [sss_parse_name_for_domains]
> (0x0200): name 'root' matched without domain, user is root
> (Tue Apr 14 13:05:08 2015) [sssd[nss]] [nss_cmd_getbynam] (0x0100):
> Requesting info for [root] from [<ALL>]
> (Tue Apr 14 13:05:08 2015) [sssd[nss]] [sss_ncache_check_str] (0x2000):
> Checking negative cache for [NCE/USER/mr.ric/root]
> (Tue Apr 14 13:05:08 2015) [sssd[nss]] [nss_cmd_initgroups_search] (0x0400):
> User [root] does not exist in [mr.ric]! (negative cache)
> (Tue Apr 14 13:05:08 2015) [sssd[nss]] [nss_cmd_initgroups_search] (0x0080):
> No matching domain found for [root], fail!
> -----
> ----- sssd_pam.log -----
> (Tue Apr 14 13:05:06 2015) [sssd[pam]] [pam_check_user_search] (0x0400):
> Returning info for user [qchang(a)mr.ric]
> (Tue Apr 14 13:05:06 2015) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending
> request with the following data:
> (Tue Apr 14 13:05:06 2015) [sssd[pam]] [pam_print_data] (0x0100): command:
> PAM_ACCT_MGMT
> (Tue Apr 14 13:05:06 2015) [sssd[pam]] [pam_print_data] (0x0100): domain:
> mr.ric
> (Tue Apr 14 13:05:06 2015) [sssd[pam]] [pam_print_data] (0x0100): user:
> qchang
> (Tue Apr 14 13:05:06 2015) [sssd[pam]] [pam_print_data] (0x0100): service:
> sshd
> (Tue Apr 14 13:05:06 2015) [sssd[pam]] [pam_print_data] (0x0100): tty: ssh
> (Tue Apr 14 13:05:06 2015) [sssd[pam]] [pam_print_data] (0x0100): ruser: not
> set
> (Tue Apr 14 13:05:06 2015) [sssd[pam]] [pam_print_data] (0x0100): rhost:
> 172.25.12.157
> (Tue Apr 14 13:05:06 2015) [sssd[pam]] [pam_print_data] (0x0100): authtok
> type: 0
> (Tue Apr 14 13:05:06 2015) [sssd[pam]] [pam_print_data] (0x0100): newauthtok
> type: 0
> (Tue Apr 14 13:05:06 2015) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
> (Tue Apr 14 13:05:06 2015) [sssd[pam]] [pam_print_data] (0x0100): cli_pid:
> 7402
> (Tue Apr 14 13:05:06 2015) [sssd[pam]] [pam_print_data] (0x0100): logon
> name: qchang
> (Tue Apr 14 13:05:06 2015) [sssd[pam]] [sbus_add_timeout] (0x2000):
> 0x7f1aff4200a0
> (Tue Apr 14 13:05:06 2015) [sssd[pam]] [pam_dom_forwarder] (0x0100):
> pam_dp_send_req returned 0
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [sbus_remove_timeout] (0x2000):
> 0x7f1aff4200a0
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn:
> 0x7f1aff41ddd0
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [sbus_dispatch] (0x4000):
> Dispatching.
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [pam_dp_process_reply] (0x0100):
> received: [0][mr.ric]
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [pam_reply] (0x0200): pam_reply
> called with result [0].
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [pam_reply] (0x0200): blen: 23
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [reset_idle_timer] (0x4000): Idle
> timer re-set for client [0x7f1aff421b40][19]
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [reset_idle_timer] (0x4000): Idle
> timer re-set for client [0x7f1aff421b40][19]
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [pam_cmd_setcred] (0x0100): entering
> pam_cmd_setcred
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [sss_parse_name_for_domains]
> (0x0200): name 'qchang' matched without domain, user is qchang
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [pam_print_data] (0x0100): command:
> PAM_SETCRED
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [pam_print_data] (0x0100): domain:
> not set
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [pam_print_data] (0x0100): user:
> qchang
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [pam_print_data] (0x0100): service:
> sshd
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [pam_print_data] (0x0100): tty: ssh
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [pam_print_data] (0x0100): ruser: not
> set
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [pam_print_data] (0x0100): rhost:
> 172.25.12.157
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [pam_print_data] (0x0100): authtok
> type: 0
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [pam_print_data] (0x0100): newauthtok
> type: 0
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [pam_print_data] (0x0100): cli_pid:
> 7402
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [pam_print_data] (0x0100): logon
> name: qchang
> (Tue Apr 14 13:05:08 2015) [sssd[pam]] [sss_ncache_check_str] (0x2000):
> Checking negative cache for [NCE/USER/mr.ric/qchang]
> -----
The logs are incomplete, moreover we also need the back end logs to be sure.
From the snippet you sent, I only see the account phase is taking 2
seconds. It's impossible what exactly is taking long without the domain
logs.
_______________________________________________
sssd-users mailing list
sssd-users(a)lists.fedorahosted.org
https://lists.fedorahosted.org/mailman/listinfo/sssd-users