On Mon, Jun 15, 2020 at 10:25 PM Holger Hoffstätte
<holger@xxxxxxxxxxxxxxxxxxxxxx> wrote:
>
> On 2020-06-15 13:56, Yafang Shao wrote:
> > Recently there is a XFS deadlock on our server with an old kernel.
> > This deadlock is caused by allocating memory in xfs_map_blocks() while
> > doing writeback on behalf of memroy reclaim. Although this deadlock happens
> > on an old kernel, I think it could happen on the upstream as well. This
> > issue only happens once and can't be reproduced, so I haven't tried to
> > reproduce it on upsteam kernel.
> >
> > Bellow is the call trace of this deadlock.
> > [480594.790087] INFO: task redis-server:16212 blocked for more than 120 seconds.
> > [480594.790087] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> > [480594.790088] redis-server D ffffffff8168bd60 0 16212 14347 0x00000004
> > [480594.790090] ffff880da128f070 0000000000000082 ffff880f94a2eeb0 ffff880da128ffd8
> > [480594.790092] ffff880da128ffd8 ffff880da128ffd8 ffff880f94a2eeb0 ffff88103f9d6c40
> > [480594.790094] 0000000000000000 7fffffffffffffff ffff88207ffc0ee8 ffffffff8168bd60
> > [480594.790096] Call Trace:
> > [480594.790101] [<ffffffff8168dce9>] schedule+0x29/0x70
> > [480594.790103] [<ffffffff8168b749>] schedule_timeout+0x239/0x2c0
> > [480594.790111] [<ffffffff8168d28e>] io_schedule_timeout+0xae/0x130
> > [480594.790114] [<ffffffff8168d328>] io_schedule+0x18/0x20
> > [480594.790116] [<ffffffff8168bd71>] bit_wait_io+0x11/0x50
> > [480594.790118] [<ffffffff8168b895>] __wait_on_bit+0x65/0x90
> > [480594.790121] [<ffffffff811814e1>] wait_on_page_bit+0x81/0xa0
> > [480594.790125] [<ffffffff81196ad2>] shrink_page_list+0x6d2/0xaf0
> > [480594.790130] [<ffffffff811975a3>] shrink_inactive_list+0x223/0x710
> > [480594.790135] [<ffffffff81198225>] shrink_lruvec+0x3b5/0x810
> > [480594.790139] [<ffffffff8119873a>] shrink_zone+0xba/0x1e0
> > [480594.790141] [<ffffffff81198c20>] do_try_to_free_pages+0x100/0x510
> > [480594.790143] [<ffffffff8119928d>] try_to_free_mem_cgroup_pages+0xdd/0x170
> > [480594.790145] [<ffffffff811f32de>] mem_cgroup_reclaim+0x4e/0x120
> > [480594.790147] [<ffffffff811f37cc>] __mem_cgroup_try_charge+0x41c/0x670
> > [480594.790153] [<ffffffff811f5cb6>] __memcg_kmem_newpage_charge+0xf6/0x180
> > [480594.790157] [<ffffffff8118c72d>] __alloc_pages_nodemask+0x22d/0x420
> > [480594.790162] [<ffffffff811d0c7a>] alloc_pages_current+0xaa/0x170
> > [480594.790165] [<ffffffff811db8fc>] new_slab+0x30c/0x320
> > [480594.790168] [<ffffffff811dd17c>] ___slab_alloc+0x3ac/0x4f0
> > [480594.790204] [<ffffffff81685656>] __slab_alloc+0x40/0x5c
> > [480594.790206] [<ffffffff811dfc43>] kmem_cache_alloc+0x193/0x1e0
> > [480594.790233] [<ffffffffa04fab67>] kmem_zone_alloc+0x97/0x130 [xfs]
> > [480594.790247] [<ffffffffa04f90ba>] _xfs_trans_alloc+0x3a/0xa0 [xfs]
> > [480594.790261] [<ffffffffa04f915c>] xfs_trans_alloc+0x3c/0x50 [xfs]
> > [480594.790276] [<ffffffffa04e958b>] xfs_iomap_write_allocate+0x1cb/0x390 [xfs]
> > [480594.790299] [<ffffffffa04d3616>] xfs_map_blocks+0x1a6/0x210 [xfs]
> > [480594.790312] [<ffffffffa04d416b>] xfs_do_writepage+0x17b/0x550 [xfs]
> > [480594.790314] [<ffffffff8118d881>] write_cache_pages+0x251/0x4d0 [xfs]
> > [480594.790338] [<ffffffffa04d3e05>] xfs_vm_writepages+0xc5/0xe0 [xfs]
> > [480594.790341] [<ffffffff8118ebfe>] do_writepages+0x1e/0x40
> > [480594.790343] [<ffffffff811837b5>] __filemap_fdatawrite_range+0x65/0x80
> > [480594.790346] [<ffffffff81183901>] filemap_write_and_wait_range+0x41/0x90
> > [480594.790360] [<ffffffffa04df2c6>] xfs_file_fsync+0x66/0x1e0 [xfs]
> > [480594.790363] [<ffffffff81231cf5>] do_fsync+0x65/0xa0
> > [480594.790365] [<ffffffff81231fe3>] SyS_fdatasync+0x13/0x20
> > [480594.790367] [<ffffffff81698d09>] system_call_fastpath+0x16/0x1b
> >
> > Note that xfs_iomap_write_allocate() is replaced by xfs_convert_blocks() in
> > commit 4ad765edb02a ("xfs: move xfs_iomap_write_allocate to xfs_aops.c")
> > and write_cache_pages() is replaced by iomap_writepages() in
> > commit 598ecfbaa742 ("iomap: lift the xfs writeback code to iomap").
> > So for upsteam, the call trace should be,
> > xfs_vm_writepages
> > -> iomap_writepages
> > -> write_cache_pages
> > -> iomap_do_writepage
> > -> xfs_map_blocks
> > -> xfs_convert_blocks
> > -> xfs_bmapi_convert_delalloc
> > -> xfs_trans_alloc //It should alloc page with GFP_NOFS
> >
> > I'm not sure whether it is proper to add the GFP_NOFS to all the
> > ->writepags, so I only add it for XFS.
> >
> > Stefan also reported that he saw this issue two times while under memory
> > pressure, So I add his reported-by.
> >
> > Reported-by: Stefan Priebe - Profihost AG <s.priebe@xxxxxxxxxxxx>
> > Signed-off-by: Yafang Shao <laoar.shao@xxxxxxxxx>
> >
> > ---
> > v2 -> v3:
> > - retitle the subject from "iomap: avoid deadlock if memory reclaim is
> > triggered in writepage path"
> > - set GFP_NOFS only for XFS ->writepages
> >
> > v1 -> v2:
> > - retitle the subject from "xfs: avoid deadlock when tigger memory reclam
> > in xfs_map_blocks()"
> > - set GFP_NOFS in iomap_do_writepage(), per Dave
> > ---
> > fs/xfs/xfs_aops.c | 14 +++++++++++++-
> > 1 file changed, 13 insertions(+), 1 deletion(-)
> >
> > diff --git a/fs/xfs/xfs_aops.c b/fs/xfs/xfs_aops.c
> > index b356118..1ccfbf2 100644
> > --- a/fs/xfs/xfs_aops.c
> > +++ b/fs/xfs/xfs_aops.c
> > @@ -573,9 +573,21 @@ static inline bool xfs_ioend_needs_workqueue(struct iomap_ioend *ioend)
> > struct writeback_control *wbc)
> > {
> > struct xfs_writepage_ctx wpc = { };
> > + unsigned int nofs_flag;
> > + int ret;
> >
> > xfs_iflags_clear(XFS_I(mapping->host), XFS_ITRUNCATED);
> > - return iomap_writepages(mapping, wbc, &wpc.ctx, &xfs_writeback_ops);
> > +
> > + /*
> > + * We can allocate memory here while doing writeback on behalf of
> > + * memory reclaim. To avoid memory allocation deadlocks set the
> > + * task-wide nofs context for the following operations.
> > + */
> > + nofs_flag = memalloc_nofs_save();
> > + ret = iomap_writepages(mapping, wbc, &wpc.ctx, &xfs_writeback_ops);
> > + memalloc_nofs_restore(nofs_flag);
> > +
> > + return ret;
> > }
> >
> > STATIC int
> >
>
> Not sure if I did something wrong, but while the previous version of this patch
> worked fine, this one gave me (with v2 removed obviously):
>
> [ +0.000004] WARNING: CPU: 0 PID: 2811 at fs/iomap/buffered-io.c:1544 iomap_do_writepage+0x6b4/0x780
> [ +0.000001] Modules linked in: tcp_bbr2 sch_fq_codel nct6775 hwmon_vid btrfs blake2b_generic xor zstd_compress x86_pkg_temp_thermal drivetemp coretemp crc32_pclmul raid6_pq zstd_decompress aesni_intel i915 crypto_simd cryptd glue_helper intel_gtt bfq i2c_algo_bit iosf_mbi drm_kms_helper i2c_i801 mq_deadline syscopyarea sysfillrect usbhid sysimgblt fb_sys_fops drm drm_panel_orientation_quirks i2c_core atlantic video backlight
> [ +0.000013] CPU: 0 PID: 2811 Comm: dmesg Not tainted 5.7.2 #1
> [ +0.000000] Hardware name: System manufacturer System Product Name/P8Z68-V LX, BIOS 4105 07/01/2013
> [ +0.000002] RIP: 0010:iomap_do_writepage+0x6b4/0x780
> [ +0.000001] Code: ff e9 bf fc ff ff 48 8b 44 24 48 48 39 44 24 28 0f 84 f7 fb ff ff 0f 0b e9 f0 fb ff ff 4c 8b 64 24 10 41 89 c7 e9 d8 fb ff ff <0f> 0b eb 88 8b 54 24 24 85 d2 75 5f 49 8b 45 50 48 8b 40 10 48 85
> [ +0.000001] RSP: 0018:ffffc90000277ae8 EFLAGS: 00010206
> [ +0.000001] RAX: 0000000000444004 RBX: ffffc90000277bc0 RCX: 0000000000000018
> [ +0.000000] RDX: 0000000000000000 RSI: ffffc90000277d58 RDI: ffffea001fd25e00
> [ +0.000001] RBP: ffff8887f7edfd40 R08: ffffffffffffffff R09: 0000000000000006
> [ +0.000001] R10: ffff88881f5dd000 R11: 000000000000020d R12: ffffea001fd25e00
> [ +0.000000] R13: ffffc90000277c80 R14: ffff8887fb95e800 R15: ffffea001fd25e00
> [ +0.000001] FS: 0000000000000000(0000) GS:ffff8887ff600000(0000) knlGS:0000000000000000
> [ +0.000001] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ +0.000000] CR2: 00007f836c0915e8 CR3: 0000000002009005 CR4: 00000000000606f0
> [ +0.000001] Call Trace:
> [ +0.000006] ? page_mkclean+0x5e/0x90
> [ +0.000003] ? clear_page_dirty_for_io+0x18a/0x1d0
> [ +0.000002] write_cache_pages+0x196/0x400
> [ +0.000001] ? iomap_readpages+0x180/0x180
> [ +0.000003] iomap_writepages+0x1c/0x40
> [ +0.000003] xfs_vm_writepages+0x68/0x90
> [ +0.000002] do_writepages+0x25/0xa0
> [ +0.000002] __filemap_fdatawrite_range+0xa7/0xe0
> [ +0.000002] xfs_release+0x11b/0x160
> [ +0.000002] __fput+0xd7/0x240
> [ +0.000003] task_work_run+0x5c/0x80
> [ +0.000001] do_exit+0x33b/0x9c0
> [ +0.000001] do_group_exit+0x33/0x90
> [ +0.000002] __x64_sys_exit_group+0x14/0x20
> [ +0.000001] do_syscall_64+0x4e/0x310
> [ +0.000003] ? do_user_addr_fault+0x1df/0x460
> [ +0.000004] entry_SYSCALL_64_after_hwframe+0x44/0xa9
> [ +0.000001] RIP: 0033:0x7f836bf73489
> [ +0.000003] Code: Bad RIP value.
> [ +0.000000] RSP: 002b:00007fff90ec3b98 EFLAGS: 00000246 ORIG_RAX: 00000000000000e7
> [ +0.000001] RAX: ffffffffffffffda RBX: 00007f836c0626e0 RCX: 00007f836bf73489
> [ +0.000001] RDX: 000000000000003c RSI: 00000000000000e7 RDI: 0000000000000000
> [ +0.000001] RBP: 00007f836c0626e0 R08: ffffffffffffff80 R09: 00007fff90ec3a60
> [ +0.000000] R10: 0000000000000003 R11: 0000000000000246 R12: 0000000000000000
> [ +0.000001] R13: 0000000000000000 R14: 0000000000000002 R15: 0000000000000000
> [ +0.000001] ---[ end trace aed8763335accf60 ]---
>
> ..and hosed the fs by eating any writeback, zeroing out $things.
> 0/10 cats, do not want.
>
> -h
Oh my bad.
I ignored the check in iomap_do_writepage() that,
if (WARN_ON_ONCE(current->flags & PF_MEMALLOC_NOFS))
goto redirty;
This check is to avoid recursive filesystem reclaim.
GFP_NOFS should be set after this check, or we should move this check
at the beginning of ->writepage(s).
v2 is fine, you can apply v2 to your kernel and feel free to let me
know if you catch any issue after applying it.
Thanks for your feedback.
--
Thanks
Yafang
