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
freeipa-users@lists.fedorahosted.org