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

[Olga Kornievskaia]

On Wed, May 29, 2019 at 1:14 PM Trond Myklebust <trondmy@xxxxxxxxxxxxxxx> wrote:
>
> 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 think this is actually different than what I encountered for the
umount case but the trigger is the same -- failing validation.

I tried to reproduce Nick's oops on 5.2-rc but haven't been able to
(but I'm not confident I produced the right trigger conditions. will
try 5.1).


>
> 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
>
>