[Freeipa-users] Kerberos hanging approx. once a day

[Torsten Harenberg]

Dear Rich, all,

Am 28.07.15 um 19:08 schrieb Rich Megginson:

>>> # ldapsearch -xLLL -D "cn=directory manager" -W -s base -b
>>> "dc=uni-wuppertal,dc=de"

[...]

>>
>>
>> real    0m4.559s
>> user    0m0.403s
>> sys     0m0.057s
>> [root at ipa httpd]#
>>
>> Looks okay to us, or?
> 
> 4 seconds?  That seems way too long.

No.. that includes the time it took me to enter the password. Only the
"user" line is relevant, so 0.4 seconds.

>>
>> So.. here is the problem which is left over. When logging in as admin
>> now through th web page or locally:
>>
>> [Thu Jul 23 21:43:47.340133 2015] [wsgi:error] [pid 1134] ipa: INFO:
>> [jsonserver_session] wensing at PLEIADES.UNI-WUPPERTAL.DE:
>> radiusproxy_find(None, version=u'2.114'): SUCCESS
>> [Thu Jul 23 21:43:48.758849 2015] [wsgi:error] [pid 1133] ipa: INFO:
>> [jsonserver_session] wensing at PLEIADES.UNI-WUPPERTAL.DE: user_find(None,
>> version=u'2.114'): SUCCESS
>> [Fri Jul 24 07:20:10.198903 2015] [wsgi:error] [pid 1134] ipa: INFO: 401
>> Unauthorized: kinit: Clients credentials have been revoked while getting
>> initial credentials
>> [Fri Jul 24 07:20:10.198977 2015] [wsgi:error] [pid 1134]
>> [Fri Jul 24 07:20:18.181715 2015] [wsgi:error] [pid 1133] ipa: INFO: 401
>> Unauthorized: kinit: Clients credentials have been revoked while getting
>> initial credentials
>> [Fri Jul 24 07:20:18.181809 2015] [wsgi:error] [pid 1133]
>> [Fri Jul 24 07:21:12.919751 2015] [wsgi:error] [pid 1134] ipa: INFO: 401
>> Unauthorized: kinit: Clients credentials have been revoked while getting
>> initial credentials
>> [Fri Jul 24 07:21:12.919878 2015] [wsgi:error] [pid 1134]
>> [root at ipa httpd]# kinit admin
>> kinit: Clients credentials have been revoked while getting initial
>> credentials
>> [root at ipa httpd]# klist
>> Ticket cache: KEYRING:persistent:0:0
>> Default principal: admin at PLEIADES.UNI-WUPPERTAL.DE
>>
>> Valid starting       Expires              Service principal
>> 07/23/2015 11:44:13  07/24/2015 11:44:08
>> HTTP/ipa.pleiades.uni-wuppertal.de at PLEIADES.UNI-WUPPERTAL.DE
>> 07/23/2015 11:44:11  07/24/2015 11:44:08
>> krbtgt/PLEIADES.UNI-WUPPERTAL.DE at PLEIADES.UNI-WUPPERTAL.DE
>> [root at ipa httpd]#
>>
>>
>> Hope you have an idea about that one as well :).
> 
> I do not, sorry.  Maybe one of our kerberos experts will know.

Hope so.. the problem still persists. Strangely, it's not always there.
And it's only on the primary, not on the secondary server.

with an strace there is a difference when it does NOT work:

keyctl(KEYCTL_GET_PERSISTENT, 0, KEY_SPEC_PROCESS_KEYRING) = 294917837
keyctl(KEYCTL_SEARCH, 294917837, "keyring", "_krb",
KEY_SPEC_PROCESS_KEYRING) = 780102244
keyctl(KEYCTL_SEARCH, 780102244, "user", "krb_ccache:primary", 0) = 12049273
keyctl(KEYCTL_READ, 12049273, NULL, 0)  = 10
keyctl(KEYCTL_READ, 12049273, "", 10)   = 10
keyctl(KEYCTL_READ, 780102244, NULL, 0) = 4
keyctl(KEYCTL_READ, 780102244, "y\333\267", 4) = 4
keyctl(KEYCTL_SEARCH, 780102244, "keyring", "0", 0) = -1 ENOKEY
(Required key not available)
keyctl(KEYCTL_DESCRIBE, 12049273, NULL, 0) = 37
keyctl(KEYCTL_DESCRIBE, 12049273, "user;0;0;3f010000;krb_ccache:pri"...,
37) = 37

compared to when it WORKS:

keyctl(KEYCTL_GET_PERSISTENT, 0, KEY_SPEC_PROCESS_KEYRING) = 294917837
keyctl(KEYCTL_SEARCH, 294917837, "keyring", "_krb",
KEY_SPEC_PROCESS_KEYRING) = 780102244
keyctl(KEYCTL_SEARCH, 780102244, "user", "krb_ccache:primary", 0) = 12049273
keyctl(KEYCTL_READ, 12049273, NULL, 0)  = 10
keyctl(KEYCTL_READ, 12049273, "", 10)   = 10
keyctl(KEYCTL_SEARCH, 780102244, "keyring", "0", 0) = 17381009
keyctl(KEYCTL_SEARCH, 17381009, "user", "__krb5_princ__", 0) = 378086918
keyctl(KEYCTL_SEARCH, 17381009, "user", "__krb5_time_offsets__", 0) =
416824569
keyctl(KEYCTL_READ, 416824569, NULL, 0) = 8
keyctl(KEYCTL_READ, 416824569, "", 8)   = 8
keyctl(KEYCTL_READ, 378086918, NULL, 0) = 46
keyctl(KEYCTL_READ, 378086918, "", 46)  = 46
keyctl(KEYCTL_GET_PERSISTENT, 0, KEY_SPEC_PROCESS_KEYRING) = 294917837
keyctl(KEYCTL_SEARCH, 294917837, "keyring", "_krb",
KEY_SPEC_PROCESS_KEYRING) = 780102244
keyctl(KEYCTL_SEARCH, 780102244, "user", "krb_ccache:primary", 0) = 12049273
keyctl(KEYCTL_READ, 12049273, NULL, 0)  = 10
keyctl(KEYCTL_READ, 12049273, "", 10)   = 10
keyctl(KEYCTL_READ, 780102244, NULL, 0) = 12
keyctl(KEYCTL_READ, 780102244, "y\333\267", 12) = 12
keyctl(KEYCTL_SEARCH, 780102244, "keyring", "0", 0) = 17381009
keyctl(KEYCTL_SEARCH, 17381009, "user", "__krb5_princ__", 0) = 378086918
keyctl(KEYCTL_READ, 378086918, NULL, 0) = 46
keyctl(KEYCTL_READ, 378086918, "", 46)  = 46

Best regards

  Torsten


-- 
<><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><>
<>                                                              <>
<> Dr. Torsten Harenberg     harenberg at physik.uni-wuppertal.de  <>
<> Bergische Universitaet                                       <>
<> FB C - Physik             Tel.: +49 (0)202 439-3521          <>
<> Gaussstr. 20              Fax : +49 (0)202 439-2811          <>
<> 42097 Wuppertal                                              <>
<>                                                              <>
<><><><><><><>< Of course it runs NetBSD http://www.netbsd.org ><>