[Freeipa-users] [FreeIPA] SUDO fails with system error

Thu Oct 1 12:14:34 UTC 2015

Dear @all,

I´ve an issue with two, Oracle Linux based, clients and my freeipa server. I can authenticate on any on the enrolled machines but the two oracle server aren´t able to access sudo and I don´t know why.

Here are a few thing I´ve already figured out.

Both machines are enrolled from scratch and I see following entries in ldap_child.log

(Thu Oct  1 12:51:52 2015) [[sssd[ldap_child[3933]]]] [ldap_child_get_tgt_sync] (0x0010): Failed to init credentials: Client 'host/<servername>@<domain>' not found in Kerberos database

(Thu Oct  1 12:51:52 2015) [[sssd[ldap_child[3934]]]] [ldap_child_get_tgt_sync] (0x0010): Failed to init credentials: Client 'host/<servername>@<domain>' not found in Kerberos database

Furthermore I get following entries in secure log

pam_unix(sudo:auth): authentication failure; logname=<username> uid=957400001 euid=0 tty=/dev/pts/1 ruser=<username> rhost=  user=<username>

pam_sss(sudo:auth): authentication failure; logname=<username> uid=957400001 euid=0 tty=/dev/pts/1 ruser=<username> rhost= user=<username>

pam_sss(sudo:auth): received for user <username>: 4 (System error)

Also I get following entries in sssd_pam.log

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [pam_check_user_search] (0x0400): Returning info for user [<username>@<domain>]

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [pam_initgr_cache_set] (0x2000): [<username>] added to PAM initgroup cache

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data:

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [pam_print_data] (0x0100): command: PAM_AUTHENTICATE

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [pam_print_data] (0x0100): domain: <domain>

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [pam_print_data] (0x0100): user: <username>

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [pam_print_data] (0x0100): service: sudo

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [pam_print_data] (0x0100): tty: /dev/pts/1

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [pam_print_data] (0x0100): ruser: <username>

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 1

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [pam_print_data] (0x0100): priv: 0

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 6457

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [pam_print_data] (0x0100): logon name: <username>

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x7f0d05f51ab0

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x7f0d04221ed0:3:<username>@<domain>]

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x7f0d05f51ab0

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x7f0d05f479e0

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching.

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [pam_dp_process_reply] (0x0100): received: [4][<domain>]

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [4].

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [pam_reply] (0x0200): blen: 26

(Thu Oct  1 14:06:14 2015) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7f0d05f51110][20]

(Thu Oct  1 14:06:17 2015) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7f0d05f51110][20]

(Thu Oct  1 14:06:17 2015) [sssd[pam]] [pam_cmd_authenticate] (0x0100): entering pam_cmd_authenticate

In krb5_child.log I get following entries

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [main] (0x0400): krb5_child started.

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [unpack_buffer] (0x1000): total buffer size: [129]

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [unpack_buffer] (0x0100): cmd [241] uid [957400001] gid [957400001] validate [true] enterprise principal [false] offline [false] UPN [<username>@<domain>]

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [unpack_buffer] (0x2000): No old ccache

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [unpack_buffer] (0x0100): ccname: [KEYRING:persistent:957400001] old_ccname: [not set] keytab: [/etc/krb5.keytab]

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [k5c_precreate_ccache] (0x4000): Recreating ccache

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [k5c_setup_fast] (0x0100): SSSD_KRB5_FAST_PRINCIPAL is set to [host/<host>@<domain>]

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [find_principal_in_keytab] (0x4000): Trying to find principal host/<host>@<domain> in keytab.

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [match_principal] (0x1000): Principal matched to the sample (host/<host>@<domain>).

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [check_fast_ccache] (0x0200): FAST TGT is still valid.

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [become_user] (0x0200): Trying to become user [957400001][957400001].

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [main] (0x2000): Running as [957400001][957400001].

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [k5c_setup] (0x2000): Running as [957400001][957400001].

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_RENEWABLE_LIFETIME] from environment.

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from environment.

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [set_canonicalize_option] (0x0100): SSSD_KRB5_CANONICALIZE is set to [true]

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [main] (0x0400): Will perform online auth

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [tgt_req_child] (0x1000): Attempting to get a TGT

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [get_and_save_tgt] (0x0400): Attempting kinit for realm [<DOMAIN>]

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [sss_child_krb5_trace_cb] (0x4000): [6458] 1443701174.736207: Getting initial credentials for <username>@<domain>

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [sss_child_krb5_trace_cb] (0x4000): [6458] 1443701174.736379: FAST armor ccache: MEMORY:/var/lib/sss/db/fast_ccache_<DOMAIN>

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [sss_child_krb5_trace_cb] (0x4000): [6458] 1443701174.736466: Retrieving host/<host>@<domain> -> krb5_ccache_conf_data/fast_avail/krbtgt\/<DOMAIN>\@<DOMAIN>@X-CACHECONF: from MEMORY:/var/lib/sss/db/fast_ccache_<DOMAIN> with result: -1765328243/Matching credential not found

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [sss_child_krb5_trace_cb] (0x4000): [6458] 1443701174.736618: Sending request (167 bytes) to <DOMAIN>

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [sss_child_krb5_trace_cb] (0x4000): [6458] 1443701174.736984: Initiating TCP connection to stream 10.46.155.120:88

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [sss_child_krb5_trace_cb] (0x4000): [6458] 1443701174.737944: Sending TCP request to stream 10.46.155.120:88

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [sss_child_krb5_trace_cb] (0x4000): [6458] 1443701174.740873: Received answer (356 bytes) from stream 10.46.155.120:88

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [sss_child_krb5_trace_cb] (0x4000): [6458] 1443701174.740920: Terminating TCP connection to stream 10.46.155.120:88

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [sss_child_krb5_trace_cb] (0x4000): [6458] 1443701174.741032: Response was from master KDC

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [sss_child_krb5_trace_cb] (0x4000): [6458] 1443701174.741096: Received error from KDC: -1765328359/Additional pre-authentication required

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [sss_child_krb5_trace_cb] (0x4000): [6458] 1443701174.741133: Upgrading to FAST due to presence of PA_FX_FAST in reply

(Thu Oct  1 14:06:14 2015) [[sssd[krb5_child[6458]]]] [sss_child_krb5_trace_cb] (0x4000): [6458] 1443701174.741151: Restarting to upgrade to FAST

Maybe someone is able and is willing to help. Thanks in advance

Markus

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/freeipa-users/attachments/20151001/4138b0b5/attachment.htm>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: PGP.sig
Type: application/pgp-signature
Size: 476 bytes
Desc: not available
URL: <http://listman.redhat.com/archives/freeipa-users/attachments/20151001/4138b0b5/attachment.sig>