Received-SPF: pass (google.com: best guess record for domain of linux-nfs-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
MIME-Version: 1.0
References: <20191010074020.o2uwtuyegtmfdlze@XZHOUW.usersys.redhat.com>
In-Reply-To: <20191010074020.o2uwtuyegtmfdlze@XZHOUW.usersys.redhat.com>
From:   Olga Kornievskaia <aglo@umich.edu>
Date:   Thu, 10 Oct 2019 13:32:50 -0400
Message-ID: <CAN-5tyGKNFsxQHne4hFhON1VRZzCkUjwFMX3ZuzfLASgEN0pMw@mail.gmail.com>
Subject: Re: [PATCH] NFSv4: fix stateid refreshing when CLOSE racing with OPEN
To:     Murphy Zhou <jencce.kernel@gmail.com>
Cc:     linux-nfs <linux-nfs@vger.kernel.org>,
        Trond Myklebust <trondmy@gmail.com>
Content-Type: text/plain; charset="UTF-8"
Sender: linux-nfs-owner@vger.kernel.org
Precedence: bulk

On Thu, Oct 10, 2019 at 3:42 AM Murphy Zhou <jencce.kernel@gmail.com> wrote:
>
> Since commit:
>   [0e0cb35] NFSv4: Handle NFS4ERR_OLD_STATEID in CLOSE/OPEN_DOWNGRADE
>
> xfstests generic/168 on v4.2 starts to fail because reflink call gets:
>   +XFS_IOC_CLONE_RANGE: Resource temporarily unavailable

I don't believe this failure has to do with getting ERR_OLD_STATEID on
the CLOSE. What you see on the network trace is expected as the client
in parallel sends OPEN/CLOSE thus server will fail the CLOSE with the
ERR_OLD_STATEID since it already updated its stateid for the OPEN.

> In tshark output, NFS4ERR_OLD_STATEID stands out when comparing with
> good ones:
>
>  5210   NFS 406 V4 Reply (Call In 5209) OPEN StateID: 0xadb5
>  5211   NFS 314 V4 Call GETATTR FH: 0x8d44a6b1
>  5212   NFS 250 V4 Reply (Call In 5211) GETATTR
>  5213   NFS 314 V4 Call GETATTR FH: 0x8d44a6b1
>  5214   NFS 250 V4 Reply (Call In 5213) GETATTR
>  5216   NFS 422 V4 Call WRITE StateID: 0xa818 Offset: 851968 Len: 65536
>  5218   NFS 266 V4 Reply (Call In 5216) WRITE
>  5219   NFS 382 V4 Call OPEN DH: 0x8d44a6b1/
>  5220   NFS 338 V4 Call CLOSE StateID: 0xadb5
>  5222   NFS 406 V4 Reply (Call In 5219) OPEN StateID: 0xa342
>  5223   NFS 250 V4 Reply (Call In 5220) CLOSE Status: NFS4ERR_OLD_STATEID
>  5225   NFS 338 V4 Call CLOSE StateID: 0xa342
>  5226   NFS 314 V4 Call GETATTR FH: 0x8d44a6b1
>  5227   NFS 266 V4 Reply (Call In 5225) CLOSE
>  5228   NFS 250 V4 Reply (Call In 5226) GETATTR

"resource temporarily unavailable" is more likely to do with ulimit limits.

I also saw the same error. After I increased the ulimit for the stack
size, the problem went away. There might still be a problem somewhere
in the kernel.

Trond, is it possible that we have too many CLOSE recovery on the
stack that's eating up stack space?

> It's easy to reproduce. By printing some logs, found that we are making
> CLOSE seqid larger then OPEN seqid when racing.
>
> Fix this by not bumping seqid when it's equal to OPEN seqid. Also
> put the whole changing process into seqlock read protection in case
> really bad luck, and this is the same locking behavior with the
> old deleted function.
>
> Fixes: 0e0cb35b417f ("NFSv4: Handle NFS4ERR_OLD_STATEID in CLOSE/OPEN_DOWNGRADE")
> Signed-off-by: Murphy Zhou <jencce.kernel@gmail.com>
> ---
>  fs/nfs/nfs4proc.c | 13 ++++++++-----
>  1 file changed, 8 insertions(+), 5 deletions(-)
>
> diff --git a/fs/nfs/nfs4proc.c b/fs/nfs/nfs4proc.c
> index 11eafcf..6db5a09 100644
> --- a/fs/nfs/nfs4proc.c
> +++ b/fs/nfs/nfs4proc.c
> @@ -3334,12 +3334,13 @@ static void nfs4_sync_open_stateid(nfs4_stateid *dst,
>                         break;
>                 }
>                 seqid_open = state->open_stateid.seqid;
> -               if (read_seqretry(&state->seqlock, seq))
> -                       continue;
>
>                 dst_seqid = be32_to_cpu(dst->seqid);
>                 if ((s32)(dst_seqid - be32_to_cpu(seqid_open)) < 0)
>                         dst->seqid = seqid_open;
> +
> +               if (read_seqretry(&state->seqlock, seq))
> +                       continue;
>                 break;
>         }
>  }
> @@ -3367,14 +3368,16 @@ static bool nfs4_refresh_open_old_stateid(nfs4_stateid *dst,
>                         break;
>                 }
>                 seqid_open = state->open_stateid.seqid;
> -               if (read_seqretry(&state->seqlock, seq))
> -                       continue;
>
>                 dst_seqid = be32_to_cpu(dst->seqid);
> -               if ((s32)(dst_seqid - be32_to_cpu(seqid_open)) >= 0)
> +               if ((s32)(dst_seqid - be32_to_cpu(seqid_open)) > 0)
>                         dst->seqid = cpu_to_be32(dst_seqid + 1);
>                 else
>                         dst->seqid = seqid_open;
> +
> +               if (read_seqretry(&state->seqlock, seq))
> +                       continue;
> +
>                 ret = true;
>                 break;
>         }
> --
> 1.8.3.1
>