On Fri, Dec 3, 2021 at 12:23 PM Chris Murphy [off-list ref] wrote:

I just did a Fedora Rawhide installation in a VM which has kernel
5.16.0-0.rc3.20211201git58e1100fdc59.25.fc36.x86_64

The installation depends on loop mounted squashfs image as the source,
and rsync as the copy mechanism. In top I see quite a few high CPU
btrfs-delalloc as well, more than expected. I'll redo the installation
and see if there were any deadlock warnings or anything like that, and
if not I'll grab sysrq+t during the heavier btrfs CPU usage.

The guest uses virtio drives; and the host uses NVMe.

On second glance, it's mostly btrfs-endio-write that's hitting 50%+
CPU on occasion, but no kernel warnings. sysrq+w caught this:

[ 1864.688477] EXT4-fs (vda2): mounted filesystem with ordered data
mode. Opts: (null). Quota mode: none.
[ 2002.412681] sysrq: Show Blocked State
[ 2002.412939] task:rsync           state:D stack:12856 pid: 3360
ppid:  3358 flags:0x00004000
[ 2002.412957] Call Trace:
[ 2002.412960]  <TASK>
[ 2002.412968]  __schedule+0x3f8/0x1500
[ 2002.412976]  ? lock_is_held_type+0xea/0x140
[ 2002.412984]  ? kvm_sched_clock_read+0x14/0x40
[ 2002.412999]  schedule+0x4e/0xc0
[ 2002.413004]  io_schedule+0x47/0x70
[ 2002.413007]  folio_wait_bit_common+0x14a/0x400
[ 2002.413024]  ? folio_unlock+0x50/0x50
[ 2002.413034]  filemap_get_pages+0x733/0x800
[ 2002.413047]  ? lock_is_held_type+0xea/0x140
[ 2002.413107]  filemap_read+0xb8/0x3f0
[ 2002.413113]  ? sched_clock_cpu+0xb/0xc0
[ 2002.413122]  ? lock_release+0x151/0x460
[ 2002.413133]  ? _copy_to_user+0x63/0x80
[ 2002.413143]  ? lock_is_held_type+0xea/0x140
[ 2002.413156]  new_sync_read+0x108/0x180
[ 2002.413175]  vfs_read+0x125/0x1c0
[ 2002.413184]  ksys_read+0x58/0xd0
[ 2002.413192]  do_syscall_64+0x38/0x90
[ 2002.413199]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 2002.413626] RIP: 0033:0x7f728b42d622
[ 2002.413631] RSP: 002b:00007ffc166df488 EFLAGS: 00000246 ORIG_RAX:
0000000000000000
[ 2002.413636] RAX: ffffffffffffffda RBX: 000055ba4417f9b0 RCX: 00007f728b42d622
[ 2002.413639] RDX: 0000000000012633 RSI: 000055ba44155990 RDI: 0000000000000003
[ 2002.413642] RBP: 0000000000012633 R08: 0000000000000000 R09: 0000000000000000
[ 2002.413644] R10: 0000000004000000 R11: 0000000000000246 R12: 0000000000000000
[ 2002.413647] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000012633
[ 2002.413671]  </TASK>
[ 2163.803113] kworker/dying (7) used greatest stack depth: 11536 bytes left




-- 
Chris Murphy