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

From: dai . ngo
Date: Sun Jan 08 2023 - 19:50:55 EST


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@xxxxxxxxxx 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
From ab0c32e0073892881da18a023490d6f811e69b5e Mon Sep 17 00:00:00 2001
From: Dai Ngo <dai.ngo@xxxxxxxxxx>
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@xxxxxxxxxx>
---
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