Hi,
While setting up some Kerberos shares with ganesha I came across an issue where the client
receives RPCSEC_GSS_CREDPROBLEM. The source of this error is is form following code in
function _svcauth_gss which is used when authenticating RPCSEC_GSS request,
442 /* Context lookup. */
443 if ((gc->gc_proc == RPCSEC_GSS_DATA)
444 || (gc->gc_proc == RPCSEC_GSS_DESTROY)) {
445
446 /* Per RFC 2203 5.3.3.3, if a valid security context
447 * cannot be found to authorize a request, the
448 * implementation returns RPCSEC_GSS_CREDPROBLEM.
449 * N.B., we are explicitly allowed to discard contexts
450 * for any reason (e.g., to save space). */
451 gd = authgss_ctx_hash_get(gc);
452 if (!gd) {
453 rc = RPCSEC_GSS_CREDPROBLEM;
454 goto cred_free;
455 }
456 if (gc->gc_svc != gd->sec.svc)
457 gd->sec.svc = gc->gc_svc;
458 }
When the GSS proc is GSS_DATA or GSS_DESTROY, ntirpc expects the context to be in the
cache. If not it returns RPCSEC_GSS_CREDPROBLEM.
For the above condition to be true, this context should have been inserted in the cache as
part of GSS_INIT request. In the same function, the svc_rpc_gss_data object is inserted in
the cache but there is a difference in the dispatch code. When the request is
RPCSEC_GSS_INIT, ntirpc sends the reply back to the client before caching the context.
533 *no_dispatch = true;
534
535 req->rq_msg.RPCM_ack.ar_results.where = &gr;
536 req->rq_msg.RPCM_ack.ar_results.proc =
537 (xdrproc_t) xdr_rpc_gss_init_res;
538 call_stat = svc_sendreply(req);
<-- Sending reply to client here
539
540 /* XXX */
541 gss_release_buffer(&min_stat, &gr.gr_token);
542 gss_release_buffer(&min_stat, &gd->checksum);
543 mem_free(gr.gr_ctx.value, 0);
544
545 if (call_stat >= XPRT_DIED) {
546 rc = AUTH_FAILED;
547 goto gd_free;
548 }
549
550 if (gr.gr_major == GSS_S_COMPLETE) {
……
……
583 (void)authgss_ctx_hash_set(gd);
<-- Inserting the svc_rpc_gss_data object into the cache
584 }
In my setup, I observed that, the client can send another request, let's say
EXCHANGE_ID with RPCSEC_GSS_DATA and end up returning the CREDPROBLEM error if that work
thread gets scheduled first and tries to authenticate the request before the context is
inserted in the cache. I believe we should be sending the reply after inserting the
context in the cache.
Please find some logs below which confirm the race. Svc_10 is the RPCSEC_GSS_INIT request
and svc_4 is RPCSEC_GSS_DATA request. We can observe that rbtree_x_cached_lookup happens
before rbtree_x_cached_insert for hash key f8003f00,
2020-01-30T16:52:42Z : ganesha.nfsd-2248[none] [svc_10] 0 :rpc :TIRPC
:xdr_reply_encode:109 SUCCESS
2020-01-30T16:52:42Z : ganesha.nfsd-2248[none] [svc_10] 0 :rpc :TIRPC
:xdr_rpc_gss_encode() success (0x7f89fc002360:16)
2020-01-30T16:52:42Z : ganesha.nfsd-2248[none] [svc_10] 0 :rpc :TIRPC
:xdr_rpc_gss_encode() success (0x7f89fc008bb0:155)
2020-01-30T16:52:42Z : ganesha.nfsd-2248[none] [svc_10] 0 :rpc :TIRPC
:xdr_rpc_gss_init_res() encode success (ctx 0x7f89fc002360:16, maj 0, min 0, win 32, token
0x7f89fc008bb0:155)
2020-01-30T16:52:42Z : ganesha.nfsd-2248[none] [svc_10] 0 :rpc :TIRPC :svc_ref_it()
0x7f8a04000a90 fd 32 xp_refcnt 5 af 10 port 35536 @svc_ioq_write_now:265
2020-01-30T16:52:42Z : ganesha.nfsd-2248[none] [svc_10] 0 :rpc :TIRPC :svc_release_it()
0x7f8a04000a90 fd 32 xp_refcnt 4 af 10 port 35536 @svc_ioq_write:233
2020-01-30T16:52:42Z : ganesha.nfsd-2248[none] [svc_10] 0 :rpc :TIRPC :xdr_ioq_destroy()
xioq 0x7f89fc002800
....
....
2020-01-30T16:52:42Z : ganesha.nfsd-2248[none] [svc_4] 0 :rpc :TIRPC :xdr_rpc_gss_cred()
decode success (v 1, proc 0, seq 1, svc 2, ctx 0x7f8a0c001780:16)
2020-01-30T16:52:42Z : ganesha.nfsd-2248[none] [svc_4] 0 :rpc :TIRPC
:rbtree_x_cached_lookup: t 0x7f8a0c0021c0 nk 0x7f8a20153e80 nv (nil)( hk f8003f00
slot/offset 56)
2020-01-30T16:52:42Z : ganesha.nfsd-2248[none] [svc_4] 0 :rpc :TIRPC :xdr_rpc_gss_cred()
decode success (v 1, proc 0, seq 1, svc 2, ctx 0x7f8a0c001780:16)
2020-01-30T16:52:42Z : ganesha.nfsd-2248[none] [svc_4] 728 :nfs_rpc_process_request :DISP
:Could not authenticate request... rejecting with AUTH_STAT=RPCSEC_GSS_CREDPROBLEM
....
....
2020-01-30T16:52:42Z : ganesha.nfsd-2248[none] [svc_10] 0 :rpc :TIRPC
:rbtree_x_cached_insert: cix 9 ct 0x7f8a0c0021c0 t 0x7f8a0c0021c0 inserting 0x7f89fc001890
(cache hk f8003f00 slot/offset 56) flags 3
2020-01-30T16:52:42Z : ganesha.nfsd-2248[none] [svc_10] 0 :rpc :TIRPC :xdr_rpc_gss_cred()
decode success (v 1, proc 1, seq 0, svc 1, ctx (nil):0)
2020-01-30T16:52:42Z : ganesha.nfsd-2248[none] [svc_10] 740 :nfs_rpc_process_request :DISP
:RPCSEC_GSS no_dispatch=1 gc->gc_proc=(1) RPCSEC_GSS_INIT
Is this a known issue or being worked on already?
Thanks,
Sriram