Expired credentials are never renewed

[zpericic]

It seams gssproxy doesn't renew client cache on expiration.

If client cache does not exists gssproxy acquire credentials and everything is working until clien cache expires. If client cache files is removed gssproxy acquire new credentials and service using it continues to work.

Service uses SASL GSSAPI to access LDAP and it's running as separate user (1000).

I have tested it with ldapsearch:
sudo -u 1000 GSS_USE_PROXY=yes ldapsearch -Y GSSAPI

klist -c /run/krb5_ccache that cache is expired.

Krb5 trace states The referenced credential has expired...

BTW. SELinux is in permissive mode.

Service configuration:

[service/example-service]
  mechs = krb5
  cred_store = keytab:/etc/krb5.keytab
  cred_store = ccache:FILE:/run/krb5_ccache
  cred_store = client_keytab:/etc/krb5.keytab
  min_lifetime = 360
  cred_usage = both
  euid = 1000

Example log with debug_level=3:

gssproxy[643415]: [2021/12/11 00:36:11]: [status] Sending data [0x7f6378076900 (168)]: successful write of 168
gssproxy[643415]: [2021/12/11 00:36:11]: [status] Sending data: 0x7f6378076900 (168)
gssproxy[643415]: [2021/12/11 00:36:11]: [status] Handling query reply: 0x7f6378076900 (168)
gssproxy[643415]: [CID 12][2021/12/11 00:36:11]: [status] Handling query output: 0x7f6378076900 (168)
gssproxy[643415]: [CID 12][2021/12/11 00:36:11]: [status] Returned buffer 8 (GSSX_INIT_SEC_CONTEXT) from [0x561388f0e370 (216)]: [0x7f6378076900 (168)]
gssproxy[643415]:     GSSX_RES_INIT_SEC_CONTEXT( status: { 851968 { 1 2 840 113554 1 2 2 } 2529638944 "Unspecified GSS failure.  Minor code may provide more information" "Ticket expired" [  ] } context_handle: <Null> output_token: <Null> )
gssproxy[643415]: [CID 12][2021/12/11 00:36:11]: No impersonator credentials detected
gssproxy[643415]:     GSSX_ARG_INIT_SEC_CONTEXT( call_ctx: { "" [  ] } context_handle: <Null> cred_handle: <Null> target_name: { "[email protected]" { 1 2 840 113554 1 2 1 4 } [  ] [  ] [ ] } mech_type: { 1 2 840 113554 1 2 2 } req_flags: 58 time_req: 0 input_cb: <Null> input_token: <Null> [ { [ 73796e635f6d6f6469666965645f63726564730 ] [ 64656661756c740 ] } ] )
gssproxy[643415]: [CID 12][2021/12/11 00:36:11]: gp_rpc_execute: executing 8 (GSSX_INIT_SEC_CONTEXT) for service "example-service", euid: 1000,socket: (null)
gssproxy[643415]: [CID 12][2021/12/11 00:36:11]: [status] Executing request 8 (GSSX_INIT_SEC_CONTEXT) from [0x561388f0e370 (216)]
gssproxy[643415]: [CID 12][2021/12/11 00:36:11]: [status] Processing request [0x561388f0e370 (216)]
gssproxy[643415]: [CID 12][2021/12/11 00:36:11]: Connection matched service example-service
gssproxy[643415]: [CID 12][2021/12/11 00:36:11]: [status] Handling query input: 0x561388f0e370 (216)
gssproxy[643415]: [2021/12/11 00:36:11]: [status] Sending data [0x7f6378023de0 (164)]: successful write of 164
gssproxy[643415]: [2021/12/11 00:36:11]: [status] Sending data: 0x7f6378023de0 (164)
gssproxy[643415]: [2021/12/11 00:36:11]: [status] Handling query reply: 0x7f6378023de0 (164)
gssproxy[643415]: [CID 12][2021/12/11 00:36:11]: [status] Handling query output: 0x7f6378023de0 (164)
gssproxy[643415]: [CID 12][2021/12/11 00:36:11]: [status] Returned buffer 6 (GSSX_ACQUIRE_CRED) from [0x561388f053e0 (848)]: [0x7f6378023de0 (164)]
gssproxy[643415]:     GSSX_RES_ACQUIRE_CRED( status: { 720896 { 1 2 840 113554 1 2 2 } 100001 "The referenced credential has expired" "Success" [  ] } output_cred_handle: { { "" <None> [  ] [  ] [ ] } [ ] [  ] 0 } )
gssproxy[643415]:     GSSX_ARG_ACQUIRE_CRED( call_ctx: { "" [  ] } input_cred_handle: { { "service1/[email protected]" { 1 2 840 113554 1 2 2 1 } [ 410b692affffff8648ffffff86fffffff7121220002f696d61702f7372762d68747a2d66736e2d312e64652e692e696e666f6d6161732e687240494e464f4d4141532e4852 ] [ 420b692affffff8648ffffff86fffffff7121220002f696d61702f7372762d68747a2d66736e2d312e64652e692e696e666f6d6161732e687240494e464f4d4141532e48520000 ] [ ] } [ { { "service1/[email protected]" { 1 2 840 113554 1 2 2 1 } [ 410b692affffff8648ffffff86fffffff7121220002f696d61702f7372762d68747a2d66736e2d312e64652e692e696e666f6d6161732e687240494e464f4d4141532e4852 ] [ 420b692affffff8648ffffff86fffffff7121220002f696d61702f7372762d68747a2d66736e2d312e64652e692e696e666f6d6161732e687240494e464f4d4141532e48520000 ] [ ] } { 1 2 840 113554 1 2 2 } INITIATE 85446 0 } ] [ ffffffd37dffffff8b1ffffff94ffffff8fffffffa05d1a3effffff96ffffff957144ffffffe5ffffffe078ffffff91ffffffc9ffffffd9ffffffb4541ffffffb5bffffffa270ffffffaaffffff862cffffffdeffffffb8481873ffffff9fffffffd44b61213ffffffcfffffff934f03bffffffb412ffffffeeffffffea75ffffffdfffffffd7646a28ffffff9a2f643134b322921407fffffff9b43ffffffffffffffb9ffffffdc7a39fffffff0ffffffe9492e4ffffffff24dffffff90fffffffafffffff128ffffffcf15ffffffaefffffff7ffffffc9ffffffb5ffffff994b5effffff8c73ffffff8dffffffa7ffffffd3ffffffd2ffffffcb571639fffffff07affffffa97affffffb836ffffff8e6d79744c357dffffffacffffffeaffffffbcffffffdc6cffffffa8ffffff844b5effffff877ffffffdc23ffffffcf22ffffff87ffffff83ffffffdf79ffffffd9ffffff912d3ffffffcaffffffbb43dffffffc8137c4cffffffe46448ffffffab262dffffffdb314469ffffffcf1b28ffffffe11121ffffffc94870ffffff8dfffffff5b2d43ffffffd8ffffffa555216e78ffffff9fffffffba6fffffffd430ffffffbaffffffbc6effffff83fffffff86b281bffffffc9137365ffffffa4ffffffaf2ffffffe0fffffff811561c51774effffffcb6a7dffffffe0ffffffecffffffa42affffffc1ffffffa7ffffff826074ffffff99757affffffb043322fffffffc5ffffff8cffffffb3ffffff8affffffd04cffffffe0ffffffb22964ffffffc2ffffff8d68ffffffaefffffff80ffffffc741fffffff1ffffff902b ] 0 } add_cred: 0 desired_name: <Null> time_req: 0 desired_mechs: { } cred_usage: INITIATE initiator_time_req: 0 acceptor_time_req: 0 )
gssproxy[643415]: [CID 12][2021/12/11 00:36:11]: gp_rpc_execute: executing 6 (GSSX_ACQUIRE_CRED) for service "example-service", euid: 1000,socket: (null)
gssproxy[643415]: [CID 12][2021/12/11 00:36:11]: [status] Executing request 6 (GSSX_ACQUIRE_CRED) from [0x561388f053e0 (848)]
gssproxy[643415]: [CID 12][2021/12/11 00:36:11]: [status] Processing request [0x561388f053e0 (848)]
gssproxy[643415]: [CID 12][2021/12/11 00:36:11]: Connection matched service example-service
gssproxy[643415]: [CID 12][2021/12/11 00:36:11]: [status] Handling query input: 0x561388f053e0 (848)
gssproxy[643415]: [2021/12/11 00:36:11]: Client [2021/12/11 00:36:11]: (/usr/bin/ldapsearch) [2021/12/11 00:36:11]:  connected (fd = 12)[2021/12/11 00:36:11]:  (pid = 643985) (uid = 1000) (gid = 1000)[2021/12/11 00:36:11]:  (context = unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023)[2021/12/11 00:36:11]:

[zpericic]

After further investigation...

I have two exactly configured services, dovecot and postfix. Postfix seams to renew ticket.

As gssproxy is used only to initiate config is converted to:

[service/dovecot]
  mechs = krb5
  cred_store = client_keytab:/etc/dovecot/krb5.keytab
  cred_store = ccache:FILE:/var/lib/dovecot/krb5_ccache
  cred_usage = initiate
  euid = dovecot

It seams that dovecot is locking keytab and SELinux is reporting. This should not be problem as SELinux is in permissive mode.

AVC avc:  denied  { lock } for  pid=690866 comm="gssproxy" path="/etc/dovecot/krb5.keytab" ...... permissive=1

After this sequence nothing changes...

Stop service using keytab and make sure nothing is locking keytab.

# systemctl stop dovecot
# lsof /etc/dovecot/krb5.keytab
# 

Remove credentials cache:

# rm -f /var/lib/dovecot/krb5_ccache
# systemctl restart gssproxy

Try it using ldapwhoami, gssproxy acquire ticket and everything is working.

# sudo -u dovecot GSS_USE_PROXY=yes ldapwhoami  -Y GSSAPI 
SASL/GSSAPI authentication started
SASL username: imap/someserver@SOMEREALM
SASL SSF: 256
SASL data security layer installed.
...

After some time when ticket expires it stop working :

# sudo -u dovecot GSS_USE_PROXY=yes ldapwhoami  -Y GSSAPI 
SASL/GSSAPI authentication started
ldap_sasl_interactive_bind_s: Local error (-2)
	additional info: SASL(-1): generic failure: GSSAPI Error: No credentials were supplied, or the credentials were unavailable or inaccessible (Credential cache is empty)

Finally I configured gssproxy without client cache file specified:

[service/dovecot]
  mechs = krb5
  cred_store = client_keytab:/etc/dovecot/krb5.keytab
  cred_usage = initiate
  euid = dovecot

Removed credentials cache and restarted gssproxy

# rm -f /var/lib/dovecot/krb5_ccache
# systemctl restart gssproxy

Try it using ldapwhoami, gssproxy acquire ticket and everything is working.

# sudo -u dovecot GSS_USE_PROXY=yes ldapwhoami  -Y GSSAPI 
SASL/GSSAPI authentication started
SASL username: imap/someserver@SOMEREALM
SASL SSF: 256
SASL data security layer installed.
...

After some time when ticket expires it continues to work:

# sudo -u dovecot GSS_USE_PROXY=yes ldapwhoami  -Y GSSAPI 
SASL/GSSAPI authentication started
SASL username: imap/someserver@SOMEREALM
SASL SSF: 256
SASL data security layer installed.
...

Conclusion

So without credentials cache specified everything is working even with dovecot started and locking keytab.

I think this issue should be investigated as this should work in original configuration. I'am not sure how to replicate problem as it works with different service identically configured. I'am even not sure if problem lays in MIT kerberos libraries.

Maybe gssproxy could check if client cache is valid ie. not been expired before returning.

P.S. I forgot to mention gssproxy is version 0.8.4 from Fedora 35 with addition of c6847f0 (Add an option for minimum lifetime)

[simo5]

The behavior you mention can happen if someone manually primes the ccache instead of letting gssprocy do it via client keytab directives.
This due to libgssapi behavior which will srt config variables in the ccache to indicate creds were obtained via keytab, whch will not happen if the creds are manually obtained via kinit or via somoe krb5 function by another program.
If the config option are not found, libgssapi will not reinitialize the ccache from a keytab unless there are no credentials at all.

As for dovecot, you should not give that process direct access to keytab/ccache. The point of gssproxy is to implement privilege separation so that the commanding process can use short term credentials but is not in direct control of the keys. Pretty sure part of your issues will go away if you avoid one interfereing with the other.