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;
Date:   Fri, 11 Oct 2019 17:42:53 +0800
From:   Murphy Zhou <jencce.kernel@gmail.com>
To:     Olga Kornievskaia <aglo@umich.edu>
Cc:     Murphy Zhou <jencce.kernel@gmail.com>,
        linux-nfs <linux-nfs@vger.kernel.org>,
        Trond Myklebust <trondmy@gmail.com>
Subject: Re: [PATCH] NFSv4: fix stateid refreshing when CLOSE racing with OPEN
Message-ID: <20191011094253.yjwncvqv4cnq7wpn@xzhoux.usersys.redhat.com>
References: <20191010074020.o2uwtuyegtmfdlze@XZHOUW.usersys.redhat.com>
 <CAN-5tyGKNFsxQHne4hFhON1VRZzCkUjwFMX3ZuzfLASgEN0pMw@mail.gmail.com>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <CAN-5tyGKNFsxQHne4hFhON1VRZzCkUjwFMX3ZuzfLASgEN0pMw@mail.gmail.com>
Sender: linux-nfs-owner@vger.kernel.org
Precedence: bulk

On Thu, Oct 10, 2019 at 01:32:50PM -0400, Olga Kornievskaia wrote:
> 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.

Do you mean ulimit -s ? I set it to 'unlimited' and still can reproduce
this.

Thanks,
M
> 
> 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
> >