Re: regression: nfs mount (even idle) eventually hangs server

[dai.ngo@oracle.com]

[-- Attachment #1: Type: text/plain, Size: 1688 bytes --]

Hi Mike,

Could you give the v2 patch a try? I will send you the location
to upload the core, if it happens, in a private email.

Thanks,
-Dai

On 12/23/22 5:05 AM, Mike Galbraith wrote:
> On Fri, 2022-12-23 at 04:02 -0800, dai.ngo@oracle.com wrote:
>> Hi Mike,
>>
>> I think the problem is the nfsd4_state_shrinker_worker is being
>> scheduled to run multiple times. This trigger the WARN_ON_ONCE
>> in __queue_delayed_work.
>>
>> Could you try the attached patch to see if it fixes this problem.
>> I tried to reproduce it on my test VMs but no success so I can't
>> verify the patch.
> That was a nogo.
>
> bart:/root # grep WARNING: netconsole.log
> [ 1030.364594] WARNING: CPU: 4 PID: 79 at kernel/workqueue.c:1655 __queue_delayed_work+0x6a/0x90
> [ 1030.364970] WARNING: CPU: 4 PID: 79 at kernel/workqueue.c:1657 __queue_delayed_work+0x5a/0x90
> [ 1030.365315] WARNING: CPU: 4 PID: 79 at kernel/workqueue.c:1500 __queue_work+0x33b/0x3d0
> [ 1030.365666] WARNING: CPU: 4 PID: 79 at kernel/workqueue.c:1500 __queue_work+0x33b/0x3d0
> [ 1030.365992] WARNING: CPU: 4 PID: 79 at kernel/workqueue.c:1500 __queue_work+0x33b/0x3d0
> [ 1030.366333] WARNING: CPU: 4 PID: 79 at kernel/workqueue.c:1500 __queue_work+0x33b/0x3d0
> [ 1030.366669] WARNING: CPU: 4 PID: 79 at kernel/workqueue.c:1500 __queue_work+0x33b/0x3d0
> [ 1030.366995] WARNING: CPU: 4 PID: 79 at kernel/workqueue.c:1500 __queue_work+0x33b/0x3d0
> [ 1030.367317] WARNING: CPU: 4 PID: 79 at kernel/workqueue.c:1500 __queue_work+0x33b/0x3d0
> [ 1030.367636] WARNING: CPU: 4 PID: 79 at kernel/workqueue.c:1500 __queue_work+0x33b/0x3d0
> [ 1030.367962] WARNING: CPU: 4 PID: 79 at kernel/workqueue.c:1500 __queue_work+0x33b/0x3d0
>

[-- Attachment #2: 0001-PATCH-v2-NFSD-fix-WARN_ON_ONCE-in-__queue_delayed_wo.patch --]
[-- Type: text/plain, Size: 7325 bytes --]

From ab0c32e0073892881da18a023490d6f811e69b5e Mon Sep 17 00:00:00 2001
From: Dai Ngo <dai.ngo@oracle.com>
Date: Thu, 5 Jan 2023 19:12:48 +0000
Subject: [PATCH] [PATCH v2] NFSD: fix WARN_ON_ONCE in __queue_delayed_work

Currently nfsd4_state_shrinker_worker can be schduled multiple times
from nfsd4_state_shrinker_count when memory is low. This causes
the WARN_ON_ONCE in __queue_delayed_work to trigger.

This patch allows only one instance of nfsd4_state_shrinker_worker
at a time using the nfsd_shrinker_active flag.

Replaces mod_delayed_work with queue_delayed_work since we
don't expect to modify the delay of any pending work.

Signed-off-by: Dai Ngo <dai.ngo@oracle.com>
---
 fs/nfsd/netns.h     |  1 +
 fs/nfsd/nfs4state.c | 37 +++++++++++++++++++++++--------------
 fs/nfsd/nfsctl.c    |  7 +------
 fs/nfsd/nfsd.h      |  6 ++----
 kernel/workqueue.c  |  9 ++++++---
 5 files changed, 33 insertions(+), 27 deletions(-)

diff --git a/fs/nfsd/netns.h b/fs/nfsd/netns.h
index 8c854ba3285b..801d70926442 100644
--- a/fs/nfsd/netns.h
+++ b/fs/nfsd/netns.h
@@ -196,6 +196,7 @@ struct nfsd_net {
 	atomic_t		nfsd_courtesy_clients;
 	struct shrinker		nfsd_client_shrinker;
 	struct delayed_work	nfsd_shrinker_work;
+	bool			nfsd_shrinker_active;
 };
 
 /* Simple check to find out if a given net was properly initialized */
diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
index 7b2ee535ade8..1f92d65bf16f 100644
--- a/fs/nfsd/nfs4state.c
+++ b/fs/nfsd/nfs4state.c
@@ -4407,11 +4407,20 @@ nfsd4_state_shrinker_count(struct shrinker *shrink, struct shrink_control *sc)
 	struct nfsd_net *nn = container_of(shrink,
 			struct nfsd_net, nfsd_client_shrinker);
 
+	spin_lock(&nn->client_lock);
+	if (nn->nfsd_shrinker_active) {
+		spin_unlock(&nn->client_lock);
+		return 0;
+	}
 	count = atomic_read(&nn->nfsd_courtesy_clients);
 	if (!count)
 		count = atomic_long_read(&num_delegations);
-	if (count)
-		mod_delayed_work(laundry_wq, &nn->nfsd_shrinker_work, 0);
+	if (count) {
+		nn->nfsd_shrinker_active = true;
+		spin_unlock(&nn->client_lock);
+		queue_delayed_work(laundry_wq, &nn->nfsd_shrinker_work, 0);
+	} else
+		spin_unlock(&nn->client_lock);
 	return (unsigned long)count;
 }
 
@@ -4421,7 +4430,7 @@ nfsd4_state_shrinker_scan(struct shrinker *shrink, struct shrink_control *sc)
 	return SHRINK_STOP;
 }
 
-int
+void
 nfsd4_init_leases_net(struct nfsd_net *nn)
 {
 	struct sysinfo si;
@@ -4443,16 +4452,6 @@ nfsd4_init_leases_net(struct nfsd_net *nn)
 	nn->nfs4_max_clients = max_t(int, max_clients, NFS4_CLIENTS_PER_GB);
 
 	atomic_set(&nn->nfsd_courtesy_clients, 0);
-	nn->nfsd_client_shrinker.scan_objects = nfsd4_state_shrinker_scan;
-	nn->nfsd_client_shrinker.count_objects = nfsd4_state_shrinker_count;
-	nn->nfsd_client_shrinker.seeks = DEFAULT_SEEKS;
-	return register_shrinker(&nn->nfsd_client_shrinker, "nfsd-client");
-}
-
-void
-nfsd4_leases_net_shutdown(struct nfsd_net *nn)
-{
-	unregister_shrinker(&nn->nfsd_client_shrinker);
 }
 
 static void init_nfs4_replay(struct nfs4_replay *rp)
@@ -6249,6 +6248,9 @@ nfsd4_state_shrinker_worker(struct work_struct *work)
 
 	courtesy_client_reaper(nn);
 	deleg_reaper(nn);
+	spin_lock(&nn->client_lock);
+	nn->nfsd_shrinker_active = 0;
+	spin_unlock(&nn->client_lock);
 }
 
 static inline __be32 nfs4_check_fh(struct svc_fh *fhp, struct nfs4_stid *stp)
@@ -8075,9 +8077,15 @@ static int nfs4_state_create_net(struct net *net)
 
 	INIT_DELAYED_WORK(&nn->laundromat_work, laundromat_main);
 	INIT_DELAYED_WORK(&nn->nfsd_shrinker_work, nfsd4_state_shrinker_worker);
+	printk("%s: nn[%px] dwork[%px] timer[%px]\n",  __func__,
+		nn, &nn->nfsd_shrinker_work,
+		nn->nfsd_shrinker_work.timer.function);
 	get_net(net);
 
-	return 0;
+	nn->nfsd_client_shrinker.scan_objects = nfsd4_state_shrinker_scan;
+	nn->nfsd_client_shrinker.count_objects = nfsd4_state_shrinker_count;
+	nn->nfsd_client_shrinker.seeks = DEFAULT_SEEKS;
+	return register_shrinker(&nn->nfsd_client_shrinker, "nfsd-client");
 
 err_sessionid:
 	kfree(nn->unconf_id_hashtbl);
@@ -8171,6 +8179,7 @@ nfs4_state_shutdown_net(struct net *net)
 	struct list_head *pos, *next, reaplist;
 	struct nfsd_net *nn = net_generic(net, nfsd_net_id);
 
+	unregister_shrinker(&nn->nfsd_client_shrinker);
 	cancel_delayed_work_sync(&nn->laundromat_work);
 	locks_end_grace(&nn->nfsd4_manager);
 
diff --git a/fs/nfsd/nfsctl.c b/fs/nfsd/nfsctl.c
index d1e581a60480..c2577ee7ffb2 100644
--- a/fs/nfsd/nfsctl.c
+++ b/fs/nfsd/nfsctl.c
@@ -1457,9 +1457,7 @@ static __net_init int nfsd_init_net(struct net *net)
 		goto out_idmap_error;
 	nn->nfsd_versions = NULL;
 	nn->nfsd4_minorversions = NULL;
-	retval = nfsd4_init_leases_net(nn);
-	if (retval)
-		goto out_drc_error;
+	nfsd4_init_leases_net(nn);
 	retval = nfsd_reply_cache_init(nn);
 	if (retval)
 		goto out_cache_error;
@@ -1469,8 +1467,6 @@ static __net_init int nfsd_init_net(struct net *net)
 	return 0;
 
 out_cache_error:
-	nfsd4_leases_net_shutdown(nn);
-out_drc_error:
 	nfsd_idmap_shutdown(net);
 out_idmap_error:
 	nfsd_export_shutdown(net);
@@ -1486,7 +1482,6 @@ static __net_exit void nfsd_exit_net(struct net *net)
 	nfsd_idmap_shutdown(net);
 	nfsd_export_shutdown(net);
 	nfsd_netns_free_versions(net_generic(net, nfsd_net_id));
-	nfsd4_leases_net_shutdown(nn);
 }
 
 static struct pernet_operations nfsd_net_ops = {
diff --git a/fs/nfsd/nfsd.h b/fs/nfsd/nfsd.h
index 93b42ef9ed91..fa0144a74267 100644
--- a/fs/nfsd/nfsd.h
+++ b/fs/nfsd/nfsd.h
@@ -504,8 +504,7 @@ extern void unregister_cld_notifier(void);
 extern void nfsd4_ssc_init_umount_work(struct nfsd_net *nn);
 #endif
 
-extern int nfsd4_init_leases_net(struct nfsd_net *nn);
-extern void nfsd4_leases_net_shutdown(struct nfsd_net *nn);
+extern void nfsd4_init_leases_net(struct nfsd_net *nn);
 
 #else /* CONFIG_NFSD_V4 */
 static inline int nfsd4_is_junction(struct dentry *dentry)
@@ -513,8 +512,7 @@ static inline int nfsd4_is_junction(struct dentry *dentry)
 	return 0;
 }
 
-static inline int nfsd4_init_leases_net(struct nfsd_net *nn) { return 0; };
-static inline void nfsd4_leases_net_shutdown(struct nfsd_net *nn) {};
+static inline void nfsd4_init_leases_net(struct nfsd_net *nn) { };
 
 #define register_cld_notifier() 0
 #define unregister_cld_notifier() do { } while(0)
diff --git a/kernel/workqueue.c b/kernel/workqueue.c
index 07895deca271..1535e7c92435 100644
--- a/kernel/workqueue.c
+++ b/kernel/workqueue.c
@@ -1497,7 +1497,7 @@ static void __queue_work(int cpu, struct workqueue_struct *wq,
 	trace_workqueue_queue_work(req_cpu, pwq, work);
 
 	if (WARN_ON(!list_empty(&work->entry)))
-		goto out;
+		panic("wq[%px] work[%px]\n", wq, work);
 
 	pwq->nr_in_flight[pwq->work_color]++;
 	work_flags = work_color_to_flags(pwq->work_color);
@@ -1651,9 +1651,12 @@ static void __queue_delayed_work(int cpu, struct workqueue_struct *wq,
 	struct work_struct *work = &dwork->work;
 
 	WARN_ON_ONCE(!wq);
-	WARN_ON_ONCE(timer->function != delayed_work_timer_fn);
+	if (WARN_ON_ONCE(timer->function != delayed_work_timer_fn))
+		panic("wq[%px] dwork[%px] timer->function[%px]\n",
+			wq, dwork, timer->function);
 	WARN_ON_ONCE(timer_pending(timer));
-	WARN_ON_ONCE(!list_empty(&work->entry));
+	if (WARN_ON_ONCE(!list_empty(&work->entry)))
+		panic("wq[%px] dwork[%px]\n", wq, dwork);
 
 	/*
 	 * If @delay is 0, queue @dwork->work immediately.  This is for
-- 
2.9.5