<div dir="ltr"><div><div>Hello, </div>From time to time we are getting complaints that I can sum up as "I cannot log in to server X" </div><div>Here is a spinet of the /var/log/sssd/sssd_DOMAIN.log ... <div style="margin-left:40px">(Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [be_pam_handler] (0x0100): Got request with the following data (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): command: PAM_ACCT_MGMT (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): domain: <a href="http://4OVER.COM">4OVER.COM</a> (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): user: tradeftp (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): service: vsftpd (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): tty: ftp (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): ruser: tradeftp (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): rhost: <a href="http://mammoth.4over.com">mammoth.4over.com</a> (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): authtok type: 0 (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): authtok size: 0 (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): newauthtok type: 0 (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): newauthtok size: 0 (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): priv: 1 (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): cli_pid: 17841 (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [ipa_hbac_evaluate_rules] (0x0080): Access granted by HBAC rule [allow_all] (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 0, <NULL>) [Success] (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 0, Success) [Success] (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [be_pam_handler_callback] (0x0100): Sending result [0][<a href="http://4OVER.COM">4OVER.COM</a>] (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [be_pam_handler_callback] (0x0100): Sent result [0][<a href="http://4OVER.COM">4OVER.COM</a>] (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [be_pam_handler] (0x0100): Got request with the following data (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): command: PAM_SETCRED (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): domain: <a href="http://4OVER.COM">4OVER.COM</a> (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): user: tradeftp (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): service: vsftpd (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): tty: ftp (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): ruser: tradeftp (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): rhost: <a href="http://mammoth.4over.com">mammoth.4over.com</a> (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): authtok type: 0 (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): authtok size: 0 (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): newauthtok type: 0 (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): newauthtok size: 0 (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): priv: 1 (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [pam_print_data] (0x0100): cli_pid: 17841 (Mon Apr 15 09:36:59 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [be_pam_handler] (0x0100): Sending result [0][<a href="http://4OVER.COM">4OVER.COM</a>] (Mon Apr 15 09:37:00 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [be_get_account_info] (0x0100): Got request for [3][1][name=tradeftp] (Mon Apr 15 09:37:00 2013) [sssd[be[<a href="http://4OVER.COM">4OVER.COM</a>]]] [sdap_initgr_nested_search] (0x0040): Search for group cn=ipausers,cn=groups,cn=accounts,dc=4over,dc=com, returned 0 results. Skipping </div> </div><div>Here (more interesting) is the krb log file <div style="margin-left:40px">(Mon Apr 15 09:36:54 2013) [[sssd[krb5_child[17855]]]] [unpack_buffer] (0x0100): cmd [241] uid [6676] gid [104] validate [true] offline [false] UPN [<a href="mailto:tradeftp@4OVER.COM">tradeftp@4OVER.COM</a>] (Mon Apr 15 09:36:54 2013) [[sssd[krb5_child[17855]]]] [unpack_buffer] (0x0100): ccname: [FILE:/tmp/krb5cc_6676_0CTKUc] keytab: [/etc/krb5.keytab] (Mon Apr 15 09:36:54 2013) [[sssd[krb5_child[17855]]]] [krb5_child_setup] (0x0100): Cannot read [SSSD_KRB5_RENEWABLE_LIFETIME] from environment. (Mon Apr 15 09:36:54 2013) [[sssd[krb5_child[17855]]]] [krb5_child_setup] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from environment. (Mon Apr 15 09:36:54 2013) [[sssd[krb5_child[17855]]]] [krb5_set_canonicalize] (0x0100): SSSD_KRB5_CANONICALIZE is set to [true] (Mon Apr 15 09:36:54 2013) [[sssd[krb5_child[17855]]]] [krb5_child_setup] (0x0100): Not using FAST. (Mon Apr 15 09:36:56 2013) [[sssd[krb5_child[17862]]]] [unpack_buffer] (0x0100): cmd [241] uid [6676] gid [104] validate [true] offline [false] UPN [<a href="mailto:tradeftp@4OVER.COM">tradeftp@4OVER.COM</a>] (Mon Apr 15 09:36:56 2013) [[sssd[krb5_child[17862]]]] [unpack_buffer] (0x0100): ccname: [FILE:/tmp/krb5cc_6676_0CTKUc] keytab: [/etc/krb5.keytab] (Mon Apr 15 09:36:56 2013) [[sssd[krb5_child[17862]]]] [krb5_child_setup] (0x0100): Cannot read [SSSD_KRB5_RENEWABLE_LIFETIME] from environment. (Mon Apr 15 09:36:56 2013) [[sssd[krb5_child[17862]]]] [krb5_child_setup] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from environment. (Mon Apr 15 09:36:56 2013) [[sssd[krb5_child[17862]]]] [krb5_set_canonicalize] (0x0100): SSSD_KRB5_CANONICALIZE is set to [true] (Mon Apr 15 09:36:56 2013) [[sssd[krb5_child[17862]]]] [krb5_child_setup] (0x0100): Not using FAST. (Mon Apr 15 09:37:00 2013) [[sssd[krb5_child[17871]]]] [unpack_buffer] (0x0100): cmd [241] uid [6676] gid [104] validate [true] offline [false] UPN [<a href="mailto:tradeftp@4OVER.COM">tradeftp@4OVER.COM</a>] (Mon Apr 15 09:37:00 2013) [[sssd[krb5_child[17871]]]] [unpack_buffer] (0x0100): ccname: [FILE:/tmp/krb5cc_6676_0CTKUc] keytab: [/etc/krb5.keytab] (Mon Apr 15 09:37:00 2013) [[sssd[krb5_child[17871]]]] [krb5_child_setup] (0x0100): Cannot read [SSSD_KRB5_RENEWABLE_LIFETIME] from environment. (Mon Apr 15 09:37:00 2013) [[sssd[krb5_child[17871]]]] [krb5_child_setup] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from environment. (Mon Apr 15 09:37:00 2013) [[sssd[krb5_child[17871]]]] [krb5_set_canonicalize] (0x0100): SSSD_KRB5_CANONICALIZE is set to [true] (Mon Apr 15 09:37:00 2013) [[sssd[krb5_child[17871]]]] [krb5_child_setup] (0x0100): Not using FAST. (Mon Apr 15 09:37:01 2013) [[sssd[krb5_child[17881]]]] [unpack_buffer] (0x0100): cmd [241] uid [6676] gid [104] validate [true] offline [false] UPN [<a href="mailto:tradeftp@4OVER.COM">tradeftp@4OVER.COM</a>] (Mon Apr 15 09:37:01 2013) [[sssd[krb5_child[17881]]]] [unpack_buffer] (0x0100): ccname: [FILE:/tmp/krb5cc_6676_NgD4RE] keytab: [/etc/krb5.keytab] (Mon Apr 15 09:37:01 2013) [[sssd[krb5_child[17881]]]] [krb5_child_setup] (0x0100): Cannot read [SSSD_KRB5_RENEWABLE_LIFETIME] from environment. (Mon Apr 15 09:37:01 2013) [[sssd[krb5_child[17881]]]] [krb5_child_setup] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from environment. (Mon Apr 15 09:37:01 2013) [[sssd[krb5_child[17881]]]] [krb5_set_canonicalize] (0x0100): SSSD_KRB5_CANONICALIZE is set to [true] (Mon Apr 15 09:37:01 2013) [[sssd[krb5_child[17881]]]] [krb5_child_setup] (0x0100): Not using FAST. </div>Here is the ldap_child.log file... <div style="margin-left:40px">(Mon Apr 15 09:41:27 2013) [[sssd[ldap_child[18435]]]] [ldap_child_get_tgt_sync] (0x0100): Will canonicalize principals (Mon Apr 15 09:43:10 2013) [[sssd[ldap_child[18779]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [host/<a href="mailto:xx.la3.4over.com@4OVER.COM">xx.la3.4over.com@4OVER.COM</a>] (Mon Apr 15 09:43:10 2013) [[sssd[ldap_child[18779]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [default] (Mon Apr 15 09:43:10 2013) [[sssd[ldap_child[18779]]]] [ldap_child_get_tgt_sync] (0x0100): Will canonicalize principals (Mon Apr 15 09:43:10 2013) [[sssd[ldap_child[18779]]]] [ldap_child_get_tgt_sync] (0x0010): Failed to init credentials: Client 'host/<a href="mailto:xx.la3.4over.com@4OVER.COM">xx.la3.4over.com@4OVER.COM</a>' not found in Kerberos database (Mon Apr 15 09:43:10 2013) [[sssd[ldap_child[18779]]]] [main] (0x0020): ldap_child_get_tgt_sync failed. (Mon Apr 15 09:43:10 2013) [[sssd[ldap_child[18780]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [host/<a href="mailto:xx.la3.4over.com@4OVER.COM">xx.la3.4over.com@4OVER.COM</a>] (Mon Apr 15 09:43:10 2013) [[sssd[ldap_child[18780]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [default] (Mon Apr 15 09:43:10 2013) [[sssd[ldap_child[18780]]]] [ldap_child_get_tgt_sync] (0x0100): Will canonicalize principals (Mon Apr 15 09:43:55 2013) [[sssd[ldap_child[18884]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [host/<a href="mailto:xx.la3.4over.com@4OVER.COM">xx.la3.4over.com@4OVER.COM</a>] (Mon Apr 15 09:43:55 2013) [[sssd[ldap_child[18884]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [default] (Mon Apr 15 09:43:55 2013) [[sssd[ldap_child[18884]]]] [ldap_child_get_tgt_sync] (0x0100): Will canonicalize principals (Mon Apr 15 09:44:50 2013) [[sssd[ldap_child[19099]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [host/<a href="mailto:xx.la3.4over.com@4OVER.COM">xx.la3.4over.com@4OVER.COM</a>] (Mon Apr 15 09:44:50 2013) [[sssd[ldap_child[19099]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [default] (Mon Apr 15 09:44:50 2013) [[sssd[ldap_child[19099]]]] [ldap_child_get_tgt_sync] (0x0100): Will canonicalize principals (Mon Apr 15 09:59:46 2013) [[sssd[ldap_child[20244]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [host/<a href="mailto:xx.la3.4over.com@4OVER.COM">xx.la3.4over.com@4OVER.COM</a>] (Mon Apr 15 09:59:46 2013) [[sssd[ldap_child[20244]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [default] (Mon Apr 15 09:59:46 2013) [[sssd[ldap_child[20244]]]] [ldap_child_get_tgt_sync] (0x0100): Will canonicalize principals (Mon Apr 15 09:59:46 2013) [[sssd[ldap_child[20244]]]] [ldap_child_get_tgt_sync] (0x0010): Failed to init credentials: Client 'host/<a href="mailto:xx.la3.4over.com@4OVER.COM">xx.la3.4over.com@4OVER.COM</a>' not found in Kerberos database (Mon Apr 15 09:59:46 2013) [[sssd[ldap_child[20244]]]] [main] (0x0020): ldap_child_get_tgt_sync failed. (Mon Apr 15 09:59:46 2013) [[sssd[ldap_child[20245]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [host/<a href="mailto:xx.la3.4over.com@4OVER.COM">xx.la3.4over.com@4OVER.COM</a>] </div>Now restarting the SSSD daemon alleviates the issue - but the problem still creeps up after a day or two. I'm running 2.1.90.rc1 on CentOS 6.3 - I have 3 IPA servers that are multimaster. </div><div>--Christian </div><div></div></div>