From owner-freebsd-net@freebsd.org Fri Mar 19 21:17:37 2021 Return-Path: Delivered-To: freebsd-net@mailman.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mailman.nyi.freebsd.org (Postfix) with ESMTP id E797D5AC916 for ; Fri, 19 Mar 2021 21:17:37 +0000 (UTC) (envelope-from rmacklem@uoguelph.ca) Received: from CAN01-TO1-obe.outbound.protection.outlook.com (mail-eopbgr670081.outbound.protection.outlook.com [40.107.67.81]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client CN "mail.protection.outlook.com", Issuer "DigiCert Cloud Services CA-1" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 4F2Gv55DWpz3vVt; Fri, 19 Mar 2021 21:17:37 +0000 (UTC) (envelope-from rmacklem@uoguelph.ca) ARC-Seal: i=1; a=rsa-sha256; s=arcselector9901; d=microsoft.com; cv=none; b=kvyYu75XVqjqyqPqEyRizBlQt/YVL9AipENCpNeAiRVQd6r8ZIVk506Wl+kZmT9Zyf8bqAF4a0Kouom0ECy7ZvnrTKNCmIi15/QLQ5MOP2EQweWOdsbTTL6+u2szUAD/SpQnNbiSX1v3IpDYHsbsr13ewMMLEl15Q3KYz5KzcDmLYQmKdQNzi/BQLkWJJ4hq03O7v2Uxuc2/wsF11IAM8/9JySsKzspUnVDw4AzjvrwnHzkct+obTQS/NSuSOrBQQ0xNhx9ryA23IQfIWkYLzxToNqIfkFNyxv+E3dlxW4l3ECsKPkA9dhwklKBFhqaKrZsbP4VNNPqyrzew2UEL3A== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=microsoft.com; s=arcselector9901; h=From:Date:Subject:Message-ID:Content-Type:MIME-Version:X-MS-Exchange-SenderADCheck; bh=1CyomNUWJSwWeoD4/IFaKIhWNqZrt1SuhqsH/wdzDYY=; b=HIAFfEUPnwOqN/RbBae7szAG2YyKUeT5XzegiDJFUycaBPJTuxq02cW+EiA8dYRdVNctPoJ8X4zuHsuxHIbjjh0vA360uSB3jHbQ+/tK8VvgYdjZ+Yh+aLPnxvwBz7aQEuyN0GD0mUAVxSSujBrq2UOqnDe1pkH+324L7nXAS2DieQG7yllP+geSKfZY6b7A8vut+DgYB9E/aC3VA3hNftnqf7zZemFT4c2UPP9MtOrjePUYg68bbsNcZYtxUEFxMKVnUHcNianAz6vW9a+8nnRg85MJE0adTb+Jj3Ls/6VJIy0+K/ILiBrmnpwr+7grGUO0lReJ3DlpHpIzdpoHBQ== ARC-Authentication-Results: i=1; mx.microsoft.com 1; spf=pass smtp.mailfrom=uoguelph.ca; dmarc=pass action=none header.from=uoguelph.ca; dkim=pass header.d=uoguelph.ca; arc=none DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=uoguelph.ca; s=selector1; h=From:Date:Subject:Message-ID:Content-Type:MIME-Version:X-MS-Exchange-SenderADCheck; bh=1CyomNUWJSwWeoD4/IFaKIhWNqZrt1SuhqsH/wdzDYY=; b=Bbm3RDSThu8UVtSTMZJyKgS4I7/1dERO0RjtBifBDaKVN9BD8LbkTtxbfbkUF+8MadewOXYB31+x/7ZUHRvFbjDxlePr35kHnUk3JCfmO2iNjHCZh+yEVbp3THOaBpU4IzOeyFDTr0LG156qKSlG+PRqkbHE6pcqR5omax7MuFHbAxGsY2SI5lavCDFeaIZ+34ABdo+PLdo+oVjLrP1ZMXQu48j5obrJHZwPKb0LbHn5TGJACphVtI9ziPvuNQuyqFOCbLkKWC7XGtIMPhCZt7hJhy3AfUFgvJgJcWXUd9yXJQRbxE+euCpiLWoEM9E3+aZCXZx5uyk0AP97hk4Dpg== Received: from YQXPR0101MB0968.CANPRD01.PROD.OUTLOOK.COM (2603:10b6:c00:19::29) by YQXPR01MB3845.CANPRD01.PROD.OUTLOOK.COM (2603:10b6:c00:50::27) with Microsoft SMTP Server (version=TLS1_2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id 15.20.3890.28; Fri, 19 Mar 2021 21:17:35 +0000 Received: from YQXPR0101MB0968.CANPRD01.PROD.OUTLOOK.COM ([fe80::6073:6fc0:5ddf:dc8a]) by YQXPR0101MB0968.CANPRD01.PROD.OUTLOOK.COM ([fe80::6073:6fc0:5ddf:dc8a%7]) with mapi id 15.20.3933.033; Fri, 19 Mar 2021 21:17:35 +0000 From: Rick Macklem To: Jason Breitman CC: "tuexen@freebsd.org" , "Scheffenegger, Richard" , "freebsd-net@freebsd.org" , Alexander Motin Subject: Re: NFS Mount Hangs Thread-Topic: NFS Mount Hangs Thread-Index: AQHXG1G2D7AHBwtmAkS1jBAqNNo2I6qIqQ+SgAEIlICAAAOAgIAAhBk7gAAEF4CAATUdPYAAF7EAgABGifg= Date: Fri, 19 Mar 2021 21:17:35 +0000 Message-ID: References: <3750001D-3F1C-4D9A-A9D9-98BCA6CA65A4@tildenparkcapital.com> <33693DE3-7FF8-4FAB-9A75-75576B88A566@tildenparkcapital.com> <2890D243-AF46-43A4-A1AD-CB0C3481511D@lurchi.franken.de> <9EE3DFAC-72B0-4256-B57C-DE6AA811413C@freebsd.org> , In-Reply-To: Accept-Language: en-US Content-Language: en-US X-MS-Has-Attach: X-MS-TNEF-Correlator: x-ms-publictraffictype: Email x-ms-office365-filtering-correlation-id: 701b6427-d4e8-40f1-ded1-08d8eb1c6ab6 x-ms-traffictypediagnostic: YQXPR01MB3845: x-microsoft-antispam-prvs: x-ms-oob-tlc-oobclassifiers: OLM:4714; x-ms-exchange-senderadcheck: 1 x-microsoft-antispam: BCL:0; x-microsoft-antispam-message-info: s7E6H3RmJbsrv3Vlbj80HtvOh1nzhJfYI+JZPpeUKzjH7RFV/aDjXUK82OVnZkFIs0kCrJm46qWcwSyF/TmhWUrCo/U35K0oV8WoBYsvYUCzUIdfkToqv6zA6vyGHB08YoBy/NQBWtPm6nGLzoKegeoa7qTQiz4eUGTl4rPn/oeDqb0mXQN5p25ZyetPccoFa+sEE5LECJHAPPYYRsLCnbFZsZcwtoeYlLgQluLK8Hd1ojgv2KcEcmxlDssljojZhrcD9VjQL0U8KWv8WFaSmfQjWwx0T42aVkDezZFDFK4sZAXozu+LaWKG1KjvAcY9iHusjvktH/V4D9+l8eq80DoqBL2C/bKmi9GvHyQKllzhA9JWOZONcft5acuO+PJFvkjd5jrCYIncUYiYJwyyytkGoQJiexGJSX8Jb791bBFF06UCBU7xtQ1Yv1+cdyqg4zwGYR2U2xvEfLUYM5++4SeqYYZW5JpDR+KdK3IliBujbi3EuuHFXXhF3CJC0Zbm7WCbwYye7beTkjQOZbUBOZY3KbUnUMfWYQS7rlQmLvH7rKfWLnybis6kDCLWRG+wOXuTsHSth7AoxeDc1u7jN9xLXJK8szygrgF2E12UKO2/MSXQNk+iW/InwfL1UC8v0Ss0dNTjjVw8vSQ7xoDxmIILBTpzX3VDyc+Ew2ficmI= x-forefront-antispam-report: CIP:255.255.255.255; CTRY:; LANG:en; SCL:1; SRV:; IPV:NLI; SFV:NSPM; H:YQXPR0101MB0968.CANPRD01.PROD.OUTLOOK.COM; PTR:; CAT:NONE; SFS:(346002)(39850400004)(366004)(396003)(136003)(376002)(966005)(53546011)(55016002)(66556008)(71200400001)(83380400001)(66446008)(86362001)(8676002)(2906002)(64756008)(66476007)(478600001)(786003)(33656002)(186003)(9686003)(38100700001)(5660300002)(91956017)(7696005)(3480700007)(54906003)(316002)(66946007)(4326008)(7116003)(8936002)(6916009)(52536014)(76116006)(6506007); DIR:OUT; SFP:1101; x-ms-exchange-antispam-messagedata: =?iso-8859-1?Q?VKnkfMvZhfZqDujSQ8wFEX4MmWvJzh5DMnIx0BqlYcP2BNS/22ppAM+UDY?= =?iso-8859-1?Q?R4hNv58Ms+1ITQpC3XlJksKrBYFMkLF3G98+OXOFA80/4oNdB9R3f2Xt4T?= =?iso-8859-1?Q?OcCnjhghEpv1xW20siFQIItMJPMahJURBYniG/9AaKpHWt3aIlRE8ix3Jn?= =?iso-8859-1?Q?9vtCkq/HL1pNypoTUTNioUgvPorj31ub+jqTTOFH9MuAEjkekBmFR7n/1p?= =?iso-8859-1?Q?gGlJpxO9SlLY055EwH3tYOsJfacDTwbPcjBk/ivsOuc/Y+7BP9aHl4fuiy?= =?iso-8859-1?Q?+LrLoHgh0ynnQtnyjRW1/eDdI+tA13k1azNB/LTy1+HABA0Y6ztw4y8rqH?= =?iso-8859-1?Q?mxK5aV44SLJ28YjUmj18rrrE7Ie/p/QYw9yvKsPXVhTJUeqeleqcrBlZP0?= =?iso-8859-1?Q?8blGxWTBo7pHqL1MKAsdzwXdRpORvswEfEzJl9gz1yezXSZtHmKWxGzsBj?= =?iso-8859-1?Q?d8LnBagkxJJXTNT2Z1YcNnSZVXNNNMYVGlq7UJgw5RJND3oSAQsliawiRw?= =?iso-8859-1?Q?8SE3tUPoD4ppLvQUoTyQwI5vPUDUzvvOk1M4UHcW5XvT7PB6vw/KFvvGQw?= =?iso-8859-1?Q?RyB7xo2P+CFXk1EiMRWx4TdcVLFHoq0rJxXpWOWAQVVG4UZ3Ow/tL+JSvo?= =?iso-8859-1?Q?IAfltGh14zU0gx5DAuvW7m0nmBjeYe3S4SOVGLuv8xHjwsnxs/8CXV4vnQ?= =?iso-8859-1?Q?7CuCJ12crN3uRsTklCapl/RAOQTgqedCsEelZ+KOBEt1YTGKpBTOoa1zuu?= =?iso-8859-1?Q?hM2IIJfj6KBTG7KdM+5M8cM1wbYmBaDKYaiN7oIk/0mrovRNyOqPFpRlhE?= =?iso-8859-1?Q?qjUabsturFqbVdQDOeNrY7Hoz9th1t7m36yueMQNYe2wdjvxPMkaMxxzlv?= =?iso-8859-1?Q?xky7DKxRTSGW86YSMH6NkMqwUBpiA91CSiGZElj+QsoCrpau4e3ZH/cDwA?= =?iso-8859-1?Q?Ks9kgkUERov2+D1wVub1yPyEs7P8Hm2SOd5dH+d7hwFAZtQ0AJuuW0Zuz1?= =?iso-8859-1?Q?wCvZkqYh8/BzBsH/NvpMimCKodzch5sm9Qy3q0x9JLxRKhocheUQdXpkx9?= =?iso-8859-1?Q?Dm86hMjDVTGRITSQv+qsOAqlxEXFhepagfd8fIg7Lz4CcNeqdQ+tmlYvsa?= =?iso-8859-1?Q?l1b36GFBxiR/d/2NjNjuT+zzVLkYPvAZiEJiWOWOAgQ7cNjaOq1GvDxE5J?= =?iso-8859-1?Q?fHDjkdKl6DGlx7p0eQxdpS6d8mugn4m54a392khekHyhCccao/YDQ4ZVNn?= =?iso-8859-1?Q?fFRR9+WY7ut8xDk5WMUpyiJj+oW+HfaPWFTBv9L9WqcZ8dE5XvfUqXIxEs?= =?iso-8859-1?Q?OKSmBXP73t+UtDVZvsZ67szbBVCt4QJ6qafc2Ul5taBcbudo2ssP3K+4j+?= =?iso-8859-1?Q?K0lzpRgJU5s6k8h39leuZn0fhAICEKu8fpbCaVg4pOXDutuce1m1E=3D?= x-ms-exchange-transport-forked: True Content-Type: text/plain; charset="iso-8859-1" Content-Transfer-Encoding: quoted-printable MIME-Version: 1.0 X-OriginatorOrg: uoguelph.ca X-MS-Exchange-CrossTenant-AuthAs: Internal X-MS-Exchange-CrossTenant-AuthSource: YQXPR0101MB0968.CANPRD01.PROD.OUTLOOK.COM X-MS-Exchange-CrossTenant-Network-Message-Id: 701b6427-d4e8-40f1-ded1-08d8eb1c6ab6 X-MS-Exchange-CrossTenant-originalarrivaltime: 19 Mar 2021 21:17:35.4456 (UTC) X-MS-Exchange-CrossTenant-fromentityheader: Hosted X-MS-Exchange-CrossTenant-id: be62a12b-2cad-49a1-a5fa-85f4f3156a7d X-MS-Exchange-CrossTenant-mailboxtype: HOSTED X-MS-Exchange-CrossTenant-userprincipalname: gZAPjKwdm6kW2oII3yBUrQwwUs8POXr2OSV+Bm3VBWD4t90XJ1K0/RtvU+/dd8eJbxe/PKtOdm0+i8WdIkhcQw== X-MS-Exchange-Transport-CrossTenantHeadersStamped: YQXPR01MB3845 X-Rspamd-Queue-Id: 4F2Gv55DWpz3vVt X-Spamd-Bar: ---- Authentication-Results: mx1.freebsd.org; none X-Spamd-Result: default: False [-4.00 / 15.00]; REPLY(-4.00)[] X-BeenThere: freebsd-net@freebsd.org X-Mailman-Version: 2.1.34 Precedence: list List-Id: Networking and TCP/IP with FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 19 Mar 2021 21:17:38 -0000 Jason Breitman wrote:=0A= >Thank you for your focus on the issue I am having and I look forward to se= eing your >patch ported to FreeBSD 12.X.=0A= I'll only be committing the patch I am convinced it actually fixes somethin= g.=0A= I'll be looking more closely at it and seeing what mav@ thinks aboutm it.= =0A= =0A= >I also appreciate that you understand the difficulties in testing changes = on a core >piece of infrastructure.=0A= >=0A= >I will let the group know if the issue occurs following the change that di= sabled TSO >and LRO on my FreeBSD NFS Server NICs.=0A= >Those types of settings are less disruptive and pose less risk to apply in= production, >so I am happy to do so. That change was made on 3/17/2021.= =0A= >My hope is that this issue is a race condition specific to my NIC handling= certain TCP >operations.=0A= >=0A= >I am happy that you are approaching the issue from multiple angles.=0A= Well, another angle would be a nfsd thread that is "stuck" while doing=0A= an RPC. If that happens, it won't call svc_freereq(), which derefs the=0A= structure.=0A= If it happens again and you can do, please go onto the FreeBSD server=0A= and perform the following commands a few times, a few minutes apart,=0A= capturing the output:=0A= # ps axHl=0A= # procstat -kk I'll be looking for an nfsd thread that is sleeping on the same thing= =0A= without cpu increasing (except for rpcsvc, which is just a thread wait= ing=0A= for an RPC to work on).=0A= --> The procstat -kk gives more information w.r.t what the thread is up to.= =0A= =0A= Good luck with it, rick=0A= =0A= Thanks.=0A= =0A= Jason Breitman=0A= =0A= =0A= On Mar 19, 2021, at 11:58 AM, Rick Macklem wrote:=0A= =0A= Michael Tuexen wrote:=0A= >> On 18. Mar 2021, at 21:55, Rick Macklem wrote:=0A= >>=0A= >> Michael Tuexen wrote:=0A= >>>> On 18. Mar 2021, at 13:42, Scheffenegger, Richard wrote:=0A= >>>>=0A= >>>>>> Output from the NFS Client when the issue occurs # netstat -an | gre= p=0A= >>>>>> NFS.Server.IP.X=0A= >>>>>> tcp 0 0 NFS.Client.IP.X:46896 NFS.Server.IP.X:2049 FIN_WAIT2=0A= >>>>> I'm no TCP guy. Hopefully others might know why the client would be s= tuck in FIN_WAIT2 (I vaguely recall this means it is waiting for a fin/ack,= but could be wrong?)=0A= >>>>=0A= >>>> When the client is in Fin-Wait2 this is the state you end up when the = Client side actively close() the tcp session, and then the server also ACKe= d the FIN.=0A= >> Jason noted:=0A= >>=0A= >>> When the issue occurs, this is what I see on the NFS Server.=0A= >>> tcp4 0 0 NFS.Server.IP.X.2049 NFS.Client.IP.X.51550 CLOSE_WAIT=0A= >>>=0A= >>> which corresponds to the state on the client side. The server received = the FIN=0A= >>> from the client and acked it.=0A= >>> The server is waiting for a close call to happen.=0A= >>> So the question is: Is the server also closing the connection?=0A= >> Did you mean to say "client closing the connection here?"=0A= >Yes.=0A= >>=0A= >> The server should call soclose() { it never calls soshutdown() } when=0A= >> soreceive(with MSG_WAIT) returns 0 bytes or an error that indicates=0A= >> the socket is broken.=0A= Btw, I looked and the soreceive() is done with MSG_DONTWAIT, but the=0A= EWOULDBLOCK is handled appropriately.=0A= =0A= >> --> The soreceive() call is triggered by an upcall for the rcv side of t= he socket.=0A= >> So, are you saying the FreeBSD NFS server did not call soclose() for thi= s case?=0A= >Yes. If the state at the server side is CLOSE_WAIT, no close call has happ= ened yet.=0A= >The FIN from the client was received, it was ACKED, but no close() call=0A= >(or shutdown(..., SHUT_WR) or shutdown(..., SHUT_RDWR)) was issued. Theref= ore,=0A= >no FIN was sent and the client should be in the FINWAIT-2 state. This was = also=0A= >reported. So the reported states are consistent.=0A= For a test, I commented out the soclose() call in the server side krpc and,= when I=0A= dismounted, it did leave the server socket in CLOSE_WAIT.=0A= For the FreeBSD client, it did the dismount and the socket was in FIN_WAIT2= =0A= for a little while and then disappeared (someone mentioned a short timeout= =0A= and that seems to be the case).=0A= I might argue that the Linux client should not get hung when this occurs,= =0A= but there does appear to be an issue on the FreeBSD end.=0A= =0A= So it does appear you have a case where the soclose() call is not happening= =0A= on the FreeBSD NFS server. I am a little surprised since I don't think I've= =0A= heard of this before and the code is at least 10years old (at least the par= ts=0A= related to this).=0A= =0A= For the soclose() to not happen, the reference count on the socket=0A= structure cannot have gone to zero. (ie a SVC_RELEASE() was missed)=0A= Upon code inspection, I was not able to spot a reference counting bug.=0A= (Not too surprising, since a reference counting bug should have shown=0A= up long ago.)=0A= =0A= The only thing I spotted that could conceivably explain this is that the=0A= function svc_vc_stat() which returns the indication that the socket has=0A= been closed at the other end did not bother to do any locking when=0A= it checked the status. (I am not yet sure if this could result in the=0A= status of XPRT_DIED being missed by the call, but if so, that would=0A= result in the soclose() call not happening.)=0A= =0A= I have attached a small patch, which I think is safe, that adds locking=0A= to svc_vc_stat(),which I am hoping you can try at some point.=0A= (I realize this is difficult for a production server, but...)=0A= I have tested it a little and will test it some more, to try and ensure=0A= it does not break anything.=0A= =0A= I have also cc'd mav@, since he's the guy who last worked on this=0A= code, in case he has any insight w.r.t. how the soclose() might get=0A= missed (or any other way the server socket gets stuck in CLOSE_WAIT).=0A= =0A= rick=0A= ps: I'll create a PR for this, so that it doesn't get forgotten.=0A= =0A= Best regards=0A= Michael=0A= =0A= >=0A= > rick=0A= >=0A= > Best regards=0A= > Michael=0A= >> This will last for ~2 min or so, but is asynchronous. However, the same = 4-tuple can not be reused during this time.=0A= >>=0A= >> With other words, from the socket / TCP, a properly executed active clos= e() will end up in this state. (If the other side initiated the close, a pa= ssive close, will not end in this state)=0A= >>=0A= >>=0A= >> _______________________________________________=0A= >> freebsd-net@freebsd.org mailing list=0A= >> https://lists.freebsd.org/mailman/listinfo/freebsd-net=0A= >> To unsubscribe, send any mail to "freebsd-net-unsubscribe@freebsd.org"= =0A= >=0A= >=0A= > _______________________________________________=0A= > freebsd-net@freebsd.org mailing list=0A= > https://lists.freebsd.org/mailman/listinfo/freebsd-net=0A= > To unsubscribe, send any mail to "freebsd-net-unsubscribe@freebsd.org"=0A= =0A= _______________________________________________=0A= freebsd-net@freebsd.org mailing list=0A= https://lists.freebsd.org/mailman/listinfo/freebsd-net=0A= To unsubscribe, send any mail to "freebsd-net-unsubscribe@freebsd.org"=0A= =0A= _______________________________________________=0A= freebsd-net@freebsd.org mailing list=0A= https://lists.freebsd.org/mailman/listinfo/freebsd-net=0A= To unsubscribe, send any mail to "freebsd-net-unsubscribe@freebsd.org"=0A= =0A= =0A=