Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::3:2 as permitted sender) client-ip=2620:137:e000::3:2;
From:   Chuck Lever III <chuck.lever@oracle.com>
To:     Donald Buczek <buczek@molgen.mpg.de>
CC:     Linux Kernel Mailing List <linux-kernel@vger.kernel.org>,
        "linux-fsdevel@vger.kernel.org" <linux-fsdevel@vger.kernel.org>
Subject: Re: Heisenbug: I/O freeze can be resolved by cat $task/cmdline of
 unrelated process
Thread-Topic: Heisenbug: I/O freeze can be resolved by cat $task/cmdline of
 unrelated process
Thread-Index: AQHaD8wf9wfCnocwJkyj2TZn1rGbbrBtUvcA
Date:   Mon, 6 Nov 2023 13:58:22 +0000
Message-ID: <9822F555-42F5-44AD-8056-469E85A86C3D@oracle.com>
References: <77184fcc-46ab-4d69-b163-368264fa49f7@molgen.mpg.de>
In-Reply-To: <77184fcc-46ab-4d69-b163-368264fa49f7@molgen.mpg.de>
Accept-Language: en-US
Content-Language: en-US
x-ms-exchange-antispam-messagedata-chunkcount: 1
x-ms-exchange-antispam-messagedata-0: =?us-ascii?Q?QRLPUupgQGQr2WF67h4w8sfBlbqBsE8MIiTlQ9b5Gcgf4ACiBQUWI2YaX6PK?=
 =?us-ascii?Q?9fyeJOmNsZCC5pd/SwhogGMYnMKVAdwv0qBIz3VaaotLSUtqfM4R+feVtNvR?=
 =?us-ascii?Q?KOJt/2Muj6hQ3i1EZ20bESQsL4DNEexsw/75LuSlTWVoP74tCtBCOWxGJn0s?=
 =?us-ascii?Q?qURul9z4I+JFXnfOT4EHFzOqLG/TyqxRCoZ8Gvv29fwy5MMiiY7rC9/8lei1?=
 =?us-ascii?Q?ZMKZLikElloIyfQCeRuUQ8NWaJ9wa7zaNJ2omVhxBrQxHzGxOfHCgWaRoecx?=
 =?us-ascii?Q?zuEShaX63a03KenVc3rvW94w58A54ZopBMzY1KXNXmqZnQlvBVvIQQiBOuEw?=
 =?us-ascii?Q?RA5PLsFjqVIl1cO6xcRRtz+s8exH82Jr33DwhWjQH35np4Ba7TT1fHcE7xLz?=
 =?us-ascii?Q?JUXRBSBdzJeA+ss+LerXdpkU0neXs8zACKYHeOJv97KoKYAdzhxD8kxh+mZR?=
 =?us-ascii?Q?kHlEThgUbva88Lf5ySNl0Rnm3gvtt4zqhGpfnPhyp6WNCchcFF3c2h7y2iVi?=
 =?us-ascii?Q?I8e1nOLIO8AHIlfx95P2Hir+FmqcW8d8pZo7h1tRVulnmc7dxANAXcRc6oVZ?=
 =?us-ascii?Q?RmQxjJUQNdQuEPQOy+u/z3E61GNHUFpGl4u/2E/cICfy0VaidChDO+pSzOk7?=
 =?us-ascii?Q?4bAGQlk0fPDxTX4wmt9Iz/MwcNNdatxJdX0D5jQ9ON0PApdtoQSO2C1VyCsB?=
 =?us-ascii?Q?K8+k7+0GLdkxY2s4UC3cEbqQaFR3EI87tP3NLrgczz8i/UIb4E+22AJWGpOK?=
 =?us-ascii?Q?uZgF0OC9tYBKHKDYjrvz0tQLC0u/9Goe5s0tywqp2Pyg2RWVJ29oyF6FD9vM?=
 =?us-ascii?Q?49w1nSOqC6s2w6KMwHt7Os/Yi2VzVNr1oHgbldGlT9H9VBYH4+P0EQSE4qlv?=
 =?us-ascii?Q?AY/cKAXzOJFksWvP/EGeiioY7MVPVkrxp4DIu7UcKV/yTPUL/Q2Z6j+ZEEQH?=
 =?us-ascii?Q?WELrrt8i7+qKaHGYA6ha1lLj/GYY9k2xl7RKVziOtViT5agPgaBzGOVz+oaM?=
 =?us-ascii?Q?qM+3wezveJXQ/1OvlLdakZHQvjt7P72AVfpTaXQAfG1XqYClJayysJmcjGNg?=
 =?us-ascii?Q?41qG/sggZwr2hWKfkKr8wj4tF+UOUaWufmLCNTUu5+GYta8vjS75rUrrce/A?=
 =?us-ascii?Q?E0L2+5BYKXknzERNzlLRqkfrmQIUEBNriyAVmLb3VRjme1+dUF90HVNU/5vs?=
 =?us-ascii?Q?Cnx65yu/lIdtO76fJhKPKb0YQ2aPZ1nkiOPVcGi7U31wiXNxxMdlwoMxAKL/?=
 =?us-ascii?Q?B1XqKzmh6o6u9zEFfCtEr1q3IhpBfMOAUw11L9fZtUHQ/zOLB8w8fA/HuZcu?=
 =?us-ascii?Q?JX114dSN5x50UKvwEhUpSGtd/wIASVP21ee8vDyiNuAybwy3oVSaluldrc/2?=
 =?us-ascii?Q?nQ/QDK76W6ZsHbZFUGxxXXI4sPo6bitKhZjfKyyUVB8xA5ThpmYDypPeJocV?=
 =?us-ascii?Q?ObOuPB6ZkfNDSMHQnQfk1c0Mp3n4LRxRKp5zlR7WLMotY2xcZ9SPvRq+zpn4?=
 =?us-ascii?Q?owSCHXpzynopC4AiPMq+YRpjpQ3/oDoLyedi/onAGasRTOaR6mC0Ppvz2tKZ?=
 =?us-ascii?Q?1UJJolhAovZiqv7bVwssAWm6rLiIXiWoEdECYSELNaRR8P1FnZcZl8+d4O1y?=
 =?us-ascii?Q?cQ=3D=3D?=
Content-Type: text/plain; charset="us-ascii"
Content-ID: <D714127A55769B4FBB0EBB476B1BFFC5@namprd10.prod.outlook.com>
Content-Transfer-Encoding: quoted-printable
MIME-Version: 1.0
X-MS-Exchange-AntiSpam-ExternalHop-MessageData-ChunkCount: 1
X-MS-Exchange-AntiSpam-ExternalHop-MessageData-0: ePbFMhxelKuxQ4Z3rjvbIfiYOVH0Plga1Rh15uHFw5LX+7u+Nqbe/gk04PrKqloDR1HKnJzJo38g3AQHyHbECajhT0+PWjrz3+CN8sLCp6iM/w3//uD2q5H6UwuB9Jjr8+sGiPp9keNy9wmpNM/d64aP0WmTs54BhLHLOOSM+IHZltzH0lfCXdX0B3BuL0R8zF/Q9JySf2eKBQTXxbCyaJcezqHoUb3GFv2cfNGmkCIhbRrfFgVAgWMSJ1xbefDjeZYsXKTJ5EvtSXS5sfZhK0BlT/KIbYa2IVmcRpUh5tL8oPzit24Ze061lCbd4yiiGi1ikp+4/mIs8icvfXtRxrd/KhR77dM/ntCK4oXnlQFHU6Oyht53qdxHwS+3dEtQKY2IC2H96IWxkAcA4yvuYmXgZa4abjAJ45bZZt/zd7xZ+DhaUNhC0Ay0+QdtpFynGpOBg+pkM4vjoHignirqLzDQPp54UIqMBhEF2+WR008wFVVouGHqAsSHgx9rt3jmbXrIew8OOP+Yyg998EUA/C3NRjjPxwpD7fadiI/DEZ1oUXuadMUaEic2I+UC9VmsmQqoOFo3VxruiyVClxrtq0VzM3m/AGJtO/1N2wFOpWDfYhgXlMTaGcg41sTQtcBZ8uyliB7Ld7tIN/gHVQldF44ov2UrnYZqsr+d4OSmaVaPNFucQtOZNgeLBzlWzxtuuMHE3vH04mBgUl5iwwWi3Y4hefkZJLGvMm4k3mQTdqud4wj/P1i76Z2cOWkfFw2YSbh0UGtIQmbVnjwwzFITvlowWxZsD7XedlMitrdEkek=
X-OriginatorOrg: oracle.com
X-MS-Exchange-CrossTenant-AuthAs: Internal
X-MS-Exchange-CrossTenant-AuthSource: BN0PR10MB5128.namprd10.prod.outlook.com
X-MS-Exchange-CrossTenant-Network-Message-Id: bb6cdee1-bf4c-4759-be39-08dbded070ce
X-MS-Exchange-CrossTenant-originalarrivaltime: 06 Nov 2023 13:58:22.9772
 (UTC)
X-MS-Exchange-CrossTenant-fromentityheader: Hosted
X-MS-Exchange-CrossTenant-id: 4e2c6054-71cb-48f1-bd6c-3a9705aca71b
X-MS-Exchange-CrossTenant-mailboxtype: HOSTED
X-MS-Exchange-CrossTenant-userprincipalname: mSDXFPh/Nl/j+F7XxDWfLiPqkfsQeGzWUoYtDNIRCeRRxLwI7xvTF5MPKkCZQDdzipSUEwjjJ60RQG/vvJROlQ==
X-MS-Exchange-Transport-CrossTenantHeadersStamped: CH3PR10MB6810
X-Proofpoint-Virus-Version: vendor=baseguard
 engine=ICAP:2.0.272,Aquarius:18.0.987,Hydra:6.0.619,FMLib:17.11.176.26
 definitions=2023-11-06_12,2023-11-02_03,2023-05-22_02
X-Proofpoint-Spam-Details: rule=notspam policy=default score=0 bulkscore=0 mlxscore=0 adultscore=0
 suspectscore=0 phishscore=0 spamscore=0 mlxlogscore=999 malwarescore=0
 classifier=spam adjust=0 reason=mlx scancount=1 engine=8.12.0-2310240000
 definitions=main-2311060113
X-Proofpoint-ORIG-GUID: 36NRgISih62OGqkcixYqJhzNMBgjyquu
X-Proofpoint-GUID: 36NRgISih62OGqkcixYqJhzNMBgjyquu
X-Spam-Status: No, score=-0.9 required=5.0 tests=DKIM_SIGNED,DKIM_VALID,
	DKIM_VALID_AU,HEADER_FROM_DIFFERENT_DOMAINS,MAILING_LIST_MULTI,
	SPF_HELO_NONE,SPF_PASS,T_SCC_BODY_TEXT_LINE autolearn=unavailable
	autolearn_force=no version=3.4.6
X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on agentk.vger.email
Precedence: bulk
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org
X-Greylist: Sender passed SPF test, not delayed by milter-greylist-4.6.4 (agentk.vger.email [0.0.0.0]); Mon, 06 Nov 2023 05:59:17 -0800 (PST)


> On Nov 5, 2023, at 4:40 AM, Donald Buczek <buczek@molgen.mpg.de> wrote:
>=20
> Hello, experts,
>=20
> we have a strange new problem on a backup server (high metadata I/O 24/7,=
 xfs -> mdraid). The system worked for years and with v5.15.86 for 8 month.=
 Then we've updated to 6.1.52 and after a few hours it froze: No more I/O a=
ctivity to one of its filesystems, processes trying to access it blocked un=
til we reboot.
>=20
> Of course, at first we blamed the kernel as this happened after an upgrad=
e. But after several experiments with different kernel versions, we've retu=
rned to the v5.15.86 kernel we used before, but still experienced the probl=
em. Then we suspected, that a microcode update (for AMD EPYC 7261), which h=
appened as a side effect of the first reboot, might be the culprit and remo=
ved it. That didn't fix it either. For all I can say, all software is back =
to the state which worked before.
>=20
> Now the strange part: What we usually do, when we have a situation like t=
his, is that we run a script which takes several procfs and sysfs informati=
on which happened to be useful in the past. It was soon discovered, that ju=
st running this script unblocks the system. I/O continues as if nothing eve=
r happened. Then we singled-stepped the operations of the script to find ou=
t, what action exactly gets the system to resume. It is this part:
>=20
>    for task in /proc/*/task/*; do
>        echo  "# # $task: $(cat $task/comm) : $(cat $task/cmdline | xargs =
-0 echo)"
>        cmd cat $task/stack
>    done
>=20
> which can further be reduced to
>=20
>    for task in /proc/*/task/*; do echo $task $(cat $task/cmdline | xargs =
-0 echo); done
>=20
> This is absolutely reproducible. Above line unblocks the system reliably.
>=20
> Another remarkable thing: We've modified above code to do the processes s=
lowly one by one and checking after each step if I/O resumed. And each time=
 we've tested that, it was one of the 64 nfsd processes (but not the very f=
irst one tried). While the systems exports filesystems, we have absolutely =
no reason to assume, that any client actually tries to access this nfs serv=
er. Additionally, when the full script is run, the stack traces show all nf=
sd tasks in their normal idle state ( [<0>] svc_recv+0x7bd/0x8d0 [sunrpc] )=
.
>=20
> Does anybody have an idea, how a `cat /proc/PID/cmdline` on a specific as=
sumed-to-be-idle nfsd thread could have such an "healing" effect?
>=20
> I'm well aware, that, for example, a hardware problem might result in jus=
t anything and that the question might not be answerable at all. If so: ple=
ase excuse the noise.

I'm with Neil on this: I believe the nfsd thread happens to be in the
wrong place at the wrong time. When idle, an nfsd thread is nothing
more than a plain kthread waiting in the kernel's scheduler.

If you have an opportunity, try testing without starting up the NFSD
service. You might find that the symptoms move to another thread or
subsystem.


--
Chuck Lever