[RFC PATCH] dcache: give a chance to yield in shrink_dentry_list

[RFC PATCH] dcache: give a chance to yield in shrink_dentry_list

[Nikolay Borisov]

A softlockup in shrink_dentry_list when called from shrink_dcache_sb
was observed on a very busy server. It's possible that the list
passed to shrink_dentry_list is so big that it takes a while to
dispose of all entries. Adding a simple cond_resched would give
the cpu a chance to do some other useful work and no trip the
softlockup watchdog.

Signed-off-by: Nikolay Borisov <kernel@kyup.com>
---

Here is what the splat looked like. Even though this was observed
on a 3.12 kernel I don't see why it can't happen on recent 
kernels as well. 

[1294411.570734] BUG: soft lockup - CPU#3 stuck for 22s! [mount:33726]
[1294411.571005] Modules linked in: xt_comment ipip tunnel4 ip6_tunnel tunnel6 tcp_diag inet_diag xt_time act_police 
cls_basic sch_ingress hijack(O) netconsole xt_multiport xt_pkttype ip6t_REJECT nf_conntrack_ipv6 nf_defrag_ipv6 xt_state veth 
openvswitch gre vxlan ip_tunnel xt_owner xt_conntrack iptable_mangle xt_nat iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 
nf_nat_ipv4 nf_nat xt_CT nf_conntrack iptable_raw ip6table_filter ip6_tables ipv6 ext2 dm_thin_pool dm_bio_prison
dm_persistent_data dm_bufio dm_mirror dm_region_hash dm_log ib_ipoib ib_cm ib_sa ib_mad ib_core ixgbe i2c_i801 lpc_ich 
mfd_core ioapic ioatdma igb dca i2c_algo_bit [last unloaded: ipmi_msghandler]

[1294411.571047] CPU: 3 PID: 33726 Comm: mount Tainted: G           O 3.12.52-clouder2 #1
[1294411.571048] Hardware name: Supermicro X9DRD-7LN4F(-JBOD)/X9DRD-EF/X9DRD-7LN4F, BIOS 3.0a 12/05/2013
[1294411.571050] task: ffff8833c55f9830 ti: ffff883fcfcf6000 task.ti: ffff883fcfcf6000
[1294411.571051] RIP: 0010:[<ffffffff811c2bc0>]  [<ffffffff811c2bc0>] __d_drop+0x60/0xf0
[1294411.571056] RSP: 0018:ffff883fcfcf7d38  EFLAGS: 00000206
[1294411.571057] RAX: ffffc9000b101770 RBX: ffff881fff8cc6a0 RCX: 0000000000000007
[1294411.571058] RDX: ffff883fcfcf6000 RSI: 0000000000000000 RDI: ffff8805bd5063c0
[1294411.571058] RBP: ffff883fcfcf7d38 R08: 0000000000000073 R09: 0000000000000000
[1294411.571059] R10: 7fffffffffffffff R11: 0000000000000000 R12: ffff8805bd506530
[1294411.571060] R13: ffff883fcfcf7cc8 R14: 0000000000000000 R15: ffff881fff8cc6a0
[1294411.571061] FS:  00007f0321cca7e0(0000) GS:ffff881fff8c0000(0000) knlGS:0000000000000000
[1294411.571062] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[1294411.571063] CR2: 00007f0320d7e0c0 CR3: 0000001e050f6000 CR4: 00000000001407e0
[1294411.571063] Stack:
[1294411.571064]  ffff883fcfcf7d68 ffffffff811c3372 0000000000000202 ffff8805bd5063c0
[1294411.571068]  ffff8805bd506440 ffff881fd0c9ec00 ffff883fcfcf7dd8 ffffffff811c36e6
[1294411.571070]  0000000000000001 ffff883fcfcf7df8 ffff883fcfcf6000 ffff883fcfcf6000
[1294411.571073] Call Trace:
[1294411.571078]  [<ffffffff811c3372>] __dentry_kill+0x62/0x210
[1294411.571080]  [<ffffffff811c36e6>] shrink_dentry_list+0x1c6/0x390
[1294411.571082]  [<ffffffff811c3bcb>] shrink_dcache_sb+0xcb/0x110
[1294411.571086]  [<ffffffff811ad42a>] do_remount_sb+0x4a/0x190
[1294411.571089]  [<ffffffff811ce200>] do_mount+0xaf0/0xd20
[1294411.571091]  [<ffffffff811ce4c7>] SyS_mount+0x97/0xf0
[1294411.571095]  [<ffffffff8164c4b2>] system_call_fastpath+0x16/0x1b


 fs/dcache.c | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/fs/dcache.c b/fs/dcache.c
index 2398f9f94337..0db355a50bc5 100644
--- a/fs/dcache.c
+++ b/fs/dcache.c
@@ -934,6 +934,9 @@ static void shrink_dentry_list(struct list_head *list)
 
 	while (!list_empty(list)) {
 		struct inode *inode;
+
+		cond_resched();
+
 		dentry = list_entry(list->prev, struct dentry, d_lru);
 		spin_lock(&dentry->d_lock);
 		parent = lock_parent(dentry);
-- 
2.5.0

Re: [RFC PATCH] dcache: give a chance to yield in shrink_dentry_list

[Nikolay Borisov]

On 07/14/2016 02:12 PM, Biscuit Ninja wrote:
>> A softlockup in shrink_dentry_list when called from shrink_dcache_sb
>> was observed on a very busy server. It's possible that the list
>> passed to shrink_dentry_list is so big that it takes a while to
>> dispose of all entries. Adding a simple cond_resched would give
>> the cpu a chance to do some other useful work and no trip the
>> softlockup watchdog.
> 
> Hello Nikolay,
> 
> I'm interested in your proposed patch because I believe I've come across
> the same issue a handful of times, typically:

[CCing Al Viro to ping re. the following patch:
https://patchwork.kernel.org/patch/8642031/ ]

I haven't looked at the 3.13 source but the patch is trivial enough so
that you can apply it. Just go ahead and test :) Too bad I didn't
receive any feedback and have frankly forgotten it.

> 
> WARNING: CPU: 0 PID: 22717
> at /build/buildd/linux-lts-trusty-3.13.0/fs/dcache.c:362 d_shrink_del
> +0x79/0x90()
> Modules linked in: pcnet32 mii vmwgfx ttm drm psmouse lp i2c_piix4 ppdev
> parport_pc vmw_vmci shpchp serio_raw mac_hid vmw_balloon parport floppy
> mptspi mptscsih mptbase e1000 vmw_pvscsi vmxnet3
> CPU: 0 PID: 22717 Comm: sh Not tainted 3.13.0-32-generic
> #57~precise1-Ubuntu
> Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop
> Reference Platform, BIOS 6.00 10/22/2013
>  000000000000016a ffff88000616bbe8 ffffffff81752c9e 0000000000000007
>  0000000000000000 ffff88000616bc28 ffffffff8106af7c ffff88000616bc08
>  ffff880037f54480 ffff880037f54480 ffff880037f54500 ffff880037f544d8
> Call Trace:
>  [<ffffffff81752c9e>] dump_stack+0x46/0x58
>  [<ffffffff8106af7c>] warn_slowpath_common+0x8c/0xc0
>  [<ffffffff8106afca>] warn_slowpath_null+0x1a/0x20
>  [<ffffffff811df419>] d_shrink_del+0x79/0x90
>  [<ffffffff811e0ad2>] shrink_dentry_list+0x62/0xe0
>  [<ffffffff811e0c18>] shrink_dcache_parent+0x28/0x70
>  [<ffffffff812321c7>] proc_flush_task_mnt.isra.15+0x77/0x170
>  [<ffffffff812356e6>] proc_flush_task+0x56/0x70
>  [<ffffffff8106c803>] release_task+0x33/0x130
>  [<ffffffff8106cdcf>] wait_task_zombie+0x4cf/0x5f0
>  [<ffffffff8106cffb>] wait_consider_task.part.8+0x10b/0x180
>  [<ffffffff8106d0d5>] wait_consider_task+0x65/0x70
>  [<ffffffff8106d1e1>] do_wait+0x101/0x260
>  [<ffffffff8106e213>] SyS_wait4+0xa3/0x100
>  [<ffffffff8106bc10>] ? task_stopped_code+0x50/0x50
>  [<ffffffff8176847f>] tracesys+0xe1/0xe6
> ---[ end trace e2a4a7d8b698f0ea ]---
> BUG: soft lockup - CPU#0 stuck for 22s! [sh:22717]
> Modules linked in: pcnet32 mii vmwgfx ttm drm psmouse lp i2c_piix4 ppdev
> parport_pc vmw_vmci shpchp serio_raw mac_hid vmw_balloon parport floppy
> mptspi mptscsih mptbase e1000 vmw_pvscsi vmxnet3
> CPU: 0 PID: 22717 Comm: sh Tainted: G        W    3.13.0-32-generic
> #57~precise1-Ubuntu
> Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop
> Reference Platform, BIOS 6.00 10/22/2013
> task: ffff88001ef717f0 ti: ffff88000616a000 task.ti: ffff88000616a000
> RIP: 0010:[<ffffffff8175f28c>]  [<ffffffff8175f28c>] _raw_spin_lock
> +0x1c/0x50
> RSP: 0018:ffff88000616bc58  EFLAGS: 00000246
> 
> 
> This is under Ubuntu 12.04.5 with kernel 3.13.0-32-generic.
> 

RE: [RFC PATCH] dcache: give a chance to yield in shrink_dentry_list

[Biscuit Ninja]

> A softlockup in shrink_dentry_list when called from shrink_dcache_sb
> was observed on a very busy server. It's possible that the list
> passed to shrink_dentry_list is so big that it takes a while to
> dispose of all entries. Adding a simple cond_resched would give
> the cpu a chance to do some other useful work and no trip the
> softlockup watchdog.

Hello Nikolay,

I'm interested in your proposed patch because I believe I've come across
the same issue a handful of times, typically:

WARNING: CPU: 0 PID: 22717
at /build/buildd/linux-lts-trusty-3.13.0/fs/dcache.c:362 d_shrink_del
+0x79/0x90()
Modules linked in: pcnet32 mii vmwgfx ttm drm psmouse lp i2c_piix4 ppdev
parport_pc vmw_vmci shpchp serio_raw mac_hid vmw_balloon parport floppy
mptspi mptscsih mptbase e1000 vmw_pvscsi vmxnet3
CPU: 0 PID: 22717 Comm: sh Not tainted 3.13.0-32-generic
#57~precise1-Ubuntu
Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop
Reference Platform, BIOS 6.00 10/22/2013
 000000000000016a ffff88000616bbe8 ffffffff81752c9e 0000000000000007
 0000000000000000 ffff88000616bc28 ffffffff8106af7c ffff88000616bc08
 ffff880037f54480 ffff880037f54480 ffff880037f54500 ffff880037f544d8
Call Trace:
 [<ffffffff81752c9e>] dump_stack+0x46/0x58
 [<ffffffff8106af7c>] warn_slowpath_common+0x8c/0xc0
 [<ffffffff8106afca>] warn_slowpath_null+0x1a/0x20
 [<ffffffff811df419>] d_shrink_del+0x79/0x90
 [<ffffffff811e0ad2>] shrink_dentry_list+0x62/0xe0
 [<ffffffff811e0c18>] shrink_dcache_parent+0x28/0x70
 [<ffffffff812321c7>] proc_flush_task_mnt.isra.15+0x77/0x170
 [<ffffffff812356e6>] proc_flush_task+0x56/0x70
 [<ffffffff8106c803>] release_task+0x33/0x130
 [<ffffffff8106cdcf>] wait_task_zombie+0x4cf/0x5f0
 [<ffffffff8106cffb>] wait_consider_task.part.8+0x10b/0x180
 [<ffffffff8106d0d5>] wait_consider_task+0x65/0x70
 [<ffffffff8106d1e1>] do_wait+0x101/0x260
 [<ffffffff8106e213>] SyS_wait4+0xa3/0x100
 [<ffffffff8106bc10>] ? task_stopped_code+0x50/0x50
 [<ffffffff8176847f>] tracesys+0xe1/0xe6
---[ end trace e2a4a7d8b698f0ea ]---
BUG: soft lockup - CPU#0 stuck for 22s! [sh:22717]
Modules linked in: pcnet32 mii vmwgfx ttm drm psmouse lp i2c_piix4 ppdev
parport_pc vmw_vmci shpchp serio_raw mac_hid vmw_balloon parport floppy
mptspi mptscsih mptbase e1000 vmw_pvscsi vmxnet3
CPU: 0 PID: 22717 Comm: sh Tainted: G        W    3.13.0-32-generic
#57~precise1-Ubuntu
Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop
Reference Platform, BIOS 6.00 10/22/2013
task: ffff88001ef717f0 ti: ffff88000616a000 task.ti: ffff88000616a000
RIP: 0010:[<ffffffff8175f28c>]  [<ffffffff8175f28c>] _raw_spin_lock
+0x1c/0x50
RSP: 0018:ffff88000616bc58  EFLAGS: 00000246


This is under Ubuntu 12.04.5 with kernel 3.13.0-32-generic.