Re: PROBLEM: oops spew with Linux 5.1.5 (NFS regression?)

[Trond Myklebust]

On Wed, 2019-05-29 at 11:10 -0400, Nick Bowler wrote:
> Hi,
> 
> I upgraded to Linux 5.1.5 on one machine yesterday, and this morning
> I
> happened noticed a large amount of backtraces in the log.  It appears
> that the system oopsed 62 times over a period of about 5 minutes,
> producing about half a megabyte of log messages, after which the
> messages stopped.  No idea what action (if any) triggered these.
> 
> However, other than the noise in the logs there is nothing obviously
> broken, but I thought I should report the spews anyway.  I was
> running
> 5.0.9 previously and have not seen any similar errors.  The first
> couple
> spews are appended.  All 64 faults look very similar to these ones,
> with
> the same faulting address and the same rpc_check_timeout function at
> the
> top of the backtrace.

OK, I think this is the same problem that Olga was seeing (Cced), and
it looks like I missed the use-after-free issue when the server returns
a credential error when she asked.

I believe that the following patch should fix it:

8<------------------------------------------------------------------
From 33905f5a7d1d200db8eeb3f4ea8670c9da4cb64d Mon Sep 17 00:00:00 2001
From: Trond Myklebust <trond.myklebust@xxxxxxxxxxxxxxx>
Date: Wed, 29 May 2019 12:49:52 -0400
Subject: [PATCH] SUNRPC: Fix a use after free when a server rejects the
 RPCSEC_GSS credential

The addition of rpc_check_timeout() to call_decode causes an Oops
when the RPCSEC_GSS credential is rejected.
The reason is that rpc_decode_header() will call xprt_release() in
order to free task->tk_rqstp, which is needed by rpc_check_timeout()
to check whether or not we should exit due to a soft timeout.

The fix is to move the call to xprt_release() into call_decode() so
we can perform it after rpc_check_timeout().

Reported-by: Olga Kornievskaia <olga.kornievskaia@xxxxxxxxx>
Reported-by: Nick Bowler <nbowler@xxxxxxxxxx>
Fixes: cea57789e408 ("SUNRPC: Clean up")
Cc: stable@xxxxxxxxxxxxxxx # v5.1+
Signed-off-by: Trond Myklebust <trond.myklebust@xxxxxxxxxxxxxxx>
---
 net/sunrpc/clnt.c | 28 ++++++++++++++--------------
 1 file changed, 14 insertions(+), 14 deletions(-)

diff --git a/net/sunrpc/clnt.c b/net/sunrpc/clnt.c
index d6e57da56c94..4c02c37fa774 100644
--- a/net/sunrpc/clnt.c
+++ b/net/sunrpc/clnt.c
@@ -2426,17 +2426,21 @@ call_decode(struct rpc_task *task)
 		return;
 	case -EAGAIN:
 		task->tk_status = 0;
-		/* Note: rpc_decode_header() may have freed the RPC slot */
-		if (task->tk_rqstp == req) {
-			xdr_free_bvec(&req->rq_rcv_buf);
-			req->rq_reply_bytes_recvd = 0;
-			req->rq_rcv_buf.len = 0;
-			if (task->tk_client->cl_discrtry)
-				xprt_conditional_disconnect(req->rq_xprt,
-							    req->rq_connect_cookie);
-		}
+		xdr_free_bvec(&req->rq_rcv_buf);
+		req->rq_reply_bytes_recvd = 0;
+		req->rq_rcv_buf.len = 0;
+		if (task->tk_client->cl_discrtry)
+			xprt_conditional_disconnect(req->rq_xprt,
+						    req->rq_connect_cookie);
 		task->tk_action = call_encode;
 		rpc_check_timeout(task);
+		break;
+	case -EKEYREJECTED:
+		task->tk_action = call_reserve;
+		rpc_check_timeout(task);
+		rpcauth_invalcred(task);
+		/* Ensure we obtain a new XID if we retry! */
+		xprt_release(task);
 	}
 }
 
@@ -2572,11 +2576,7 @@ rpc_decode_header(struct rpc_task *task, struct xdr_stream *xdr)
 			break;
 		task->tk_cred_retry--;
 		trace_rpc__stale_creds(task);
-		rpcauth_invalcred(task);
-		/* Ensure we obtain a new XID! */
-		xprt_release(task);
-		task->tk_action = call_reserve;
-		return -EAGAIN;
+		return -EKEYREJECTED;
 	case rpc_autherr_badcred:
 	case rpc_autherr_badverf:
 		/* possibly garbled cred/verf? */
-- 
2.21.0

-- 
Trond Myklebust
Linux NFS client maintainer, Hammerspace
trond.myklebust@xxxxxxxxxxxxxxx