xfs: soft lockups in unmapping and reflink remapping path
v4 cover xfs: soft lockups in unmapping and reflink remapping path
Hello,
In one of the testcases, parallel async dio writes to a file generates large no. of extents (upto 2M or more), and then this file is cleaned up for running other I/O tests. In the process of deleting this file, soft lockup messages are observed. We believe this is happening due to kernel being busy in unmapping/freeing those extents as part of the transaction processing. This is similar observation with the same call stack which was also reported here [1]. I also tried the qemu-img bench testcase shared in [1], and I was able to reproduce the soft lockup with that on Power.
Similarly another instance was reported where xfs reflink remapping path also saw a similar softlockup problem while iterating over a million extent entries.
So as I understood from that discussion [1], that kernel is moving towards a new preemption model, but IIUC, it is still an ongoing work.
Also IMHO, this is still a problem in upstream and in older stable kernels which we still do support and such a fix might still be necessary for them.
This patch adds the cond_resched() to both xfs_bunmapi_range() and xfs_reflink_remap_blocks() functions.
v3 -> v4:
Remove cond_resched() from defer finish and add it to both the unmap range and reflink remap functions individually.
v2 -> v3:
Move cond_resched within xfs_defer_finish_noroll() loop
Ritesh Harjani (IBM) (1):
xfs: Add cond_resched to block unmap range and reflink remap path
fs/xfs/libxfs/xfs_bmap.c | 1 + fs/xfs/xfs_reflink.c | 1 + 2 files changed, 2 insertions(+)
--
2.44.0
PATCH v4 1/1 xfs: Add cond_resched to block unmap range and reflink remap path
An async dio write to a sparse file can generate a lot of extents and when we unlink this file (using rm), the kernel can be busy in umapping and freeing those extents as part of transaction processing.
Similarly xfs reflink remapping path can also iterate over a million extent entries in xfs_reflink_remap_blocks().
Since we can busy loop in these two functions, so let's add cond_resched() to avoid softlockup messages like these.
watchdog: BUG: soft lockup - CPU#1 stuck for 22s! [kworker/1:0:82435] CPU: 1 PID: 82435 Comm: kworker/1:0 Tainted: G S L 6.9.0-rc5-0-default #1 Workqueue: xfs-inodegc/sda2 xfs_inodegc_worker NIP [c000000000beea10] xfs_extent_busy_trim+0x100/0x290 LR [c000000000bee958] xfs_extent_busy_trim+0x48/0x290 Call Trace: xfs_alloc_get_rec+0x54/0x1b0 (unreliable) xfs_alloc_compute_aligned+0x5c/0x144 xfs_alloc_ag_vextent_size+0x238/0x8d4 xfs_alloc_fix_freelist+0x540/0x694 xfs_free_extent_fix_freelist+0x84/0xe0 __xfs_free_extent+0x74/0x1ec xfs_extent_free_finish_item+0xcc/0x214 xfs_defer_finish_one+0x194/0x388 xfs_defer_finish_noroll+0x1b4/0x5c8 xfs_defer_finish+0x2c/0xc4 xfs_bunmapi_range+0xa4/0x100 xfs_itruncate_extents_flags+0x1b8/0x2f4 xfs_inactive_truncate+0xe0/0x124 xfs_inactive+0x30c/0x3e0 xfs_inodegc_worker+0x140/0x234 process_scheduled_works+0x240/0x57c worker_thread+0x198/0x468 kthread+0x138/0x140 start_kernel_thread+0x14/0x18
run fstests generic/175 at 2024-02-02 04:40:21
[ C17] watchdog: BUG: soft lockup - CPU#17 stuck for 23s! [xfs_io:7679]
watchdog: BUG: soft lockup - CPU#17 stuck for 23s! [xfs_io:7679] CPU: 17 PID: 7679 Comm: xfs_io Kdump: loaded Tainted: G X 6.4.0 NIP [c008000005e3ec94] xfs_rmapbt_diff_two_keys+0x54/0xe0 [xfs] LR [c008000005e08798] xfs_btree_get_leaf_keys+0x110/0x1e0 [xfs] Call Trace: 0xc000000014107c00 (unreliable) __xfs_btree_updkeys+0x8c/0x2c0 [xfs] xfs_btree_update_keys+0x150/0x170 [xfs] xfs_btree_lshift+0x534/0x660 [xfs] xfs_btree_make_block_unfull+0x19c/0x240 [xfs] xfs_btree_insrec+0x4e4/0x630 [xfs] xfs_btree_insert+0x104/0x2d0 [xfs] xfs_rmap_insert+0xc4/0x260 [xfs] xfs_rmap_map_shared+0x228/0x630 [xfs] xfs_rmap_finish_one+0x2d4/0x350 [xfs] xfs_rmap_update_finish_item+0x44/0xc0 [xfs] xfs_defer_finish_noroll+0x2e4/0x740 [xfs] __xfs_trans_commit+0x1f4/0x400 [xfs] xfs_reflink_remap_extent+0x2d8/0x650 [xfs] xfs_reflink_remap_blocks+0x154/0x320 [xfs] xfs_file_remap_range+0x138/0x3a0 [xfs] do_clone_file_range+0x11c/0x2f0 vfs_clone_file_range+0x60/0x1c0 ioctl_file_clone+0x78/0x140 sys_ioctl+0x934/0x1270 system_call_exception+0x158/0x320 system_call_vectored_common+0x15c/0x2ec
--- fs/xfs/libxfs/xfs_bmap.c | 1 + fs/xfs/xfs_reflink.c | 1 + 2 files changed, 2 insertions(+)
fs/xfs/libxfs/xfs_bmap.c +1 -0
@@ -6354,6 +6354,7 @@ xfs_bunmapi_range( error =xfs_defer_finish (tpp);if (error) goto out; +cond_resched (); } out:return error;
fs/xfs/xfs_reflink.c +1 -0
@@ -1417,6 +1417,7 @@ xfs_reflink_remap_blocks( destoff += imap.br_blockcount; len -= imap.br_blockcount; remapped_len += imap.br_blockcount; +cond_resched (); }if (error)
--
2.44.0
Re: [PATCHv4 1/1] xfs: Add cond_resched to block unmap range and reflink remap path
Quoted 66 lines · Ritesh Harjani (IBM)
An async dio write to a sparse file can generate a lot of extents and when we unlink this file (using rm), the kernel can be busy in umapping and freeing those extents as part of transaction processing.
Similarly xfs reflink remapping path can also iterate over a million extent entries in
xfs_reflink_remap_blocks().Since we can busy loop in these two functions, so let's add
cond_resched()to avoid softlockup messages like these.watchdog: BUG: soft lockup - CPU#1 stuck for 22s! [kworker/1:0:82435] CPU: 1 PID: 82435 Comm: kworker/1:0 Tainted: G S L 6.9.0-rc5-0-default #1 Workqueue: xfs-inodegc/sda2 xfs_inodegc_worker NIP [c000000000beea10] xfs_extent_busy_trim+0x100/0x290 LR [c000000000bee958] xfs_extent_busy_trim+0x48/0x290 Call Trace: xfs_alloc_get_rec+0x54/0x1b0 (unreliable) xfs_alloc_compute_aligned+0x5c/0x144 xfs_alloc_ag_vextent_size+0x238/0x8d4 xfs_alloc_fix_freelist+0x540/0x694 xfs_free_extent_fix_freelist+0x84/0xe0 __xfs_free_extent+0x74/0x1ec xfs_extent_free_finish_item+0xcc/0x214 xfs_defer_finish_one+0x194/0x388 xfs_defer_finish_noroll+0x1b4/0x5c8 xfs_defer_finish+0x2c/0xc4 xfs_bunmapi_range+0xa4/0x100 xfs_itruncate_extents_flags+0x1b8/0x2f4 xfs_inactive_truncate+0xe0/0x124 xfs_inactive+0x30c/0x3e0 xfs_inodegc_worker+0x140/0x234 process_scheduled_works+0x240/0x57c worker_thread+0x198/0x468 kthread+0x138/0x140 start_kernel_thread+0x14/0x18run fstests generic/175 at 2024-02-02 04:40:21
[ C17] watchdog: BUG: soft lockup - CPU#17 stuck for 23s! [xfs_io:7679]watchdog: BUG: soft lockup - CPU#17 stuck for 23s! [xfs_io:7679] CPU: 17 PID: 7679 Comm: xfs_io Kdump: loaded Tainted: G X 6.4.0 NIP [c008000005e3ec94] xfs_rmapbt_diff_two_keys+0x54/0xe0 [xfs] LR [c008000005e08798] xfs_btree_get_leaf_keys+0x110/0x1e0 [xfs] Call Trace: 0xc000000014107c00 (unreliable) __xfs_btree_updkeys+0x8c/0x2c0 [xfs] xfs_btree_update_keys+0x150/0x170 [xfs] xfs_btree_lshift+0x534/0x660 [xfs] xfs_btree_make_block_unfull+0x19c/0x240 [xfs] xfs_btree_insrec+0x4e4/0x630 [xfs] xfs_btree_insert+0x104/0x2d0 [xfs] xfs_rmap_insert+0xc4/0x260 [xfs] xfs_rmap_map_shared+0x228/0x630 [xfs] xfs_rmap_finish_one+0x2d4/0x350 [xfs] xfs_rmap_update_finish_item+0x44/0xc0 [xfs] xfs_defer_finish_noroll+0x2e4/0x740 [xfs] __xfs_trans_commit+0x1f4/0x400 [xfs] xfs_reflink_remap_extent+0x2d8/0x650 [xfs] xfs_reflink_remap_blocks+0x154/0x320 [xfs] xfs_file_remap_range+0x138/0x3a0 [xfs] do_clone_file_range+0x11c/0x2f0 vfs_clone_file_range+0x60/0x1c0 ioctl_file_clone+0x78/0x140 sys_ioctl+0x934/0x1270 system_call_exception+0x158/0x320 system_call_vectored_common+0x15c/0x2ec
Quoted 2 lines
Cc Ojaswin Mujoo <[email protected]>Signed-off-by Ritesh Harjani (IBM) <[email protected]>
LGTM,
--D
Quoted 33 lines
--- fs/xfs/libxfs/xfs_bmap.c | 1 + fs/xfs/xfs_reflink.c | 1 + 2 files changed, 2 insertions(+)fs/xfs/libxfs/xfs_bmap.c +1
-0@@ -6354,6 +6354,7 @@ xfs_bunmapi_range( error =xfs_defer_finish (tpp);if (error) goto out; +cond_resched (); } out:return error;fs/xfs/xfs_reflink.c +1
-1@@ -1417,6 +1417,7 @@ xfs_reflink_remap_blocks( destoff += imap.br_blockcount; len -= imap.br_blockcount; remapped_len += imap.br_blockcount; +cond_resched (); }if (error) --2.44.0
Re: [PATCHv4 1/1] xfs: Add cond_resched to block unmap range and reflink remap path
In reply to Ritesh Harjani (IBM)Quoted 66 lines · Ritesh Harjani (IBM)
An async dio write to a sparse file can generate a lot of extents and when we unlink this file (using rm), the kernel can be busy in umapping and freeing those extents as part of transaction processing.
Similarly xfs reflink remapping path can also iterate over a million extent entries in
xfs_reflink_remap_blocks().Since we can busy loop in these two functions, so let's add
cond_resched()to avoid softlockup messages like these.watchdog: BUG: soft lockup - CPU#1 stuck for 22s! [kworker/1:0:82435] CPU: 1 PID: 82435 Comm: kworker/1:0 Tainted: G S L 6.9.0-rc5-0-default #1 Workqueue: xfs-inodegc/sda2 xfs_inodegc_worker NIP [c000000000beea10] xfs_extent_busy_trim+0x100/0x290 LR [c000000000bee958] xfs_extent_busy_trim+0x48/0x290 Call Trace: xfs_alloc_get_rec+0x54/0x1b0 (unreliable) xfs_alloc_compute_aligned+0x5c/0x144 xfs_alloc_ag_vextent_size+0x238/0x8d4 xfs_alloc_fix_freelist+0x540/0x694 xfs_free_extent_fix_freelist+0x84/0xe0 __xfs_free_extent+0x74/0x1ec xfs_extent_free_finish_item+0xcc/0x214 xfs_defer_finish_one+0x194/0x388 xfs_defer_finish_noroll+0x1b4/0x5c8 xfs_defer_finish+0x2c/0xc4 xfs_bunmapi_range+0xa4/0x100 xfs_itruncate_extents_flags+0x1b8/0x2f4 xfs_inactive_truncate+0xe0/0x124 xfs_inactive+0x30c/0x3e0 xfs_inodegc_worker+0x140/0x234 process_scheduled_works+0x240/0x57c worker_thread+0x198/0x468 kthread+0x138/0x140 start_kernel_thread+0x14/0x18run fstests generic/175 at 2024-02-02 04:40:21
[ C17] watchdog: BUG: soft lockup - CPU#17 stuck for 23s! [xfs_io:7679]watchdog: BUG: soft lockup - CPU#17 stuck for 23s! [xfs_io:7679] CPU: 17 PID: 7679 Comm: xfs_io Kdump: loaded Tainted: G X 6.4.0 NIP [c008000005e3ec94] xfs_rmapbt_diff_two_keys+0x54/0xe0 [xfs] LR [c008000005e08798] xfs_btree_get_leaf_keys+0x110/0x1e0 [xfs] Call Trace: 0xc000000014107c00 (unreliable) __xfs_btree_updkeys+0x8c/0x2c0 [xfs] xfs_btree_update_keys+0x150/0x170 [xfs] xfs_btree_lshift+0x534/0x660 [xfs] xfs_btree_make_block_unfull+0x19c/0x240 [xfs] xfs_btree_insrec+0x4e4/0x630 [xfs] xfs_btree_insert+0x104/0x2d0 [xfs] xfs_rmap_insert+0xc4/0x260 [xfs] xfs_rmap_map_shared+0x228/0x630 [xfs] xfs_rmap_finish_one+0x2d4/0x350 [xfs] xfs_rmap_update_finish_item+0x44/0xc0 [xfs] xfs_defer_finish_noroll+0x2e4/0x740 [xfs] __xfs_trans_commit+0x1f4/0x400 [xfs] xfs_reflink_remap_extent+0x2d8/0x650 [xfs] xfs_reflink_remap_blocks+0x154/0x320 [xfs] xfs_file_remap_range+0x138/0x3a0 [xfs] do_clone_file_range+0x11c/0x2f0 vfs_clone_file_range+0x60/0x1c0 ioctl_file_clone+0x78/0x140 sys_ioctl+0x934/0x1270 system_call_exception+0x158/0x320 system_call_vectored_common+0x15c/0x2ec
Quoted 2 lines
Cc Ojaswin Mujoo <[email protected]>Signed-off-by Ritesh Harjani (IBM) <[email protected]>
Thanks for the fix patch. I have tested it on a power machine, and it resolves the soft lockup issue.
Quoted 33 lines
--- fs/xfs/libxfs/xfs_bmap.c | 1 + fs/xfs/xfs_reflink.c | 1 + 2 files changed, 2 insertions(+)fs/xfs/libxfs/xfs_bmap.c +1
-0@@ -6354,6 +6354,7 @@ xfs_bunmapi_range( error =xfs_defer_finish (tpp);if (error) goto out; +cond_resched (); } out:return error;fs/xfs/xfs_reflink.c +1
-1@@ -1417,6 +1417,7 @@ xfs_reflink_remap_blocks( destoff += imap.br_blockcount; len -= imap.br_blockcount; remapped_len += imap.br_blockcount; +cond_resched (); }if (error) --2.44.0