tue...@freebsd.org wrote:
>> On 10. Apr 2021, at 02:44, Rick Macklem <rmack...@uoguelph.ca> wrote:
>>
>> tue...@freebsd.org wrote:
>>>> On 6. Apr 2021, at 01:24, Rick Macklem <rmack...@uoguelph.ca> wrote:
>>>>
>>>> tue...@freebsd.org wrote:
>>>> [stuff snipped]
>>>>> OK. What is the FreeBSD version you are using?
>>>> main Dec. 23, 2020.
>>>>
>>>>>
>>>>> It seems that the TCP connection on the FreeBSD is still alive,
>>>>> Linux has decided to start a new TCP connection using the old
>>>>> port numbers. So it sends a SYN. The response is a challenge ACK
>>>>> and Linux responds with a RST. This looks good so far. However,
>>>>> FreeBSD should accept the RST and kill the TCP connection. The
>>>>> next SYN from the Linux side would establish a new TCP connection.
>>>>>
>>>>> So I'm wondering why the RST is not accepted. I made the timestamp
>>>>> checking stricter but introduced a bug where RST segments without
>>>>> timestamps were ignored. This was fixed.
>>>>>
>>>>> Introduced in main on 2020/11/09:
>>>>> https://svnweb.freebsd.org/changeset/base/367530
>>>>> Introduced in stable/12 on 2020/11/30:
>>>>> https://svnweb.freebsd.org/changeset/base/36818
>>>>>> Fix in main on 2021/01/13:
>>>>> https://cgit.FreeBSD.org/src/commit/?id=cc3c34859eab1b317d0f38731355b53f7d978c97
>>>>> Fix in stable/12 on 2021/01/24:
>>>>> https://cgit.FreeBSD.org/src/commit/?id=d05d908d6d3c85479c84c707f931148439ae826b
>>>>>
>>>>> Are you using a version which is affected by this bug?
>>>> I was. Now I've applied the patch.
>>>> Bad News. It did not fix the problem.
>>>> It still gets into an endless "ignore RST" and stay established when
>>>> the Send-Q is empty.
>>> OK. Let us focus on this case.
>>>
>>> Could you:
>>> 1. sudo sysctl net.inet.tcp.log_debug=1
>>> 2. repeat the situation where RSTs are ignored.
>>> 3. check if there is some output on the console (/var/log/messages).
>>> 4. Either provide the output or let me know that there is none.
>> Well, I have some good news and some bad news (the bad is mostly for
>> Richard).
>> The only message logged is:
>> tcpflags 0x4<RST>; tcp_do_segment: Timestamp missing, segment processed
>> normally
>>
>> But...the RST battle no longer occurs. Just one RST that works and then
>> the SYN gets SYN,ACK'd by the FreeBSD end and off it goes...
>The above is what I would expect if you integrated
>cc3c34859eab1b317d0f38731355b53f7d978c97
>or reverted r367530. Did you do that?
r367530 is in the kernel that does not cause the "RST battle".
>
>
> So, what is different?
>
> r367492 is reverted from the FreeBSD server.
Only that? So you still have the bug I introduced in tree, but the RST segment
is accepted?
No. The kernel being tested includes the fix (you committed mid-January) for
the bug
that went in in Nov.
However, adding the mid-January patch did not fix the problem.
Then reverting r367492 (and only r367492) made the problem go away.
I did not expect reverting r367492 to affect this.
I reverted r367492 because otis@ gets Linux client mounts "stuck" against a
FreBSD13
NFS server, where the Recv-Q size grows and the client gets no RPC replies.
Other
clients are still working fine. I can only think of one explanations for this:
- An upcall gets missed or occurs at the wrong time.
--> Since what this patch does is move where the upcalls is done, it is the
logical
culprit.
Hopefully otis@ will be able to determine if reverting r367492 fixes the
problem.
This will take weeks, since the problem recently took two weeks to recur.
--> This would be the receive path, so reverting the send path would not
be
relevant.
*** I'd like to hear from otis@ before testing a "send path only" revert.
--> Also, it has been a long time since I worked on the socket upcall code, but
I
vaguely remember that the upcalls needed to be done before SOCKBUF_LOCK()
is dropped to ensure that the socket buffer is in the expected state.
r367492 drops SOCKBUF_LOCK() and then picks it up again for the upcalls.
I'll send you guys the otis@ problem email. (I don't think that one is cc'd to
a list.
rick
Best regards
Michael
> I did the revert because I think it might be what otis@ hang is being
> caused by. (In his case, the Recv-Q grows on the socket for the
> stuck Linux client, while others work.
>
> Why does reverting fix this?
> My only guess is that the krpc gets the upcall right away and sees
> a EPIPE when it does soreceive()->results in soshutdown(SHUT_WR).
> I know from a printf that this happened, but whether it caused the
> RST battle to not happen, I don't know.
>
> I can put r367492 back in and do more testing if you'd like, but
> I think it probably needs to be reverted?
>
> This does not explain the original hung Linux client problem,
> but does shed light on the RST war I could create by doing a
> network partitioning.
>
> rick
>
> Best regards
> Michael
>>
>> If the Send-Q is non-empty when I partition, it recovers fine,
>> sometimes not even needing to see an RST.
>>
>> rick
>> ps: If you think there might be other recent changes that matter,
>> just say the word and I'll upgrade to bits de jur.
>>
>> rick
>>
>> Best regards
>> Michael
>>>
>>> If I wait long enough before healing the partition, it will
>>> go to FIN_WAIT_1, and then if I plug it back in, it does not
>>> do battle (at least not for long).
>>>
>>> Btw, I have one running now that seems stuck really good.
>>> It has been 20minutes since I plugged the net cable back in.
>>> (Unfortunately, I didn't have tcpdump running until after
>>> I saw it was not progressing after healing.
>>> --> There is one difference. There was a 6minute timeout
>>> enabled on the server krpc for "no activity", which is
>>> now disabled like it is for NFSv4.1 in freebsd-current.
>>> I had forgotten to re-disable it.
>>> So, when it does battle, it might have been the 6minute
>>> timeout, which would then do the soshutdown(..SHUT_WR)
>>> which kept it from getting "stuck" forever.
>>> -->This time I had to reboot the FreeBSD NFS server to
>>> get the Linux client unstuck, so this one looked a lot
>>> like what has been reported.
>>> The pcap for this one, started after the network was plugged
>>> back in and I noticed it was stuck for quite a while is here:
>>> fetch https://people.freebsd.org/~rmacklem/stuck.pcap
>>>
>>> In it, there is just a bunch of RST followed by SYN sent
>>> from client->FreeBSD and FreeBSD just keeps sending
>>> acks for the old segment back.
>>> --> It looks like FreeBSD did the "RST, ACK" after the
>>> krpc did a soshutdown(..SHUT_WR) on the socket,
>>> for the one you've been looking at.
>>> I'll test some more...
>>>
>>>> I would like to understand why the reestablishment of the connection
>>>> did not work...
>>> It is looking like it takes either a non-empty send-q or a
>>> soshutdown(..SHUT_WR) to get the FreeBSD socket
>>> out of established, where it just ignores the RSTs and
>>> SYN packets.
>>>
>>> Thanks for looking at it, rick
>>>
>>> Best regards
>>> Michael
>>>>
>>>> Have fun with it, rick
>>>>
>>>>
>>>> ________________________________________
>>>> From: tue...@freebsd.org <tue...@freebsd.org>
>>>> Sent: Sunday, April 4, 2021 12:41 PM
>>>> To: Rick Macklem
>>>> Cc: Scheffenegger, Richard; Youssef GHORBAL; freebsd-net@freebsd.org
>>>> Subject: Re: NFS Mount Hangs
>>>>
>>>> CAUTION: This email originated from outside of the University of Guelph.
>>>> Do not click links or open attachments unless you recognize the sender and
>>>> know the content is safe. If in doubt, forward suspicious emails to
>>>> ith...@uoguelph.ca
>>>>
>>>>
>>>>> On 4. Apr 2021, at 17:27, Rick Macklem <rmack...@uoguelph.ca> wrote:
>>>>>
>>>>> Well, I'm going to cheat and top post, since this is elated info. and
>>>>> not really part of the discussion...
>>>>>
>>>>> I've been testing network partitioning between a Linux client (5.2 kernel)
>>>>> and a FreeBSD-current NFS server. I have not gotten a solid hang, but
>>>>> I have had the Linux client doing "battle" with the FreeBSD server for
>>>>> several minutes after un-partitioning the connection.
>>>>>
>>>>> The battle basically consists of the Linux client sending an RST, followed
>>>>> by a SYN.
>>>>> The FreeBSD server ignores the RST and just replies with the same old ack.
>>>>> --> This varies from "just a SYN" that succeeds to 100+ cycles of the
>>>>> above
>>>>> over several minutes.
>>>>>
>>>>> I had thought that an RST was a "pretty heavy hammer", but FreeBSD seems
>>>>> pretty good at ignoring it.
>>>>>
>>>>> A full packet capture of one of these is in
>>>>> /home/rmacklem/linuxtofreenfs.pcap
>>>>> in case anyone wants to look at it.
>>>> On freefall? I would like to take a look at it...
>>>>
>>>> Best regards
>>>> Michael
>>>>>
>>>>> Here's a tcpdump snippet of the interesting part (see the *** comments):
>>>>> 19:10:09.305775 IP nfsv4-new3.home.rick.nfsd >
>>>>> nfsv4-linux.home.rick.apex-mesh: Flags [P.], seq 202585:202749, ack
>>>>> 212293, win 29128, options [nop,nop,TS val 2073636037 ecr 2671204825],
>>>>> length 164: NFS reply xid 613153685 reply ok 160 getattr NON 4 ids
>>>>> 0/33554432 sz 0
>>>>> 19:10:09.305850 IP nfsv4-linux.home.rick.apex-mesh >
>>>>> nfsv4-new3.home.rick.nfsd: Flags [.], ack 202749, win 501, options
>>>>> [nop,nop,TS val 2671204825 ecr 2073636037], length 0
>>>>> *** Network is now partitioned...
>>>>>
>>>>> 19:10:09.407840 IP nfsv4-linux.home.rick.apex-mesh >
>>>>> nfsv4-new3.home.rick.nfsd: Flags [P.], seq 212293:212525, ack 202749, win
>>>>> 501, options [nop,nop,TS val 2671204927 ecr 2073636037], length 232: NFS
>>>>> request xid 629930901 228 getattr fh 0,1/53
>>>>> 19:10:09.615779 IP nfsv4-linux.home.rick.apex-mesh >
>>>>> nfsv4-new3.home.rick.nfsd: Flags [P.], seq 212293:212525, ack 202749, win
>>>>> 501, options [nop,nop,TS val 2671205135 ecr 2073636037], length 232: NFS
>>>>> request xid 629930901 228 getattr fh 0,1/53
>>>>> 19:10:09.823780 IP nfsv4-linux.home.rick.apex-mesh >
>>>>> nfsv4-new3.home.rick.nfsd: Flags [P.], seq 212293:212525, ack 202749, win
>>>>> 501, options [nop,nop,TS val 2671205343 ecr 2073636037], length 232: NFS
>>>>> request xid 629930901 228 getattr fh 0,1/53
>>>>> *** Lots of lines snipped.
>>>>>
>>>>>
>>>>> 19:13:41.295783 ARP, Request who-has nfsv4-new3.home.rick tell
>>>>> nfsv4-linux.home.rick, length 28
>>>>> 19:13:42.319767 ARP, Request who-has nfsv4-new3.home.rick tell
>>>>> nfsv4-linux.home.rick, length 28
>>>>> 19:13:46.351966 ARP, Request who-has nfsv4-new3.home.rick tell
>>>>> nfsv4-linux.home.rick, length 28
>>>>> 19:13:47.375790 ARP, Request who-has nfsv4-new3.home.rick tell
>>>>> nfsv4-linux.home.rick, length 28
>>>>> 19:13:48.399786 ARP, Request who-has nfsv4-new3.home.rick tell
>>>>> nfsv4-linux.home.rick, length 28
>>>>> *** Network is now unpartitioned...
>>>>>
>>>>> 19:13:48.399990 ARP, Reply nfsv4-new3.home.rick is-at d4:be:d9:07:81:72
>>>>> (oui Unknown), length 46
>>>>> 19:13:48.400002 IP nfsv4-linux.home.rick.apex-mesh >
>>>>> nfsv4-new3.home.rick.nfsd: Flags [S], seq 416692300, win 64240, options
>>>>> [mss 1460,sackOK,TS val 2671421871 ecr 0,nop,wscale 7], length 0
>>>>> 19:13:48.400185 IP nfsv4-new3.home.rick.nfsd >
>>>>> nfsv4-linux.home.rick.apex-mesh: Flags [.], ack 212293, win 29127,
>>>>> options [nop,nop,TS val 2073855137 ecr 2671204825], length 0
>>>>> 19:13:48.400273 IP nfsv4-linux.home.rick.apex-mesh >
>>>>> nfsv4-new3.home.rick.nfsd: Flags [R], seq 964161458, win 0, length 0
>>>>> 19:13:49.423833 IP nfsv4-linux.home.rick.apex-mesh >
>>>>> nfsv4-new3.home.rick.nfsd: Flags [S], seq 416692300, win 64240, options
>>>>> [mss 1460,sackOK,TS val 2671424943 ecr 0,nop,wscale 7], length 0
>>>>> 19:13:49.424056 IP nfsv4-new3.home.rick.nfsd >
>>>>> nfsv4-linux.home.rick.apex-mesh: Flags [.], ack 212293, win 29127,
>>>>> options [nop,nop,TS val 2073856161 ecr 2671204825], length 0
>>>>> *** This "battle" goes on for 223sec...
>>>>> I snipped out 13 cycles of this "Linux sends an RST, followed by SYN"
>>>>> "FreeBSD replies with same old ACK". In another test run I saw this
>>>>> cycle continue non-stop for several minutes. This time, the Linux
>>>>> client paused for a while (see ARPs below).
>>>>>
>>>>> 19:13:49.424101 IP nfsv4-linux.home.rick.apex-mesh >
>>>>> nfsv4-new3.home.rick.nfsd: Flags [R], seq 964161458, win 0, length 0
>>>>> 19:13:53.455867 IP nfsv4-linux.home.rick.apex-mesh >
>>>>> nfsv4-new3.home.rick.nfsd: Flags [S], seq 416692300, win 64240, options
>>>>> [mss 1460,sackOK,TS val 2671428975 ecr 0,nop,wscale 7], length 0
>>>>> 19:13:53.455991 IP nfsv4-new3.home.rick.nfsd >
>>>>> nfsv4-linux.home.rick.apex-mesh: Flags [.], ack 212293, win 29127,
>>>>> options [nop,nop,TS val 2073860193 ecr 2671204825], length 0
>>>>> *** Snipped a bunch of stuff out, mostly ARPs, plus one more RST.
>>>>>
>>>>> 19:16:57.775780 ARP, Request who-has nfsv4-new3.home.rick tell
>>>>> nfsv4-linux.home.rick, length 28
>>>>> 19:16:57.775937 ARP, Reply nfsv4-new3.home.rick is-at d4:be:d9:07:81:72
>>>>> (oui Unknown), length 46
>>>>> 19:16:57.980240 ARP, Request who-has nfsv4-new3.home.rick tell
>>>>> 192.168.1.254, length 46
>>>>> 19:16:58.555663 ARP, Request who-has nfsv4-new3.home.rick tell
>>>>> 192.168.1.254, length 46
>>>>> 19:17:00.104701 IP nfsv4-new3.home.rick.nfsd >
>>>>> nfsv4-linux.home.rick.apex-mesh: Flags [F.], seq 202749, ack 212293, win
>>>>> 29128, options [nop,nop,TS val 2074046846 ecr 2671204825], length 0
>>>>> 19:17:15.664354 IP nfsv4-new3.home.rick.nfsd >
>>>>> nfsv4-linux.home.rick.apex-mesh: Flags [F.], seq 202749, ack 212293, win
>>>>> 29128, options [nop,nop,TS val 2074062406 ecr 2671204825], length 0
>>>>> 19:17:31.239246 IP nfsv4-new3.home.rick.nfsd >
>>>>> nfsv4-linux.home.rick.apex-mesh: Flags [R.], seq 202750, ack 212293, win
>>>>> 0, options [nop,nop,TS val 2074077981 ecr 2671204825], length 0
>>>>> *** FreeBSD finally acknowledges the RST 38sec after Linux sent the last
>>>>> of 13 (100+ for another test run).
>>>>>
>>>>> 19:17:51.535979 IP nfsv4-linux.home.rick.apex-mesh >
>>>>> nfsv4-new3.home.rick.nfsd: Flags [S], seq 4247692373, win 64240, options
>>>>> [mss 1460,sackOK,TS val 2671667055 ecr 0,nop,wscale 7], length 0
>>>>> 19:17:51.536130 IP nfsv4-new3.home.rick.nfsd >
>>>>> nfsv4-linux.home.rick.apex-mesh: Flags [S.], seq 661237469, ack
>>>>> 4247692374, win 65535, options [mss 1460,nop,wscale 6,sackOK,TS val
>>>>> 2074098278 ecr 2671667055], length 0
>>>>> *** Now back in business...
>>>>>
>>>>> 19:17:51.536218 IP nfsv4-linux.home.rick.apex-mesh >
>>>>> nfsv4-new3.home.rick.nfsd: Flags [.], ack 1, win 502, options [nop,nop,TS
>>>>> val 2671667055 ecr 2074098278], length 0
>>>>> 19:17:51.536295 IP nfsv4-linux.home.rick.apex-mesh >
>>>>> nfsv4-new3.home.rick.nfsd: Flags [P.], seq 1:233, ack 1, win 502, options
>>>>> [nop,nop,TS val 2671667056 ecr 2074098278], length 232: NFS request xid
>>>>> 629930901 228 getattr fh 0,1/53
>>>>> 19:17:51.536346 IP nfsv4-linux.home.rick.apex-mesh >
>>>>> nfsv4-new3.home.rick.nfsd: Flags [P.], seq 233:505, ack 1, win 502,
>>>>> options [nop,nop,TS val 2671667056 ecr 2074098278], length 272: NFS
>>>>> request xid 697039765 132 getattr fh 0,1/53
>>>>> 19:17:51.536515 IP nfsv4-new3.home.rick.nfsd >
>>>>> nfsv4-linux.home.rick.apex-mesh: Flags [.], ack 505, win 29128, options
>>>>> [nop,nop,TS val 2074098279 ecr 2671667056], length 0
>>>>> 19:17:51.536553 IP nfsv4-linux.home.rick.apex-mesh >
>>>>> nfsv4-new3.home.rick.nfsd: Flags [P.], seq 505:641, ack 1, win 502,
>>>>> options [nop,nop,TS val 2671667056 ecr 2074098279], length 136: NFS
>>>>> request xid 730594197 132 getattr fh 0,1/53
>>>>> 19:17:51.536562 IP nfsv4-new3.home.rick.nfsd >
>>>>> nfsv4-linux.home.rick.apex-mesh: Flags [P.], seq 1:49, ack 505, win
>>>>> 29128, options [nop,nop,TS val 2074098279 ecr 2671667056], length 48: NFS
>>>>> reply xid 697039765 reply ok 44 getattr ERROR: unk 10063
>>>>>
>>>>> This error 10063 after the partition heals is also "bad news". It
>>>>> indicates the Session
>>>>> (which is supposed to maintain "exactly once" RPC semantics is broken).
>>>>> I'll admit I
>>>>> suspect a Linux client bug, but will be investigating further.
>>>>>
>>>>> So, hopefully TCP conversant folk can confirm if the above is correct
>>>>> behaviour
>>>>> or if the RST should be ack'd sooner?
>>>>>
>>>>> I could also see this becoming a "forever" TCP battle for other versions
>>>>> of Linux client.
>>>>>
>>>>> rick
>>>>>
>>>>>
>>>>> ________________________________________
>>>>> From: Scheffenegger, Richard <richard.scheffeneg...@netapp.com>
>>>>> Sent: Sunday, April 4, 2021 7:50 AM
>>>>> To: Rick Macklem; tue...@freebsd.org
>>>>> Cc: Youssef GHORBAL; freebsd-net@freebsd.org
>>>>> Subject: Re: NFS Mount Hangs
>>>>>
>>>>> CAUTION: This email originated from outside of the University of Guelph.
>>>>> Do not click links or open attachments unless you recognize the sender
>>>>> and know the content is safe. If in doubt, forward suspicious emails to
>>>>> ith...@uoguelph.ca
>>>>>
>>>>>
>>>>> For what it‘s worth, suse found two bugs in the linux nfconntrack
>>>>> (stateful firewall), and pfifo-fast scheduler, which could conspire to
>>>>> make tcp sessions hang forever.
>>>>>
>>>>> One is a missed updaten when the cöient is not using the noresvport moint
>>>>> option, which makes tje firewall think rsts are illegal (and drop them);
>>>>>
>>>>> The fast scheduler can run into an issue if only a single packet should
>>>>> be forwarded (note that this is not the default scheduler, but often
>>>>> recommended for perf, as it runs lockless and lower cpu cost that pfq
>>>>> (default). If no other/additional packet pushes out that last packet of a
>>>>> flow, it can become stuck forever...
>>>>>
>>>>> I can try getting the relevant bug info next week...
>>>>>
>>>>> ________________________________
>>>>> Von: owner-freebsd-...@freebsd.org <owner-freebsd-...@freebsd.org> im
>>>>> Auftrag von Rick Macklem <rmack...@uoguelph.ca>
>>>>> Gesendet: Friday, April 2, 2021 11:31:01 PM
>>>>> An: tue...@freebsd.org <tue...@freebsd.org>
>>>>> Cc: Youssef GHORBAL <youssef.ghor...@pasteur.fr>; freebsd-net@freebsd.org
>>>>> <freebsd-net@freebsd.org>
>>>>> Betreff: Re: NFS Mount Hangs
>>>>>
>>>>> NetApp Security WARNING: This is an external email. Do not click links or
>>>>> open attachments unless you recognize the sender and know the content is
>>>>> safe.
>>>>>
>>>>>
>>>>>
>>>>>
>>>>> tue...@freebsd.org wrote:
>>>>>>> On 2. Apr 2021, at 02:07, Rick Macklem <rmack...@uoguelph.ca> wrote:
>>>>>>>
>>>>>>> I hope you don't mind a top post...
>>>>>>> I've been testing network partitioning between the only Linux client
>>>>>>> I have (5.2 kernel) and a FreeBSD server with the xprtdied.patch
>>>>>>> (does soshutdown(..SHUT_WR) when it knows the socket is broken)
>>>>>>> applied to it.
>>>>>>>
>>>>>>> I'm not enough of a TCP guy to know if this is useful, but here's what
>>>>>>> I see...
>>>>>>>
>>>>>>> While partitioned:
>>>>>>> On the FreeBSD server end, the socket either goes to CLOSED during
>>>>>>> the network partition or stays ESTABLISHED.
>>>>>> If it goes to CLOSED you called shutdown(, SHUT_WR) and the peer also
>>>>>> sent a FIN, but you never called close() on the socket.
>>>>>> If the socket stays in ESTABLISHED, there is no communication ongoing,
>>>>>> I guess, and therefore the server does not even detect that the peer
>>>>>> is not reachable.
>>>>>>> On the Linux end, the socket seems to remain ESTABLISHED for a
>>>>>>> little while, and then disappears.
>>>>>> So how does Linux detect the peer is not reachable?
>>>>> Well, here's what I see in a packet capture in the Linux client once
>>>>> I partition it (just unplug the net cable):
>>>>> - lots of retransmits of the same segment (with ACK) for 54sec
>>>>> - then only ARP queries
>>>>>
>>>>> Once I plug the net cable back in:
>>>>> - ARP works
>>>>> - one more retransmit of the same segement
>>>>> - receives RST from FreeBSD
>>>>> ** So, is this now a "new" TCP connection, despite
>>>>> using the same port#.
>>>>> --> It matters for NFS, since "new connection"
>>>>> implies "must retry all outstanding RPCs".
>>>>> - sends SYN
>>>>> - receives SYN, ACK from FreeBSD
>>>>> --> connection starts working again
>>>>> Always uses same port#.
>>>>>
>>>>> On the FreeBSD server end:
>>>>> - receives the last retransmit of the segment (with ACK)
>>>>> - sends RST
>>>>> - receives SYN
>>>>> - sends SYN, ACK
>>>>>
>>>>> I thought that there was no RST in the capture I looked at
>>>>> yesterday, so I'm not sure if FreeBSD always sends an RST,
>>>>> but the Linux client behaviour was the same. (Sent a SYN, etc).
>>>>> The socket disappears from the Linux "netstat -a" and I
>>>>> suspect that happens after about 54sec, but I am not sure
>>>>> about the timing.
>>>>>
>>>>>>>
>>>>>>> After unpartitioning:
>>>>>>> On the FreeBSD server end, you get another socket showing up at
>>>>>>> the same port#
>>>>>>> Active Internet connections (including servers)
>>>>>>> Proto Recv-Q Send-Q Local Address Foreign Address
>>>>>>> (state)
>>>>>>> tcp4 0 0 nfsv4-new3.nfsd nfsv4-linux.678
>>>>>>> ESTABLISHED
>>>>>>> tcp4 0 0 nfsv4-new3.nfsd nfsv4-linux.678 CLOSED
>>>>>>>
>>>>>>> The Linux client shows the same connection ESTABLISHED.
>>>>> But disappears from "netstat -a" for a while during the partitioning.
>>>>>
>>>>>>> (The mount sometimes reports an error. I haven't looked at packet
>>>>>>> traces to see if it retries RPCs or why the errors occur.)
>>>>> I have now done so, as above.
>>>>>
>>>>>>> --> However I never get hangs.
>>>>>>> Sometimes it goes to SYN_SENT for a while and the FreeBSD server
>>>>>>> shows FIN_WAIT_1, but then both ends go to ESTABLISHED and the
>>>>>>> mount starts working again.
>>>>>>>
>>>>>>> The most obvious thing is that the Linux client always keeps using
>>>>>>> the same port#. (The FreeBSD client will use a different port# when
>>>>>>> it does a TCP reconnect after no response from the NFS server for
>>>>>>> a little while.)
>>>>>>>
>>>>>>> What do those TCP conversant think?
>>>>>> I guess you are you are never calling close() on the socket, for with
>>>>>> the connection state is CLOSED.
>>>>> Ok, that makes sense. For this case the Linux client has not done a
>>>>> BindConnectionToSession to re-assign the back channel.
>>>>> I'll have to bug them about this. However, I'll bet they'll answer
>>>>> that I have to tell them the back channel needs re-assignment
>>>>> or something like that.
>>>>>
>>>>> I am pretty certain they are broken, in that the client needs to
>>>>> retry all outstanding RPCs.
>>>>>
>>>>> For others, here's the long winded version of this that I just
>>>>> put on the phabricator review:
>>>>> In the server side kernel RPC, the socket (struct socket *) is in a
>>>>> structure called SVCXPRT (normally pointed to by "xprt").
>>>>> These structures a ref counted and the soclose() is done
>>>>> when the ref. cnt goes to zero. My understanding is that
>>>>> "struct socket *" is free'd by soclose() so this cannot be done
>>>>> before the xprt ref. cnt goes to zero.
>>>>>
>>>>> For NFSv4.1/4.2 there is something called a back channel
>>>>> which means that a "xprt" is used for server->client RPCs,
>>>>> although the TCP connection is established by the client
>>>>> to the server.
>>>>> --> This back channel holds a ref cnt on "xprt" until the
>>>>>
>>>>> client re-assigns it to a different TCP connection
>>>>> via an operation called BindConnectionToSession
>>>>> and the Linux client is not doing this soon enough,
>>>>> it appears.
>>>>>
>>>>> So, the soclose() is delayed, which is why I think the
>>>>> TCP connection gets stuck in CLOSE_WAIT and that is
>>>>> why I've added the soshutdown(..SHUT_WR) calls,
>>>>> which can happen before the client gets around to
>>>>> re-assigning the back channel.
>>>>>
>>>>> Thanks for your help with this Michael, rick
>>>>>
>>>>> Best regards
>>>>> Michael
>>>>>>
>>>>>> rick
>>>>>> ps: I can capture packets while doing this, if anyone has a use
>>>>>> for them.
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>> ________________________________________
>>>>>> From: owner-freebsd-...@freebsd.org <owner-freebsd-...@freebsd.org> on
>>>>>> behalf of Youssef GHORBAL <youssef.ghor...@pasteur.fr>
>>>>>> Sent: Saturday, March 27, 2021 6:57 PM
>>>>>> To: Jason Breitman
>>>>>> Cc: Rick Macklem; freebsd-net@freebsd.org
>>>>>> Subject: Re: NFS Mount Hangs
>>>>>>
>>>>>> CAUTION: This email originated from outside of the University of Guelph.
>>>>>> Do not click links or open attachments unless you recognize the sender
>>>>>> and know the content is safe. If in doubt, forward suspicious emails to
>>>>>> ith...@uoguelph.ca
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>> On 27 Mar 2021, at 13:20, Jason Breitman
>>>>>> <jbreit...@tildenparkcapital.com<mailto:jbreit...@tildenparkcapital.com>>
>>>>>> wrote:
>>>>>>
>>>>>> The issue happened again so we can say that disabling TSO and LRO on the
>>>>>> NIC did not resolve this issue.
>>>>>> # ifconfig lagg0 -rxcsum -rxcsum6 -txcsum -txcsum6 -lro -tso -vlanhwtso
>>>>>> # ifconfig lagg0
>>>>>> lagg0: flags=8943<UP,BROADCAST,RUNNING,PROMISC,SIMPLEX,MULTICAST> metric
>>>>>> 0 mtu 1500
>>>>>>
>>>>>> options=8100b8<VLAN_MTU,VLAN_HWTAGGING,JUMBO_MTU,VLAN_HWCSUM,VLAN_HWFILTER>
>>>>>>
>>>>>> We can also say that the sysctl settings did not resolve this issue.
>>>>>>
>>>>>> # sysctl net.inet.tcp.fast_finwait2_recycle=1
>>>>>> net.inet.tcp.fast_finwait2_recycle: 0 -> 1
>>>>>>
>>>>>> # sysctl net.inet.tcp.finwait2_timeout=1000
>>>>>> net.inet.tcp.finwait2_timeout: 60000 -> 1000
>>>>>>
>>>>>> I don’t think those will do anything in your case since the FIN_WAIT2
>>>>>> are on the client side and those sysctls are for BSD.
>>>>>> By the way it seems that Linux recycles automatically TCP sessions in
>>>>>> FIN_WAIT2 after 60 seconds (sysctl net.ipv4.tcp_fin_timeout)
>>>>>>
>>>>>> tcp_fin_timeout (integer; default: 60; since Linux 2.2)
>>>>>> This specifies how many seconds to wait for a final FIN
>>>>>> packet before the socket is forcibly closed. This is
>>>>>> strictly a violation of the TCP specification, but
>>>>>> required to prevent denial-of-service attacks. In Linux
>>>>>> 2.2, the default value was 180.
>>>>>>
>>>>>> So I don’t get why it stucks in the FIN_WAIT2 state anyway.
>>>>>>
>>>>>> You really need to have a packet capture during the outage (client and
>>>>>> server side) so you’ll get over the wire chat and start speculating from
>>>>>> there.
>>>>>> No need to capture the beginning of the outage for now. All you have to
>>>>>> do, is run a tcpdump for 10 minutes or so when you notice a client stuck.
>>>>>>
>>>>>> * I have not rebooted the NFS Server nor have I restarted nfsd, but do
>>>>>> not believe that is required as these settings are at the TCP level and
>>>>>> I would expect new sessions to use the updated settings.
>>>>>>
>>>>>> The issue occurred after 5 days following a reboot of the client
>>>>>> machines.
>>>>>> I ran the capture information again to make use of the situation.
>>>>>>
>>>>>> #!/bin/sh
>>>>>>
>>>>>> while true
>>>>>> do
>>>>>> /bin/date >> /tmp/nfs-hang.log
>>>>>> /bin/ps axHl | grep nfsd | grep -v grep >> /tmp/nfs-hang.log
>>>>>> /usr/bin/procstat -kk 2947 >> /tmp/nfs-hang.log
>>>>>> /usr/bin/procstat -kk 2944 >> /tmp/nfs-hang.log
>>>>>> /bin/sleep 60
>>>>>> done
>>>>>>
>>>>>>
>>>>>> On the NFS Server
>>>>>> Active Internet connections (including servers)
>>>>>> Proto Recv-Q Send-Q Local Address Foreign Address (state)
>>>>>> tcp4 0 0 NFS.Server.IP.X.2049 NFS.Client.IP.X.48286
>>>>>> CLOSE_WAIT
>>>>>>
>>>>>> On the NFS Client
>>>>>> tcp 0 0 NFS.Client.IP.X:48286 NFS.Server.IP.X:2049
>>>>>> FIN_WAIT2
>>>>>>
>>>>>>
>>>>>>
>>>>>> You had also asked for the output below.
>>>>>>
>>>>>> # nfsstat -E -s
>>>>>> BackChannelCtBindConnToSes
>>>>>> 0 0
>>>>>>
>>>>>> # sysctl vfs.nfsd.request_space_throttle_count
>>>>>> vfs.nfsd.request_space_throttle_count: 0
>>>>>>
>>>>>> I see that you are testing a patch and I look forward to seeing the
>>>>>> results.
>>>>>>
>>>>>>
>>>>>> Jason Breitman
>>>>>>
>>>>>>
>>>>>> On Mar 21, 2021, at 6:21 PM, Rick Macklem
>>>>>> <rmack...@uoguelph.ca<mailto:rmack...@uoguelph.ca>> wrote:
>>>>>>
>>>>>> Youssef GHORBAL
>>>>>> <youssef.ghor...@pasteur.fr<mailto:youssef.ghor...@pasteur.fr>> wrote:
>>>>>>> Hi Jason,
>>>>>>>
>>>>>>>> On 17 Mar 2021, at 18:17, Jason Breitman
>>>>>>>> <jbreit...@tildenparkcapital.com<mailto:jbreit...@tildenparkcapital.com>>
>>>>>>>> wrote:
>>>>>>>>
>>>>>>>> Please review the details below and let me know if there is a setting
>>>>>>>> that I should apply to my FreeBSD NFS Server or if there is a bug fix
>>>>>>>> that I can apply to resolve my issue.
>>>>>>>> I shared this information with the linux-nfs mailing list and they
>>>>>>>> believe the issue is on the server side.
>>>>>>>>
>>>>>>>> Issue
>>>>>>>> NFSv4 mounts periodically hang on the NFS Client.
>>>>>>>>
>>>>>>>> During this time, it is possible to manually mount from another NFS
>>>>>>>> Server on the NFS Client having issues.
>>>>>>>> Also, other NFS Clients are successfully mounting from the NFS Server
>>>>>>>> in question.
>>>>>>>> Rebooting the NFS Client appears to be the only solution.
>>>>>>>
>>>>>>> I had experienced a similar weird situation with periodically stuck
>>>>>>> Linux NFS clients >mounting Isilon NFS servers (Isilon is FreeBSD based
>>>>>>> but they seem to have there >own nfsd)
>>>>>> Yes, my understanding is that Isilon uses a proprietary user space nfsd
>>>>>> and
>>>>>> not the kernel based RPC and nfsd in FreeBSD.
>>>>>>
>>>>>>> We’ve had better luck and we did manage to have packet captures on both
>>>>>>> sides >during the issue. The gist of it goes like follows:
>>>>>>>
>>>>>>> - Data flows correctly between SERVER and the CLIENT
>>>>>>> - At some point SERVER starts decreasing it's TCP Receive Window until
>>>>>>> it reachs 0
>>>>>>> - The client (eager to send data) can only ack data sent by SERVER.
>>>>>>> - When SERVER was done sending data, the client starts sending TCP
>>>>>>> Window >Probes hoping that the TCP Window opens again so he can flush
>>>>>>> its buffers.
>>>>>>> - SERVER responds with a TCP Zero Window to those probes.
>>>>>> Having the window size drop to zero is not necessarily incorrect.
>>>>>> If the server is overloaded (has a backlog of NFS requests), it can stop
>>>>>> doing
>>>>>> soreceive() on the socket (so the socket rcv buffer can fill up and the
>>>>>> TCP window
>>>>>> closes). This results in "backpressure" to stop the NFS client from
>>>>>> flooding the
>>>>>> NFS server with requests.
>>>>>> --> However, once the backlog is handled, the nfsd should start to
>>>>>> soreceive()
>>>>>> again and this shouls cause the window to open back up.
>>>>>> --> Maybe this is broken in the socket/TCP code. I quickly got lost in
>>>>>> tcp_output() when it decides what to do about the rcvwin.
>>>>>>
>>>>>>> - After 6 minutes (the NFS server default Idle timeout) SERVER
>>>>>>> racefully closes the >TCP connection sending a FIN Packet (and still a
>>>>>>> TCP Window 0)
>>>>>> This probably does not happen for Jason's case, since the 6minute timeout
>>>>>> is disabled when the TCP connection is assigned as a backchannel (most
>>>>>> likely
>>>>>> the case for NFSv4.1).
>>>>>>
>>>>>>> - CLIENT ACK that FIN.
>>>>>>> - SERVER goes in FIN_WAIT_2 state
>>>>>>> - CLIENT closes its half part part of the socket and goes in LAST_ACK
>>>>>>> state.
>>>>>>> - FIN is never sent by the client since there still data in its SendQ
>>>>>>> and receiver TCP >Window is still 0. At this stage the client starts
>>>>>>> sending TCP Window Probes again >and again hoping that the server opens
>>>>>>> its TCP Window so it can flush it's buffers >and terminate its side of
>>>>>>> the socket.
>>>>>>> - SERVER keeps responding with a TCP Zero Window to those probes.
>>>>>>> => The last two steps goes on and on for hours/days freezing the NFS
>>>>>>> mount bound >to that TCP session.
>>>>>>>
>>>>>>> If we had a situation where CLIENT was responsible for closing the TCP
>>>>>>> Window (and >initiating the TCP FIN first) and server wanting to send
>>>>>>> data we’ll end up in the same >state as you I think.
>>>>>>>
>>>>>>> We’ve never had the root cause of why the SERVER decided to close the
>>>>>>> TCP >Window and no more acccept data, the fix on the Isilon part was to
>>>>>>> recycle more >aggressively the FIN_WAIT_2 sockets
>>>>>>> (net.inet.tcp.fast_finwait2_recycle=1 &
>>>>>>> >net.inet.tcp.finwait2_timeout=5000). Once the socket recycled and at
>>>>>>> the next >occurence of CLIENT TCP Window probe, SERVER sends a RST,
>>>>>>> triggering the >teardown of the session on the client side, a new TCP
>>>>>>> handchake, etc and traffic >flows again (NFS starts responding)
>>>>>>>
>>>>>>> To avoid rebooting the client (and before the aggressive FIN_WAIT_2 was
>>>>>>> >implemented on the Isilon side) we’ve added a check script on the
>>>>>>> client that detects >LAST_ACK sockets on the client and through
>>>>>>> iptables rule enforces a TCP RST, >Something like: -A OUTPUT -p tcp -d
>>>>>>> $nfs_server_addr --sport $local_port -j REJECT >--reject-with tcp-reset
>>>>>>> (the script removes this iptables rule as soon as the LAST_ACK
>>>>>>> >disappears)
>>>>>>>
>>>>>>> The bottom line would be to have a packet capture during the outage
>>>>>>> (client and/or >server side), it will show you at least the shape of
>>>>>>> the TCP exchange when NFS is >stuck.
>>>>>> Interesting story and good work w.r.t. sluething, Youssef, thanks.
>>>>>>
>>>>>> I looked at Jason's log and it shows everything is ok w.r.t the nfsd
>>>>>> threads.
>>>>>> (They're just waiting for RPC requests.)
>>>>>> However, I do now think I know why the soclose() does not happen.
>>>>>> When the TCP connection is assigned as a backchannel, that takes a
>>>>>> reference
>>>>>> cnt on the structure. This refcnt won't be released until the connection
>>>>>> is
>>>>>> replaced by a BindConnectiotoSession operation from the client. But that
>>>>>> won't
>>>>>> happen until the client creates a new TCP connection.
>>>>>> --> No refcnt release-->no refcnt of 0-->no soclose().
>>>>>>
>>>>>> I've created the attached patch (completely different from the previous
>>>>>> one)
>>>>>> that adds soshutdown(SHUT_WR) calls in the three places where the TCP
>>>>>> connection is going away. This seems to get it past CLOSE_WAIT without a
>>>>>> soclose().
>>>>>> --> I know you are not comfortable with patching your server, but I do
>>>>>> think
>>>>>> this change will get the socket shutdown to complete.
>>>>>>
>>>>>> There are a couple more things you can check on the server...
>>>>>> # nfsstat -E -s
>>>>>> --> Look for the count under "BindConnToSes".
>>>>>> --> If non-zero, backchannels have been assigned
>>>>>> # sysctl -a | fgrep request_space_throttle_count
>>>>>> --> If non-zero, the server has been overloaded at some point.
>>>>>>
>>>>>> I think the attached patch might work around the problem.
>>>>>> The code that should open up the receive window needs to be checked.
>>>>>> I am also looking at enabling the 6minute timeout when a backchannel is
>>>>>> assigned.
>>>>>>
>>>>>> rick
>>>>>>
>>>>>> Youssef
>>>>>>
>>>>>> _______________________________________________
>>>>>> freebsd-net@freebsd.org<mailto:freebsd-net@freebsd.org> mailing list
>>>>>> https://urldefense.com/v3/__https://lists.freebsd.org/mailman/listinfo/freebsd-net__;!!JFdNOqOXpB6UZW0!_c2MFNbir59GXudWPVdE5bNBm-qqjXeBuJ2UEmFv5OZciLj4ObR_drJNv5yryaERfIbhKR2d$
>>>>>> To unsubscribe, send any mail to
>>>>>> "freebsd-net-unsubscr...@freebsd.org<mailto:freebsd-net-unsubscr...@freebsd.org>"
>>>>>> <xprtdied.patch>
>>>>>>
>>>>>> <nfs-hang.log.gz>
>>>>>>
>>>>>> _______________________________________________
>>>>>> freebsd-net@freebsd.org mailing list
>>>>>> https://lists.freebsd.org/mailman/listinfo/freebsd-net
>>>>>> To unsubscribe, send any mail to "freebsd-net-unsubscr...@freebsd.org"
>>>>>> _______________________________________________
>>>>>> freebsd-net@freebsd.org mailing list
>>>>>> https://lists.freebsd.org/mailman/listinfo/freebsd-net
>>>>>> To unsubscribe, send any mail to "freebsd-net-unsubscr...@freebsd.org"
>>>>>
>>>>> _______________________________________________
>>>>> freebsd-net@freebsd.org mailing list
>>>>> https://lists.freebsd.org/mailman/listinfo/freebsd-net
>>>>> To unsubscribe, send any mail to "freebsd-net-unsubscr...@freebsd.org"
>>>>> _______________________________________________
>>>>> freebsd-net@freebsd.org mailing list
>>>>> https://lists.freebsd.org/mailman/listinfo/freebsd-net
>>>>> To unsubscribe, send any mail to "freebsd-net-unsubscr...@freebsd.org"
>>>>
>>>
>>
>> _______________________________________________
>> freebsd-net@freebsd.org mailing list
>> https://lists.freebsd.org/mailman/listinfo/freebsd-net
>> To unsubscribe, send any mail to "freebsd-net-unsubscr...@freebsd.org"
>
> _______________________________________________
> freebsd-net@freebsd.org mailing list
> https://lists.freebsd.org/mailman/listinfo/freebsd-net
> To unsubscribe, send any mail to "freebsd-net-unsubscr...@freebsd.org"
_______________________________________________
freebsd-net@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-net
To unsubscribe, send any mail to "freebsd-net-unsubscr...@freebsd.org"
