From nobody Fri May 27 23:56:32 2022 X-Original-To: freebsd-fs@mlmmj.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mlmmj.nyi.freebsd.org (Postfix) with ESMTP id 679C81B3E1CD for ; Fri, 27 May 2022 23:56:40 +0000 (UTC) (envelope-from rmacklem@uoguelph.ca) Received: from CAN01-QB1-obe.outbound.protection.outlook.com (mail-qb1can01on2044.outbound.protection.outlook.com [40.107.66.44]) (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 4L91tH3GGnz4SvR for ; Fri, 27 May 2022 23:56:39 +0000 (UTC) (envelope-from rmacklem@uoguelph.ca) ARC-Seal: i=1; a=rsa-sha256; s=arcselector9901; d=microsoft.com; cv=none; b=XIQdYzgXgPqUgZHd4Q2uuKWjEo7fDwLEeMoSKCQYG6YIIWdsV0pP2o+iE90S/wyiBKkrIiKtvG0R+A28qVt5sp9o9Ai9Kxl6v8zbQSrRNHbp4L2miFKocXx9lljWLBfjnQTTve6FVm7ketdQ5qzoyVqdha/LAoELvWT/3bE7jdRuBFpR/Ovi8vzMxaegrUl+UG0cMyty1ChFCwsbwpT2dwIpin/oMr5vfhGdDTkjptexWNBOAzNb1tchyMBFLTcsyMfjoW1AhqZGHDU9FpzC1d8fOYcVR6Z/9yhIMqkgp94fuIYQe4V34kmCHWsqeZvholVYx0UDkYMIU2oKdcb2wA== 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-AntiSpam-MessageData-ChunkCount:X-MS-Exchange-AntiSpam-MessageData-0:X-MS-Exchange-AntiSpam-MessageData-1; bh=hmDitkr4bUt+p8XJATX3yoDvcLUj+qNuj3cZ4NrwII4=; b=UDeMgmmmoDuySDNUUSqqD9TcPmJRrsXSz/SW1ALeJ9OadgNyDlkWShMXhPlHHLvqXnDF77LncJQVwN0d25azru+uTI9zqhgp32JNDgWjYkLWoi7utCtKWQVhDMVcJFxZOBBNCFnmv0tMUNUgOmMB+Hb9ak0qGZgtGBUXvjn6CaVnCEjEo6L1MSR6vqGs+MRPD+566xLzfz2Q5bd2ZpMoUcBDtiEbfrbjufRwl5RwTZpX34HDTqzryxeijhlCANEirAU7NUMUodJu1MIf1s1EqePkRZsNlX9w14JeRJogJEFYLYF774yt5MsHK+7l6XSlERXCWONgIzmSr55YSu1CHQ== 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=selector2; h=From:Date:Subject:Message-ID:Content-Type:MIME-Version:X-MS-Exchange-SenderADCheck; bh=hmDitkr4bUt+p8XJATX3yoDvcLUj+qNuj3cZ4NrwII4=; b=bDykNjiZAdAhQk0yGybdwnFDWo+/iDo7UJN5V8Zk/9Ta7eAQPOS6+5vky1IYoWvfmsdBpEdmkU8v684uQv5wwEEXFLGo6bQaBLT54kl7B+UQuipGfEMQpxVCGsiCn9XlcbMDyeluSBLYqq6EfoPbhoGKACrVJDF/hihFrfYDmyJznL0CsVMgAdOECFsb/QDGA5dEY8zOoB7/OPd9xgr8a1bwsS4x+kLTXaUlzURa6i0UAXUX/khr+Xp+Jlu7Z4lniHhBDi8mtSlI1dbXyk+8bJCqwMeDUg1IcZqcZCygixPg7TagxYFY3fzG/EZCYNXaWt+rau82y1vsVfbWqmtnCA== Received: from YQBPR0101MB9742.CANPRD01.PROD.OUTLOOK.COM (2603:10b6:c01:81::14) by YQXPR01MB5121.CANPRD01.PROD.OUTLOOK.COM (2603:10b6:c01:25::14) with Microsoft SMTP Server (version=TLS1_2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id 15.20.5293.13; Fri, 27 May 2022 23:56:32 +0000 Received: from YQBPR0101MB9742.CANPRD01.PROD.OUTLOOK.COM ([fe80::b921:251e:4a0b:54fc]) by YQBPR0101MB9742.CANPRD01.PROD.OUTLOOK.COM ([fe80::b921:251e:4a0b:54fc%6]) with mapi id 15.20.5293.016; Fri, 27 May 2022 23:56:32 +0000 From: Rick Macklem To: Andreas Kempe CC: "freebsd-fs@freebsd.org" Subject: Re: FreeBSD 12.3/13.1 NFS client hang Thread-Topic: FreeBSD 12.3/13.1 NFS client hang Thread-Index: AQHYcgY+3LPS/CtmUk+ZVTnbRrY6qK0zLx2fgAAamoCAABgQoA== Date: Fri, 27 May 2022 23:56:32 +0000 Message-ID: References: In-Reply-To: Accept-Language: en-US Content-Language: en-US X-MS-Has-Attach: X-MS-TNEF-Correlator: suggested_attachment_session_id: d82dab0d-ccd1-319d-5002-110f6730bc98 x-ms-publictraffictype: Email x-ms-office365-filtering-correlation-id: d6ea25cc-4da4-4a07-7d9e-08da403c8678 x-ms-traffictypediagnostic: YQXPR01MB5121:EE_ x-microsoft-antispam-prvs: x-ms-exchange-senderadcheck: 1 x-ms-exchange-antispam-relay: 0 x-microsoft-antispam: BCL:0; x-microsoft-antispam-message-info: rrRwKnQFl9MIki4GCUoJMl1ZDEF6WSbcw1iGBQUO4HsXEvFEzEusHUdu47lPy+KHTdXP7RbEwS9vYnCN9fws4ilego9YTSyKMwedtqQ4wG8sSogTa4hfT6oR9HAwt90qG1XRgBwDyCwUbWTAgN51gT/ueCvRWcBCniTx4rHtguMD56GsXoMtJBysQjFILDcieRHy7Q85GN2C/xUygnzCsUW6WTMnJ74ugq1CFm2oAuA4PMPmRRyA5gl6mYzKiegMoVGWLJmWxU+3OhpSvRUEou0EoYCp0cy7dl+02LLeOiwTKUKUEP8cDb5Vs7xwKiCT4ewl0BWYt0beLRPMss7rnZyBdwfhfSDiH27npmOtfTp1CpO4TobgoMg1ieNq8x4SWeiG6+kdb1qXrPJZ1hYkRAptXsyMAvgyb9g3xCj65kIPOlUEhRl7T6gOuwQ20963VW5SK9FcxOA29oTYJX97yQIs/hmIs38CElx+2pUk9RoYV/Jb/mHys54RWRhd8Ssqu8mdTn9dabckOgPn2DAMP0uSL8eGvEmNyFN03DGNxl9yHEXC1uPaq8qwYwMwFZqSoaJbgpH2T2pdexfKaLtn269dnuUksbu2FIflsHfXpcOjPlwWjNak7AQqphEhd/bA x-forefront-antispam-report: CIP:255.255.255.255;CTRY:;LANG:en;SCL:1;SRV:;IPV:NLI;SFV:NSPM;H:YQBPR0101MB9742.CANPRD01.PROD.OUTLOOK.COM;PTR:;CAT:NONE;SFS:(13230001)(4636009)(366004)(122000001)(38070700005)(33656002)(71200400001)(83380400001)(186003)(66476007)(5660300002)(6916009)(38100700002)(2906002)(64756008)(6506007)(316002)(7696005)(8936002)(52536014)(86362001)(296002)(508600001)(9686003)(786003)(76116006)(91956017)(8676002)(66946007)(4326008)(66556008)(55016003)(66446008);DIR:OUT;SFP:1101; x-ms-exchange-antispam-messagedata-chunkcount: 1 x-ms-exchange-antispam-messagedata-0: 7TBJE1GBMoefg2rgZywGpCDhVDxDCfkKAoWGd+ki6us+b9YRoHDwFWFB/CH/2OeBDkxUgY4x+SpLsmPg2OLW/FyXz/ZBMEA7+2wKPxInZS3nPdp1VAI1cd9p5/UzMs79EM/iQPPGJmDhUbH3+z54d0VWxyw2a+jWqug75mSh1725aqa8AwEwfBq3XX832e0PnVsGL3zUIIBhAH9rSotX9cyj3C3qBpqAu6uJaYOBeXEM2FYFR00AnlyetSrl/vHaQ/1ATFMVXrZeUvnP6wif/g5wOLdtu4IF+tPjfPKcH18y1Ll4lH20sGwzhEGUpJJbX6jmhQKY65wDQpifNsNYScpvB8UNVvkrWicriLhbiD4TEGeFbXuo1rBcJArG4d6A+PwVrPvPSi/LXA1TIK2iQZ1CA9QhB5Mh9XYxSun81BPV+RRdTlvvuH0l3qcmL1gvjXTJTIBJcOIF8O8FeC45pCxzobwmBEOPyxkTmjeHFLM= Content-Type: text/plain; charset="iso-8859-1" Content-Transfer-Encoding: quoted-printable List-Id: Filesystems List-Archive: https://lists.freebsd.org/archives/freebsd-fs List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-freebsd-fs@freebsd.org MIME-Version: 1.0 X-OriginatorOrg: uoguelph.ca X-MS-Exchange-CrossTenant-AuthAs: Internal X-MS-Exchange-CrossTenant-AuthSource: YQBPR0101MB9742.CANPRD01.PROD.OUTLOOK.COM X-MS-Exchange-CrossTenant-Network-Message-Id: d6ea25cc-4da4-4a07-7d9e-08da403c8678 X-MS-Exchange-CrossTenant-originalarrivaltime: 27 May 2022 23:56:32.4449 (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: MRblcWP21yF9dtlmErh5NfNrdnTtyEilA3ZA1usxZbSK0oLD2QQhDmvt3wzX1SWQu1V6InjCkoRWSN+Pq3FbYA== X-MS-Exchange-Transport-CrossTenantHeadersStamped: YQXPR01MB5121 X-Rspamd-Queue-Id: 4L91tH3GGnz4SvR X-Spamd-Bar: ----- Authentication-Results: mx1.freebsd.org; dkim=pass header.d=uoguelph.ca header.s=selector2 header.b=bDykNjiZ; arc=pass ("microsoft.com:s=arcselector9901:i=1"); dmarc=pass (policy=none) header.from=uoguelph.ca; spf=pass (mx1.freebsd.org: domain of rmacklem@uoguelph.ca designates 40.107.66.44 as permitted sender) smtp.mailfrom=rmacklem@uoguelph.ca X-Spamd-Result: default: False [-5.97 / 15.00]; TO_DN_EQ_ADDR_SOME(0.00)[]; NEURAL_HAM_MEDIUM(-1.00)[-1.000]; R_DKIM_ALLOW(-0.20)[uoguelph.ca:s=selector2]; FREEFALL_USER(0.00)[rmacklem]; FROM_HAS_DN(0.00)[]; TO_DN_SOME(0.00)[]; R_SPF_ALLOW(-0.20)[+ip4:40.107.0.0/16]; NEURAL_HAM_LONG(-1.00)[-1.000]; MIME_GOOD(-0.10)[text/plain]; DWL_DNSWL_LOW(-1.00)[uoguelph.ca:dkim]; RCVD_COUNT_THREE(0.00)[3]; TO_MATCH_ENVRCPT_SOME(0.00)[]; DKIM_TRACE(0.00)[uoguelph.ca:+]; RCPT_COUNT_TWO(0.00)[2]; RCVD_IN_DNSWL_NONE(0.00)[40.107.66.44:from]; NEURAL_HAM_SHORT(-0.97)[-0.970]; DMARC_POLICY_ALLOW(-0.50)[uoguelph.ca,none]; MLMMJ_DEST(0.00)[freebsd-fs]; FROM_EQ_ENVFROM(0.00)[]; MIME_TRACE(0.00)[0:+]; RCVD_TLS_LAST(0.00)[]; ASN(0.00)[asn:8075, ipnet:40.104.0.0/14, country:US]; ARC_ALLOW(-1.00)[microsoft.com:s=arcselector9901:i=1]; RWL_MAILSPIKE_POSSIBLE(0.00)[40.107.66.44:from] X-ThisMailContainsUnwantedMimeParts: N Andreas Kempe wrote:=0A= > On Fri, May 27, 2022 at 08:59:57PM +0000, Rick Macklem wrote:=0A= > > Andreas Kempe wrote:=0A= > > > Hello everyone!=0A= > > >=0A= > > > I'm having issues with the NFS clients on FreeBSD 12.3 and 13.1=0A= > > > systems hanging when using a CentOS 7 server.=0A= > > First, make sure you are using hard mounts. "soft" or "intr" mounts won= 't=0A= > > work and will mess up the session sooner or later. (A messed up session= could=0A= > > result in no free slots on the session and that will wedge threads in= =0A= > > nfsv4_sequencelookup() as you describe.=0A= > > (This is briefly described in the BUGS section of "man mount_nfs".)=0A= > >=0A= >=0A= > I had totally missed that soft and interruptible mounts have these=0A= > issues. I switched the FreeBSD-machines to soft and intr on purpose=0A= > to be able to fix hung mounts without having to restart the machine on=0A= > NFS hangs. Since they are shared machines, it is an inconvinience for=0A= > other users if one user causes a hang.=0A= Usually, a "umount -N " should dismount a hung mount=0A= point. It can take a couple of minutes to complete.=0A= =0A= > Switching our test machine back to hard mounts did prevent recursive=0A= > grep from immediately causing the slot type hang again.=0A= >=0A= > > Do a:=0A= > > # nfsstat -m=0A= > > on the clients and look for "hard".=0A= > >=0A= > > Next, is there anything logged on the console for the 13.1 client(s)?= =0A= > > (13.1 has some diagnostics for things like a server replying with the= =0A= > > wrong session slot#.)=0A= > >=0A= >=0A= > The one thing we have seen logged are messages along the lines of:=0A= > kernel: newnfs: server 'mail' error: fileid changed. fsid 4240eca6003a052= a:0: expected fileid 0x22, got 0x2. (BROKEN NFS SERVER OR MIDDLEWARE)=0A= It means that the server returned a different fileid number for the same fi= le, although it should never change.=0A= There's a description in a comment in sys/fs/nfsclient/nfs_clport.c.=0A= I doubt the broken middleware is anywhere any more. I never knew the=0A= details, since the guy that told me about it was under NDA to the=0A= company that sold it. It cached Getattr replies and would sometimes return= =0A= the wrong cached entry. I think it only worked for NFSv3, anyhow.=0A= =0A= However, it does indicate something is seriously wrong, probably on the ser= ver end.=0A= (If you can capture packets when it gets logged, we could look at them in w= ireshark.)=0A= --> I'm not sure if a soft mount could somehow cause this?=0A= =0A= The diagnostics I was referring to would be things like "Wrong session" or = "freeing free slot".=0A= It was these that identified the Amazon EFS bug I mention later.=0A= =0A= > > Also, maybe I'm old fashioned, but I find "ps axHl" useful, since it sh= ows=0A= > > where all the processes are sleeping.=0A= > > And "procstat -kk" covers all of the locks.=0A= > >=0A= > =0A= > I don't know if it is a matter of being old fashioned as much as one=0A= > of taste. :) In future dumps, I can provide both ps axHl and procstat -kk= .=0A= Ok. Lets see how things go with hard mounts.=0A= =0A= > > > Below are procstat kstack $PID invocations showing where the processe= s=0A= > > > have hung. In the nfsv4_sequencelookup it seems hung waiting for=0A= > > > nfsess_slots to have an available slot. In the second nfs_lock case,= =0A= > > > it seems the processes are stuck waiting on vnode locks.=0A= > > >=0A= > > > These issues seem to appear seemingly at random, but also if=0A= > > > operations that open a lot of files or create a lot of file locks are= =0A= > > > used. An example that can often provoke a hang is performing a=0A= > > > recursive grep through a large file hierarchy like the FreeBSD=0A= > > > codebase.=0A= > > >=0A= > > > The NFS code is large and complicated so any advice is appriciated!= =0A= > > Yea. I'm the author and I don't know exactly what it all does;-)\=0A= > >=0A= > > > Cordially,=0A= > > > Andreas Kempe=0A= > > >=0A= > >=0A= > > [...]=0A= > >=0A= > > Not very useful unless you have all the processes and their locks to tr= y and figure out what is holding=0A= > > the vnode locks.=0A= > >=0A= > =0A= > Yes, I sent this mostly in the hope that it might be something that=0A= > someone has seen before. I understand that more verbose information is=0A= > needed to track down the lock contention.=0A= There is PR#260011. It is similar and he was also using soft mounts, althou= gh he is now trying=0A= hard mounts. Also, we now know that the Amazon EFS server has a serious=0A= bug where it sometimes replies with the wrong slotid.=0A= =0A= > I'll switch our machines back to using hard mounts and try to get as=0A= > much diagnostic information as possible when the next lockup happens.=0A= >=0A= > Do you have any good suggestions for tracking down the issue? I've=0A= > been contemplating enabling WITNESS or building with debug information=0A= > to be able to hook in the kernel debugger.=0A= I don't think WITNESS or the kernel debugger will help.=0A= Beyond what you get from "ps axHl", it has happened before the hang.=0A= If you can reproduce it for a hard mount, you could capture packets via:=0A= # tcpdump -s 0 -w out.pcap host =0A= Tcpdump is useless at decoding NFS, but wireshark can decode the out.pcap= =0A= quite nicely. I can look at the out.pcap or, if you do so, you start by loo= king for=0A= NFSv4 specific errors.=0A= --> The client will usually log if it gets one of these. It will be an erro= r # > 10000.=0A= =0A= Good luck with it, rick=0A= =0A= Thank you very much for your reply!=0A= Cordially,=0A= Andreas Kempe=0A= =0A= > rick=0A= >=0A= >=0A= =0A=