2021-04-13 07:08:30

by Rick Macklem

[permalink] [raw]
Subject: Linux NFSv4.1 client session seqid sometimes advances by 2

Hi,

During testing of a Fedora Core 30 (5.2.10 kernel) against a FreeBSD
server (4.1 mount), I have been simulating a network partitioning
for a few minutes (until the TCP connection goes to SYN_SENT on
the Linux client).

Sometimes, after the network partition heals, the FreeBSD server
replies NFS4ERR_SEQ_MISORDERED.
Looking at the packet trace, the seqid for the slot has advanced by
2 instead of 1. An RPC request for old-seqid + 1 never seems to get
sent.
--> Since sending an RPC with "seqid + 2" but never sending one
that is "seqid + 1" for a slot seems harmless, I have added an optional
hack (can be turned off), to allow this case instead of replying
NFS4ERR_SEQ_MISORDERED for it. The code will still reply
NFS4ERR_SEQ_MISORDERED if an RPC for the slot with
"old seqid + 1" in it.
--> Yes, doing this hack is a violation of RFC5661, but I've
done it anyhow.

If you are interested in a packet capture with this in it:
fetch https://people.freebsd.org/~rmacklem/linuxtofreenfs.pcap
- then look at packet #1945 and #2072
--> You'll see that slot #1 seqid goes from 4 to 6. There is no
slot#1 seqid 5 RPC sent on the wire.
(This packet capture was taken on the Linux client using
tcpdump.)
--> Btw, the "RST battle" you'll see in the above trace between
#2005 and #2068 that goes on until the FreeBSD
krpc/NFS times out the connection after 6min. seems to be a recent
FreeBSD TCP bug.
I have reproduced this seqid advances by 2 on an older system
that does not "RST battle" and allows the reconnect right away,
once the network partition is healed, so it does seem to be
relevant to this bug.

Someday, I will get around to upgrading to a more recent Linux
kernel and will test to see if I can still reproduce this bug.
On 5.2.10, it is intermittent and does not occur every time I
do the network partitioning test.

Mostly just fyi, rick


2021-04-13 15:25:35

by Olga Kornievskaia

[permalink] [raw]
Subject: Re: Linux NFSv4.1 client session seqid sometimes advances by 2

On Tue, Apr 13, 2021 at 3:08 AM Rick Macklem <[email protected]> wrote:
>
> Hi,
>
> During testing of a Fedora Core 30 (5.2.10 kernel) against a FreeBSD
> server (4.1 mount), I have been simulating a network partitioning
> for a few minutes (until the TCP connection goes to SYN_SENT on
> the Linux client).
>
> Sometimes, after the network partition heals, the FreeBSD server
> replies NFS4ERR_SEQ_MISORDERED.
> Looking at the packet trace, the seqid for the slot has advanced by
> 2 instead of 1. An RPC request for old-seqid + 1 never seems to get
> sent.
> --> Since sending an RPC with "seqid + 2" but never sending one
> that is "seqid + 1" for a slot seems harmless, I have added an optional
> hack (can be turned off), to allow this case instead of replying
> NFS4ERR_SEQ_MISORDERED for it. The code will still reply
> NFS4ERR_SEQ_MISORDERED if an RPC for the slot with
> "old seqid + 1" in it.
> --> Yes, doing this hack is a violation of RFC5661, but I've
> done it anyhow.
>
> If you are interested in a packet capture with this in it:
> fetch https://people.freebsd.org/~rmacklem/linuxtofreenfs.pcap
> - then look at packet #1945 and #2072
> --> You'll see that slot #1 seqid goes from 4 to 6. There is no
> slot#1 seqid 5 RPC sent on the wire.
> (This packet capture was taken on the Linux client using
> tcpdump.)
> --> Btw, the "RST battle" you'll see in the above trace between
> #2005 and #2068 that goes on until the FreeBSD
> krpc/NFS times out the connection after 6min. seems to be a recent
> FreeBSD TCP bug.
> I have reproduced this seqid advances by 2 on an older system
> that does not "RST battle" and allows the reconnect right away,
> once the network partition is healed, so it does seem to be
> relevant to this bug.
>
> Someday, I will get around to upgrading to a more recent Linux
> kernel and will test to see if I can still reproduce this bug.
> On 5.2.10, it is intermittent and does not occur every time I
> do the network partitioning test.
>
> Mostly just fyi, rick

Hi Rick,

I think this is happening because slotid=1 had something queued up
using seqid=5 and that was interrupted because the connection was
RSTed. For the interrupted slot, the client would send solo SEQUENCE
with +1 seqid.

2021-04-13 22:03:49

by J. Bruce Fields

[permalink] [raw]
Subject: Re: Linux NFSv4.1 client session seqid sometimes advances by 2

On Tue, Apr 13, 2021 at 09:31:37AM -0400, Olga Kornievskaia wrote:
> On Tue, Apr 13, 2021 at 3:08 AM Rick Macklem <[email protected]> wrote:
> >
> > Hi,
> >
> > During testing of a Fedora Core 30 (5.2.10 kernel) against a FreeBSD
> > server (4.1 mount), I have been simulating a network partitioning
> > for a few minutes (until the TCP connection goes to SYN_SENT on
> > the Linux client).
> >
> > Sometimes, after the network partition heals, the FreeBSD server
> > replies NFS4ERR_SEQ_MISORDERED.
> > Looking at the packet trace, the seqid for the slot has advanced by
> > 2 instead of 1. An RPC request for old-seqid + 1 never seems to get
> > sent.
> > --> Since sending an RPC with "seqid + 2" but never sending one
> > that is "seqid + 1" for a slot seems harmless, I have added an optional
> > hack (can be turned off), to allow this case instead of replying
> > NFS4ERR_SEQ_MISORDERED for it. The code will still reply
> > NFS4ERR_SEQ_MISORDERED if an RPC for the slot with
> > "old seqid + 1" in it.
> > --> Yes, doing this hack is a violation of RFC5661, but I've
> > done it anyhow.
> >
> > If you are interested in a packet capture with this in it:
> > fetch https://people.freebsd.org/~rmacklem/linuxtofreenfs.pcap
> > - then look at packet #1945 and #2072
> > --> You'll see that slot #1 seqid goes from 4 to 6. There is no
> > slot#1 seqid 5 RPC sent on the wire.
> > (This packet capture was taken on the Linux client using
> > tcpdump.)
> > --> Btw, the "RST battle" you'll see in the above trace between
> > #2005 and #2068 that goes on until the FreeBSD
> > krpc/NFS times out the connection after 6min. seems to be a recent
> > FreeBSD TCP bug.
> > I have reproduced this seqid advances by 2 on an older system
> > that does not "RST battle" and allows the reconnect right away,
> > once the network partition is healed, so it does seem to be
> > relevant to this bug.
> >
> > Someday, I will get around to upgrading to a more recent Linux
> > kernel and will test to see if I can still reproduce this bug.
> > On 5.2.10, it is intermittent and does not occur every time I
> > do the network partitioning test.
> >
> > Mostly just fyi, rick
>
> Hi Rick,
>
> I think this is happening because slotid=1 had something queued up
> using seqid=5 and that was interrupted because the connection was
> RSTed. For the interrupted slot, the client would send solo SEQUENCE
> with +1 seqid.

Doesn't the client send the solo SEQUENCE with seqid 5 in that case?

--b.

2021-04-13 23:09:28

by Olga Kornievskaia

[permalink] [raw]
Subject: Re: Linux NFSv4.1 client session seqid sometimes advances by 2

On Tue, Apr 13, 2021 at 1:17 PM J. Bruce Fields <[email protected]> wrote:
>
> On Tue, Apr 13, 2021 at 09:31:37AM -0400, Olga Kornievskaia wrote:
> > On Tue, Apr 13, 2021 at 3:08 AM Rick Macklem <[email protected]> wrote:
> > >
> > > Hi,
> > >
> > > During testing of a Fedora Core 30 (5.2.10 kernel) against a FreeBSD
> > > server (4.1 mount), I have been simulating a network partitioning
> > > for a few minutes (until the TCP connection goes to SYN_SENT on
> > > the Linux client).
> > >
> > > Sometimes, after the network partition heals, the FreeBSD server
> > > replies NFS4ERR_SEQ_MISORDERED.
> > > Looking at the packet trace, the seqid for the slot has advanced by
> > > 2 instead of 1. An RPC request for old-seqid + 1 never seems to get
> > > sent.
> > > --> Since sending an RPC with "seqid + 2" but never sending one
> > > that is "seqid + 1" for a slot seems harmless, I have added an optional
> > > hack (can be turned off), to allow this case instead of replying
> > > NFS4ERR_SEQ_MISORDERED for it. The code will still reply
> > > NFS4ERR_SEQ_MISORDERED if an RPC for the slot with
> > > "old seqid + 1" in it.
> > > --> Yes, doing this hack is a violation of RFC5661, but I've
> > > done it anyhow.
> > >
> > > If you are interested in a packet capture with this in it:
> > > fetch https://people.freebsd.org/~rmacklem/linuxtofreenfs.pcap
> > > - then look at packet #1945 and #2072
> > > --> You'll see that slot #1 seqid goes from 4 to 6. There is no
> > > slot#1 seqid 5 RPC sent on the wire.
> > > (This packet capture was taken on the Linux client using
> > > tcpdump.)
> > > --> Btw, the "RST battle" you'll see in the above trace between
> > > #2005 and #2068 that goes on until the FreeBSD
> > > krpc/NFS times out the connection after 6min. seems to be a recent
> > > FreeBSD TCP bug.
> > > I have reproduced this seqid advances by 2 on an older system
> > > that does not "RST battle" and allows the reconnect right away,
> > > once the network partition is healed, so it does seem to be
> > > relevant to this bug.
> > >
> > > Someday, I will get around to upgrading to a more recent Linux
> > > kernel and will test to see if I can still reproduce this bug.
> > > On 5.2.10, it is intermittent and does not occur every time I
> > > do the network partitioning test.
> > >
> > > Mostly just fyi, rick
> >
> > Hi Rick,
> >
> > I think this is happening because slotid=1 had something queued up
> > using seqid=5 and that was interrupted because the connection was
> > RSTed. For the interrupted slot, the client would send solo SEQUENCE
> > with +1 seqid.
>
> Doesn't the client send the solo SEQUENCE with seqid 5 in that case?

No it sends with seq+1 because NFS layer client doesn't know if seqid
actually was actually transmitted before the connection got caught
(and/or received by the server).

>
> --b.

2021-04-13 23:20:32

by J. Bruce Fields

[permalink] [raw]
Subject: Re: Linux NFSv4.1 client session seqid sometimes advances by 2

On Tue, Apr 13, 2021 at 02:59:27PM -0400, Olga Kornievskaia wrote:
> On Tue, Apr 13, 2021 at 1:17 PM J. Bruce Fields <[email protected]> wrote:
> >
> > On Tue, Apr 13, 2021 at 09:31:37AM -0400, Olga Kornievskaia wrote:
> > > On Tue, Apr 13, 2021 at 3:08 AM Rick Macklem <[email protected]> wrote:
> > > >
> > > > Hi,
> > > >
> > > > During testing of a Fedora Core 30 (5.2.10 kernel) against a FreeBSD
> > > > server (4.1 mount), I have been simulating a network partitioning
> > > > for a few minutes (until the TCP connection goes to SYN_SENT on
> > > > the Linux client).
> > > >
> > > > Sometimes, after the network partition heals, the FreeBSD server
> > > > replies NFS4ERR_SEQ_MISORDERED.
> > > > Looking at the packet trace, the seqid for the slot has advanced by
> > > > 2 instead of 1. An RPC request for old-seqid + 1 never seems to get
> > > > sent.
> > > > --> Since sending an RPC with "seqid + 2" but never sending one
> > > > that is "seqid + 1" for a slot seems harmless, I have added an optional
> > > > hack (can be turned off), to allow this case instead of replying
> > > > NFS4ERR_SEQ_MISORDERED for it. The code will still reply
> > > > NFS4ERR_SEQ_MISORDERED if an RPC for the slot with
> > > > "old seqid + 1" in it.
> > > > --> Yes, doing this hack is a violation of RFC5661, but I've
> > > > done it anyhow.
> > > >
> > > > If you are interested in a packet capture with this in it:
> > > > fetch https://people.freebsd.org/~rmacklem/linuxtofreenfs.pcap
> > > > - then look at packet #1945 and #2072
> > > > --> You'll see that slot #1 seqid goes from 4 to 6. There is no
> > > > slot#1 seqid 5 RPC sent on the wire.
> > > > (This packet capture was taken on the Linux client using
> > > > tcpdump.)
> > > > --> Btw, the "RST battle" you'll see in the above trace between
> > > > #2005 and #2068 that goes on until the FreeBSD
> > > > krpc/NFS times out the connection after 6min. seems to be a recent
> > > > FreeBSD TCP bug.
> > > > I have reproduced this seqid advances by 2 on an older system
> > > > that does not "RST battle" and allows the reconnect right away,
> > > > once the network partition is healed, so it does seem to be
> > > > relevant to this bug.
> > > >
> > > > Someday, I will get around to upgrading to a more recent Linux
> > > > kernel and will test to see if I can still reproduce this bug.
> > > > On 5.2.10, it is intermittent and does not occur every time I
> > > > do the network partitioning test.
> > > >
> > > > Mostly just fyi, rick
> > >
> > > Hi Rick,
> > >
> > > I think this is happening because slotid=1 had something queued up
> > > using seqid=5 and that was interrupted because the connection was
> > > RSTed. For the interrupted slot, the client would send solo SEQUENCE
> > > with +1 seqid.
> >
> > Doesn't the client send the solo SEQUENCE with seqid 5 in that case?
>
> No it sends with seq+1 because NFS layer client doesn't know if seqid
> actually was actually transmitted before the connection got caught
> (and/or received by the server).

But then the MISORDERED tells the client it wasn't received, so the
client follows up with a call with seqid 5--is that what happens?

Sorry, I seem to recall we went through this all a couple years ago, but
now I've forgotten how it works.

--b.

2021-04-14 06:49:27

by Olga Kornievskaia

[permalink] [raw]
Subject: Re: Linux NFSv4.1 client session seqid sometimes advances by 2

On Tue, Apr 13, 2021 at 3:29 PM J. Bruce Fields <[email protected]> wrote:
>
> On Tue, Apr 13, 2021 at 02:59:27PM -0400, Olga Kornievskaia wrote:
> > On Tue, Apr 13, 2021 at 1:17 PM J. Bruce Fields <[email protected]> wrote:
> > >
> > > On Tue, Apr 13, 2021 at 09:31:37AM -0400, Olga Kornievskaia wrote:
> > > > On Tue, Apr 13, 2021 at 3:08 AM Rick Macklem <[email protected]> wrote:
> > > > >
> > > > > Hi,
> > > > >
> > > > > During testing of a Fedora Core 30 (5.2.10 kernel) against a FreeBSD
> > > > > server (4.1 mount), I have been simulating a network partitioning
> > > > > for a few minutes (until the TCP connection goes to SYN_SENT on
> > > > > the Linux client).
> > > > >
> > > > > Sometimes, after the network partition heals, the FreeBSD server
> > > > > replies NFS4ERR_SEQ_MISORDERED.
> > > > > Looking at the packet trace, the seqid for the slot has advanced by
> > > > > 2 instead of 1. An RPC request for old-seqid + 1 never seems to get
> > > > > sent.
> > > > > --> Since sending an RPC with "seqid + 2" but never sending one
> > > > > that is "seqid + 1" for a slot seems harmless, I have added an optional
> > > > > hack (can be turned off), to allow this case instead of replying
> > > > > NFS4ERR_SEQ_MISORDERED for it. The code will still reply
> > > > > NFS4ERR_SEQ_MISORDERED if an RPC for the slot with
> > > > > "old seqid + 1" in it.
> > > > > --> Yes, doing this hack is a violation of RFC5661, but I've
> > > > > done it anyhow.
> > > > >
> > > > > If you are interested in a packet capture with this in it:
> > > > > fetch https://people.freebsd.org/~rmacklem/linuxtofreenfs.pcap
> > > > > - then look at packet #1945 and #2072
> > > > > --> You'll see that slot #1 seqid goes from 4 to 6. There is no
> > > > > slot#1 seqid 5 RPC sent on the wire.
> > > > > (This packet capture was taken on the Linux client using
> > > > > tcpdump.)
> > > > > --> Btw, the "RST battle" you'll see in the above trace between
> > > > > #2005 and #2068 that goes on until the FreeBSD
> > > > > krpc/NFS times out the connection after 6min. seems to be a recent
> > > > > FreeBSD TCP bug.
> > > > > I have reproduced this seqid advances by 2 on an older system
> > > > > that does not "RST battle" and allows the reconnect right away,
> > > > > once the network partition is healed, so it does seem to be
> > > > > relevant to this bug.
> > > > >
> > > > > Someday, I will get around to upgrading to a more recent Linux
> > > > > kernel and will test to see if I can still reproduce this bug.
> > > > > On 5.2.10, it is intermittent and does not occur every time I
> > > > > do the network partitioning test.
> > > > >
> > > > > Mostly just fyi, rick
> > > >
> > > > Hi Rick,
> > > >
> > > > I think this is happening because slotid=1 had something queued up
> > > > using seqid=5 and that was interrupted because the connection was
> > > > RSTed. For the interrupted slot, the client would send solo SEQUENCE
> > > > with +1 seqid.
> > >
> > > Doesn't the client send the solo SEQUENCE with seqid 5 in that case?
> >
> > No it sends with seq+1 because NFS layer client doesn't know if seqid
> > actually was actually transmitted before the connection got caught
> > (and/or received by the server).
>
> But then the MISORDERED tells the client it wasn't received, so the
> client follows up with a call with seqid 5--is that what happens?

Correct. If there were no error then the server did indeed consume
seqid. And if an error was returned then the client knows to
decrement.

> Sorry, I seem to recall we went through this all a couple years ago, but
> now I've forgotten how it works.
>
> --b.

2021-04-14 07:36:55

by Rick Macklem

[permalink] [raw]
Subject: Re: Linux NFSv4.1 client session seqid sometimes advances by 2

Olga Kornievskaia wrote:
>On Tue, Apr 13, 2021 at 3:29 PM J. Bruce Fields <[email protected]> wrote:
>>
>> On Tue, Apr 13, 2021 at 02:59:27PM -0400, Olga Kornievskaia wrote:
>> > On Tue, Apr 13, 2021 at 1:17 PM J. Bruce Fields <[email protected]> wrote:
>> > >
>> > > On Tue, Apr 13, 2021 at 09:31:37AM -0400, Olga Kornievskaia wrote:
>> > > > On Tue, Apr 13, 2021 at 3:08 AM Rick Macklem <[email protected]> wrote:
>> > > > >
>> > > > > Hi,
>> > > > >
>> > > > > During testing of a Fedora Core 30 (5.2.10 kernel) against a FreeBSD
>> > > > > server (4.1 mount), I have been simulating a network partitioning
>> > > > > for a few minutes (until the TCP connection goes to SYN_SENT on
>> > > > > the Linux client).
>> > > > >
>> > > > > Sometimes, after the network partition heals, the FreeBSD server
>> > > > > replies NFS4ERR_SEQ_MISORDERED.
>> > > > > Looking at the packet trace, the seqid for the slot has advanced by
>> > > > > 2 instead of 1. An RPC request for old-seqid + 1 never seems to get
>> > > > > sent.
>> > > > > --> Since sending an RPC with "seqid + 2" but never sending one
>> > > > > that is "seqid + 1" for a slot seems harmless, I have added an optional
>> > > > > hack (can be turned off), to allow this case instead of replying
>> > > > > NFS4ERR_SEQ_MISORDERED for it. The code will still reply
>> > > > > NFS4ERR_SEQ_MISORDERED if an RPC for the slot with
>> > > > > "old seqid + 1" in it.
>> > > > > --> Yes, doing this hack is a violation of RFC5661, but I've
>> > > > > done it anyhow.
>> > > > >
>> > > > > If you are interested in a packet capture with this in it:
>> > > > > fetch https://people.freebsd.org/~rmacklem/linuxtofreenfs.pcap
>> > > > > - then look at packet #1945 and #2072
>> > > > > --> You'll see that slot #1 seqid goes from 4 to 6. There is no
>> > > > > slot#1 seqid 5 RPC sent on the wire.
>> > > > > (This packet capture was taken on the Linux client using
>> > > > > tcpdump.)
>> > > > > --> Btw, the "RST battle" you'll see in the above trace between
>> > > > > #2005 and #2068 that goes on until the FreeBSD
>> > > > > krpc/NFS times out the connection after 6min. seems to be a recent
>> > > > > FreeBSD TCP bug.
>> > > > > I have reproduced this seqid advances by 2 on an older system
>> > > > > that does not "RST battle" and allows the reconnect right away,
>> > > > > once the network partition is healed, so it does seem to be
>> > > > > relevant to this bug.
>> > > > >
>> > > > > Someday, I will get around to upgrading to a more recent Linux
>> > > > > kernel and will test to see if I can still reproduce this bug.
>> > > > > On 5.2.10, it is intermittent and does not occur every time I
>> > > > > do the network partitioning test.
>> > > > >
>> > > > > Mostly just fyi, rick
>> > > >
>> > > > Hi Rick,
>> > > >
>> > > > I think this is happening because slotid=1 had something queued up
>> > > > using seqid=5 and that was interrupted because the connection was
>> > > > RSTed. For the interrupted slot, the client would send solo SEQUENCE
>> > > > with +1 seqid.
>> > >
>> > > Doesn't the client send the solo SEQUENCE with seqid 5 in that case?
>> >
>> > No it sends with seq+1 because NFS layer client doesn't know if seqid
>> > actually was actually transmitted before the connection got caught
>> > (and/or received by the server).
>>
>> But then the MISORDERED tells the client it wasn't received, so the
>> client follows up with a call with seqid 5--is that what happens?
>
>Correct. If there were no error then the server did indeed consume
>seqid. And if an error was returned then the client knows to
>decrement.
Ok. Yes. I took a closer look at the packet capture and that is what happened.
On slot#1...(server expecting seqid == 5):
- Sequence with seqid 6
--> reply NFS4ERR_SEQ_MISORDERED
- next use of slot#1, Sequence with seqid 5
--> reply NFS_OK
- next use of slot#1, Sequence with seqid 6
--> reply NFS_OK
- then slot#1 gets used normally by other RPCs

So it's an intentional "probe to re-synchronize the
seqid for the slot"?
Clever.

I'll back my "hack" out, since I now see it is not necessary
(and does violate the RFC'-).

So, is this how the Linux client deals with "soft,intr" NFSv4.1
mounts?
--> I've never solved that for FreeBSD and just note in the BUGS
section of the man page that "soft,intr" mount options break
an NFSv4 mount.
I might *borrow* this idea. I'll attribute it to whoever thought of
the idea, if you let me know who that is?

Thanks for the clarification, rick

> Sorry, I seem to recall we went through this all a couple years ago, but
> now I've forgotten how it works.
>
> --b.