generic/626 fails on btrfs_simple_zns with a hung task on v5.17-rc7

gistfile1.txt

[ 9442.851891] run fstests generic/626 at 2022-04-03 20:36:35
[ 9443.488457] BTRFS info (device nvme5n1): flagging fs with big metadata feature
[ 9443.493506] BTRFS info (device nvme5n1): using free space tree
[ 9443.497747] BTRFS info (device nvme5n1): has skinny extents
[ 9443.506841] BTRFS info (device nvme5n1): host-managed zoned block device /dev/nvme5n1, 800 zones of 134217728 bytes
[ 9443.513038] BTRFS info (device nvme5n1): zoned mode enabled with zone size 134217728
[ 9443.519748] BTRFS info (device nvme5n1): enabling ssd optimizations
[ 9506.338573] nvme nvme5: I/O 654 QID 2 timeout, aborting
[ 9506.340724] nvme nvme5: Abort status: 0x0
[ 9537.054550] nvme nvme5: I/O 654 QID 2 timeout, reset controller
[ 9668.126546] INFO: task kworker/u16:4:1044590 blocked for more than 120 seconds.
[ 9668.130585]       Tainted: G        W   E     5.17.0-rc7 #1
[ 9668.133497] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 9668.137182] task:kworker/u16:4   state:D stack:    0 pid:1044590 ppid:     2 flags:0x00004000
[ 9668.142428] Workqueue: events_unbound btrfs_async_reclaim_data_space [btrfs]
[ 9668.147029] Call Trace:
[ 9668.149652]  <TASK>
[ 9668.151607]  __schedule+0x300/0x980
[ 9668.154395]  ? slab_free_freelist_hook.constprop.0+0xca/0x140
[ 9668.158093]  schedule+0x4e/0xc0
[ 9668.160730]  schedule_preempt_disabled+0x14/0x20
[ 9668.163953]  __mutex_lock.constprop.0+0x2b8/0x470
[ 9668.167285]  ? _raw_read_unlock+0x18/0x30
[ 9668.170272]  btrfs_create_pending_block_groups+0x21b/0x5b0 [btrfs]
[ 9668.174322]  __btrfs_end_transaction+0x3b/0x240 [btrfs]
[ 9668.177971]  flush_space+0x36f/0x570 [btrfs]
[ 9668.181353]  ? newidle_balance+0x2e4/0x400
[ 9668.184438]  btrfs_async_reclaim_data_space+0x6e/0x170 [btrfs]
[ 9668.187488]  process_one_work+0x1e2/0x3b0
[ 9668.190392]  worker_thread+0x50/0x3a0
[ 9668.192850]  ? rescuer_thread+0x390/0x390
[ 9668.195425]  kthread+0xe5/0x110
[ 9668.197729]  ? kthread_complete_and_exit+0x20/0x20
[ 9668.200451]  ret_from_fork+0x1f/0x30
[ 9668.203520]  </TASK>
[ 9668.205767] INFO: task kworker/u16:9:1359420 blocked for more than 120 seconds.
[ 9668.210177]       Tainted: G        W   E     5.17.0-rc7 #1
[ 9668.213898] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 9668.218134] task:kworker/u16:9   state:D stack:    0 pid:1359420 ppid:     2 flags:0x00004000
[ 9668.222279] Workqueue: writeback wb_workfn (flush-btrfs-1687)
[ 9668.225584] Call Trace:
[ 9668.228059]  <TASK>
[ 9668.230388]  __schedule+0x300/0x980
[ 9668.233023]  schedule+0x4e/0xc0
[ 9668.235395]  schedule_preempt_disabled+0x14/0x20
[ 9668.238232]  __mutex_lock.constprop.0+0x2b8/0x470
[ 9668.241044]  ? unwind_next_frame+0x32b/0x690
[ 9668.243722]  ? process_one_work+0x1e2/0x3b0
[ 9668.246453]  ? kernel_text_address+0x13/0xd0
[ 9668.248941]  btrfs_can_activate_zone+0x37/0x90 [btrfs]
[ 9668.252025]  find_free_extent+0x1098/0x1310 [btrfs]
[ 9668.254472]  btrfs_reserve_extent+0x147/0x290 [btrfs]
[ 9668.255988]  cow_file_range+0x169/0x450 [btrfs]
[ 9668.257247]  ? _raw_spin_unlock+0x16/0x30
[ 9668.258389]  run_delalloc_zoned+0x25/0x90 [btrfs]
[ 9668.260967]  btrfs_run_delalloc_range+0x259/0x650 [btrfs]
[ 9668.263752]  writepage_delalloc+0xc1/0x180 [btrfs]
[ 9668.266410]  __extent_writepage+0x139/0x350 [btrfs]
[ 9668.269185]  extent_write_cache_pages+0x260/0x410 [btrfs]
[ 9668.271195]  extent_writepages+0x7a/0x140 [btrfs]
[ 9668.272971]  do_writepages+0xcc/0x1c0
[ 9668.274545]  ? find_busiest_group+0x41/0x2e0
[ 9668.276177]  __writeback_single_inode+0x41/0x340
[ 9668.277823]  writeback_sb_inodes+0x1fc/0x480
[ 9668.280459]  __writeback_inodes_wb+0x4c/0xe0
[ 9668.284240]  wb_writeback+0x1d7/0x2c0
[ 9668.287447]  wb_workfn+0x2a4/0x510
[ 9668.290104]  ? _raw_spin_unlock+0x16/0x30
[ 9668.292683]  process_one_work+0x1e2/0x3b0
[ 9668.295195]  ? rescuer_thread+0x390/0x390
[ 9668.298409]  worker_thread+0x50/0x3a0
[ 9668.300658]  ? rescuer_thread+0x390/0x390
[ 9668.303048]  kthread+0xe5/0x110
[ 9668.305100]  ? kthread_complete_and_exit+0x20/0x20
[ 9668.307475]  ret_from_fork+0x1f/0x30
[ 9668.308821]  </TASK>
[ 9668.309884] INFO: task btrfs-transacti:1426677 blocked for more than 121 seconds.
[ 9668.312069]       Tainted: G        W   E     5.17.0-rc7 #1
[ 9668.313850] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 9668.316035] task:btrfs-transacti state:D stack:    0 pid:1426677 ppid:     2 flags:0x00004000
[ 9668.319101] Call Trace:
[ 9668.320860]  <TASK>
[ 9668.323648]  __schedule+0x300/0x980
[ 9668.324807]  schedule+0x4e/0xc0
[ 9668.325719]  schedule_timeout+0x115/0x150
[ 9668.326716]  io_schedule_timeout+0x51/0x80
[ 9668.327692]  wait_for_completion_io+0x89/0xe0
[ 9668.328698]  write_all_supers+0x9b4/0xa80 [btrfs]
[ 9668.329780]  ? extent_io_tree_release+0x1a/0x80 [btrfs]
[ 9668.330953]  ? _raw_write_lock_irq+0x20/0x40
[ 9668.331938]  btrfs_commit_transaction+0x7a6/0xb30 [btrfs]
[ 9668.333127]  ? start_transaction+0xc7/0x610 [btrfs]
[ 9668.334241]  transaction_kthread+0x139/0x1b0 [btrfs]
[ 9668.335367]  ? _raw_spin_lock_irqsave+0x26/0x50
[ 9668.336408]  ? btrfs_cleanup_transaction.isra.0+0x580/0x580 [btrfs]
[ 9668.337647]  kthread+0xe5/0x110
[ 9668.338581]  ? kthread_complete_and_exit+0x20/0x20
[ 9668.339655]  ret_from_fork+0x1f/0x30
[ 9668.340587]  </TASK>
[ 9788.958435] INFO: task kworker/u16:4:1044590 blocked for more than 241 seconds.
[ 9788.962037]       Tainted: G        W   E     5.17.0-rc7 #1
[ 9788.964906] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 9788.968631] task:kworker/u16:4   state:D stack:    0 pid:1044590 ppid:     2 flags:0x00004000
[ 9788.973631] Workqueue: events_unbound btrfs_async_reclaim_data_space [btrfs]
[ 9788.977958] Call Trace:
[ 9788.979874]  <TASK>
[ 9788.982168]  __schedule+0x300/0x980
[ 9788.984756]  ? slab_free_freelist_hook.constprop.0+0xca/0x140
[ 9788.988029]  schedule+0x4e/0xc0
[ 9788.990303]  schedule_preempt_disabled+0x14/0x20
[ 9788.991724]  __mutex_lock.constprop.0+0x2b8/0x470
[ 9788.993016]  ? _raw_read_unlock+0x18/0x30
[ 9788.994233]  btrfs_create_pending_block_groups+0x21b/0x5b0 [btrfs]
[ 9788.995830]  __btrfs_end_transaction+0x3b/0x240 [btrfs]
[ 9788.997204]  flush_space+0x36f/0x570 [btrfs]
[ 9788.998401]  ? newidle_balance+0x2e4/0x400
[ 9789.002283]  btrfs_async_reclaim_data_space+0x6e/0x170 [btrfs]
[ 9789.003499]  process_one_work+0x1e2/0x3b0
[ 9789.004437]  worker_thread+0x50/0x3a0
[ 9789.005309]  ? rescuer_thread+0x390/0x390
[ 9789.006278]  kthread+0xe5/0x110
[ 9789.007107]  ? kthread_complete_and_exit+0x20/0x20
[ 9789.008165]  ret_from_fork+0x1f/0x30
[ 9789.009041]  </TASK>
...