* [Bug 218230] New: xfstests xfs/538 hung
@ 2023-12-05 12:31 bugzilla-daemon
2023-12-05 14:29 ` [Bug 218230] " bugzilla-daemon
2024-06-24 9:42 ` bugzilla-daemon
0 siblings, 2 replies; 4+ messages in thread
From: bugzilla-daemon @ 2023-12-05 12:31 UTC (permalink / raw)
To: linux-xfs
https://bugzilla.kernel.org/show_bug.cgi?id=218230
Bug ID: 218230
Summary: xfstests xfs/538 hung
Product: File System
Version: 2.5
Hardware: All
OS: Linux
Status: NEW
Severity: normal
Priority: P3
Component: XFS
Assignee: filesystem_xfs@kernel-bugs.kernel.org
Reporter: dagmcr@gmail.com
Regression: No
While doing fstests baseline testing on v6.6-rc5 with kdevops [0] we found a
failure for xfs/538 test.
[0] https://github.com/linux-kdevops
This fails on the following test sections as defined by kdevops [1]:
* xfs_crc_logdev_rtdev: failure rate ~1/17
* xfs_crc_rtdev_extsize_64k: failure rate ~1/3
[0] https://github.com/linux-kdevops
[1]
https://github.com/linux-kdevops/kdevops/blob/master/playbooks/roles/fstests/templates/xfs/xfs.config
Below is just one full trace.
Nov 02 20:23:13 line-xfs-crc-logdev-rtdev unknown: run fstests xfs/538 at
2023-11-02 20:23:13
Nov 02 20:23:14 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Mounting V5
Filesystem 8e731ab8-42fb-48c5-8877-b4fb526e9609
Nov 02 20:23:14 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Ending clean
mount
Nov 02 20:23:23 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4123, on filesystem "loop5"
Nov 02 20:23:23 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
Nov 02 20:23:23 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
Nov 02 20:23:23 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
Nov 02 20:23:23 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
Nov 02 20:23:23 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
Nov 02 20:23:23 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
Nov 02 20:23:23 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
Nov 02 20:23:23 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
Nov 02 20:23:23 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: xfs_errortag_test: 43825
callbacks suppressed
Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
Nov 02 20:23:33 line-xfs-crc-logdev-rtdev kernel: xfs_errortag_test: 37630
callbacks suppressed
Nov 02 20:23:38 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
Nov 02 20:23:38 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting error
(false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: INFO: task kcompactd0:71
blocked for more than 120 seconds.
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: Not tainted 6.6.0-rc5
#2
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: task:kcompactd0 state:D
stack:0 pid:71 ppid:2 flags:0x00004000
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: Call Trace:
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: <TASK>
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: __schedule+0x3ab/0xab0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: schedule+0x5d/0xe0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: io_schedule+0x42/0x70
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
folio_wait_bit_common+0x12e/0x380
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
__pfx_wake_page_function+0x10/0x10
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
migrate_pages_batch+0x632/0xdb0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
__pfx_compaction_free+0x10/0x10
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
__pfx_compaction_alloc+0x10/0x10
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
__pfx_remove_migration_pte+0x10/0x10
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: migrate_pages+0xc22/0xda0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
__pfx_compaction_alloc+0x10/0x10
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
__pfx_compaction_free+0x10/0x10
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: compact_zone+0x927/0xfe0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? _raw_spin_unlock+0x15/0x30
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
finish_task_switch.isra.0+0x91/0x2a0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? __switch_to+0x106/0x3a0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
proactive_compact_node+0x87/0xe0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? finish_wait+0x41/0x90
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: kcompactd+0x30d/0x3f0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
__pfx_autoremove_wake_function+0x10/0x10
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? __pfx_kcompactd+0x10/0x10
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: kthread+0xf3/0x120
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? __pfx_kthread+0x10/0x10
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ret_from_fork+0x30/0x50
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? __pfx_kthread+0x10/0x10
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ret_from_fork_asm+0x1b/0x30
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: </TASK>
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: INFO: task
kworker/5:0:2369803 blocked for more than 120 seconds.
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: Not tainted 6.6.0-rc5
#2
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: task:kworker/5:0 state:D
stack:0 pid:2369803 ppid:2 flags:0x00004000
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: Workqueue: xfs-inodegc/loop5
xfs_inodegc_worker [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: Call Trace:
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: <TASK>
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: __schedule+0x3ab/0xab0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
finish_task_switch.isra.0+0x91/0x2a0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: schedule+0x5d/0xe0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: schedule_timeout+0x143/0x150
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
preempt_count_add+0x6a/0xa0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: __down_common+0xf6/0x200
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: down+0x43/0x60
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: xfs_buf_lock+0x2d/0xe0 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: xfs_buf_find_lock+0x60/0x140
[xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: xfs_buf_get_map+0x1bd/0xaf0
[xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? __module_address+0x2f/0xb0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? __module_address+0x2f/0xb0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
preempt_count_add+0x47/0xa0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: xfs_buf_read_map+0x54/0x250
[xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? xfs_read_agf+0x90/0x130
[xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
xfs_trans_read_buf_map+0x1c2/0x4d0 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? xfs_read_agf+0x90/0x130
[xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: xfs_read_agf+0x90/0x130
[xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
xfs_alloc_read_agf+0x5e/0x390 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
__xfs_trans_commit+0xc8/0x390 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
xfs_alloc_fix_freelist+0x3cb/0x750 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
unwind_next_frame+0x120/0x890
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? arch_stack_walk+0x88/0xf0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
ret_from_fork_asm+0x1b/0x30
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
__stack_depot_save+0x35/0x480
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
xfs_free_extent_fix_freelist+0x61/0xa0 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: __xfs_free_extent+0x8c/0x1f0
[xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
xfs_trans_free_extent+0x97/0x270 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
xfs_extent_free_finish_item+0xf/0x40 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
xfs_defer_finish_noroll+0x19f/0x760 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: xfs_defer_finish+0x11/0xa0
[xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
xfs_itruncate_extents_flags+0x14f/0x4c0 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
xfs_inactive_truncate+0xbf/0x140 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: xfs_inactive+0x22d/0x290
[xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
xfs_inodegc_worker+0xb4/0x1a0 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: process_one_work+0x174/0x340
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: worker_thread+0x277/0x390
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
__pfx_worker_thread+0x10/0x10
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: kthread+0xf3/0x120
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? __pfx_kthread+0x10/0x10
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ret_from_fork+0x30/0x50
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? __pfx_kthread+0x10/0x10
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ret_from_fork_asm+0x1b/0x30
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: </TASK>
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: INFO: task
kworker/u17:7:3188941 blocked for more than 120 seconds.
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: Not tainted 6.6.0-rc5
#2
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: task:kworker/u17:7 state:D
stack:0 pid:3188941 ppid:2 flags:0x00004000
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: Workqueue: writeback
wb_workfn (flush-7:5)
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: Call Trace:
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: <TASK>
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: __schedule+0x3ab/0xab0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: schedule+0x5d/0xe0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: schedule_timeout+0x143/0x150
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
_raw_spin_unlock_irqrestore+0x23/0x40
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
preempt_count_add+0x6a/0xa0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
_raw_spin_lock_irqsave+0x23/0x50
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: __down_common+0xf6/0x200
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: down+0x43/0x60
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: xfs_buf_lock+0x2d/0xe0 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: xfs_buf_find_lock+0x60/0x140
[xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: xfs_buf_get_map+0x1bd/0xaf0
[xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
_xfs_trans_bjoin+0x76/0x120 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: xfs_buf_read_map+0x54/0x250
[xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? xfs_read_agf+0x90/0x130
[xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
xfs_trans_read_buf_map+0x1c2/0x4d0 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? xfs_read_agf+0x90/0x130
[xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: xfs_read_agf+0x90/0x130
[xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
xfs_alloc_read_agf+0x5e/0x390 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
xfs_alloc_fix_freelist+0x3cb/0x750 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? wb_workfn+0x30f/0x4b0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
set_track_prepare+0x4a/0x70
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
xlog_ticket_alloc+0x29/0xa0 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? xfs_log_reserve+0x9c/0x220
[xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
xfs_trans_reserve+0x199/0x270 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
__pv_queued_spin_lock_slowpath+0x16c/0x380
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
xfs_alloc_vextent_prepare_ag+0x2d/0x120 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
xfs_alloc_vextent_iterate_ags.constprop.0+0x99/0x230 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
xfs_alloc_vextent_first_ag+0xf1/0x130 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
xfs_bmap_exact_minlen_extent_alloc+0x138/0x1b0 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
xfs_bmapi_allocate+0x282/0x450 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
xfs_bmapi_convert_delalloc+0x2ee/0x4e0 [xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: xfs_map_blocks+0x1f2/0x590
[xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
iomap_do_writepage+0x28b/0x8d0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
write_cache_pages+0x159/0x3c0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
__pfx_iomap_do_writepage+0x10/0x10
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: iomap_writepages+0x1c/0x40
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: xfs_vm_writepages+0x79/0xb0
[xfs]
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: do_writepages+0xcb/0x1a0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? touch_atime+0x1c/0x160
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? filemap_read+0x32f/0x340
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
__writeback_single_inode+0x3d/0x350
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? _raw_spin_lock+0x13/0x40
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
writeback_sb_inodes+0x1f5/0x4c0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
__writeback_inodes_wb+0x4c/0xe0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: wb_writeback+0x26b/0x2e0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: wb_workfn+0x30f/0x4b0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? _raw_spin_unlock+0x15/0x30
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
finish_task_switch.isra.0+0x91/0x2a0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? __switch_to+0x106/0x3a0
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: process_one_work+0x174/0x340
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: worker_thread+0x277/0x390
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
__pfx_worker_thread+0x10/0x10
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: kthread+0xf3/0x120
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? __pfx_kthread+0x10/0x10
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ret_from_fork+0x30/0x50
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? __pfx_kthread+0x10/0x10
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ret_from_fork_asm+0x1b/0x30
Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: </TASK>
--
You may reply to this email to add a comment.
You are receiving this mail because:
You are watching the assignee of the bug.
^ permalink raw reply [flat|nested] 4+ messages in thread* [Bug 218230] xfstests xfs/538 hung
2023-12-05 12:31 [Bug 218230] New: xfstests xfs/538 hung bugzilla-daemon
@ 2023-12-05 14:29 ` bugzilla-daemon
2024-06-24 9:39 ` Chandan Babu R
2024-06-24 9:42 ` bugzilla-daemon
1 sibling, 1 reply; 4+ messages in thread
From: bugzilla-daemon @ 2023-12-05 14:29 UTC (permalink / raw)
To: linux-xfs
https://bugzilla.kernel.org/show_bug.cgi?id=218230
--- Comment #1 from chandanbabu@kernel.org ---
On Tue, Dec 05, 2023 at 12:31:34 PM +0000, bugzilla-daemon@kernel.org wrote:
> https://bugzilla.kernel.org/show_bug.cgi?id=218230
>
> Bug ID: 218230
> Summary: xfstests xfs/538 hung
> Product: File System
> Version: 2.5
> Hardware: All
> OS: Linux
> Status: NEW
> Severity: normal
> Priority: P3
> Component: XFS
> Assignee: filesystem_xfs@kernel-bugs.kernel.org
> Reporter: dagmcr@gmail.com
> Regression: No
>
> While doing fstests baseline testing on v6.6-rc5 with kdevops [0] we found a
> failure for xfs/538 test.
>
> [0] https://github.com/linux-kdevops
>
> This fails on the following test sections as defined by kdevops [1]:
>
> * xfs_crc_logdev_rtdev: failure rate ~1/17
> * xfs_crc_rtdev_extsize_64k: failure rate ~1/3
>
> [0] https://github.com/linux-kdevops
> [1]
>
> https://github.com/linux-kdevops/kdevops/blob/master/playbooks/roles/fstests/templates/xfs/xfs.config
>
> Below is just one full trace.
>
> Nov 02 20:23:13 line-xfs-crc-logdev-rtdev unknown: run fstests xfs/538 at
> 2023-11-02 20:23:13
> Nov 02 20:23:14 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Mounting V5
> Filesystem 8e731ab8-42fb-48c5-8877-b4fb526e9609
> Nov 02 20:23:14 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Ending clean
> mount
> Nov 02 20:23:23 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4123, on filesystem "loop5"
> Nov 02 20:23:23 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
> Nov 02 20:23:23 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
> Nov 02 20:23:23 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
> Nov 02 20:23:23 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
> Nov 02 20:23:23 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
> Nov 02 20:23:23 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
> Nov 02 20:23:23 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
> Nov 02 20:23:23 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
> Nov 02 20:23:23 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
> Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: xfs_errortag_test: 43825
> callbacks suppressed
> Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
> Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
> Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
> Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
> Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
> Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
> Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
> Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
> Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
> Nov 02 20:23:28 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
> Nov 02 20:23:33 line-xfs-crc-logdev-rtdev kernel: xfs_errortag_test: 37630
> callbacks suppressed
> Nov 02 20:23:38 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
> Nov 02 20:23:38 line-xfs-crc-logdev-rtdev kernel: XFS (loop5): Injecting
> error
> (false) at file fs/xfs/libxfs/xfs_bmap.c, line 4082, on filesystem "loop5"
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: INFO: task kcompactd0:71
> blocked for more than 120 seconds.
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: Not tainted 6.6.0-rc5
> #2
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: "echo 0 >
> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: task:kcompactd0
> state:D
> stack:0 pid:71 ppid:2 flags:0x00004000
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: Call Trace:
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: <TASK>
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: __schedule+0x3ab/0xab0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: schedule+0x5d/0xe0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: io_schedule+0x42/0x70
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> folio_wait_bit_common+0x12e/0x380
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> __pfx_wake_page_function+0x10/0x10
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> migrate_pages_batch+0x632/0xdb0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> __pfx_compaction_free+0x10/0x10
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> __pfx_compaction_alloc+0x10/0x10
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> __pfx_remove_migration_pte+0x10/0x10
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: migrate_pages+0xc22/0xda0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> __pfx_compaction_alloc+0x10/0x10
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> __pfx_compaction_free+0x10/0x10
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: compact_zone+0x927/0xfe0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> _raw_spin_unlock+0x15/0x30
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> finish_task_switch.isra.0+0x91/0x2a0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? __switch_to+0x106/0x3a0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> proactive_compact_node+0x87/0xe0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? finish_wait+0x41/0x90
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: kcompactd+0x30d/0x3f0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> __pfx_autoremove_wake_function+0x10/0x10
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> __pfx_kcompactd+0x10/0x10
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: kthread+0xf3/0x120
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? __pfx_kthread+0x10/0x10
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ret_from_fork+0x30/0x50
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? __pfx_kthread+0x10/0x10
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> ret_from_fork_asm+0x1b/0x30
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: </TASK>
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: INFO: task
> kworker/5:0:2369803 blocked for more than 120 seconds.
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: Not tainted 6.6.0-rc5
> #2
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: "echo 0 >
> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: task:kworker/5:0
> state:D
> stack:0 pid:2369803 ppid:2 flags:0x00004000
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: Workqueue:
> xfs-inodegc/loop5
> xfs_inodegc_worker [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: Call Trace:
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: <TASK>
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: __schedule+0x3ab/0xab0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> finish_task_switch.isra.0+0x91/0x2a0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: schedule+0x5d/0xe0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> schedule_timeout+0x143/0x150
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> preempt_count_add+0x6a/0xa0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: __down_common+0xf6/0x200
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: down+0x43/0x60
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: xfs_buf_lock+0x2d/0xe0
> [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_buf_find_lock+0x60/0x140
> [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_buf_get_map+0x1bd/0xaf0
> [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> __module_address+0x2f/0xb0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> __module_address+0x2f/0xb0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> preempt_count_add+0x47/0xa0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_buf_read_map+0x54/0x250
> [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? xfs_read_agf+0x90/0x130
> [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_trans_read_buf_map+0x1c2/0x4d0 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? xfs_read_agf+0x90/0x130
> [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: xfs_read_agf+0x90/0x130
> [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_alloc_read_agf+0x5e/0x390 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> __xfs_trans_commit+0xc8/0x390 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_alloc_fix_freelist+0x3cb/0x750 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> unwind_next_frame+0x120/0x890
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> arch_stack_walk+0x88/0xf0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> ret_from_fork_asm+0x1b/0x30
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> __stack_depot_save+0x35/0x480
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_free_extent_fix_freelist+0x61/0xa0 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> __xfs_free_extent+0x8c/0x1f0
> [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_trans_free_extent+0x97/0x270 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_extent_free_finish_item+0xf/0x40 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_defer_finish_noroll+0x19f/0x760 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: xfs_defer_finish+0x11/0xa0
> [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_itruncate_extents_flags+0x14f/0x4c0 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_inactive_truncate+0xbf/0x140 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: xfs_inactive+0x22d/0x290
> [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_inodegc_worker+0xb4/0x1a0 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> process_one_work+0x174/0x340
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: worker_thread+0x277/0x390
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> __pfx_worker_thread+0x10/0x10
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: kthread+0xf3/0x120
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? __pfx_kthread+0x10/0x10
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ret_from_fork+0x30/0x50
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? __pfx_kthread+0x10/0x10
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> ret_from_fork_asm+0x1b/0x30
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: </TASK>
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: INFO: task
> kworker/u17:7:3188941 blocked for more than 120 seconds.
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: Not tainted 6.6.0-rc5
> #2
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: "echo 0 >
> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: task:kworker/u17:7
> state:D
> stack:0 pid:3188941 ppid:2 flags:0x00004000
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: Workqueue: writeback
> wb_workfn (flush-7:5)
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: Call Trace:
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: <TASK>
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: __schedule+0x3ab/0xab0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: schedule+0x5d/0xe0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> schedule_timeout+0x143/0x150
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> _raw_spin_unlock_irqrestore+0x23/0x40
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> preempt_count_add+0x6a/0xa0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> _raw_spin_lock_irqsave+0x23/0x50
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: __down_common+0xf6/0x200
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: down+0x43/0x60
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: xfs_buf_lock+0x2d/0xe0
> [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_buf_find_lock+0x60/0x140
> [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_buf_get_map+0x1bd/0xaf0
> [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> _xfs_trans_bjoin+0x76/0x120 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_buf_read_map+0x54/0x250
> [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? xfs_read_agf+0x90/0x130
> [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_trans_read_buf_map+0x1c2/0x4d0 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? xfs_read_agf+0x90/0x130
> [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: xfs_read_agf+0x90/0x130
> [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_alloc_read_agf+0x5e/0x390 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_alloc_fix_freelist+0x3cb/0x750 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? wb_workfn+0x30f/0x4b0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> set_track_prepare+0x4a/0x70
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> xlog_ticket_alloc+0x29/0xa0 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> xfs_log_reserve+0x9c/0x220
> [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> xfs_trans_reserve+0x199/0x270 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> __pv_queued_spin_lock_slowpath+0x16c/0x380
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_alloc_vextent_prepare_ag+0x2d/0x120 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_alloc_vextent_iterate_ags.constprop.0+0x99/0x230 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_alloc_vextent_first_ag+0xf1/0x130 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_bmap_exact_minlen_extent_alloc+0x138/0x1b0 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_bmapi_allocate+0x282/0x450 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_bmapi_convert_delalloc+0x2ee/0x4e0 [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: xfs_map_blocks+0x1f2/0x590
> [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> iomap_do_writepage+0x28b/0x8d0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> write_cache_pages+0x159/0x3c0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> __pfx_iomap_do_writepage+0x10/0x10
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: iomap_writepages+0x1c/0x40
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> xfs_vm_writepages+0x79/0xb0
> [xfs]
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: do_writepages+0xcb/0x1a0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? touch_atime+0x1c/0x160
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? filemap_read+0x32f/0x340
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> __writeback_single_inode+0x3d/0x350
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? _raw_spin_lock+0x13/0x40
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> writeback_sb_inodes+0x1f5/0x4c0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> __writeback_inodes_wb+0x4c/0xe0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: wb_writeback+0x26b/0x2e0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: wb_workfn+0x30f/0x4b0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> _raw_spin_unlock+0x15/0x30
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> finish_task_switch.isra.0+0x91/0x2a0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? __switch_to+0x106/0x3a0
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> process_one_work+0x174/0x340
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: worker_thread+0x277/0x390
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ?
> __pfx_worker_thread+0x10/0x10
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: kthread+0xf3/0x120
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? __pfx_kthread+0x10/0x10
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ret_from_fork+0x30/0x50
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: ? __pfx_kthread+0x10/0x10
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel:
> ret_from_fork_asm+0x1b/0x30
> Nov 02 20:27:11 line-xfs-crc-logdev-rtdev kernel: </TASK>
I have root caused the bug and hope to post the patches soon.
--
You may reply to this email to add a comment.
You are receiving this mail because:
You are watching the assignee of the bug.
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [Bug 218230] xfstests xfs/538 hung
2023-12-05 14:29 ` [Bug 218230] " bugzilla-daemon
@ 2024-06-24 9:39 ` Chandan Babu R
0 siblings, 0 replies; 4+ messages in thread
From: Chandan Babu R @ 2024-06-24 9:39 UTC (permalink / raw)
To: bugzilla-daemon; +Cc: linux-xfs
>
> I have root caused the bug and hope to post the patches soon.
Sorry, I had forgotten about this bug. Luis reminded me about this
recently. The patches I had written turned out to be incorrect. However, the
following provides the root cause analysis of the bug.
Executing xfs/538 on a Linux v6.6 kernel can lead to the following
deadlock,
|------------------+------------------+------------------|
| Task A | Task B | Task C |
|------------------+------------------+------------------|
| Lock AG 1's AGF | | |
| | Lock AG 2's AGI | |
| | Wait for lock on | |
| | AG 1's AGF | |
| | | Lock AG 3's AGF |
| | | Wait for lock on |
| | | AG 2's AGI |
| Wait for lock on | | |
| AG 3's AGF | | |
|------------------+------------------+------------------|
As illustrated above, Task B and C are violating the AG locking order
rule i.e. AGI/AGF must be locked in increasing AG order and that
within an AG, AGI must be locked before an AGF.
Task B's call trace:
context_switch (kernel/sched/core.c:5382:2)
__schedule (kernel/sched/core.c:6695:8)
schedule (kernel/sched/core.c:6771:3)
schedule_timeout (kernel/time/timer.c:2143:3)
___down_common (kernel/locking/semaphore.c:225:13)
__down_common (kernel/locking/semaphore.c:246:8)
down (kernel/locking/semaphore.c:63:3)
xfs_buf_lock (fs/xfs/xfs_buf.c:1126:2)
xfs_buf_find_lock (fs/xfs/xfs_buf.c:553:3)
xfs_buf_lookup (fs/xfs/xfs_buf.c:592:10)
xfs_buf_get_map (fs/xfs/xfs_buf.c:702:10)
xfs_buf_read_map (fs/xfs/xfs_buf.c:817:10)
xfs_trans_read_buf_map (fs/xfs/xfs_trans_buf.c:289:10)
xfs_trans_read_buf (./fs/xfs/xfs_trans.h:212:9)
xfs_read_agf (fs/xfs/libxfs/xfs_alloc.c:3153:10)
xfs_alloc_read_agf (fs/xfs/libxfs/xfs_alloc.c:3185:10)
xfs_alloc_fix_freelist (fs/xfs/libxfs/xfs_alloc.c:2658:11)
xfs_alloc_vextent_prepare_ag (fs/xfs/libxfs/xfs_alloc.c:3321:10)
xfs_alloc_vextent_iterate_ags (fs/xfs/libxfs/xfs_alloc.c:3506:11)
xfs_alloc_vextent_first_ag (fs/xfs/libxfs/xfs_alloc.c:3641:10)
xfs_bmap_exact_minlen_extent_alloc (fs/xfs/libxfs/xfs_bmap.c:3434:10)
xfs_bmap_alloc_userdata (fs/xfs/libxfs/xfs_bmap.c:4084:10)
xfs_bmapi_allocate (fs/xfs/libxfs/xfs_bmap.c:4129:11)
xfs_bmapi_write (fs/xfs/libxfs/xfs_bmap.c:4438:12)
xfs_symlink (fs/xfs/xfs_symlink.c:271:11)
xfs_vn_symlink (fs/xfs/xfs_iops.c:419:10)
vfs_symlink (fs/namei.c:4480:10)
vfs_symlink (fs/namei.c:4464:5)
do_symlinkat (fs/namei.c:4506:11)
__do_sys_symlink (fs/namei.c:4527:9)
__se_sys_symlink (fs/namei.c:4525:1)
__x64_sys_symlink (fs/namei.c:4525:1)
do_syscall_x64 (arch/x86/entry/common.c:50:14)
do_syscall_64 (arch/x86/entry/common.c:80:7)
entry_SYSCALL_64+0xaa/0x1a6 (arch/x86/entry/entry_64.S:120)
Task B above locked AG 2's AGI, allocated an ondisk inode, then tried
to allocate blocks (required for holding pathname representing the
symbolic link) from AG 1. This happened due to
xfs_bmap_exact_minlen_extent_alloc() iterating across AGs starting
from AG 0.
Task C's call trace:
context_switch (kernel/sched/core.c:5382:2)
__schedule (kernel/sched/core.c:6695:8)
schedule (kernel/sched/core.c:6771:3)
schedule_timeout (kernel/time/timer.c:2143:3)
___down_common (kernel/locking/semaphore.c:225:13)
__down_common (kernel/locking/semaphore.c:246:8)
down (kernel/locking/semaphore.c:63:3)
xfs_buf_lock (fs/xfs/xfs_buf.c:1126:2)
xfs_buf_find_lock (fs/xfs/xfs_buf.c:553:3)
xfs_buf_lookup (fs/xfs/xfs_buf.c:592:10)
xfs_buf_get_map (fs/xfs/xfs_buf.c:702:10)
xfs_buf_read_map (fs/xfs/xfs_buf.c:817:10)
xfs_trans_read_buf_map (fs/xfs/xfs_trans_buf.c:289:10)
xfs_trans_read_buf (./fs/xfs/xfs_trans.h:212:9)
xfs_read_agi (fs/xfs/libxfs/xfs_ialloc.c:2598:10)
xfs_ialloc_read_agi (fs/xfs/libxfs/xfs_ialloc.c:2626:10)
xfs_dialloc_try_ag (fs/xfs/libxfs/xfs_ialloc.c:1690:10)
xfs_dialloc (fs/xfs/libxfs/xfs_ialloc.c:1803:12)
xfs_create (fs/xfs/xfs_inode.c:1020:10)
xfs_generic_create (fs/xfs/xfs_iops.c:199:11)
vfs_mkdir (fs/namei.c:4120:10)
do_mkdirat (fs/namei.c:4143:11)
__do_sys_mkdir (fs/namei.c:4163:9)
__se_sys_mkdir (fs/namei.c:4161:1)
__x64_sys_mkdir (fs/namei.c:4161:1)
do_syscall_x64 (arch/x86/entry/common.c:50:14)
do_syscall_64 (arch/x86/entry/common.c:80:7)
entry_SYSCALL_64+0xaa/0x1a6 (arch/x86/entry/entry_64.S:120)
Task C above was trying to allocate an inode chunk to serve a mkdir()
syscall request. Task C locked AG 3's AGF and searched for the
required extent. However, the only suitable extent was found to be
straddling xfs_alloc_arg->max_agbno. Hence, it moved to the next AG
and ended up wrapping around the AG list.
--
Chandan
^ permalink raw reply [flat|nested] 4+ messages in thread
* [Bug 218230] xfstests xfs/538 hung
2023-12-05 12:31 [Bug 218230] New: xfstests xfs/538 hung bugzilla-daemon
2023-12-05 14:29 ` [Bug 218230] " bugzilla-daemon
@ 2024-06-24 9:42 ` bugzilla-daemon
1 sibling, 0 replies; 4+ messages in thread
From: bugzilla-daemon @ 2024-06-24 9:42 UTC (permalink / raw)
To: linux-xfs
https://bugzilla.kernel.org/show_bug.cgi?id=218230
--- Comment #2 from chandanbabu@kernel.org ---
>
> I have root caused the bug and hope to post the patches soon.
Sorry, I had forgotten about this bug. Luis reminded me about this
recently. The patches I had written turned out to be incorrect. However, the
following provides the root cause analysis of the bug.
Executing xfs/538 on a Linux v6.6 kernel can lead to the following
deadlock,
|------------------+------------------+------------------|
| Task A | Task B | Task C |
|------------------+------------------+------------------|
| Lock AG 1's AGF | | |
| | Lock AG 2's AGI | |
| | Wait for lock on | |
| | AG 1's AGF | |
| | | Lock AG 3's AGF |
| | | Wait for lock on |
| | | AG 2's AGI |
| Wait for lock on | | |
| AG 3's AGF | | |
|------------------+------------------+------------------|
As illustrated above, Task B and C are violating the AG locking order
rule i.e. AGI/AGF must be locked in increasing AG order and that
within an AG, AGI must be locked before an AGF.
Task B's call trace:
context_switch (kernel/sched/core.c:5382:2)
__schedule (kernel/sched/core.c:6695:8)
schedule (kernel/sched/core.c:6771:3)
schedule_timeout (kernel/time/timer.c:2143:3)
___down_common (kernel/locking/semaphore.c:225:13)
__down_common (kernel/locking/semaphore.c:246:8)
down (kernel/locking/semaphore.c:63:3)
xfs_buf_lock (fs/xfs/xfs_buf.c:1126:2)
xfs_buf_find_lock (fs/xfs/xfs_buf.c:553:3)
xfs_buf_lookup (fs/xfs/xfs_buf.c:592:10)
xfs_buf_get_map (fs/xfs/xfs_buf.c:702:10)
xfs_buf_read_map (fs/xfs/xfs_buf.c:817:10)
xfs_trans_read_buf_map (fs/xfs/xfs_trans_buf.c:289:10)
xfs_trans_read_buf (./fs/xfs/xfs_trans.h:212:9)
xfs_read_agf (fs/xfs/libxfs/xfs_alloc.c:3153:10)
xfs_alloc_read_agf (fs/xfs/libxfs/xfs_alloc.c:3185:10)
xfs_alloc_fix_freelist (fs/xfs/libxfs/xfs_alloc.c:2658:11)
xfs_alloc_vextent_prepare_ag (fs/xfs/libxfs/xfs_alloc.c:3321:10)
xfs_alloc_vextent_iterate_ags (fs/xfs/libxfs/xfs_alloc.c:3506:11)
xfs_alloc_vextent_first_ag (fs/xfs/libxfs/xfs_alloc.c:3641:10)
xfs_bmap_exact_minlen_extent_alloc (fs/xfs/libxfs/xfs_bmap.c:3434:10)
xfs_bmap_alloc_userdata (fs/xfs/libxfs/xfs_bmap.c:4084:10)
xfs_bmapi_allocate (fs/xfs/libxfs/xfs_bmap.c:4129:11)
xfs_bmapi_write (fs/xfs/libxfs/xfs_bmap.c:4438:12)
xfs_symlink (fs/xfs/xfs_symlink.c:271:11)
xfs_vn_symlink (fs/xfs/xfs_iops.c:419:10)
vfs_symlink (fs/namei.c:4480:10)
vfs_symlink (fs/namei.c:4464:5)
do_symlinkat (fs/namei.c:4506:11)
__do_sys_symlink (fs/namei.c:4527:9)
__se_sys_symlink (fs/namei.c:4525:1)
__x64_sys_symlink (fs/namei.c:4525:1)
do_syscall_x64 (arch/x86/entry/common.c:50:14)
do_syscall_64 (arch/x86/entry/common.c:80:7)
entry_SYSCALL_64+0xaa/0x1a6 (arch/x86/entry/entry_64.S:120)
Task B above locked AG 2's AGI, allocated an ondisk inode, then tried
to allocate blocks (required for holding pathname representing the
symbolic link) from AG 1. This happened due to
xfs_bmap_exact_minlen_extent_alloc() iterating across AGs starting
from AG 0.
Task C's call trace:
context_switch (kernel/sched/core.c:5382:2)
__schedule (kernel/sched/core.c:6695:8)
schedule (kernel/sched/core.c:6771:3)
schedule_timeout (kernel/time/timer.c:2143:3)
___down_common (kernel/locking/semaphore.c:225:13)
__down_common (kernel/locking/semaphore.c:246:8)
down (kernel/locking/semaphore.c:63:3)
xfs_buf_lock (fs/xfs/xfs_buf.c:1126:2)
xfs_buf_find_lock (fs/xfs/xfs_buf.c:553:3)
xfs_buf_lookup (fs/xfs/xfs_buf.c:592:10)
xfs_buf_get_map (fs/xfs/xfs_buf.c:702:10)
xfs_buf_read_map (fs/xfs/xfs_buf.c:817:10)
xfs_trans_read_buf_map (fs/xfs/xfs_trans_buf.c:289:10)
xfs_trans_read_buf (./fs/xfs/xfs_trans.h:212:9)
xfs_read_agi (fs/xfs/libxfs/xfs_ialloc.c:2598:10)
xfs_ialloc_read_agi (fs/xfs/libxfs/xfs_ialloc.c:2626:10)
xfs_dialloc_try_ag (fs/xfs/libxfs/xfs_ialloc.c:1690:10)
xfs_dialloc (fs/xfs/libxfs/xfs_ialloc.c:1803:12)
xfs_create (fs/xfs/xfs_inode.c:1020:10)
xfs_generic_create (fs/xfs/xfs_iops.c:199:11)
vfs_mkdir (fs/namei.c:4120:10)
do_mkdirat (fs/namei.c:4143:11)
__do_sys_mkdir (fs/namei.c:4163:9)
__se_sys_mkdir (fs/namei.c:4161:1)
__x64_sys_mkdir (fs/namei.c:4161:1)
do_syscall_x64 (arch/x86/entry/common.c:50:14)
do_syscall_64 (arch/x86/entry/common.c:80:7)
entry_SYSCALL_64+0xaa/0x1a6 (arch/x86/entry/entry_64.S:120)
Task C above was trying to allocate an inode chunk to serve a mkdir()
syscall request. Task C locked AG 3's AGF and searched for the
required extent. However, the only suitable extent was found to be
straddling xfs_alloc_arg->max_agbno. Hence, it moved to the next AG
and ended up wrapping around the AG list.
--
You may reply to this email to add a comment.
You are receiving this mail because:
You are watching the assignee of the bug.
^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2024-06-24 9:42 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2023-12-05 12:31 [Bug 218230] New: xfstests xfs/538 hung bugzilla-daemon
2023-12-05 14:29 ` [Bug 218230] " bugzilla-daemon
2024-06-24 9:39 ` Chandan Babu R
2024-06-24 9:42 ` bugzilla-daemon
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox