Hello !
I contact you because I have a random problem with my 3.0.0.47 FreeIPA
server.
Sometimes, suddenly, I cannot use anymore the REST API and I got the
following errors when I try things like ipa user-show <myuser> :
Insufficient access: SASL(-1): generic failure: GSSAPI Error: Unspecified
GSS failure. Minor code may provide more information (Ticket expired)]
traceback : <traceback object at 0x3b917a0>
The kinit works fine, klist also.
My ticket is valid until the day after so no problem from there.
The datetime is the same between the IPA server and the IPA client.
When I check the httpd logs on the IPA server, as long as this error lasts,
I don't see any logs at all.
For example, today, the problem occured at 12:06:39 and in the HTTPD error
logs :
[Wed Oct 31 12:05:23 2018] [error] ipa: INFO: aPrincipal@MYREALM:
user_show(u'anotherPincipal', rights=False, all=True, raw=False,
version=u'2.49', no_members=False): SUCCESS
[Wed Oct 31 12:07:23 2018] [error] ipa: INFO: aPrincipal@MYREALM:
user_find(u'PrincipalPattern_', sizelimit=1000, whoami=False, all=False,
raw=False, version=u'2.49', no_members=False, pkey_only=False): SUCCESS
There is nothing in the dirsrv error logs at this time and around this time.
Nothing neither in the PKI CA logs.
When I check the logs in cli.log, I find this kind of lines :
2018-10-31T12:06:39Z 1933 MainThread ipa.ipalib.rpc.xmlclient
INFO trying https://<IPA-MASTER>/ipa/xml
2018-10-31T12:06:39Z 1933 MainThread ipa.ipalib.rpc.xmlclient
INFO Forwarding 'user_show' to server
u'https://<IPA-MASTER>/ipa/xml'
2018-10-31T12:06:39Z 1947 MainThread ipa.ipalib.rpc.xmlclient
INFO trying https://<IPA-MASTER>/ipa/xml
2018-10-31T12:06:39Z 1947 MainThread ipa.ipalib.rpc.xmlclient
INFO Forwarding 'user_show' to server
u'https://<IPA-MASTER>/ipa/xml'
2018-10-31T12:06:40Z 1961 MainThread ipa.ipalib.rpc.xmlclient
INFO trying https://<IPA-MASTER>/ipa/xml
2018-10-31T12:06:40Z 1961 MainThread ipa.ipalib.rpc.xmlclient
INFO Forwarding 'user_show' to server
u'https://<IPA-MASTER>/ipa/xml'
2018-10-31T12:06:40Z 1975 MainThread ipa.ipalib.rpc.xmlclient
INFO trying https://<IPA-MASTER>/ipa/xml
2018-10-31T12:06:40Z 1975 MainThread ipa.ipalib.rpc.xmlclient
INFO Forwarding 'user_show' to server
u'https://<IPA-MASTER>/ipa/xml'
2018-10-31T12:07:27Z 2159 MainThread ipa INFO The ipactl
command was successful
2018-10-31T12:07:27Z 2160 MainThread ipa INFO The ipactl
command was successful
I cannot see anything special in the krb5kdc.log neither for this time. The
only line corresponding to the IP of the client are the followings :
Oct 31 12:06:24 <IPA-MASTER> krb5kdc[137188](info): AS_REQ (4 etypes {18 17
16 23}) <IP CLIENT>: NEEDED_PREAUTH: <MYUSER>@<MYREALM> for
krbtgt/<MYREALM>@<MYREALM>, Additional pre-authentication required
Oct 31 12:06:24 <IPA-MASTER> krb5kdc[137188](info): AS_REQ (4 etypes {18 17
16 23}) <IP CLIENT>: NEEDED_PREAUTH: <MYUSER>@<MYREALM> for
krbtgt/<MYREALM>@<MYREALM>, Additional pre-authentication required
Oct 31 12:06:24 <IPA-MASTER> krb5kdc[137188](info): closing down fd 10
Oct 31 12:06:24 <IPA-MASTER> krb5kdc[137188](info): closing down fd 10
Oct 31 12:06:24 <IPA-MASTER> krb5kdc[137181](info): AS_REQ (4 etypes {18 17
16 23}) <IP CLIENT>: ISSUE: authtime 1540983984, etypes {rep=18 tkt=18
ses=18}, <MYUSER>@<MYREALM> for krbtgt/<MYREALM>@<MYREALM>
Oct 31 12:06:24 <IPA-MASTER> krb5kdc[137181](info): AS_REQ (4 etypes {18 17
16 23}) <IP CLIENT>: ISSUE: authtime 1540983984, etypes {rep=18 tkt=18
ses=18}, <MYUSER>@<MYREALM> for krbtgt/<MYREALM>@<MYREALM>
Oct 31 12:06:24 <IPA-MASTER> krb5kdc[137181](info): closing down fd 10
Oct 31 12:06:24 <IPA-MASTER> krb5kdc[137181](info): closing down fd 10
We are multiple users connecting to the same server with SSH and using root.
But each one of us use a different KRB5CCNAME to take a kerberos ticket.
(we take different ticket, me for example I take an admin ticket, a
colleague takes another principal ticket).
I tried using the ipa user-show with the -d flag : ipa -d user-show
<myuser> and I compared the result between one which failed and one which
was successfull.
The difference came at this step :
When it failed :
ipa: DEBUG: approved_usage = SSL Server intended_usage = SSL Server
ipa: DEBUG: cert valid True for "CN=<IPA-MASTER>,O=<MYREALM>"
ipa: DEBUG: handshake complete, peer = <IP>:443
ipa: DEBUG: Protocol: TLS1.2
ipa: DEBUG: Cipher: TLS_RSA_WITH_AES_128_CBC_SHA
ipa: DEBUG: Caught fault 2100 from server
https://<IPA-MASTER>/ipa/session/xml: Insufficient access: SASL(-1):
generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may
provide more information (Ticket expired)
ipa: DEBUG: Destroyed connection context.xmlclient
ipa: ERROR: Insufficient access: SASL(-1): generic failure: GSSAPI
Error: Unspecified GSS failure. Minor code may provide more information
(Ticket expired)
When it succeeds :
ipa: DEBUG: approved_usage = SSL Server intended_usage = SSL Server
ipa: DEBUG: cert valid True for "CN=<IPA-MASTER>,O=<MYREALM>"
ipa: DEBUG: handshake complete, peer = <IP>:<PORT>
ipa: DEBUG: Protocol: TLS1.2
ipa: DEBUG: Cipher: TLS_RSA_WITH_AES_128_CBC_SHA
ipa: DEBUG: received Set-Cookie
'ipa_session=385454761d74afed915a24124ba5ef25; Domain=<IPA-MASTER>;
Path=/ipa; Expires=Wed, 31 Oct 2018 15:57:45 GMT; Secure; HttpOnly'
ipa: DEBUG: storing cookie 'ipa_session=385454761d74afed915a24124ba5ef25;
Domain=<IPA-MASTER>; Path=/ipa; Expires=Wed, 31 Oct 2018 15:57:45 GMT;
Secure; HttpOnly' for principal <myPrincipal>@<MYREALM>
ipa: DEBUG: args=keyctl search @s user
ipa_session_cookie:<myPrincipal>@<MYREALM>
ipa: DEBUG: stdout=485338998
ipa: DEBUG: stderr=
ipa: DEBUG: args=keyctl search @s user
ipa_session_cookie:<myPrincipal>@<MYREALM>
ipa: DEBUG: stdout=485338998
ipa: DEBUG: stderr=
ipa: DEBUG: args=keyctl pupdate 485338998
ipa: DEBUG: stdout=
ipa: DEBUG: stderr=
ipa: DEBUG: Destroyed connection context.xmlclient
So when it works, it sets a session cookie ?
Some information about FreeIPA and cookies :
https://vda.li/en/posts/2015/05/28/talking-to-freeipa-api-with-sessions/
May you help me please ?
As a note, I found a workaround for that. I need to destroy my ticket with
kdestroy and then to disconnect from the server.
Then when I connect back to the server, I take a kerberos ticket and I can
use the rest api.
This problem is really strange, thank you in advance for your help guys.
Lune