Discussion:
Centos IPA Client fails after upgrade to 6.6
(too old to reply)
David Taylor
2014-10-31 01:23:29 UTC
Permalink
I just recently updated one of our test servers from CentOS 6.5 to CentOS 6.6, after which I noticed that IPA logons were no longer available. From what I can see the upgrade includes quite a few changes with regard to sssd.


- NTP is up and synced on the Auth servers and the client.

- DNS is working to the IPA servers

- I can do a kinit for users with no problem

- I have uninstalled the ipa client, deleted the host profile on the IPA server and one a rejoin. The rejoin worked but the problem is the same.

Software versions using

- rpm -qa | grep -i ipa

- rpm -qa | grep -i sssd

Software versions before:
libipa_hbac-1.9.2-129.el6_5.4.x86_64
device-mapper-multipath-0.4.9-72.el6_5.4.x86_64
libipa_hbac-python-1.9.2-129.el6_5.4.x86_64
ipa-python-3.0.0-37.el6.x86_64
ipa-client-3.0.0-37.el6.x86_64
device-mapper-multipath-libs-0.4.9-72.el6_5.4.x86_64
sssd-1.9.2-129.el6_5.4.x86_64
sssd-client-1.9.2-129.el6_5.4.x86_64

Software version after:
sssd-ipa-1.11.6-30.el6.x86_64
libipa_hbac-1.11.6-30.el6.x86_64
device-mapper-multipath-libs-0.4.9-80.el6.x86_64
ipa-client-3.0.0-42.el6.centos.x86_64
libipa_hbac-python-1.11.6-30.el6.x86_64
ipa-python-3.0.0-42.el6.centos.x86_64
device-mapper-multipath-0.4.9-80.el6.x86_64
sssd-ldap-1.11.6-30.el6.x86_64
sssd-ad-1.11.6-30.el6.x86_64
python-sssdconfig-1.11.6-30.el6.noarch
sssd-client-1.11.6-30.el6.x86_64
sssd-krb5-common-1.11.6-30.el6.x86_64
sssd-ipa-1.11.6-30.el6.x86_64
sssd-common-1.11.6-30.el6.x86_64
sssd-proxy-1.11.6-30.el6.x86_64
sssd-common-pac-1.11.6-30.el6.x86_64
sssd-krb5-1.11.6-30.el6.x86_64
sssd-1.11.6-30.el6.x86_64
The /var/log/secure logs show the following

Oct 31 10:38:30 test01 sshd[2790]: Invalid user dtaylor from <ip removed>
Oct 31 10:38:30 test01 sshd[2791]: input_userauth_request: invalid user dtaylor
Oct 31 10:38:30 test01 sshd[2790]: pam_unix(sshd:auth): check pass; user unknown
Oct 31 10:38:30 test01 sshd[2790]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=<host removed>
Oct 31 10:38:30 test01 sshd[2790]: pam_succeed_if(sshd:auth): error retrieving information about user dtaylor

The /var/log/audit/audit.log logs show the following

type=CRYPTO_KEY_USER msg=audit(1414715857.270:107): user pid=5831 uid=0 auid=0 ses=1 msg='op=destroy kind=server fp=5e:ee:58:a2:25:ec:16:3e:8c:61:01:e6:de:76:3d:32 direction=? spid=5831 suid=0 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=? res=success'
type=CRYPTO_KEY_USER msg=audit(1414715857.270:108): user pid=5831 uid=0 auid=0 ses=1 msg='op=destroy kind=server fp=d0:6f:2f:5f:49:44:94:f2:b2:4e:15:43:69:89:9c:1d direction=? spid=5831 suid=0 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=? res=success'
type=CRYPTO_SESSION msg=audit(1414715857.272:109): user pid=5830 uid=0 auid=0 ses=1 msg='op=start direction=from-client cipher=aes256-ctr ksize=256 spid=5831 suid=74 rport=44361 laddr=<Client ip removed> lport=22 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=? res=success'
type=CRYPTO_SESSION msg=audit(1414715857.272:110): user pid=5830 uid=0 auid=0 ses=1 msg='op=start direction=from-server cipher=aes256-ctr ksize=256 spid=5831 suid=74 rport=44361 laddr=<Client ip removed> lport=22 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=? res=success'
type=USER_LOGIN msg=audit(1414715857.310:111): user pid=5830 uid=0 auid=0 ses=1 msg='op=login acct=28756E6B6E6F776E207573657229 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=ssh res=failed'
type=USER_AUTH msg=audit(1414715859.211:112): user pid=5830 uid=0 auid=0 ses=1 msg='op=PAM:authentication acct="?" exe="/usr/sbin/sshd" hostname=<hostname removed> addr=<ip removed> terminal=ssh res=failed'
type=USER_AUTH msg=audit(1414715859.212:113): user pid=5830 uid=0 auid=0 ses=1 msg='op=password acct=28696E76616C6964207573657229 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=ssh res=failed'
type=CRYPTO_KEY_USER msg=audit(1414715862.076:114): user pid=5830 uid=0 auid=0 ses=1 msg='op=destroy kind=session fp=? direction=both spid=5831 suid=74 rport=44361 laddr=<Client ip removed> lport=22 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=? res=success'
type=CRYPTO_KEY_USER msg=audit(1414715862.078:115): user pid=5830 uid=0 auid=0 ses=1 msg='op=destroy kind=server fp=5e:ee:58:a2:25:ec:16:3e:8c:61:01:e6:de:76:3d:32 direction=? spid=5830 suid=0 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=? res=success'
type=CRYPTO_KEY_USER msg=audit(1414715862.079:116): user pid=5830 uid=0 auid=0 ses=1 msg='op=destroy kind=server fp=d0:6f:2f:5f:49:44:94:f2:b2:4e:15:43:69:89:9c:1d direction=? spid=5830 suid=0 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=? res=success'
type=USER_LOGIN msg=audit(1414715862.079:117): user pid=5830 uid=0 auid=0 ses=1 msg='op=login acct=28696E76616C6964207573657229 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=ssh res=failed'

The /var/log/sssd/sssd_<IPA Svr IP removed>.log logs show the following

==> /var/log/sssd/sssd_<IPA Svr IP removed>.log <==
(Fri Oct 31 12:13:39 2014) [sssd[be[<IPA Svr IP removed>]]] [sbus_dispatch] (0x4000): dbus conn: 0x16699b0
(Fri Oct 31 12:13:39 2014) [sssd[be[<IPA Svr IP removed>]]] [sbus_dispatch] (0x4000): Dispatching.
(Fri Oct 31 12:13:39 2014) [sssd[be[<IPA Svr IP removed>]]] [sbus_message_handler] (0x4000): Received SBUS method [ping]
(Fri Oct 31 12:13:39 2014) [sssd[be[<IPA Svr IP removed>]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Fri Oct 31 12:13:39 2014) [sssd[be[<IPA Svr IP removed>]]] [sbus_handler_got_caller_id] (0x4000): Received SBUS method [ping]
Jakub Hrozek
2014-10-31 08:35:18 UTC
Permalink
Post by David Taylor
I just recently updated one of our test servers from CentOS 6.5 to CentOS 6.6, after which I noticed that IPA logons were no longer available. From what I can see the upgrade includes quite a few changes with regard to sssd.
- NTP is up and synced on the Auth servers and the client.
- DNS is working to the IPA servers
- I can do a kinit for users with no problem
- I have uninstalled the ipa client, deleted the host profile on the IPA server and one a rejoin. The rejoin worked but the problem is the same.
Software versions using
- rpm -qa | grep -i ipa
- rpm -qa | grep -i sssd
libipa_hbac-1.9.2-129.el6_5.4.x86_64
device-mapper-multipath-0.4.9-72.el6_5.4.x86_64
libipa_hbac-python-1.9.2-129.el6_5.4.x86_64
ipa-python-3.0.0-37.el6.x86_64
ipa-client-3.0.0-37.el6.x86_64
device-mapper-multipath-libs-0.4.9-72.el6_5.4.x86_64
sssd-1.9.2-129.el6_5.4.x86_64
sssd-client-1.9.2-129.el6_5.4.x86_64
sssd-ipa-1.11.6-30.el6.x86_64
libipa_hbac-1.11.6-30.el6.x86_64
device-mapper-multipath-libs-0.4.9-80.el6.x86_64
ipa-client-3.0.0-42.el6.centos.x86_64
libipa_hbac-python-1.11.6-30.el6.x86_64
ipa-python-3.0.0-42.el6.centos.x86_64
device-mapper-multipath-0.4.9-80.el6.x86_64
sssd-ldap-1.11.6-30.el6.x86_64
sssd-ad-1.11.6-30.el6.x86_64
python-sssdconfig-1.11.6-30.el6.noarch
sssd-client-1.11.6-30.el6.x86_64
sssd-krb5-common-1.11.6-30.el6.x86_64
sssd-ipa-1.11.6-30.el6.x86_64
sssd-common-1.11.6-30.el6.x86_64
sssd-proxy-1.11.6-30.el6.x86_64
sssd-common-pac-1.11.6-30.el6.x86_64
sssd-krb5-1.11.6-30.el6.x86_64
sssd-1.11.6-30.el6.x86_64
The /var/log/secure logs show the following
Oct 31 10:38:30 test01 sshd[2790]: Invalid user dtaylor from <ip removed>
Oct 31 10:38:30 test01 sshd[2791]: input_userauth_request: invalid user dtaylor
Oct 31 10:38:30 test01 sshd[2790]: pam_unix(sshd:auth): check pass; user unknown
Oct 31 10:38:30 test01 sshd[2790]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=<host removed>
Oct 31 10:38:30 test01 sshd[2790]: pam_succeed_if(sshd:auth): error retrieving information about user dtaylor
Do you also see pam_sss being mentioned at all in your /var/log/secure at all? Can you paste your PAM configuration? It’s expected that pam_unix fails to find the IPA user, but I would also expect the PAM stack to ask pam_sss next...
Post by David Taylor
The /var/log/audit/audit.log logs show the following
type=CRYPTO_KEY_USER msg=audit(1414715857.270:107): user pid=5831 uid=0 auid=0 ses=1 msg='op=destroy kind=server fp=5e:ee:58:a2:25:ec:16:3e:8c:61:01:e6:de:76:3d:32 direction=? spid=5831 suid=0 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=? res=success'
type=CRYPTO_KEY_USER msg=audit(1414715857.270:108): user pid=5831 uid=0 auid=0 ses=1 msg='op=destroy kind=server fp=d0:6f:2f:5f:49:44:94:f2:b2:4e:15:43:69:89:9c:1d direction=? spid=5831 suid=0 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=? res=success'
type=CRYPTO_SESSION msg=audit(1414715857.272:109): user pid=5830 uid=0 auid=0 ses=1 msg='op=start direction=from-client cipher=aes256-ctr ksize=256 spid=5831 suid=74 rport=44361 laddr=<Client ip removed> lport=22 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=? res=success'
type=CRYPTO_SESSION msg=audit(1414715857.272:110): user pid=5830 uid=0 auid=0 ses=1 msg='op=start direction=from-server cipher=aes256-ctr ksize=256 spid=5831 suid=74 rport=44361 laddr=<Client ip removed> lport=22 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=? res=success'
type=USER_LOGIN msg=audit(1414715857.310:111): user pid=5830 uid=0 auid=0 ses=1 msg='op=login acct=28756E6B6E6F776E207573657229 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=ssh res=failed'
type=USER_AUTH msg=audit(1414715859.211:112): user pid=5830 uid=0 auid=0 ses=1 msg='op=PAM:authentication acct="?" exe="/usr/sbin/sshd" hostname=<hostname removed> addr=<ip removed> terminal=ssh res=failed'
type=USER_AUTH msg=audit(1414715859.212:113): user pid=5830 uid=0 auid=0 ses=1 msg='op=password acct=28696E76616C6964207573657229 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=ssh res=failed'
type=CRYPTO_KEY_USER msg=audit(1414715862.076:114): user pid=5830 uid=0 auid=0 ses=1 msg='op=destroy kind=session fp=? direction=both spid=5831 suid=74 rport=44361 laddr=<Client ip removed> lport=22 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=? res=success'
type=CRYPTO_KEY_USER msg=audit(1414715862.078:115): user pid=5830 uid=0 auid=0 ses=1 msg='op=destroy kind=server fp=5e:ee:58:a2:25:ec:16:3e:8c:61:01:e6:de:76:3d:32 direction=? spid=5830 suid=0 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=? res=success'
type=CRYPTO_KEY_USER msg=audit(1414715862.079:116): user pid=5830 uid=0 auid=0 ses=1 msg='op=destroy kind=server fp=d0:6f:2f:5f:49:44:94:f2:b2:4e:15:43:69:89:9c:1d direction=? spid=5830 suid=0 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=? res=success'
type=USER_LOGIN msg=audit(1414715862.079:117): user pid=5830 uid=0 auid=0 ses=1 msg='op=login acct=28696E76616C6964207573657229 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=ssh res=failed'
The /var/log/sssd/sssd_<IPA Svr IP removed>.log logs show the following
==> /var/log/sssd/sssd_<IPA Svr IP removed>.log <==
(Fri Oct 31 12:13:39 2014) [sssd[be[<IPA Svr IP removed>]]] [sbus_dispatch] (0x4000): dbus conn: 0x16699b0
(Fri Oct 31 12:13:39 2014) [sssd[be[<IPA Svr IP removed>]]] [sbus_dispatch] (0x4000): Dispatching.
(Fri Oct 31 12:13:39 2014) [sssd[be[<IPA Svr IP removed>]]] [sbus_message_handler] (0x4000): Received SBUS method [ping]
(Fri Oct 31 12:13:39 2014) [sssd[be[<IPA Svr IP removed>]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Fri Oct 31 12:13:39 2014) [sssd[be[<IPA Svr IP removed>]]] [sbus_handler_got_caller_id] (0x4000): Received SBUS method [ping]
These are just heartbeats between sssd_be and the main sssd process, not a real activity.
Post by David Taylor
--
https://www.redhat.com/mailman/listinfo/freeipa-users
Go To http://freeipa.org for more info on the project
--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go To http://freeipa.org for more
David Taylor
2014-11-05 02:30:55 UTC
Permalink
Thanks for the reply. The PAM file is pretty stock for a centos build

#%PAM-1.0
# This file is auto-generated.
# User changes will be destroyed the next time authconfig is run.
auth required pam_env.so
auth sufficient pam_unix.so nullok try_first_pass
auth requisite pam_succeed_if.so uid >= 500 quiet
auth sufficient pam_sss.so use_first_pass
auth required pam_deny.so

account required pam_unix.so
account sufficient pam_localuser.so
account sufficient pam_succeed_if.so uid < 500 quiet
account [default=bad success=ok user_unknown=ignore] pam_sss.so
account required pam_permit.so

password requisite pam_cracklib.so try_first_pass retry=3 type=
password sufficient pam_unix.so sha512 shadow nullok try_first_pass use_authtok
password sufficient pam_sss.so use_authtok
password required pam_deny.so

session optional pam_keyinit.so revoke
session required pam_limits.so
session [success=1 default=ignore] pam_succeed_if.so service in crond quiet use_uid
session required pam_unix.so
session optional pam_sss.so


Best regards
David Taylor


-----Original Message-----
From: Jakub Hrozek [mailto:***@redhat.com]
Sent: Friday, 31 October 2014 7:35 PM
To: David Taylor
Cc: freeipa-***@redhat.com
Subject: Re: [Freeipa-users] Centos IPA Client fails after upgrade to 6.6
Post by David Taylor
I just recently updated one of our test servers from CentOS 6.5 to CentOS 6.6, after which I noticed that IPA logons were no longer available. From what I can see the upgrade includes quite a few changes with regard to sssd.
- NTP is up and synced on the Auth servers and the client.
- DNS is working to the IPA servers
- I can do a kinit for users with no problem
- I have uninstalled the ipa client, deleted the host profile on the IPA server and one a rejoin. The rejoin worked but the problem is the same.
Software versions using
- rpm -qa | grep -i ipa
- rpm -qa | grep -i sssd
libipa_hbac-1.9.2-129.el6_5.4.x86_64
device-mapper-multipath-0.4.9-72.el6_5.4.x86_64
libipa_hbac-python-1.9.2-129.el6_5.4.x86_64
ipa-python-3.0.0-37.el6.x86_64
ipa-client-3.0.0-37.el6.x86_64
device-mapper-multipath-libs-0.4.9-72.el6_5.4.x86_64
sssd-1.9.2-129.el6_5.4.x86_64
sssd-client-1.9.2-129.el6_5.4.x86_64
sssd-ipa-1.11.6-30.el6.x86_64
libipa_hbac-1.11.6-30.el6.x86_64
device-mapper-multipath-libs-0.4.9-80.el6.x86_64
ipa-client-3.0.0-42.el6.centos.x86_64
libipa_hbac-python-1.11.6-30.el6.x86_64
ipa-python-3.0.0-42.el6.centos.x86_64
device-mapper-multipath-0.4.9-80.el6.x86_64
sssd-ldap-1.11.6-30.el6.x86_64
sssd-ad-1.11.6-30.el6.x86_64
python-sssdconfig-1.11.6-30.el6.noarch
sssd-client-1.11.6-30.el6.x86_64
sssd-krb5-common-1.11.6-30.el6.x86_64
sssd-ipa-1.11.6-30.el6.x86_64
sssd-common-1.11.6-30.el6.x86_64
sssd-proxy-1.11.6-30.el6.x86_64
sssd-common-pac-1.11.6-30.el6.x86_64
sssd-krb5-1.11.6-30.el6.x86_64
sssd-1.11.6-30.el6.x86_64
The /var/log/secure logs show the following
Oct 31 10:38:30 test01 sshd[2790]: Invalid user dtaylor from <ip
pam_unix(sshd:auth): check pass; user unknown Oct 31 10:38:30 test01
sshd[2790]: pam_unix(sshd:auth): authentication failure; logname=
uid=0 euid=0 tty=ssh ruser= rhost=<host removed> Oct 31 10:38:30
test01 sshd[2790]: pam_succeed_if(sshd:auth): error retrieving
information about user dtaylor
Do you also see pam_sss being mentioned at all in your /var/log/secure at all? Can you paste your PAM configuration? It’s expected that pam_unix fails to find the IPA user, but I would also expect the PAM stack to ask pam_sss next...
Post by David Taylor
The /var/log/audit/audit.log logs show the following
type=CRYPTO_KEY_USER msg=audit(1414715857.270:107): user pid=5831 uid=0 auid=0 ses=1 msg='op=destroy kind=server fp=5e:ee:58:a2:25:ec:16:3e:8c:61:01:e6:de:76:3d:32 direction=? spid=5831 suid=0 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=? res=success'
type=CRYPTO_KEY_USER msg=audit(1414715857.270:108): user pid=5831 uid=0 auid=0 ses=1 msg='op=destroy kind=server fp=d0:6f:2f:5f:49:44:94:f2:b2:4e:15:43:69:89:9c:1d direction=? spid=5831 suid=0 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=? res=success'
type=CRYPTO_SESSION msg=audit(1414715857.272:109): user pid=5830 uid=0 auid=0 ses=1 msg='op=start direction=from-client cipher=aes256-ctr ksize=256 spid=5831 suid=74 rport=44361 laddr=<Client ip removed> lport=22 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=? res=success'
type=CRYPTO_SESSION msg=audit(1414715857.272:110): user pid=5830 uid=0 auid=0 ses=1 msg='op=start direction=from-server cipher=aes256-ctr ksize=256 spid=5831 suid=74 rport=44361 laddr=<Client ip removed> lport=22 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=? res=success'
type=USER_LOGIN msg=audit(1414715857.310:111): user pid=5830 uid=0 auid=0 ses=1 msg='op=login acct=28756E6B6E6F776E207573657229 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=ssh res=failed'
type=USER_AUTH msg=audit(1414715859.211:112): user pid=5830 uid=0 auid=0 ses=1 msg='op=PAM:authentication acct="?" exe="/usr/sbin/sshd" hostname=<hostname removed> addr=<ip removed> terminal=ssh res=failed'
type=USER_AUTH msg=audit(1414715859.212:113): user pid=5830 uid=0 auid=0 ses=1 msg='op=password acct=28696E76616C6964207573657229 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=ssh res=failed'
type=CRYPTO_KEY_USER msg=audit(1414715862.076:114): user pid=5830 uid=0 auid=0 ses=1 msg='op=destroy kind=session fp=? direction=both spid=5831 suid=74 rport=44361 laddr=<Client ip removed> lport=22 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=? res=success'
type=CRYPTO_KEY_USER msg=audit(1414715862.078:115): user pid=5830 uid=0 auid=0 ses=1 msg='op=destroy kind=server fp=5e:ee:58:a2:25:ec:16:3e:8c:61:01:e6:de:76:3d:32 direction=? spid=5830 suid=0 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=? res=success'
type=CRYPTO_KEY_USER msg=audit(1414715862.079:116): user pid=5830 uid=0 auid=0 ses=1 msg='op=destroy kind=server fp=d0:6f:2f:5f:49:44:94:f2:b2:4e:15:43:69:89:9c:1d direction=? spid=5830 suid=0 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=? res=success'
type=USER_LOGIN msg=audit(1414715862.079:117): user pid=5830 uid=0 auid=0 ses=1 msg='op=login acct=28696E76616C6964207573657229 exe="/usr/sbin/sshd" hostname=? addr=<ip removed> terminal=ssh res=failed'
The /var/log/sssd/sssd_<IPA Svr IP removed>.log logs show the
following
==> /var/log/sssd/sssd_<IPA Svr IP removed>.log <== (Fri Oct 31
12:13:39 2014) [sssd[be[<IPA Svr IP removed>]]] [sbus_dispatch]
(0x4000): dbus conn: 0x16699b0 (Fri Oct 31 12:13:39 2014) [sssd[be[<IPA Svr IP removed>]]] [sbus_dispatch] (0x4000): Dispatching.
(Fri Oct 31 12:13:39 2014) [sssd[be[<IPA Svr IP removed>]]]
[sbus_message_handler] (0x4000): Received SBUS method [ping] (Fri Oct
31 12:13:39 2014) [sssd[be[<IPA Svr IP removed>]]]
[sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Fri
Oct 31 12:13:39 2014) [sssd[be[<IPA Svr IP removed>]]]
[sbus_handler_got_caller_id] (0x4000): Received SBUS method [ping]
These are just heartbeats between sssd_be and the main sssd process, not a real activity.
Post by David Taylor
--
https://www.redhat.com/mailman/listinfo/freeipa-users
Go To http://freeipa.org for more info on the project
--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go To http://freeipa.org for more info on the proj
Jakub Hrozek
2014-11-05 09:05:07 UTC
Permalink
Post by David Taylor
Thanks for the reply. The PAM file is pretty stock for a centos build
#%PAM-1.0
# This file is auto-generated.
# User changes will be destroyed the next time authconfig is run.
auth required pam_env.so
auth sufficient pam_unix.so nullok try_first_pass
auth requisite pam_succeed_if.so uid >= 500 quiet
auth sufficient pam_sss.so use_first_pass
auth required pam_deny.so
account required pam_unix.so
account sufficient pam_localuser.so
account sufficient pam_succeed_if.so uid < 500 quiet
account [default=bad success=ok user_unknown=ignore] pam_sss.so
account required pam_permit.so
password requisite pam_cracklib.so try_first_pass retry=3 type=
password sufficient pam_unix.so sha512 shadow nullok try_first_pass use_authtok
password sufficient pam_sss.so use_authtok
password required pam_deny.so
session optional pam_keyinit.so revoke
session required pam_limits.so
session [success=1 default=ignore] pam_succeed_if.so service in crond quiet use_uid
session required pam_unix.so
session optional pam_sss.so
Best regards
David Taylor
OK, so pam_sss is there ...

And yet you see no mention of pam_sss.so in /var/log/secure ?

Is this the file that was included from the service-specific PAM
configuration?
--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go To http://freeipa.org for more info on the project
Michael Lasevich
2014-11-07 05:00:04 UTC
Permalink
I am seeing somewhat similar behavior once upgrading from sssd 1.9 to 1.11
(centos 6.5 to 6.6)

I seem to be able to log in via ssh, but when I use http pam service, I get
inconsistent behavior - seems like sometimes it works and others it errors
out (success and failure can happen within a second)

In the logs I see things like:

[sssd[krb5_child[15410]]]: Internal credentials cache error

and

authentication failure; logname= uid=48 euid=48 tty= ruser= rhost=
user=username
received for user username: 4 (System error)

Nothing in the audit.log that I can see

I am guessing this is an sssd issue but I am hoping someone here knows how
to deal with it.

IN case it matters - here is the pam config:

auth required pam_env.so
auth sufficient pam_sss.so
auth required pam_deny.so

account [default=bad success=ok user_unknown=ignore] pam_sss.so
account required pam_permit.so

password requisite pam_cracklib.so try_first_pass retry=3 type=
password sufficient pam_sss.so use_authtok
password required pam_deny.so


session optional pam_keyinit.so revoke
session required pam_limits.so
session optional pam_oddjob_mkhomedir.so
session [success=1 default=ignore] pam_succeed_if.so service in crond
quiet use_uid
session optional pam_sss.so

-M
Post by David Taylor
Post by David Taylor
Thanks for the reply. The PAM file is pretty stock for a centos build
#%PAM-1.0
# This file is auto-generated.
# User changes will be destroyed the next time authconfig is run.
auth required pam_env.so
auth sufficient pam_unix.so nullok try_first_pass
auth requisite pam_succeed_if.so uid >= 500 quiet
auth sufficient pam_sss.so use_first_pass
auth required pam_deny.so
account required pam_unix.so
account sufficient pam_localuser.so
account sufficient pam_succeed_if.so uid < 500 quiet
account [default=bad success=ok user_unknown=ignore] pam_sss.so
account required pam_permit.so
password requisite pam_cracklib.so try_first_pass retry=3 type=
password sufficient pam_unix.so sha512 shadow nullok
try_first_pass use_authtok
Post by David Taylor
password sufficient pam_sss.so use_authtok
password required pam_deny.so
session optional pam_keyinit.so revoke
session required pam_limits.so
session [success=1 default=ignore] pam_succeed_if.so service in
crond quiet use_uid
Post by David Taylor
session required pam_unix.so
session optional pam_sss.so
Best regards
David Taylor
OK, so pam_sss is there ...
And yet you see no mention of pam_sss.so in /var/log/secure ?
Is this the file that was included from the service-specific PAM
configuration?
--
https://www.redhat.com/mailman/listinfo/freeipa-users
Go To http://freeipa.org for more info on the project
David Taylor
2014-11-07 05:26:32 UTC
Permalink
As an add on, I’ve upgraded our Xen template to 6.6 and run up a new VM using that and it attaches to the IPA environment perfectly well, so I’m guessing it is an issue with the upgrade scripts.


Best regards
David Taylor

From: Michael Lasevich [mailto:***@gmail.com]
Sent: Friday, 7 November 2014 4:00 PM
To: Jakub Hrozek
Cc: David Taylor; freeipa-***@redhat.com
Subject: Re: [Freeipa-users] Centos IPA Client fails after upgrade to 6.6

I am seeing somewhat similar behavior once upgrading from sssd 1.9 to 1.11 (centos 6.5 to 6.6)

I seem to be able to log in via ssh, but when I use http pam service, I get inconsistent behavior - seems like sometimes it works and others it errors out (success and failure can happen within a second)

In the logs I see things like:

[sssd[krb5_child[15410]]]: Internal credentials cache error
and
authentication failure; logname= uid=48 euid=48 tty= ruser= rhost= user=username
received for user username: 4 (System error)
Nothing in the audit.log that I can see
I am guessing this is an sssd issue but I am hoping someone here knows how to deal with it.
IN case it matters - here is the pam config:
auth required pam_env.so
auth sufficient pam_sss.so
auth required pam_deny.so
account [default=bad success=ok user_unknown=ignore] pam_sss.so
account required pam_permit.so
password requisite pam_cracklib.so try_first_pass retry=3 type=
password sufficient pam_sss.so use_authtok
password required pam_deny.so

session optional pam_keyinit.so revoke
session required pam_limits.so
session optional pam_oddjob_mkhomedir.so
session [success=1 default=ignore] pam_succeed_if.so service in crond quiet use_uid
session optional pam_sss.so
-M
Post by David Taylor
Thanks for the reply. The PAM file is pretty stock for a centos build
#%PAM-1.0
# This file is auto-generated.
# User changes will be destroyed the next time authconfig is run.
auth required pam_env.so
auth sufficient pam_unix.so nullok try_first_pass
auth requisite pam_succeed_if.so uid >= 500 quiet
auth sufficient pam_sss.so use_first_pass
auth required pam_deny.so
account required pam_unix.so
account sufficient pam_localuser.so
account sufficient pam_succeed_if.so uid < 500 quiet
account [default=bad success=ok user_unknown=ignore] pam_sss.so
account required pam_permit.so
password requisite pam_cracklib.so try_first_pass retry=3 type=
password sufficient pam_unix.so sha512 shadow nullok try_first_pass use_authtok
password sufficient pam_sss.so use_authtok
password required pam_deny.so
session optional pam_keyinit.so revoke
session required pam_limits.so
session [success=1 default=ignore] pam_succeed_if.so service in crond quiet use_uid
session required pam_unix.so
session optional pam_sss.so
Best regards
David Taylor
OK, so pam_sss is there ...

And yet you see no mention of pam_sss.so in /var/log/secure ?

Is this the file that was included from the service-specific PAM
configuration?
--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go To http://freeipa.org for more info on the project
Michael Lasevich
2014-11-07 05:33:35 UTC
Permalink
For what its worth, my issue was resolved when I rebooted the server.

Restarting sssd and/or clearing it's cache did not do it, but a full reboot
seems to have done it. Something much have been cached or some temp file I
missed. Will need to look into it further as I have a number of servers yet
to be upgraded and having to reboot linux servers to do an upgrade seem
sacrilegious...

-M
Post by David Taylor
As an add on, I’ve upgraded our Xen template to 6.6 and run up a new VM
using that and it attaches to the IPA environment perfectly well, so I’m
guessing it is an issue with the upgrade scripts.
Best regards
*David Taylor*
*Sent:* Friday, 7 November 2014 4:00 PM
*To:* Jakub Hrozek
*Subject:* Re: [Freeipa-users] Centos IPA Client fails after upgrade to
6.6
I am seeing somewhat similar behavior once upgrading from sssd 1.9 to 1.11
(centos 6.5 to 6.6)
I seem to be able to log in via ssh, but when I use http pam service, I
get inconsistent behavior - seems like sometimes it works and others it
errors out (success and failure can happen within a second)
[sssd[krb5_child[15410]]]: Internal credentials cache error
and
authentication failure; logname= uid=48 euid=48 tty= ruser= rhost= user=username
received for user username: 4 (System error)
Nothing in the audit.log that I can see
I am guessing this is an sssd issue but I am hoping someone here knows how to deal with it.
auth required pam_env.so
auth sufficient pam_sss.so
auth required pam_deny.so
account [default=bad success=ok user_unknown=ignore] pam_sss.so
account required pam_permit.so
password requisite pam_cracklib.so try_first_pass retry=3 type=
password sufficient pam_sss.so use_authtok
password required pam_deny.so
session optional pam_keyinit.so revoke
session required pam_limits.so
session optional pam_oddjob_mkhomedir.so
session [success=1 default=ignore] pam_succeed_if.so service in crond quiet use_uid
session optional pam_sss.so
-M
Post by David Taylor
Thanks for the reply. The PAM file is pretty stock for a centos build
#%PAM-1.0
# This file is auto-generated.
# User changes will be destroyed the next time authconfig is run.
auth required pam_env.so
auth sufficient pam_unix.so nullok try_first_pass
auth requisite pam_succeed_if.so uid >= 500 quiet
auth sufficient pam_sss.so use_first_pass
auth required pam_deny.so
account required pam_unix.so
account sufficient pam_localuser.so
account sufficient pam_succeed_if.so uid < 500 quiet
account [default=bad success=ok user_unknown=ignore] pam_sss.so
account required pam_permit.so
password requisite pam_cracklib.so try_first_pass retry=3 type=
password sufficient pam_unix.so sha512 shadow nullok
try_first_pass use_authtok
Post by David Taylor
password sufficient pam_sss.so use_authtok
password required pam_deny.so
session optional pam_keyinit.so revoke
session required pam_limits.so
session [success=1 default=ignore] pam_succeed_if.so service in
crond quiet use_uid
Post by David Taylor
session required pam_unix.so
session optional pam_sss.so
Best regards
David Taylor
OK, so pam_sss is there ...
And yet you see no mention of pam_sss.so in /var/log/secure ?
Is this the file that was included from the service-specific PAM
configuration?
--
https://www.redhat.com/mailman/listinfo/freeipa-users
Go To http://freeipa.org for more info on the project
Jakub Hrozek
2014-11-07 09:18:31 UTC
Permalink
Post by Michael Lasevich
For what its worth, my issue was resolved when I rebooted the server.
Restarting sssd and/or clearing it's cache did not do it, but a full reboot
seems to have done it. Something much have been cached or some temp file I
missed. Will need to look into it further as I have a number of servers yet
to be upgraded and having to reboot linux servers to do an upgrade seem
sacrilegious...
We need to see the krb5_child.log file ideally with a very high
debug_level (10 would enable KRB5_TRACE debugging as well..)
Post by Michael Lasevich
-M
As an add on, I’ve upgraded our Xen template to 6.6 and run up a new VM
using that and it attaches to the IPA environment perfectly well, so I’m
guessing it is an issue with the upgrade scripts.
Best regards
*David Taylor*
*Sent:* Friday, 7 November 2014 4:00 PM
*To:* Jakub Hrozek
*Subject:* Re: [Freeipa-users] Centos IPA Client fails after upgrade to
6.6
I am seeing somewhat similar behavior once upgrading from sssd 1.9 to 1.11
(centos 6.5 to 6.6)
I seem to be able to log in via ssh, but when I use http pam service, I
get inconsistent behavior - seems like sometimes it works and others it
errors out (success and failure can happen within a second)
[sssd[krb5_child[15410]]]: Internal credentials cache error
and
authentication failure; logname= uid=48 euid=48 tty= ruser= rhost= user=username
received for user username: 4 (System error)
Nothing in the audit.log that I can see
I am guessing this is an sssd issue but I am hoping someone here knows how
to deal with it.
auth required pam_env.so
auth sufficient pam_sss.so
auth required pam_deny.so
account [default=bad success=ok user_unknown=ignore] pam_sss.so
account required pam_permit.so
password requisite pam_cracklib.so try_first_pass retry=3 type=
password sufficient pam_sss.so use_authtok
password required pam_deny.so
session optional pam_keyinit.so revoke
session required pam_limits.so
session optional pam_oddjob_mkhomedir.so
session [success=1 default=ignore] pam_succeed_if.so service in crond quiet use_uid
session optional pam_sss.so
-M
Post by David Taylor
Thanks for the reply. The PAM file is pretty stock for a centos build
#%PAM-1.0
# This file is auto-generated.
# User changes will be destroyed the next time authconfig is run.
auth required pam_env.so
auth sufficient pam_unix.so nullok try_first_pass
auth requisite pam_succeed_if.so uid >= 500 quiet
auth sufficient pam_sss.so use_first_pass
auth required pam_deny.so
account required pam_unix.so
account sufficient pam_localuser.so
account sufficient pam_succeed_if.so uid < 500 quiet
account [default=bad success=ok user_unknown=ignore] pam_sss.so
account required pam_permit.so
password requisite pam_cracklib.so try_first_pass retry=3 type=
password sufficient pam_unix.so sha512 shadow nullok
try_first_pass use_authtok
Post by David Taylor
password sufficient pam_sss.so use_authtok
password required pam_deny.so
session optional pam_keyinit.so revoke
session required pam_limits.so
session [success=1 default=ignore] pam_succeed_if.so service in
crond quiet use_uid
Post by David Taylor
session required pam_unix.so
session optional pam_sss.so
Best regards
David Taylor
OK, so pam_sss is there ...
And yet you see no mention of pam_sss.so in /var/log/secure ?
Is this the file that was included from the service-specific PAM
configuration?
--
https://www.redhat.com/mailman/listinfo/freeipa-users
Go To http://freeipa.org for more info on the project
--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go To http://freeipa.org for more info on t
Michael Lasevich
2014-11-08 00:00:19 UTC
Permalink
Exactly 16 hours after reboot the problem returned on both servers. What
has a 16 hour timeout?

I set log level to 10 and got some logs, but they are long and not sure
what I am looking for. I am attaching some logs ( out of sheer paranoia I
have slightly sanitized them, 1.1.1.2 is the secondary IPA server,
***@MY.DOMAIN.COM is the principle and endserver.my.domain.com is the
IPA client this is happening on)
Post by Michael Lasevich
Post by Michael Lasevich
For what its worth, my issue was resolved when I rebooted the server.
Restarting sssd and/or clearing it's cache did not do it, but a full
reboot
Post by Michael Lasevich
seems to have done it. Something much have been cached or some temp file
I
Post by Michael Lasevich
missed. Will need to look into it further as I have a number of servers
yet
Post by Michael Lasevich
to be upgraded and having to reboot linux servers to do an upgrade seem
sacrilegious...
We need to see the krb5_child.log file ideally with a very high
debug_level (10 would enable KRB5_TRACE debugging as well..)
Post by Michael Lasevich
-M
Post by David Taylor
As an add on, I’ve upgraded our Xen template to 6.6 and run up a new
VM
Post by Michael Lasevich
Post by David Taylor
using that and it attaches to the IPA environment perfectly well, so
I’m
Post by Michael Lasevich
Post by David Taylor
guessing it is an issue with the upgrade scripts.
Best regards
*David Taylor*
*Sent:* Friday, 7 November 2014 4:00 PM
*To:* Jakub Hrozek
*Subject:* Re: [Freeipa-users] Centos IPA Client fails after upgrade to
6.6
I am seeing somewhat similar behavior once upgrading from sssd 1.9 to
1.11
Post by Michael Lasevich
Post by David Taylor
(centos 6.5 to 6.6)
I seem to be able to log in via ssh, but when I use http pam service, I
get inconsistent behavior - seems like sometimes it works and others it
errors out (success and failure can happen within a second)
[sssd[krb5_child[15410]]]: Internal credentials cache error
and
authentication failure; logname= uid=48 euid=48 tty= ruser= rhost= user=username
received for user username: 4 (System error)
Nothing in the audit.log that I can see
I am guessing this is an sssd issue but I am hoping someone here knows
how
Post by Michael Lasevich
Post by David Taylor
to deal with it.
auth required pam_env.so
auth sufficient pam_sss.so
auth required pam_deny.so
account [default=bad success=ok user_unknown=ignore] pam_sss.so
account required pam_permit.so
password requisite pam_cracklib.so try_first_pass retry=3 type=
password sufficient pam_sss.so use_authtok
password required pam_deny.so
session optional pam_keyinit.so revoke
session required pam_limits.so
session optional pam_oddjob_mkhomedir.so
session [success=1 default=ignore] pam_succeed_if.so service in
crond
Post by Michael Lasevich
Post by David Taylor
quiet use_uid
session optional pam_sss.so
-M
Post by David Taylor
Thanks for the reply. The PAM file is pretty stock for a centos build
#%PAM-1.0
# This file is auto-generated.
# User changes will be destroyed the next time authconfig is run.
auth required pam_env.so
auth sufficient pam_unix.so nullok try_first_pass
auth requisite pam_succeed_if.so uid >= 500 quiet
auth sufficient pam_sss.so use_first_pass
auth required pam_deny.so
account required pam_unix.so
account sufficient pam_localuser.so
account sufficient pam_succeed_if.so uid < 500 quiet
account [default=bad success=ok user_unknown=ignore] pam_sss.so
account required pam_permit.so
password requisite pam_cracklib.so try_first_pass retry=3
type=
Post by Michael Lasevich
Post by David Taylor
Post by David Taylor
password sufficient pam_unix.so sha512 shadow nullok
try_first_pass use_authtok
Post by David Taylor
password sufficient pam_sss.so use_authtok
password required pam_deny.so
session optional pam_keyinit.so revoke
session required pam_limits.so
session [success=1 default=ignore] pam_succeed_if.so service in
crond quiet use_uid
Post by David Taylor
session required pam_unix.so
session optional pam_sss.so
Best regards
David Taylor
OK, so pam_sss is there ...
And yet you see no mention of pam_sss.so in /var/log/secure ?
Is this the file that was included from the service-specific PAM
configuration?
--
https://www.redhat.com/mailman/listinfo/freeipa-users
Go To http://freeipa.org for more info on the project
Diaulas Castro
2014-11-08 14:24:50 UTC
Permalink
We have similar issue but on RHEL 6.6 (sssd 1.11), the problem is about
enumerating groups.

Use the command "id some_group_that_user_belong" on affected client, logout
and try logon again.

Our issue was with sudo not working, but everything based on groups stopped
to work too.

For workaround (if this is your problem too) edit sssd.con on domain
section:
enumarating = true
Post by Michael Lasevich
Exactly 16 hours after reboot the problem returned on both servers. What
has a 16 hour timeout?
I set log level to 10 and got some logs, but they are long and not sure
what I am looking for. I am attaching some logs ( out of sheer paranoia I
have slightly sanitized them, 1.1.1.2 is the secondary IPA server,
the IPA client this is happening on)
Post by Michael Lasevich
Post by Michael Lasevich
For what its worth, my issue was resolved when I rebooted the server.
Restarting sssd and/or clearing it's cache did not do it, but a full
reboot
Post by Michael Lasevich
seems to have done it. Something much have been cached or some temp
file I
Post by Michael Lasevich
missed. Will need to look into it further as I have a number of servers
yet
Post by Michael Lasevich
to be upgraded and having to reboot linux servers to do an upgrade seem
sacrilegious...
We need to see the krb5_child.log file ideally with a very high
debug_level (10 would enable KRB5_TRACE debugging as well..)
Post by Michael Lasevich
-M
On Thu, Nov 6, 2014 at 9:26 PM, David Taylor <
As an add on, I've upgraded our Xen template to 6.6 and run up a new
VM
Post by Michael Lasevich
using that and it attaches to the IPA environment perfectly well, so
I'm
Post by Michael Lasevich
guessing it is an issue with the upgrade scripts.
Best regards
*David Taylor*
*Sent:* Friday, 7 November 2014 4:00 PM
*To:* Jakub Hrozek
*Subject:* Re: [Freeipa-users] Centos IPA Client fails after upgrade
to
Post by Michael Lasevich
6.6
I am seeing somewhat similar behavior once upgrading from sssd 1.9 to
1.11
Post by Michael Lasevich
(centos 6.5 to 6.6)
I seem to be able to log in via ssh, but when I use http pam service,
I
Post by Michael Lasevich
get inconsistent behavior - seems like sometimes it works and others
it
Post by Michael Lasevich
errors out (success and failure can happen within a second)
[sssd[krb5_child[15410]]]: Internal credentials cache error
and
authentication failure; logname= uid=48 euid=48 tty= ruser= rhost= user=username
received for user username: 4 (System error)
Nothing in the audit.log that I can see
I am guessing this is an sssd issue but I am hoping someone here
knows how
Post by Michael Lasevich
to deal with it.
auth required pam_env.so
auth sufficient pam_sss.so
auth required pam_deny.so
account [default=bad success=ok user_unknown=ignore] pam_sss.so
account required pam_permit.so
password requisite pam_cracklib.so try_first_pass retry=3 type=
password sufficient pam_sss.so use_authtok
password required pam_deny.so
session optional pam_keyinit.so revoke
session required pam_limits.so
session optional pam_oddjob_mkhomedir.so
session [success=1 default=ignore] pam_succeed_if.so service in
crond
Post by Michael Lasevich
quiet use_uid
session optional pam_sss.so
-M
Post by David Taylor
Thanks for the reply. The PAM file is pretty stock for a centos
build
Post by Michael Lasevich
Post by David Taylor
#%PAM-1.0
# This file is auto-generated.
# User changes will be destroyed the next time authconfig is run.
auth required pam_env.so
auth sufficient pam_unix.so nullok try_first_pass
auth requisite pam_succeed_if.so uid >= 500 quiet
auth sufficient pam_sss.so use_first_pass
auth required pam_deny.so
account required pam_unix.so
account sufficient pam_localuser.so
account sufficient pam_succeed_if.so uid < 500 quiet
account [default=bad success=ok user_unknown=ignore] pam_sss.so
account required pam_permit.so
password requisite pam_cracklib.so try_first_pass retry=3
type=
Post by Michael Lasevich
Post by David Taylor
password sufficient pam_unix.so sha512 shadow nullok
try_first_pass use_authtok
Post by David Taylor
password sufficient pam_sss.so use_authtok
password required pam_deny.so
session optional pam_keyinit.so revoke
session required pam_limits.so
session [success=1 default=ignore] pam_succeed_if.so service in
crond quiet use_uid
Post by David Taylor
session required pam_unix.so
session optional pam_sss.so
Best regards
David Taylor
OK, so pam_sss is there ...
And yet you see no mention of pam_sss.so in /var/log/secure ?
Is this the file that was included from the service-specific PAM
configuration?
--
https://www.redhat.com/mailman/listinfo/freeipa-users
Go To http://freeipa.org for more info on the project
--
https://www.redhat.com/mailman/listinfo/freeipa-users
Go To http://freeipa.org for more info on the project
Lukas Slebodnik
2014-11-08 16:44:51 UTC
Permalink
Post by Diaulas Castro
We have similar issue but on RHEL 6.6 (sssd 1.11), the problem is about
enumerating groups.
Diaulas,
Have you reported your problem?

I know just about one problem with IPA and sssd-1.11 (on RHEL 6.6)
The upstream bug is https://fedorahosted.org/sssd/ticket/2471

There is a workaround. You can change value of option ldap_group_object_class
in domain section to ipaUserGroup

ldap_group_object_class = ipaUserGroup

Could you confirm that you had the same problem?
Otherwise please report bug either to upstream trac or Red Had Bugzilla.
Post by Diaulas Castro
Use the command "id some_group_that_user_belong" on affected client, logout
and try logon again.
Our issue was with sudo not working, but everything based on groups stopped
to work too.
For workaround (if this is your problem too) edit sssd.con on domain
enumarating = true
It would be better to fix it in sssd.

LS
--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go To http://freeipa.org for more info on the project
Diaulas Castro
2014-11-10 10:04:04 UTC
Permalink
Hi Lukas,
Already opened case within Red Hat. They told on case there is "private"
bugzilla for this "known" problem, the case got closed.

Im on vacation and RH Customer Portal seems off right now, cant find if
got the case got updated or there is errata for this issue.
Post by Lukas Slebodnik
Post by Diaulas Castro
We have similar issue but on RHEL 6.6 (sssd 1.11), the problem is about
enumerating groups.
Diaulas,
Have you reported your problem?
I know just about one problem with IPA and sssd-1.11 (on RHEL 6.6)
The upstream bug is https://fedorahosted.org/sssd/ticket/2471
There is a workaround. You can change value of option
ldap_group_object_class
in domain section to ipaUserGroup
ldap_group_object_class = ipaUserGroup
Could you confirm that you had the same problem?
Otherwise please report bug either to upstream trac or Red Had Bugzilla.
Post by Diaulas Castro
Use the command "id some_group_that_user_belong" on affected client,
logout
Post by Diaulas Castro
and try logon again.
Our issue was with sudo not working, but everything based on groups
stopped
Post by Diaulas Castro
to work too.
For workaround (if this is your problem too) edit sssd.con on domain
enumarating = true
It would be better to fix it in sssd.
LS
Jakub Hrozek
2014-11-10 10:10:45 UTC
Permalink
Post by Michael Lasevich
Exactly 16 hours after reboot the problem returned on both servers. What
has a 16 hour timeout?
I set log level to 10 and got some logs, but they are long and not sure
what I am looking for. I am attaching some logs ( out of sheer paranoia I
have slightly sanitized them, 1.1.1.2 is the secondary IPA server,
IPA client this is happening on)
Thank you, I see some errors in the log:
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [get_and_save_tgt] (0x0020): 1021: [-1765328188][Internal credentials cache error]
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [map_krb5_error] (0x0020): 1043: [-1765328188][Internal credentials cache error]
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [k5c_send_data] (0x0200): Received error code 1432158209
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [pack_response_packet] (0x2000): response packet size: [20]
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [k5c_send_data] (0x4000): Response sent.
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [main] (0x0400): krb5_child completed successfully


The complete run for that particular process is:
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [main] (0x0400): krb5_child started.
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [unpack_buffer] (0x1000): total buffer size: [132]
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [unpack_buffer] (0x0100): cmd [241] uid [241600006] gid [241600006] validate [true] enterprise principal [false] offline [false] UPN [***@MY.DOMAIN.COM]
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [unpack_buffer] (0x0100): ccname: [FILE:/tmp/krb5cc_241600006_jgS4rv] keytab: [/etc/krb5.keytab]
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_RENEWABLE_LIFETIME] from environment.
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from environment.
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [set_canonicalize_option] (0x0100): SSSD_KRB5_CANONICALIZE is set to [true]
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [k5c_setup_fast] (0x0100): SSSD_KRB5_FAST_PRINCIPAL is set to [host/***@MY.DOMAIN.COM]
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [find_principal_in_keytab] (0x4000): Trying to find principal host/***@MY.DOMAIN.COM in keytab.
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [match_principal] (0x1000): Principal matched to the sample (host/***@MY.DOMAIN.COM).
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401793.988922: Retrieving host/***@MY.DOMAIN.COM -> krbtgt/***@MY.DOMAIN.COM from FILE:/var/lib/sss/db/fast_ccache_MY.DOMAIN.COM with result: 0/Success
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [check_fast_ccache] (0x0200): FAST TGT is still valid.
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [main] (0x0400): Will perform online auth
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [tgt_req_child] (0x1000): Attempting to get a TGT
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [get_and_save_tgt] (0x0400): Attempting kinit for realm [MY.DOMAIN.COM]
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401793.989029: Getting initial credentials for ***@MY.DOMAIN.COM
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401793.989099: FAST armor ccache: FILE:/var/lib/sss/db/fast_ccache_MY.DOMAIN.COM
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401793.989173: Retrieving host/***@MY.DOMAIN.COM -> krb5_ccache_conf_data/fast_avail/krbtgt\/MY.DOMAIN.COM\@***@X-CACHECONF: from FILE:/var/lib/sss/db/fast_ccache_MY.DOMAIN.COM with result: -1765328243/Matching credential not found
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401793.989247: Sending request (190 bytes) to MY.DOMAIN.COM
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401793.989534: Sending initial UDP request to dgram 1.1.1.2:88
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2160: Received answer from dgram 1.1.1.2:88
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2229: Response was from master KDC
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2258: Received error from KDC: -1765328359/Additional pre-authentication required
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2283: Upgrading to FAST due to presence of PA_FX_FAST in reply
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2300: Restarting to upgrade to FAST
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2320: FAST armor ccache: FILE:/var/lib/sss/db/fast_ccache_MY.DOMAIN.COM
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2390: Retrieving host/***@MY.DOMAIN.COM -> krb5_ccache_conf_data/fast_avail/krbtgt\/MY.DOMAIN.COM\@***@X-CACHECONF: from FILE:/var/lib/sss/db/fast_ccache_MY.DOMAIN.COM with result: -1765328243/Matching credential not found
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2414: Upgrading to FAST due to presence of PA_FX_FAST in reply
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2431: FAST armor ccache: FILE:/var/lib/sss/db/fast_ccache_MY.DOMAIN.COM
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2489: Retrieving host/***@MY.DOMAIN.COM -> krb5_ccache_conf_data/fast_avail/krbtgt\/MY.DOMAIN.COM\@***@X-CACHECONF: from FILE:/var/lib/sss/db/fast_ccache_MY.DOMAIN.COM with result: -1765328243/Matching credential not found
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2551: Getting credentials host/***@MY.DOMAIN.COM -> krbtgt/***@MY.DOMAIN.COM using ccache FILE:/var/lib/sss/db/fast_ccache_MY.DOMAIN.COM
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2607: Retrieving host/***@MY.DOMAIN.COM -> krbtgt/***@MY.DOMAIN.COM from FILE:/var/lib/sss/db/fast_ccache_MY.DOMAIN.COM with result: 0/Success
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2643: Armor ccache sesion key: aes256-cts/CB2D
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2694: Creating authenticator for host/***@MY.DOMAIN.COM -> krbtgt/***@MY.DOMAIN.COM, seqnum 0, subkey aes256-cts/73F3, session key aes256-cts/CB2D
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2774: FAST armor key: aes256-cts/581F
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2811: Encoding request body and padata into FAST request
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2885: Sending request (1092 bytes) to MY.DOMAIN.COM (master)
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2978: Sending initial UDP request to dgram 1.1.1.2:88
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.7625: Received answer from dgram 1.1.1.2:88
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.7658: Received error from KDC: -1765328359/Additional pre-authentication required
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.7672: Decoding FAST response
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.7728: Processing preauth types: 136, 19, 138, 133, 137
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.7748: Selected etype info: etype aes256-cts, salt "MY.DOMAIN.COMusername", params ""
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.7759: Received cookie: MIT
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.26210: Preauth module encrypted_challenge (138) (flags=1) returned: 0/Success
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.26229: Produced preauth for next request: 133, 138
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.26239: Encoding request body and padata into FAST request
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.26287: Sending request (1190 bytes) to MY.DOMAIN.COM (master)
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.26349: Sending initial UDP request to dgram 1.1.1.2:88
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.46917: Received answer from dgram 1.1.1.2:88
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.46954: Decoding FAST response
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47024: Processing preauth types: 19, 138
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47048: Selected etype info: etype aes256-cts, salt "MY.DOMAIN.COMusername", params ""
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47104: Preauth module encrypted_challenge (138) (flags=1) returned: 0/Success
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47124: Produced preauth for next request: (empty)
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47145: AS key determined by preauth: aes256-cts/33DF
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47184: FAST reply key: aes256-cts/1E4A
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47232: Decrypted AS reply; session key is: aes256-cts/6732
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47266: FAST negotiation: available
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_krb5_expire_callback_func] (0x2000): exp_time: [10357377]
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [validate_tgt] (0x2000): Found keytab entry with the realm of the credential.
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47385: Retrieving host/***@MY.DOMAIN.COM from FILE:/etc/krb5.keytab (vno 0, enctype 0) with result: 0/Success
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47405: Resolving unique ccache of type MEMORY
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47430: Initializing MEMORY:YCZ1t6d with default princ ***@MY.DOMAIN.COM
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47451: Removing ***@MY.DOMAIN.COM -> krbtgt/***@MY.DOMAIN.COM from MEMORY:YCZ1t6d
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47495: Storing ***@MY.DOMAIN.COM -> krbtgt/***@MY.DOMAIN.COM in MEMORY:YCZ1t6d
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47527: Getting credentials ***@MY.DOMAIN.COM -> host/***@MY.DOMAIN.COM using ccache MEMORY:YCZ1t6d
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47561: Retrieving ***@MY.DOMAIN.COM -> host/***@MY.DOMAIN.COM from MEMORY:YCZ1t6d with result: -1765328243/Matching credential not found
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47592: Retrieving ***@MY.DOMAIN.COM -> krbtgt/***@MY.DOMAIN.COM from MEMORY:YCZ1t6d with result: 0/Success
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47613: Found cached TGT for service realm: ***@MY.DOMAIN.COM -> krbtgt/***@MY.DOMAIN.COM
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47630: Requesting tickets for host/***@MY.DOMAIN.COM, referrals on
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47660: Generated subkey for TGS request: aes256-cts/4300
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47682: etypes requested in TGS request: aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47759: Sending request (761 bytes) to MY.DOMAIN.COM
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47849: Sending initial UDP request to dgram 1.1.1.2:88
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.61746: Received answer from dgram 1.1.1.2:88
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.61822: Response was from master KDC
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.61893: TGS reply is for ***@MY.DOMAIN.COM -> host/***@MY.DOMAIN.COM with session key aes256-cts/61B8
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.61931: TGS request result: 0/Success
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.61960: Received creds for desired service host/***@MY.DOMAIN.COM
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.61989: Removing ***@MY.DOMAIN.COM -> host/***@MY.DOMAIN.COM from MEMORY:YCZ1t6d
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62014: Storing ***@MY.DOMAIN.COM -> host/***@MY.DOMAIN.COM in MEMORY:YCZ1t6d
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62057: Creating authenticator for ***@MY.DOMAIN.COM -> host/***@MY.DOMAIN.COM, seqnum 0, subkey (null, session key aes256-cts/61B8
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62152: Retrieving host/***@MY.DOMAIN.COM from FILE:/etc/krb5.keytab (vno 1, enctype aes256-cts) with result: 0/Success
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62213: Decrypted AP-REQ with specified server principal host/***@MY.DOMAIN.COM: aes256-cts/AFF6
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62244: AP-REQ ticket: ***@MY.DOMAIN.COM -> host/***@MY.DOMAIN.COM, session key aes256-cts/61B8
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62456: Negotiated enctype based on authenticator: aes256-cts
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62510: Initializing MEMORY:rd_req2 with default princ ***@MY.DOMAIN.COM
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62541: Removing ***@MY.DOMAIN.COM -> host/***@MY.DOMAIN.COM from MEMORY:rd_req2
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62567: Storing ***@MY.DOMAIN.COM -> host/***@MY.DOMAIN.COM in MEMORY:rd_req2
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62597: Destroying ccache MEMORY:YCZ1t6d
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [validate_tgt] (0x0400): TGT verified using key for [host/***@MY.DOMAIN.COM].
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62666: Destroying ccache MEMORY:rd_req2
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [become_user] (0x0200): Trying to become user [241600006][241600006].
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_get_ccache_name_for_principal] (0x4000): Location: [FILE:/tmp/krb5cc_241600006_jgS4rv]
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_get_ccache_name_for_principal] (0x2000): krb5_cc_cache_match failed: [-1765328243][Can't find client principal ***@MY.DOMAIN.COM in cache collection]
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [create_ccache] (0x4000): Initializing ccache of type [FILE]
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [get_and_save_tgt] (0x0020): 1021: [-1765328188][Internal credentials cache error]
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [map_krb5_error] (0x0020): 1043: [-1765328188][Internal credentials cache error]
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [k5c_send_data] (0x0200): Received error code 1432158209
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [pack_response_packet] (0x2000): response packet size: [20]
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [k5c_send_data] (0x4000): Response sent.
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [main] (0x0400): krb5_child completed successfully

So according to the logs, the create_ccache() function failed. Unfortunately,
we don't do very good job at logging the failures there..

Michael, are you able to run a custom package with extra debugging? It
would help us pinpoint which line actually is failing.

Thanks a lot for providing the logs!
--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go To http://freeipa.org for more info on the project
Michael Lasevich
2014-11-10 17:29:04 UTC
Permalink
I can certainly try, it would need to be compatible with CentOS 6.6 though.

-M
Post by Jakub Hrozek
So according to the logs, the create_ccache() function failed.
Unfortunately,
we don't do very good job at logging the failures there..
Post by Jakub Hrozek
Michael, are you able to run a custom package with extra debugging? It
would help us pinpoint which line actually is failing.
Post by Jakub Hrozek
Thanks a lot for providing the logs!
Jakub Hrozek
2014-11-11 13:33:25 UTC
Permalink
Post by Michael Lasevich
I can certainly try, it would need to be compatible with CentOS 6.6 though.
-M
Thank you very much, can you try these packages?

Please note they wouldn't fix your problem, but will hopefully shed some
more light on what's going on:
https://jhrozek.fedorapeople.org/sssd-test-builds/krb5-ccache-debugging/
Post by Michael Lasevich
Post by Jakub Hrozek
So according to the logs, the create_ccache() function failed.
Unfortunately,
we don't do very good job at logging the failures there..
Post by Jakub Hrozek
Michael, are you able to run a custom package with extra debugging? It
would help us pinpoint which line actually is failing.
Post by Jakub Hrozek
Thanks a lot for providing the logs!
--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go To http://freeipa.org for more info on the project
Michael Lasevich
2014-11-11 22:49:10 UTC
Permalink
Sending you logs directly. Thanks.

-M
Post by Jakub Hrozek
Post by Michael Lasevich
I can certainly try, it would need to be compatible with CentOS 6.6 though.
-M
Thank you very much, can you try these packages?
Please note they wouldn't fix your problem, but will hopefully shed some
https://jhrozek.fedorapeople.org/sssd-test-builds/krb5-ccache-debugging/
Post by Michael Lasevich
Post by Jakub Hrozek
So according to the logs, the create_ccache() function failed.
Unfortunately,
we don't do very good job at logging the failures there..
Post by Jakub Hrozek
Michael, are you able to run a custom package with extra debugging? It
would help us pinpoint which line actually is failing.
Post by Jakub Hrozek
Thanks a lot for providing the logs!
--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go To http://freeipa.org for more info on the project
Lukas Slebodnik
2014-11-07 07:04:41 UTC
Permalink
Post by Michael Lasevich
I am seeing somewhat similar behavior once upgrading from sssd 1.9 to 1.11
(centos 6.5 to 6.6)
I seem to be able to log in via ssh, but when I use http pam service, I get
inconsistent behavior - seems like sometimes it works and others it errors
out (success and failure can happen within a second)
[sssd[krb5_child[15410]]]: Internal credentials cache error
and
authentication failure; logname= uid=48 euid=48 tty= ruser= rhost=
user=username
received for user username: 4 (System error)
When pam_sss returned "System error" it meand unextected situation in sssd.
If you are able to reproduce problem on another machine (youhave alredy
restarted this one) could you provide log files from sssd?

put "debug_level = 7" into doman section of /etc/sssd/sssd.conf and log files
will be stored in directory /var/log/sssd/

LS
--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go To http://freeipa.org for more info on the project
Loading...