Received-SPF: pass (google.com: domain of linux-nfs-owner@vger.kernel.org designates 23.128.96.18 as permitted sender) client-ip=23.128.96.18;
Content-Type: text/plain; charset="utf-8"
Content-Transfer-Encoding: quoted-printable
MIME-Version: 1.0
From:   "NeilBrown" <neilb@suse.de>
To:     "Mike Javorski" <mike.javorski@gmail.com>
Cc:     linux-nfs@vger.kernel.org
Subject: Re: NFS server regression in kernel 5.13 (tested w/ 5.13.9)
In-reply-to: <CAOv1SKAaSbfw53LWCCrvGCHESgdtCf5h275Zkzi9_uHkqnCrdg@mail.gmail.com>
References: <CAOv1SKCmdtchm5Z2NU80o49tkrHpAkPFaHKj4-vLDN5bZNCz-Q@mail.gmail.com>,
 <162846730406.22632.14734595494457390936@noble.neil.brown.name>,
 <CAOv1SKBZ7sGBnvG9-M+De+s=CfU=H_GBs4hJah1E4ks+NSMyPw@mail.gmail.com>,
 <CAOv1SKCUM5cGuXWAc7dsXtbmPMATqd245juC+S9gVXHWiZsvmQ@mail.gmail.com>,
 <162855893202.12431.3423894387218130632@noble.neil.brown.name>,
 <CAOv1SKAaSbfw53LWCCrvGCHESgdtCf5h275Zkzi9_uHkqnCrdg@mail.gmail.com>
Date:   Fri, 13 Aug 2021 12:39:44 +1000
Message-id: <162882238416.1695.4958036322575947783@noble.neil.brown.name>
Precedence: bulk

On Fri, 13 Aug 2021, Mike Javorski wrote:
> Neil:
>=20
> Apologies for the delay, your message didn't get properly flagged in my ema=
il.

:-)

>=20
> To answer your questions, both client (my Desktop PC) and server (my
> NAS) are running ArchLinux; client w/ current kernel (5.13.9), server
> w/ current or alternate testing kernels (see below).

So the bug could be in the server or the client.  I assume you are
careful to test a client against a know-good server, or a server against
a known-good client.

>                                                                 I
> intend to spend some time this weekend attempting to get the tcpdump.
> My initial attempts wound up with 400+Mb files which would be
> difficult to ship and use for diagnostics.

Rather than you sending me the dump, I'll send you the code.

Run
  tshark -r filename -d tcp.port=3D=3D2049,rpc -Y 'tcp.port=3D=3D2049 && rpc.=
time > 1'

This will ensure the NFS traffic is actually decoded as NFS and then
report only NFS(rpc) replies that arrive more than 1 second after the
request.
You can add

    -T fields -e frame.number -e rpc.time

to find out what the actual delay was.

If it reports any, that will be interesting.  Try with a larger time if
necessary to get a modest number of hits.  Using editcap and the given
frame number you can select out 1000 packets either side of the problem
and that should compress to be small enough to transport.

However it might not find anything.  If the reply never arrives, you'll
never get a reply with a long timeout.  So we need to check that
everything got a reply...

 tshark -r filename -t tcp.port=3D=3D2049,rpc  \
   -Y 'tcp.port=3D=3D2049 && rpc.msg =3D=3D 0' -T fields \
   -e rpc.xid -e frame.number | sort > /tmp/requests

 tshark -r filename -t tcp.port=3D=3D2049,rpc  \
   -Y 'tcp.port=3D=3D2049 && rpc.msg =3D=3D 1' -T fields \
   -e rpc.xid -e frame.number | sort > /tmp/replies

 join -a1 /tmp/requests /tmp/replies | awk 'NF=3D=3D2'

This should list the xid and frame number of all requests that didn't
get a reply.  Again, editcap can extract a range of frames into a file of
manageable size.

Another possibility is that requests are getting replies, but the reply
says "NFS4ERR_DELAY"

 tshark -r filename -t tcp.port=3D=3D2049,rpc -Y nfs.nfsstat4=3D=3D10008

should report any reply with that error code.

Hopefully something there will be interesting.

NeilBrown