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.

>
> 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.