* [PATCH] nfs: don't call blocking operations while !TASK_RUNNING
@ 2015-01-14 15:32 Jeff Layton
2015-01-14 17:13 ` Trond Myklebust
2015-01-14 18:08 ` [PATCH v2] " Jeff Layton
0 siblings, 2 replies; 9+ messages in thread
From: Jeff Layton @ 2015-01-14 15:32 UTC (permalink / raw)
To: trond.myklebust; +Cc: bfields, linux-nfs
Bruce reported seeing this warning pop when mounting using v4.1:
------------[ cut here ]------------
WARNING: CPU: 1 PID: 1121 at kernel/sched/core.c:7300 __might_sleep+0xbd/0xd0()
do not call blocking ops when !TASK_RUNNING; state=1 set at [<ffffffff810ff58f>] prepare_to_wait+0x2f/0x90
Modules linked in: rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver nfs lockd grace sunrpc fscache ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ebtable_nat ebtable_broute bridge stp llc ebtable_filter ebtables ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_security ip6table_raw ip6table_filter ip6_tables iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_mangle iptable_security iptable_raw snd_hda_codec_generic snd_hda_intel snd_hda_controller snd_hda_codec snd_hwdep snd_pcm snd_timer ppdev joydev snd virtio_console virtio_balloon pcspkr serio_raw parport_pc parport pvpanic floppy soundcore i2c_piix4 virtio_blk virtio_net qxl drm_kms_helper ttm drm virtio_pci virtio_ring ata_generic virtio pata_acpi
CPU: 1 PID: 1121 Comm: nfsv4.1-svc Not tainted 3.19.0-rc4+ #25
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140709_153950- 04/01/2014
0000000000000000 000000004e5e3f73 ffff8800b998fb48 ffffffff8186ac78
0000000000000000 ffff8800b998fba0 ffff8800b998fb88 ffffffff810ac9da
ffff8800b998fb68 ffffffff81c923e7 00000000000004d9 0000000000000000
Call Trace:
[<ffffffff8186ac78>] dump_stack+0x4c/0x65
[<ffffffff810ac9da>] warn_slowpath_common+0x8a/0xc0
[<ffffffff810aca65>] warn_slowpath_fmt+0x55/0x70
[<ffffffff810ff58f>] ? prepare_to_wait+0x2f/0x90
[<ffffffff810ff58f>] ? prepare_to_wait+0x2f/0x90
[<ffffffff810dd2ad>] __might_sleep+0xbd/0xd0
[<ffffffff8124c973>] kmem_cache_alloc_trace+0x243/0x430
[<ffffffff810d941e>] ? groups_alloc+0x3e/0x130
[<ffffffff810d941e>] groups_alloc+0x3e/0x130
[<ffffffffa0301b1e>] svcauth_unix_accept+0x16e/0x290 [sunrpc]
[<ffffffffa0300571>] svc_authenticate+0xe1/0xf0 [sunrpc]
[<ffffffffa02fc564>] svc_process_common+0x244/0x6a0 [sunrpc]
[<ffffffffa02fd044>] bc_svc_process+0x1c4/0x260 [sunrpc]
[<ffffffffa03d5478>] nfs41_callback_svc+0x128/0x1f0 [nfsv4]
[<ffffffff810ff970>] ? wait_woken+0xc0/0xc0
[<ffffffffa03d5350>] ? nfs4_callback_svc+0x60/0x60 [nfsv4]
[<ffffffff810d45bf>] kthread+0x11f/0x140
[<ffffffff810ea815>] ? local_clock+0x15/0x30
[<ffffffff810d44a0>] ? kthread_create_on_node+0x250/0x250
[<ffffffff81874bfc>] ret_from_fork+0x7c/0xb0
[<ffffffff810d44a0>] ? kthread_create_on_node+0x250/0x250
---[ end trace 675220a11e30f4f2 ]---
nfs41_callback_svc does most of its work while in TASK_INTERRUPTIBLE,
which is just wrong. Fix that by finishing the wait immediately if we've
found that the list has something on it.
Also, we don't expect this kthread to accept signals, so we should be
using a TASK_UNINTERRUPTIBLE sleep instead.
Reported-by: "J. Bruce Fields" <bfields@fieldses.org>
Signed-off-by: Jeff Layton <jlayton@primarydata.com>
---
fs/nfs/callback.c | 5 +++--
1 file changed, 3 insertions(+), 2 deletions(-)
diff --git a/fs/nfs/callback.c b/fs/nfs/callback.c
index b8fb3a4ef649..ebba958e084c 100644
--- a/fs/nfs/callback.c
+++ b/fs/nfs/callback.c
@@ -128,13 +128,14 @@ nfs41_callback_svc(void *vrqstp)
if (try_to_freeze())
continue;
- prepare_to_wait(&serv->sv_cb_waitq, &wq, TASK_INTERRUPTIBLE);
+ prepare_to_wait(&serv->sv_cb_waitq, &wq, TASK_UNINTERRUPTIBLE);
spin_lock_bh(&serv->sv_cb_lock);
if (!list_empty(&serv->sv_cb_list)) {
req = list_first_entry(&serv->sv_cb_list,
struct rpc_rqst, rq_bc_list);
list_del(&req->rq_bc_list);
spin_unlock_bh(&serv->sv_cb_lock);
+ finish_wait(&serv->sv_cb_waitq, &wq);
dprintk("Invoking bc_svc_process()\n");
error = bc_svc_process(serv, req, rqstp);
dprintk("bc_svc_process() returned w/ error code= %d\n",
@@ -142,8 +143,8 @@ nfs41_callback_svc(void *vrqstp)
} else {
spin_unlock_bh(&serv->sv_cb_lock);
schedule();
+ finish_wait(&serv->sv_cb_waitq, &wq);
}
- finish_wait(&serv->sv_cb_waitq, &wq);
}
return 0;
}
--
2.1.0
^ permalink raw reply related [flat|nested] 9+ messages in thread* Re: [PATCH] nfs: don't call blocking operations while !TASK_RUNNING
2015-01-14 15:32 [PATCH] nfs: don't call blocking operations while !TASK_RUNNING Jeff Layton
@ 2015-01-14 17:13 ` Trond Myklebust
2015-01-14 17:27 ` Jeff Layton
2015-01-14 18:08 ` [PATCH v2] " Jeff Layton
1 sibling, 1 reply; 9+ messages in thread
From: Trond Myklebust @ 2015-01-14 17:13 UTC (permalink / raw)
To: Jeff Layton; +Cc: Bruce Fields, Linux NFS Mailing List
On Wed, Jan 14, 2015 at 10:32 AM, Jeff Layton <jlayton@primarydata.com> wrote:
> Bruce reported seeing this warning pop when mounting using v4.1:
>
> ------------[ cut here ]------------
> WARNING: CPU: 1 PID: 1121 at kernel/sched/core.c:7300 __might_sleep+0xbd/0xd0()
> do not call blocking ops when !TASK_RUNNING; state=1 set at [<ffffffff810ff58f>] prepare_to_wait+0x2f/0x90
> Modules linked in: rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver nfs lockd grace sunrpc fscache ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ebtable_nat ebtable_broute bridge stp llc ebtable_filter ebtables ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_security ip6table_raw ip6table_filter ip6_tables iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_mangle iptable_security iptable_raw snd_hda_codec_generic snd_hda_intel snd_hda_controller snd_hda_codec snd_hwdep snd_pcm snd_timer ppdev joydev snd virtio_console virtio_balloon pcspkr serio_raw parport_pc parport pvpanic floppy soundcore i2c_piix4 virtio_blk virtio_net qxl drm_kms_helper ttm drm virtio_pci virtio_ring ata_generic virtio pata_acpi
> CPU: 1 PID: 1121 Comm: nfsv4.1-svc Not tainted 3.19.0-rc4+ #25
> Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140709_153950- 04/01/2014
> 0000000000000000 000000004e5e3f73 ffff8800b998fb48 ffffffff8186ac78
> 0000000000000000 ffff8800b998fba0 ffff8800b998fb88 ffffffff810ac9da
> ffff8800b998fb68 ffffffff81c923e7 00000000000004d9 0000000000000000
> Call Trace:
> [<ffffffff8186ac78>] dump_stack+0x4c/0x65
> [<ffffffff810ac9da>] warn_slowpath_common+0x8a/0xc0
> [<ffffffff810aca65>] warn_slowpath_fmt+0x55/0x70
> [<ffffffff810ff58f>] ? prepare_to_wait+0x2f/0x90
> [<ffffffff810ff58f>] ? prepare_to_wait+0x2f/0x90
> [<ffffffff810dd2ad>] __might_sleep+0xbd/0xd0
> [<ffffffff8124c973>] kmem_cache_alloc_trace+0x243/0x430
> [<ffffffff810d941e>] ? groups_alloc+0x3e/0x130
> [<ffffffff810d941e>] groups_alloc+0x3e/0x130
> [<ffffffffa0301b1e>] svcauth_unix_accept+0x16e/0x290 [sunrpc]
> [<ffffffffa0300571>] svc_authenticate+0xe1/0xf0 [sunrpc]
> [<ffffffffa02fc564>] svc_process_common+0x244/0x6a0 [sunrpc]
> [<ffffffffa02fd044>] bc_svc_process+0x1c4/0x260 [sunrpc]
> [<ffffffffa03d5478>] nfs41_callback_svc+0x128/0x1f0 [nfsv4]
> [<ffffffff810ff970>] ? wait_woken+0xc0/0xc0
> [<ffffffffa03d5350>] ? nfs4_callback_svc+0x60/0x60 [nfsv4]
> [<ffffffff810d45bf>] kthread+0x11f/0x140
> [<ffffffff810ea815>] ? local_clock+0x15/0x30
> [<ffffffff810d44a0>] ? kthread_create_on_node+0x250/0x250
> [<ffffffff81874bfc>] ret_from_fork+0x7c/0xb0
> [<ffffffff810d44a0>] ? kthread_create_on_node+0x250/0x250
> ---[ end trace 675220a11e30f4f2 ]---
>
> nfs41_callback_svc does most of its work while in TASK_INTERRUPTIBLE,
> which is just wrong. Fix that by finishing the wait immediately if we've
> found that the list has something on it.
ACK.
> Also, we don't expect this kthread to accept signals, so we should be
> using a TASK_UNINTERRUPTIBLE sleep instead.
Umm... Won't that end up triggering the hung task watchdog for every
120seconds with no callback activity?
> Reported-by: "J. Bruce Fields" <bfields@fieldses.org>
> Signed-off-by: Jeff Layton <jlayton@primarydata.com>
> ---
> fs/nfs/callback.c | 5 +++--
> 1 file changed, 3 insertions(+), 2 deletions(-)
>
> diff --git a/fs/nfs/callback.c b/fs/nfs/callback.c
> index b8fb3a4ef649..ebba958e084c 100644
> --- a/fs/nfs/callback.c
> +++ b/fs/nfs/callback.c
> @@ -128,13 +128,14 @@ nfs41_callback_svc(void *vrqstp)
> if (try_to_freeze())
> continue;
>
> - prepare_to_wait(&serv->sv_cb_waitq, &wq, TASK_INTERRUPTIBLE);
> + prepare_to_wait(&serv->sv_cb_waitq, &wq, TASK_UNINTERRUPTIBLE);
> spin_lock_bh(&serv->sv_cb_lock);
> if (!list_empty(&serv->sv_cb_list)) {
> req = list_first_entry(&serv->sv_cb_list,
> struct rpc_rqst, rq_bc_list);
> list_del(&req->rq_bc_list);
> spin_unlock_bh(&serv->sv_cb_lock);
> + finish_wait(&serv->sv_cb_waitq, &wq);
> dprintk("Invoking bc_svc_process()\n");
> error = bc_svc_process(serv, req, rqstp);
> dprintk("bc_svc_process() returned w/ error code= %d\n",
> @@ -142,8 +143,8 @@ nfs41_callback_svc(void *vrqstp)
> } else {
> spin_unlock_bh(&serv->sv_cb_lock);
> schedule();
> + finish_wait(&serv->sv_cb_waitq, &wq);
> }
> - finish_wait(&serv->sv_cb_waitq, &wq);
> }
> return 0;
> }
> --
> 2.1.0
>
--
Trond Myklebust
Linux NFS client maintainer, PrimaryData
trond.myklebust@primarydata.com
^ permalink raw reply [flat|nested] 9+ messages in thread* Re: [PATCH] nfs: don't call blocking operations while !TASK_RUNNING
2015-01-14 17:13 ` Trond Myklebust
@ 2015-01-14 17:27 ` Jeff Layton
2015-01-14 18:06 ` Trond Myklebust
0 siblings, 1 reply; 9+ messages in thread
From: Jeff Layton @ 2015-01-14 17:27 UTC (permalink / raw)
To: Trond Myklebust; +Cc: Bruce Fields, Linux NFS Mailing List
On Wed, 14 Jan 2015 12:13:43 -0500
Trond Myklebust <trond.myklebust@primarydata.com> wrote:
> On Wed, Jan 14, 2015 at 10:32 AM, Jeff Layton <jlayton@primarydata.com> wrote:
> > Bruce reported seeing this warning pop when mounting using v4.1:
> >
> > ------------[ cut here ]------------
> > WARNING: CPU: 1 PID: 1121 at kernel/sched/core.c:7300 __might_sleep+0xbd/0xd0()
> > do not call blocking ops when !TASK_RUNNING; state=1 set at [<ffffffff810ff58f>] prepare_to_wait+0x2f/0x90
> > Modules linked in: rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver nfs lockd grace sunrpc fscache ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ebtable_nat ebtable_broute bridge stp llc ebtable_filter ebtables ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_security ip6table_raw ip6table_filter ip6_tables iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_mangle iptable_security iptable_raw snd_hda_codec_generic snd_hda_intel snd_hda_controller snd_hda_codec snd_hwdep snd_pcm snd_timer ppdev joydev snd virtio_console virtio_balloon pcspkr serio_raw parport_pc parport pvpanic floppy soundcore i2c_piix4 virtio_blk virtio_net qxl drm_kms_helper ttm drm virtio_pci virtio_ring ata_generic virtio pata_acpi
> > CPU: 1 PID: 1121 Comm: nfsv4.1-svc Not tainted 3.19.0-rc4+ #25
> > Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140709_153950- 04/01/2014
> > 0000000000000000 000000004e5e3f73 ffff8800b998fb48 ffffffff8186ac78
> > 0000000000000000 ffff8800b998fba0 ffff8800b998fb88 ffffffff810ac9da
> > ffff8800b998fb68 ffffffff81c923e7 00000000000004d9 0000000000000000
> > Call Trace:
> > [<ffffffff8186ac78>] dump_stack+0x4c/0x65
> > [<ffffffff810ac9da>] warn_slowpath_common+0x8a/0xc0
> > [<ffffffff810aca65>] warn_slowpath_fmt+0x55/0x70
> > [<ffffffff810ff58f>] ? prepare_to_wait+0x2f/0x90
> > [<ffffffff810ff58f>] ? prepare_to_wait+0x2f/0x90
> > [<ffffffff810dd2ad>] __might_sleep+0xbd/0xd0
> > [<ffffffff8124c973>] kmem_cache_alloc_trace+0x243/0x430
> > [<ffffffff810d941e>] ? groups_alloc+0x3e/0x130
> > [<ffffffff810d941e>] groups_alloc+0x3e/0x130
> > [<ffffffffa0301b1e>] svcauth_unix_accept+0x16e/0x290 [sunrpc]
> > [<ffffffffa0300571>] svc_authenticate+0xe1/0xf0 [sunrpc]
> > [<ffffffffa02fc564>] svc_process_common+0x244/0x6a0 [sunrpc]
> > [<ffffffffa02fd044>] bc_svc_process+0x1c4/0x260 [sunrpc]
> > [<ffffffffa03d5478>] nfs41_callback_svc+0x128/0x1f0 [nfsv4]
> > [<ffffffff810ff970>] ? wait_woken+0xc0/0xc0
> > [<ffffffffa03d5350>] ? nfs4_callback_svc+0x60/0x60 [nfsv4]
> > [<ffffffff810d45bf>] kthread+0x11f/0x140
> > [<ffffffff810ea815>] ? local_clock+0x15/0x30
> > [<ffffffff810d44a0>] ? kthread_create_on_node+0x250/0x250
> > [<ffffffff81874bfc>] ret_from_fork+0x7c/0xb0
> > [<ffffffff810d44a0>] ? kthread_create_on_node+0x250/0x250
> > ---[ end trace 675220a11e30f4f2 ]---
> >
> > nfs41_callback_svc does most of its work while in TASK_INTERRUPTIBLE,
> > which is just wrong. Fix that by finishing the wait immediately if we've
> > found that the list has something on it.
>
> ACK.
>
> > Also, we don't expect this kthread to accept signals, so we should be
> > using a TASK_UNINTERRUPTIBLE sleep instead.
>
> Umm... Won't that end up triggering the hung task watchdog for every
> 120seconds with no callback activity?
>
Doh! You're correct.
What's the right way to do this then? Do we need to use
schedule_timeout and wake up every 100s or so? Using TASK_INTERRUPTIBLE
to work around the watchdog seems wrong but I guess we can live with
that in the short term if it's the only way.
Long-term, it would probably make sense to convert this (and other
service threads like this) over to workqueue-based services. I
still need to chase down where the latency comes from before that
patchset is ready for merge though.
> > Reported-by: "J. Bruce Fields" <bfields@fieldses.org>
> > Signed-off-by: Jeff Layton <jlayton@primarydata.com>
> > ---
> > fs/nfs/callback.c | 5 +++--
> > 1 file changed, 3 insertions(+), 2 deletions(-)
> >
> > diff --git a/fs/nfs/callback.c b/fs/nfs/callback.c
> > index b8fb3a4ef649..ebba958e084c 100644
> > --- a/fs/nfs/callback.c
> > +++ b/fs/nfs/callback.c
> > @@ -128,13 +128,14 @@ nfs41_callback_svc(void *vrqstp)
> > if (try_to_freeze())
> > continue;
> >
> > - prepare_to_wait(&serv->sv_cb_waitq, &wq,
> > TASK_INTERRUPTIBLE);
> > + prepare_to_wait(&serv->sv_cb_waitq, &wq,
> > TASK_UNINTERRUPTIBLE); spin_lock_bh(&serv->sv_cb_lock);
> > if (!list_empty(&serv->sv_cb_list)) {
> > req = list_first_entry(&serv->sv_cb_list,
> > struct rpc_rqst,
> > rq_bc_list); list_del(&req->rq_bc_list);
> > spin_unlock_bh(&serv->sv_cb_lock);
> > + finish_wait(&serv->sv_cb_waitq, &wq);
> > dprintk("Invoking bc_svc_process()\n");
> > error = bc_svc_process(serv, req, rqstp);
> > dprintk("bc_svc_process() returned w/ error
> > code= %d\n", @@ -142,8 +143,8 @@ nfs41_callback_svc(void *vrqstp)
> > } else {
> > spin_unlock_bh(&serv->sv_cb_lock);
> > schedule();
> > + finish_wait(&serv->sv_cb_waitq, &wq);
> > }
> > - finish_wait(&serv->sv_cb_waitq, &wq);
> > }
> > return 0;
> > }
> > --
> > 2.1.0
> >
>
>
>
--
Jeff Layton <jlayton@primarydata.com>
^ permalink raw reply [flat|nested] 9+ messages in thread* Re: [PATCH] nfs: don't call blocking operations while !TASK_RUNNING
2015-01-14 17:27 ` Jeff Layton
@ 2015-01-14 18:06 ` Trond Myklebust
2015-01-14 18:32 ` Jeff Layton
0 siblings, 1 reply; 9+ messages in thread
From: Trond Myklebust @ 2015-01-14 18:06 UTC (permalink / raw)
To: Jeff Layton; +Cc: Bruce Fields, Linux NFS Mailing List
On Wed, Jan 14, 2015 at 12:27 PM, Jeff Layton
<jeff.layton@primarydata.com> wrote:
> On Wed, 14 Jan 2015 12:13:43 -0500
> Trond Myklebust <trond.myklebust@primarydata.com> wrote:
>
>> On Wed, Jan 14, 2015 at 10:32 AM, Jeff Layton <jlayton@primarydata.com> wrote:
>> > Bruce reported seeing this warning pop when mounting using v4.1:
>> >
>> > ------------[ cut here ]------------
>> > WARNING: CPU: 1 PID: 1121 at kernel/sched/core.c:7300 __might_sleep+0xbd/0xd0()
>> > do not call blocking ops when !TASK_RUNNING; state=1 set at [<ffffffff810ff58f>] prepare_to_wait+0x2f/0x90
>> > Modules linked in: rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver nfs lockd grace sunrpc fscache ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ebtable_nat ebtable_broute bridge stp llc ebtable_filter ebtables ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_security ip6table_raw ip6table_filter ip6_tables iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_mangle iptable_security iptable_raw snd_hda_codec_generic snd_hda_intel snd_hda_controller snd_hda_codec snd_hwdep snd_pcm snd_timer ppdev joydev snd virtio_console virtio_balloon pcspkr serio_raw parport_pc parport pvpanic floppy soundcore i2c_piix4 virtio_blk virtio_net qxl drm_kms_helper ttm drm virtio_pci virtio_ring ata_generic virtio pata_acpi
>> > CPU: 1 PID: 1121 Comm: nfsv4.1-svc Not tainted 3.19.0-rc4+ #25
>> > Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140709_153950- 04/01/2014
>> > 0000000000000000 000000004e5e3f73 ffff8800b998fb48 ffffffff8186ac78
>> > 0000000000000000 ffff8800b998fba0 ffff8800b998fb88 ffffffff810ac9da
>> > ffff8800b998fb68 ffffffff81c923e7 00000000000004d9 0000000000000000
>> > Call Trace:
>> > [<ffffffff8186ac78>] dump_stack+0x4c/0x65
>> > [<ffffffff810ac9da>] warn_slowpath_common+0x8a/0xc0
>> > [<ffffffff810aca65>] warn_slowpath_fmt+0x55/0x70
>> > [<ffffffff810ff58f>] ? prepare_to_wait+0x2f/0x90
>> > [<ffffffff810ff58f>] ? prepare_to_wait+0x2f/0x90
>> > [<ffffffff810dd2ad>] __might_sleep+0xbd/0xd0
>> > [<ffffffff8124c973>] kmem_cache_alloc_trace+0x243/0x430
>> > [<ffffffff810d941e>] ? groups_alloc+0x3e/0x130
>> > [<ffffffff810d941e>] groups_alloc+0x3e/0x130
>> > [<ffffffffa0301b1e>] svcauth_unix_accept+0x16e/0x290 [sunrpc]
>> > [<ffffffffa0300571>] svc_authenticate+0xe1/0xf0 [sunrpc]
>> > [<ffffffffa02fc564>] svc_process_common+0x244/0x6a0 [sunrpc]
>> > [<ffffffffa02fd044>] bc_svc_process+0x1c4/0x260 [sunrpc]
>> > [<ffffffffa03d5478>] nfs41_callback_svc+0x128/0x1f0 [nfsv4]
>> > [<ffffffff810ff970>] ? wait_woken+0xc0/0xc0
>> > [<ffffffffa03d5350>] ? nfs4_callback_svc+0x60/0x60 [nfsv4]
>> > [<ffffffff810d45bf>] kthread+0x11f/0x140
>> > [<ffffffff810ea815>] ? local_clock+0x15/0x30
>> > [<ffffffff810d44a0>] ? kthread_create_on_node+0x250/0x250
>> > [<ffffffff81874bfc>] ret_from_fork+0x7c/0xb0
>> > [<ffffffff810d44a0>] ? kthread_create_on_node+0x250/0x250
>> > ---[ end trace 675220a11e30f4f2 ]---
>> >
>> > nfs41_callback_svc does most of its work while in TASK_INTERRUPTIBLE,
>> > which is just wrong. Fix that by finishing the wait immediately if we've
>> > found that the list has something on it.
>>
>> ACK.
>>
>> > Also, we don't expect this kthread to accept signals, so we should be
>> > using a TASK_UNINTERRUPTIBLE sleep instead.
>>
>> Umm... Won't that end up triggering the hung task watchdog for every
>> 120seconds with no callback activity?
>>
>
> Doh! You're correct.
>
> What's the right way to do this then? Do we need to use
> schedule_timeout and wake up every 100s or so? Using TASK_INTERRUPTIBLE
> to work around the watchdog seems wrong but I guess we can live with
> that in the short term if it's the only way.
The alternative is to use TASK_KILLABLE. That's a little more
restrictive, but still a PITA. Note the both TASK_INTERRUPTIBLE and
TASK_KILLABLE will need something to handle that signalled() case,
otherwise we end up with a permanent busy-waiting loop.
--
Trond Myklebust
Linux NFS client maintainer, PrimaryData
trond.myklebust@primarydata.com
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: [PATCH] nfs: don't call blocking operations while !TASK_RUNNING
2015-01-14 18:06 ` Trond Myklebust
@ 2015-01-14 18:32 ` Jeff Layton
2015-03-20 0:59 ` Chuck Lever
0 siblings, 1 reply; 9+ messages in thread
From: Jeff Layton @ 2015-01-14 18:32 UTC (permalink / raw)
To: Trond Myklebust; +Cc: Jeff Layton, Bruce Fields, Linux NFS Mailing List
On Wed, 14 Jan 2015 13:06:17 -0500
Trond Myklebust <trond.myklebust@primarydata.com> wrote:
> On Wed, Jan 14, 2015 at 12:27 PM, Jeff Layton
> <jeff.layton@primarydata.com> wrote:
> > On Wed, 14 Jan 2015 12:13:43 -0500
> > Trond Myklebust <trond.myklebust@primarydata.com> wrote:
> >
> >> On Wed, Jan 14, 2015 at 10:32 AM, Jeff Layton <jlayton@primarydata.com> wrote:
> >> > Bruce reported seeing this warning pop when mounting using v4.1:
> >> >
> >> > ------------[ cut here ]------------
> >> > WARNING: CPU: 1 PID: 1121 at kernel/sched/core.c:7300 __might_sleep+0xbd/0xd0()
> >> > do not call blocking ops when !TASK_RUNNING; state=1 set at [<ffffffff810ff58f>] prepare_to_wait+0x2f/0x90
> >> > Modules linked in: rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver nfs lockd grace sunrpc fscache ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ebtable_nat ebtable_broute bridge stp llc ebtable_filter ebtables ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_security ip6table_raw ip6table_filter ip6_tables iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_mangle iptable_security iptable_raw snd_hda_codec_generic snd_hda_intel snd_hda_controller snd_hda_codec snd_hwdep snd_pcm snd_timer ppdev joydev snd virtio_console virtio_balloon pcspkr serio_raw parport_pc parport pvpanic floppy soundcore i2c_piix4 virtio_blk virtio_net qxl drm_kms_helper ttm drm virtio_pci virtio_ring ata_generic virtio pata_acpi
> >> > CPU: 1 PID: 1121 Comm: nfsv4.1-svc Not tainted 3.19.0-rc4+ #25
> >> > Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140709_153950- 04/01/2014
> >> > 0000000000000000 000000004e5e3f73 ffff8800b998fb48 ffffffff8186ac78
> >> > 0000000000000000 ffff8800b998fba0 ffff8800b998fb88 ffffffff810ac9da
> >> > ffff8800b998fb68 ffffffff81c923e7 00000000000004d9 0000000000000000
> >> > Call Trace:
> >> > [<ffffffff8186ac78>] dump_stack+0x4c/0x65
> >> > [<ffffffff810ac9da>] warn_slowpath_common+0x8a/0xc0
> >> > [<ffffffff810aca65>] warn_slowpath_fmt+0x55/0x70
> >> > [<ffffffff810ff58f>] ? prepare_to_wait+0x2f/0x90
> >> > [<ffffffff810ff58f>] ? prepare_to_wait+0x2f/0x90
> >> > [<ffffffff810dd2ad>] __might_sleep+0xbd/0xd0
> >> > [<ffffffff8124c973>] kmem_cache_alloc_trace+0x243/0x430
> >> > [<ffffffff810d941e>] ? groups_alloc+0x3e/0x130
> >> > [<ffffffff810d941e>] groups_alloc+0x3e/0x130
> >> > [<ffffffffa0301b1e>] svcauth_unix_accept+0x16e/0x290 [sunrpc]
> >> > [<ffffffffa0300571>] svc_authenticate+0xe1/0xf0 [sunrpc]
> >> > [<ffffffffa02fc564>] svc_process_common+0x244/0x6a0 [sunrpc]
> >> > [<ffffffffa02fd044>] bc_svc_process+0x1c4/0x260 [sunrpc]
> >> > [<ffffffffa03d5478>] nfs41_callback_svc+0x128/0x1f0 [nfsv4]
> >> > [<ffffffff810ff970>] ? wait_woken+0xc0/0xc0
> >> > [<ffffffffa03d5350>] ? nfs4_callback_svc+0x60/0x60 [nfsv4]
> >> > [<ffffffff810d45bf>] kthread+0x11f/0x140
> >> > [<ffffffff810ea815>] ? local_clock+0x15/0x30
> >> > [<ffffffff810d44a0>] ? kthread_create_on_node+0x250/0x250
> >> > [<ffffffff81874bfc>] ret_from_fork+0x7c/0xb0
> >> > [<ffffffff810d44a0>] ? kthread_create_on_node+0x250/0x250
> >> > ---[ end trace 675220a11e30f4f2 ]---
> >> >
> >> > nfs41_callback_svc does most of its work while in TASK_INTERRUPTIBLE,
> >> > which is just wrong. Fix that by finishing the wait immediately if we've
> >> > found that the list has something on it.
> >>
> >> ACK.
> >>
> >> > Also, we don't expect this kthread to accept signals, so we should be
> >> > using a TASK_UNINTERRUPTIBLE sleep instead.
> >>
> >> Umm... Won't that end up triggering the hung task watchdog for every
> >> 120seconds with no callback activity?
> >>
> >
> > Doh! You're correct.
> >
> > What's the right way to do this then? Do we need to use
> > schedule_timeout and wake up every 100s or so? Using TASK_INTERRUPTIBLE
> > to work around the watchdog seems wrong but I guess we can live with
> > that in the short term if it's the only way.
>
> The alternative is to use TASK_KILLABLE. That's a little more
> restrictive, but still a PITA. Note the both TASK_INTERRUPTIBLE and
> TASK_KILLABLE will need something to handle that signalled() case,
> otherwise we end up with a permanent busy-waiting loop.
>
Heh, our emails appear to have crossed. I went with a schedule_timeout
for v2 so we can sidestep the whole issue of signals.
It's simple enough to add a flush_signals() call at the end of the
loop, but I'm a little leery of what effects we might see if the thread
catches a signal while in the middle of doing real work.
If you really think that's the better approach, I can do a v3 patch
that does that however.
--
Jeff Layton <jlayton@primarydata.com>
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: [PATCH] nfs: don't call blocking operations while !TASK_RUNNING
2015-01-14 18:32 ` Jeff Layton
@ 2015-03-20 0:59 ` Chuck Lever
2015-03-20 1:24 ` Jeff Layton
0 siblings, 1 reply; 9+ messages in thread
From: Chuck Lever @ 2015-03-20 0:59 UTC (permalink / raw)
To: Jeff Layton; +Cc: Trond Myklebust, J. Bruce Fields, Linux NFS Mailing List
On Jan 14, 2015, at 10:32 AM, Jeff Layton <jeff.layton@primarydata.com> wrote:
> On Wed, 14 Jan 2015 13:06:17 -0500
> Trond Myklebust <trond.myklebust@primarydata.com> wrote:
>
>> On Wed, Jan 14, 2015 at 12:27 PM, Jeff Layton
>> <jeff.layton@primarydata.com> wrote:
>>> On Wed, 14 Jan 2015 12:13:43 -0500
>>> Trond Myklebust <trond.myklebust@primarydata.com> wrote:
>>>
>>>> On Wed, Jan 14, 2015 at 10:32 AM, Jeff Layton <jlayton@primarydata.com> wrote:
>>>>> Bruce reported seeing this warning pop when mounting using v4.1:
>>>>>
>>>>> ------------[ cut here ]------------
>>>>> WARNING: CPU: 1 PID: 1121 at kernel/sched/core.c:7300 __might_sleep+0xbd/0xd0()
>>>>> do not call blocking ops when !TASK_RUNNING; state=1 set at [<ffffffff810ff58f>] prepare_to_wait+0x2f/0x90
>>>>> Modules linked in: rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver nfs lockd grace sunrpc fscache ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ebtable_nat ebtable_broute bridge stp llc ebtable_filter ebtables ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_security ip6table_raw ip6table_filter ip6_tables iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_mangle iptable_security iptable_raw snd_hda_codec_generic snd_hda_intel snd_hda_controller snd_hda_codec snd_hwdep snd_pcm snd_timer ppdev joydev snd virtio_console virtio_balloon pcspkr serio_raw parport_pc parport pvpanic floppy soundcore i2c_piix4 virtio_blk virtio_net qxl drm_kms_helper ttm drm virtio_pci virtio_ring ata_generic virtio pata_acpi
>>>>> CPU: 1 PID: 1121 Comm: nfsv4.1-svc Not tainted 3.19.0-rc4+ #25
>>>>> Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140709_153950- 04/01/2014
>>>>> 0000000000000000 000000004e5e3f73 ffff8800b998fb48 ffffffff8186ac78
>>>>> 0000000000000000 ffff8800b998fba0 ffff8800b998fb88 ffffffff810ac9da
>>>>> ffff8800b998fb68 ffffffff81c923e7 00000000000004d9 0000000000000000
>>>>> Call Trace:
>>>>> [<ffffffff8186ac78>] dump_stack+0x4c/0x65
>>>>> [<ffffffff810ac9da>] warn_slowpath_common+0x8a/0xc0
>>>>> [<ffffffff810aca65>] warn_slowpath_fmt+0x55/0x70
>>>>> [<ffffffff810ff58f>] ? prepare_to_wait+0x2f/0x90
>>>>> [<ffffffff810ff58f>] ? prepare_to_wait+0x2f/0x90
>>>>> [<ffffffff810dd2ad>] __might_sleep+0xbd/0xd0
>>>>> [<ffffffff8124c973>] kmem_cache_alloc_trace+0x243/0x430
>>>>> [<ffffffff810d941e>] ? groups_alloc+0x3e/0x130
>>>>> [<ffffffff810d941e>] groups_alloc+0x3e/0x130
>>>>> [<ffffffffa0301b1e>] svcauth_unix_accept+0x16e/0x290 [sunrpc]
>>>>> [<ffffffffa0300571>] svc_authenticate+0xe1/0xf0 [sunrpc]
>>>>> [<ffffffffa02fc564>] svc_process_common+0x244/0x6a0 [sunrpc]
>>>>> [<ffffffffa02fd044>] bc_svc_process+0x1c4/0x260 [sunrpc]
>>>>> [<ffffffffa03d5478>] nfs41_callback_svc+0x128/0x1f0 [nfsv4]
>>>>> [<ffffffff810ff970>] ? wait_woken+0xc0/0xc0
>>>>> [<ffffffffa03d5350>] ? nfs4_callback_svc+0x60/0x60 [nfsv4]
>>>>> [<ffffffff810d45bf>] kthread+0x11f/0x140
>>>>> [<ffffffff810ea815>] ? local_clock+0x15/0x30
>>>>> [<ffffffff810d44a0>] ? kthread_create_on_node+0x250/0x250
>>>>> [<ffffffff81874bfc>] ret_from_fork+0x7c/0xb0
>>>>> [<ffffffff810d44a0>] ? kthread_create_on_node+0x250/0x250
>>>>> ---[ end trace 675220a11e30f4f2 ]---
>>>>>
>>>>> nfs41_callback_svc does most of its work while in TASK_INTERRUPTIBLE,
>>>>> which is just wrong. Fix that by finishing the wait immediately if we've
>>>>> found that the list has something on it.
>>>>
>>>> ACK.
>>>>
>>>>> Also, we don't expect this kthread to accept signals, so we should be
>>>>> using a TASK_UNINTERRUPTIBLE sleep instead.
>>>>
>>>> Umm... Won't that end up triggering the hung task watchdog for every
>>>> 120seconds with no callback activity?
>>>>
>>>
>>> Doh! You're correct.
>>>
>>> What's the right way to do this then? Do we need to use
>>> schedule_timeout and wake up every 100s or so? Using TASK_INTERRUPTIBLE
>>> to work around the watchdog seems wrong but I guess we can live with
>>> that in the short term if it's the only way.
>>
>> The alternative is to use TASK_KILLABLE. That's a little more
>> restrictive, but still a PITA. Note the both TASK_INTERRUPTIBLE and
>> TASK_KILLABLE will need something to handle that signalled() case,
>> otherwise we end up with a permanent busy-waiting loop.
>>
>
> Heh, our emails appear to have crossed. I went with a schedule_timeout
> for v2 so we can sidestep the whole issue of signals.
>
> It's simple enough to add a flush_signals() call at the end of the
> loop, but I'm a little leery of what effects we might see if the thread
> catches a signal while in the middle of doing real work.
>
> If you really think that's the better approach, I can do a v3 patch
> that does that however.
After applying this patch to a 3.19.0 test system, the WARNINGS are
gone, but the system load average is pinned at 1.00.
root 12105 0.1 0.0 0 0 ? D Mar18 1:19 [nfsv4.1-svc]
--
Chuck Lever
chuck[dot]lever[at]oracle[dot]com
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: [PATCH] nfs: don't call blocking operations while !TASK_RUNNING
2015-03-20 0:59 ` Chuck Lever
@ 2015-03-20 1:24 ` Jeff Layton
0 siblings, 0 replies; 9+ messages in thread
From: Jeff Layton @ 2015-03-20 1:24 UTC (permalink / raw)
To: Chuck Lever; +Cc: Trond Myklebust, J. Bruce Fields, Linux NFS Mailing List
On Thu, 19 Mar 2015 17:59:15 -0700
Chuck Lever <chuck.lever@oracle.com> wrote:
>
> On Jan 14, 2015, at 10:32 AM, Jeff Layton <jeff.layton@primarydata.com> wrote:
>
> > On Wed, 14 Jan 2015 13:06:17 -0500
> > Trond Myklebust <trond.myklebust@primarydata.com> wrote:
> >
> >> On Wed, Jan 14, 2015 at 12:27 PM, Jeff Layton
> >> <jeff.layton@primarydata.com> wrote:
> >>> On Wed, 14 Jan 2015 12:13:43 -0500
> >>> Trond Myklebust <trond.myklebust@primarydata.com> wrote:
> >>>
> >>>> On Wed, Jan 14, 2015 at 10:32 AM, Jeff Layton <jlayton@primarydata.com> wrote:
> >>>>> Bruce reported seeing this warning pop when mounting using v4.1:
> >>>>>
> >>>>> ------------[ cut here ]------------
> >>>>> WARNING: CPU: 1 PID: 1121 at kernel/sched/core.c:7300 __might_sleep+0xbd/0xd0()
> >>>>> do not call blocking ops when !TASK_RUNNING; state=1 set at [<ffffffff810ff58f>] prepare_to_wait+0x2f/0x90
> >>>>> Modules linked in: rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver nfs lockd grace sunrpc fscache ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ebtable_nat ebtable_broute bridge stp llc ebtable_filter ebtables ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_security ip6table_raw ip6table_filter ip6_tables iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_mangle iptable_security iptable_raw snd_hda_codec_generic snd_hda_intel snd_hda_controller snd_hda_codec snd_hwdep snd_pcm snd_timer ppdev joydev snd virtio_console virtio_balloon pcspkr serio_raw parport_pc parport pvpanic floppy soundcore i2c_piix4 virtio_blk virtio_net qxl drm_kms_helper ttm drm virtio_pci virtio_ring ata_generic virtio pata_acpi
> >>>>> CPU: 1 PID: 1121 Comm: nfsv4.1-svc Not tainted 3.19.0-rc4+ #25
> >>>>> Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140709_153950- 04/01/2014
> >>>>> 0000000000000000 000000004e5e3f73 ffff8800b998fb48 ffffffff8186ac78
> >>>>> 0000000000000000 ffff8800b998fba0 ffff8800b998fb88 ffffffff810ac9da
> >>>>> ffff8800b998fb68 ffffffff81c923e7 00000000000004d9 0000000000000000
> >>>>> Call Trace:
> >>>>> [<ffffffff8186ac78>] dump_stack+0x4c/0x65
> >>>>> [<ffffffff810ac9da>] warn_slowpath_common+0x8a/0xc0
> >>>>> [<ffffffff810aca65>] warn_slowpath_fmt+0x55/0x70
> >>>>> [<ffffffff810ff58f>] ? prepare_to_wait+0x2f/0x90
> >>>>> [<ffffffff810ff58f>] ? prepare_to_wait+0x2f/0x90
> >>>>> [<ffffffff810dd2ad>] __might_sleep+0xbd/0xd0
> >>>>> [<ffffffff8124c973>] kmem_cache_alloc_trace+0x243/0x430
> >>>>> [<ffffffff810d941e>] ? groups_alloc+0x3e/0x130
> >>>>> [<ffffffff810d941e>] groups_alloc+0x3e/0x130
> >>>>> [<ffffffffa0301b1e>] svcauth_unix_accept+0x16e/0x290 [sunrpc]
> >>>>> [<ffffffffa0300571>] svc_authenticate+0xe1/0xf0 [sunrpc]
> >>>>> [<ffffffffa02fc564>] svc_process_common+0x244/0x6a0 [sunrpc]
> >>>>> [<ffffffffa02fd044>] bc_svc_process+0x1c4/0x260 [sunrpc]
> >>>>> [<ffffffffa03d5478>] nfs41_callback_svc+0x128/0x1f0 [nfsv4]
> >>>>> [<ffffffff810ff970>] ? wait_woken+0xc0/0xc0
> >>>>> [<ffffffffa03d5350>] ? nfs4_callback_svc+0x60/0x60 [nfsv4]
> >>>>> [<ffffffff810d45bf>] kthread+0x11f/0x140
> >>>>> [<ffffffff810ea815>] ? local_clock+0x15/0x30
> >>>>> [<ffffffff810d44a0>] ? kthread_create_on_node+0x250/0x250
> >>>>> [<ffffffff81874bfc>] ret_from_fork+0x7c/0xb0
> >>>>> [<ffffffff810d44a0>] ? kthread_create_on_node+0x250/0x250
> >>>>> ---[ end trace 675220a11e30f4f2 ]---
> >>>>>
> >>>>> nfs41_callback_svc does most of its work while in TASK_INTERRUPTIBLE,
> >>>>> which is just wrong. Fix that by finishing the wait immediately if we've
> >>>>> found that the list has something on it.
> >>>>
> >>>> ACK.
> >>>>
> >>>>> Also, we don't expect this kthread to accept signals, so we should be
> >>>>> using a TASK_UNINTERRUPTIBLE sleep instead.
> >>>>
> >>>> Umm... Won't that end up triggering the hung task watchdog for every
> >>>> 120seconds with no callback activity?
> >>>>
> >>>
> >>> Doh! You're correct.
> >>>
> >>> What's the right way to do this then? Do we need to use
> >>> schedule_timeout and wake up every 100s or so? Using TASK_INTERRUPTIBLE
> >>> to work around the watchdog seems wrong but I guess we can live with
> >>> that in the short term if it's the only way.
> >>
> >> The alternative is to use TASK_KILLABLE. That's a little more
> >> restrictive, but still a PITA. Note the both TASK_INTERRUPTIBLE and
> >> TASK_KILLABLE will need something to handle that signalled() case,
> >> otherwise we end up with a permanent busy-waiting loop.
> >>
> >
> > Heh, our emails appear to have crossed. I went with a schedule_timeout
> > for v2 so we can sidestep the whole issue of signals.
> >
> > It's simple enough to add a flush_signals() call at the end of the
> > loop, but I'm a little leery of what effects we might see if the thread
> > catches a signal while in the middle of doing real work.
> >
> > If you really think that's the better approach, I can do a v3 patch
> > that does that however.
>
> After applying this patch to a 3.19.0 test system, the WARNINGS are
> gone, but the system load average is pinned at 1.00.
>
> root 12105 0.1 0.0 0 0 ? D Mar18 1:19 [nfsv4.1-svc]
>
Darn, good point...
I forgot about the stupid load avg on Linux counting D state tasks
toward the load avg (why, oh why...).
I guess we will have to use a different task state after all --
probably TASK_KILLABLE and just try to ignore fatal signals as best
we can. I'll plan to do that when I get a minute. Suggestions of better
ways to do this would be appreciated though.
Cheers,
--
Jeff Layton <jlayton@primarydata.com>
^ permalink raw reply [flat|nested] 9+ messages in thread
* [PATCH v2] nfs: don't call blocking operations while !TASK_RUNNING
2015-01-14 15:32 [PATCH] nfs: don't call blocking operations while !TASK_RUNNING Jeff Layton
2015-01-14 17:13 ` Trond Myklebust
@ 2015-01-14 18:08 ` Jeff Layton
2015-01-14 19:05 ` J. Bruce Fields
1 sibling, 1 reply; 9+ messages in thread
From: Jeff Layton @ 2015-01-14 18:08 UTC (permalink / raw)
To: trond.myklebust; +Cc: bfields, linux-nfs
Bruce reported seeing this warning pop when mounting using v4.1:
------------[ cut here ]------------
WARNING: CPU: 1 PID: 1121 at kernel/sched/core.c:7300 __might_sleep+0xbd/0xd0()
do not call blocking ops when !TASK_RUNNING; state=1 set at [<ffffffff810ff58f>] prepare_to_wait+0x2f/0x90
Modules linked in: rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver nfs lockd grace sunrpc fscache ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ebtable_nat ebtable_broute bridge stp llc ebtable_filter ebtables ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_security ip6table_raw ip6table_filter ip6_tables iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_mangle iptable_security iptable_raw snd_hda_codec_generic snd_hda_intel snd_hda_controller snd_hda_codec snd_hwdep snd_pcm snd_timer ppdev joydev snd virtio_console virtio_balloon pcspkr serio_raw parport_pc parport pvpanic floppy soundcore i2c_piix4 virtio_blk virtio_net qxl drm_kms_helper ttm drm virtio_pci virtio_ring ata_generic virtio pata_acpi
CPU: 1 PID: 1121 Comm: nfsv4.1-svc Not tainted 3.19.0-rc4+ #25
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140709_153950- 04/01/2014
0000000000000000 000000004e5e3f73 ffff8800b998fb48 ffffffff8186ac78
0000000000000000 ffff8800b998fba0 ffff8800b998fb88 ffffffff810ac9da
ffff8800b998fb68 ffffffff81c923e7 00000000000004d9 0000000000000000
Call Trace:
[<ffffffff8186ac78>] dump_stack+0x4c/0x65
[<ffffffff810ac9da>] warn_slowpath_common+0x8a/0xc0
[<ffffffff810aca65>] warn_slowpath_fmt+0x55/0x70
[<ffffffff810ff58f>] ? prepare_to_wait+0x2f/0x90
[<ffffffff810ff58f>] ? prepare_to_wait+0x2f/0x90
[<ffffffff810dd2ad>] __might_sleep+0xbd/0xd0
[<ffffffff8124c973>] kmem_cache_alloc_trace+0x243/0x430
[<ffffffff810d941e>] ? groups_alloc+0x3e/0x130
[<ffffffff810d941e>] groups_alloc+0x3e/0x130
[<ffffffffa0301b1e>] svcauth_unix_accept+0x16e/0x290 [sunrpc]
[<ffffffffa0300571>] svc_authenticate+0xe1/0xf0 [sunrpc]
[<ffffffffa02fc564>] svc_process_common+0x244/0x6a0 [sunrpc]
[<ffffffffa02fd044>] bc_svc_process+0x1c4/0x260 [sunrpc]
[<ffffffffa03d5478>] nfs41_callback_svc+0x128/0x1f0 [nfsv4]
[<ffffffff810ff970>] ? wait_woken+0xc0/0xc0
[<ffffffffa03d5350>] ? nfs4_callback_svc+0x60/0x60 [nfsv4]
[<ffffffff810d45bf>] kthread+0x11f/0x140
[<ffffffff810ea815>] ? local_clock+0x15/0x30
[<ffffffff810d44a0>] ? kthread_create_on_node+0x250/0x250
[<ffffffff81874bfc>] ret_from_fork+0x7c/0xb0
[<ffffffff810d44a0>] ? kthread_create_on_node+0x250/0x250
---[ end trace 675220a11e30f4f2 ]---
nfs41_callback_svc does most of its work while in TASK_INTERRUPTIBLE,
which is just wrong. Fix that by finishing the wait immediately if we've
found that the list has something on it.
Also, we don't expect this kthread to accept signals, so we should be
using a TASK_UNINTERRUPTIBLE sleep instead. That however, opens us up
hung task warnings from the watchdog, so have the schedule_timeout
wake up every 60s if there's no callback activity.
Reported-by: "J. Bruce Fields" <bfields@fieldses.org>
Signed-off-by: Jeff Layton <jlayton@primarydata.com>
---
fs/nfs/callback.c | 8 +++++---
1 file changed, 5 insertions(+), 3 deletions(-)
diff --git a/fs/nfs/callback.c b/fs/nfs/callback.c
index b8fb3a4ef649..351be9205bf8 100644
--- a/fs/nfs/callback.c
+++ b/fs/nfs/callback.c
@@ -128,22 +128,24 @@ nfs41_callback_svc(void *vrqstp)
if (try_to_freeze())
continue;
- prepare_to_wait(&serv->sv_cb_waitq, &wq, TASK_INTERRUPTIBLE);
+ prepare_to_wait(&serv->sv_cb_waitq, &wq, TASK_UNINTERRUPTIBLE);
spin_lock_bh(&serv->sv_cb_lock);
if (!list_empty(&serv->sv_cb_list)) {
req = list_first_entry(&serv->sv_cb_list,
struct rpc_rqst, rq_bc_list);
list_del(&req->rq_bc_list);
spin_unlock_bh(&serv->sv_cb_lock);
+ finish_wait(&serv->sv_cb_waitq, &wq);
dprintk("Invoking bc_svc_process()\n");
error = bc_svc_process(serv, req, rqstp);
dprintk("bc_svc_process() returned w/ error code= %d\n",
error);
} else {
spin_unlock_bh(&serv->sv_cb_lock);
- schedule();
+ /* schedule_timeout to game the hung task watchdog */
+ schedule_timeout(60 * HZ);
+ finish_wait(&serv->sv_cb_waitq, &wq);
}
- finish_wait(&serv->sv_cb_waitq, &wq);
}
return 0;
}
--
2.1.0
^ permalink raw reply related [flat|nested] 9+ messages in thread* Re: [PATCH v2] nfs: don't call blocking operations while !TASK_RUNNING
2015-01-14 18:08 ` [PATCH v2] " Jeff Layton
@ 2015-01-14 19:05 ` J. Bruce Fields
0 siblings, 0 replies; 9+ messages in thread
From: J. Bruce Fields @ 2015-01-14 19:05 UTC (permalink / raw)
To: Jeff Layton; +Cc: trond.myklebust, linux-nfs
On Wed, Jan 14, 2015 at 01:08:57PM -0500, Jeff Layton wrote:
> Bruce reported seeing this warning pop when mounting using v4.1:
>
> ------------[ cut here ]------------
> WARNING: CPU: 1 PID: 1121 at kernel/sched/core.c:7300 __might_sleep+0xbd/0xd0()
> do not call blocking ops when !TASK_RUNNING; state=1 set at [<ffffffff810ff58f>] prepare_to_wait+0x2f/0x90
> Modules linked in: rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver nfs lockd grace sunrpc fscache ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ebtable_nat ebtable_broute bridge stp llc ebtable_filter ebtables ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_security ip6table_raw ip6table_filter ip6_tables iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_mangle iptable_security iptable_raw snd_hda_codec_generic snd_hda_intel snd_hda_controller snd_hda_codec snd_hwdep snd_pcm snd_timer ppdev joydev snd virtio_console virtio_balloon pcspkr serio_raw parport_pc parport pvpanic floppy soundcore i2c_piix4 virtio_blk virtio_net qxl drm_kms_helper ttm drm virtio_pci virtio_ring ata_generic virtio pata_acpi
> CPU: 1 PID: 1121 Comm: nfsv4.1-svc Not tainted 3.19.0-rc4+ #25
> Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140709_153950- 04/01/2014
> 0000000000000000 000000004e5e3f73 ffff8800b998fb48 ffffffff8186ac78
> 0000000000000000 ffff8800b998fba0 ffff8800b998fb88 ffffffff810ac9da
> ffff8800b998fb68 ffffffff81c923e7 00000000000004d9 0000000000000000
> Call Trace:
> [<ffffffff8186ac78>] dump_stack+0x4c/0x65
> [<ffffffff810ac9da>] warn_slowpath_common+0x8a/0xc0
> [<ffffffff810aca65>] warn_slowpath_fmt+0x55/0x70
> [<ffffffff810ff58f>] ? prepare_to_wait+0x2f/0x90
> [<ffffffff810ff58f>] ? prepare_to_wait+0x2f/0x90
> [<ffffffff810dd2ad>] __might_sleep+0xbd/0xd0
> [<ffffffff8124c973>] kmem_cache_alloc_trace+0x243/0x430
> [<ffffffff810d941e>] ? groups_alloc+0x3e/0x130
> [<ffffffff810d941e>] groups_alloc+0x3e/0x130
> [<ffffffffa0301b1e>] svcauth_unix_accept+0x16e/0x290 [sunrpc]
> [<ffffffffa0300571>] svc_authenticate+0xe1/0xf0 [sunrpc]
> [<ffffffffa02fc564>] svc_process_common+0x244/0x6a0 [sunrpc]
> [<ffffffffa02fd044>] bc_svc_process+0x1c4/0x260 [sunrpc]
> [<ffffffffa03d5478>] nfs41_callback_svc+0x128/0x1f0 [nfsv4]
> [<ffffffff810ff970>] ? wait_woken+0xc0/0xc0
> [<ffffffffa03d5350>] ? nfs4_callback_svc+0x60/0x60 [nfsv4]
> [<ffffffff810d45bf>] kthread+0x11f/0x140
> [<ffffffff810ea815>] ? local_clock+0x15/0x30
> [<ffffffff810d44a0>] ? kthread_create_on_node+0x250/0x250
> [<ffffffff81874bfc>] ret_from_fork+0x7c/0xb0
> [<ffffffff810d44a0>] ? kthread_create_on_node+0x250/0x250
> ---[ end trace 675220a11e30f4f2 ]---
>
> nfs41_callback_svc does most of its work while in TASK_INTERRUPTIBLE,
> which is just wrong. Fix that by finishing the wait immediately if we've
> found that the list has something on it.
>
> Also, we don't expect this kthread to accept signals, so we should be
> using a TASK_UNINTERRUPTIBLE sleep instead. That however, opens us up
> hung task warnings from the watchdog, so have the schedule_timeout
> wake up every 60s if there's no callback activity.
Works for me, for what it's worth.
>
> Reported-by: "J. Bruce Fields" <bfields@fieldses.org>
> Signed-off-by: Jeff Layton <jlayton@primarydata.com>
> ---
> fs/nfs/callback.c | 8 +++++---
> 1 file changed, 5 insertions(+), 3 deletions(-)
>
> diff --git a/fs/nfs/callback.c b/fs/nfs/callback.c
> index b8fb3a4ef649..351be9205bf8 100644
> --- a/fs/nfs/callback.c
> +++ b/fs/nfs/callback.c
> @@ -128,22 +128,24 @@ nfs41_callback_svc(void *vrqstp)
> if (try_to_freeze())
> continue;
>
> - prepare_to_wait(&serv->sv_cb_waitq, &wq, TASK_INTERRUPTIBLE);
> + prepare_to_wait(&serv->sv_cb_waitq, &wq, TASK_UNINTERRUPTIBLE);
> spin_lock_bh(&serv->sv_cb_lock);
> if (!list_empty(&serv->sv_cb_list)) {
> req = list_first_entry(&serv->sv_cb_list,
> struct rpc_rqst, rq_bc_list);
> list_del(&req->rq_bc_list);
> spin_unlock_bh(&serv->sv_cb_lock);
> + finish_wait(&serv->sv_cb_waitq, &wq);
> dprintk("Invoking bc_svc_process()\n");
> error = bc_svc_process(serv, req, rqstp);
> dprintk("bc_svc_process() returned w/ error code= %d\n",
> error);
> } else {
> spin_unlock_bh(&serv->sv_cb_lock);
> - schedule();
> + /* schedule_timeout to game the hung task watchdog */
> + schedule_timeout(60 * HZ);
> + finish_wait(&serv->sv_cb_waitq, &wq);
> }
> - finish_wait(&serv->sv_cb_waitq, &wq);
> }
> return 0;
> }
> --
> 2.1.0
>
^ permalink raw reply [flat|nested] 9+ messages in thread
end of thread, other threads:[~2015-03-20 1:24 UTC | newest]
Thread overview: 9+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2015-01-14 15:32 [PATCH] nfs: don't call blocking operations while !TASK_RUNNING Jeff Layton
2015-01-14 17:13 ` Trond Myklebust
2015-01-14 17:27 ` Jeff Layton
2015-01-14 18:06 ` Trond Myklebust
2015-01-14 18:32 ` Jeff Layton
2015-03-20 0:59 ` Chuck Lever
2015-03-20 1:24 ` Jeff Layton
2015-01-14 18:08 ` [PATCH v2] " Jeff Layton
2015-01-14 19:05 ` J. Bruce Fields
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox