VMs freeze on "heavy" IO load with tasks blocked/hanging

CaffeineFlo

New Member
Dec 17, 2023
1
0
1
After many frustrating weeks of trying to figure this out on my own, I'm hoping that someone here can help me with this issue.

My setup:
HP DL380 Gen9 w/ P840 HBA set to IT mode (passed through to another VM, intel rmrr and the iommu kernel parameters are applied and that part is working fine)
Proxmox 8.2.2 with ZFS Pool on a recent Crucial SSD with VM os images on. This SSD is connected to the internal SATA controller on the HP ProLiant - not the passed through HBA.
HP amsd is installed

Whenever there's heavy IO, my system will freeze all VMs and "hang" (pretty much rejecting all input) for a couple of minutes. Initially I thought this was a function of oversubscribing the CPU/RAM/HDDs, but after seeing the issue persist with all VMs shut down, I no longer believe this is the issue. This can also be seen even in simple actions such as an `apt upgrade` where package installations can take ages and other actions that might take a while to complete that the server should handle almost instantaneous.

These "hangs" manifest in dmesg like this (just a small example):
Code:
[  492.808491] INFO: task txg_sync:951 blocked for more than 122 seconds.
[  492.808519]       Tainted: P           O       6.8.4-3-pve #1
[  492.808542] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  492.809368] task:txg_sync        state:D stack:0     pid:951   tgid:951   ppid:2      flags:0x00004000
[  492.810201] Call Trace:
[  492.811009]  <TASK>
[  492.811801]  __schedule+0x401/0x15e0
[  492.812594]  ? sg_init_table+0x15/0x50
[  492.813373]  schedule+0x33/0x110
[  492.814150]  schedule_timeout+0x95/0x170
[  492.814930]  ? __pfx_process_timeout+0x10/0x10
[  492.815716]  io_schedule_timeout+0x51/0x80
[  492.816499]  __cv_timedwait_common+0x140/0x180 [spl]
[  492.817285]  ? __pfx_autoremove_wake_function+0x10/0x10
[  492.818026]  __cv_timedwait_io+0x19/0x30 [spl]
[  492.818744]  zio_wait+0x13a/0x2c0 [zfs]
[  492.819916]  vdev_config_sync+0x1ee/0x550 [zfs]
[  492.821094]  spa_sync+0xd4b/0x1030 [zfs]
[  492.822287]  txg_sync_thread+0x1fd/0x390 [zfs]
[  492.823466]  ? __pfx_txg_sync_thread+0x10/0x10 [zfs]
[  492.824624]  ? __pfx_thread_generic_wrapper+0x10/0x10 [spl]
[  492.825296]  thread_generic_wrapper+0x5f/0x70 [spl]
[  492.825971]  kthread+0xf2/0x120
[  492.826621]  ? __pfx_kthread+0x10/0x10
[  492.827268]  ret_from_fork+0x47/0x70
[  492.827918]  ? __pfx_kthread+0x10/0x10
[  492.828564]  ret_from_fork_asm+0x1b/0x30
[  492.829210]  </TASK>
[  492.829855] INFO: task journal-offline:4435 blocked for more than 122 seconds.
[  492.830520]       Tainted: P           O       6.8.4-3-pve #1
[  492.831180] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  492.831856] task:journal-offline state:D stack:0     pid:4435  tgid:1107  ppid:1      flags:0x00004006
[  492.832557] Call Trace:
[  492.833242]  <TASK>
[  492.833926]  __schedule+0x401/0x15e0
[  492.834620]  schedule+0x33/0x110
[  492.835304]  cv_wait_common+0x109/0x140 [spl]
[  492.836021]  ? __pfx_autoremove_wake_function+0x10/0x10
[  492.836724]  __cv_wait+0x15/0x30 [spl]
[  492.837443]  zil_commit_impl+0x2d0/0x1260 [zfs]
[  492.838628]  zil_commit+0x3d/0x80 [zfs]
[  492.839803]  zpl_fsync+0x97/0x1a0 [zfs]
[  492.840947]  vfs_fsync_range+0x4b/0xa0
[  492.841642]  ? __fdget+0xc7/0xf0
[  492.842330]  __x64_sys_fsync+0x3c/0x70
[  492.843025]  x64_sys_call+0x21e3/0x24b0
[  492.843717]  do_syscall_64+0x81/0x170
[  492.844405]  ? syscall_exit_to_user_mode+0x86/0x260
[  492.845107]  ? do_syscall_64+0x8d/0x170
[  492.845800]  ? do_syscall_64+0x8d/0x170
[  492.846493]  ? switch_fpu_return+0x55/0xf0
[  492.847180]  ? syscall_exit_to_user_mode+0x86/0x260
[  492.847879]  ? ret_from_fork+0x29/0x70
[  492.848577]  entry_SYSCALL_64_after_hwframe+0x78/0x80
[  492.849280] RIP: 0033:0x7c26f0ce0b3a
[  492.850012] RSP: 002b:00007c26eefffc40 EFLAGS: 00000293 ORIG_RAX: 000000000000004a
[  492.850726] RAX: ffffffffffffffda RBX: 000062cbec5ee180 RCX: 00007c26f0ce0b3a
[  492.851432] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000016
[  492.852137] RBP: 000062cbec5ee160 R08: 0000000000000000 R09: 00007c26ef0006c0
[  492.852833] R10: 00007c26f0c6af86 R11: 0000000000000293 R12: 000062cbec230c60
[  492.853521] R13: 0000000000000002 R14: 00007ffdff679500 R15: 00007c26ee800000
[  492.854215]  </TASK>
[  492.854908] INFO: task journal-offline:4436 blocked for more than 122 seconds.
[  492.855627]       Tainted: P           O       6.8.4-3-pve #1
[  492.856347] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  492.857085] task:journal-offline state:D stack:0     pid:4436  tgid:1107  ppid:1      flags:0x00004006
[  492.857850] Call Trace:
[  492.858601]  <TASK>
[  492.859340]  __schedule+0x401/0x15e0
[  492.860098]  ? zio_add_child+0x13d/0x160 [zfs]
[  492.861335]  ? __pfx_read_tsc+0x10/0x10
[  492.862083]  ? zio_nowait+0xd5/0x1c0 [zfs]
[  492.863310]  schedule+0x33/0x110
[  492.864060]  cv_wait_common+0x109/0x140 [spl]
[  492.864831]  ? __pfx_autoremove_wake_function+0x10/0x10
[  492.865584]  __cv_wait+0x15/0x30 [spl]
[  492.866352]  zil_commit_impl+0x2d0/0x1260 [zfs]
[  492.867599]  zil_commit+0x3d/0x80 [zfs]
[  492.868820]  zfs_fsync+0xa5/0x140 [zfs]
[  492.870043]  zpl_fsync+0x112/0x1a0 [zfs]
[  492.871230]  vfs_fsync_range+0x4b/0xa0
[  492.871966]  ? __fdget+0xc7/0xf0
[  492.872703]  __x64_sys_fsync+0x3c/0x70
[  492.873433]  x64_sys_call+0x21e3/0x24b0
[  492.874155]  do_syscall_64+0x81/0x170
[  492.874871]  ? __x64_sys_rt_sigprocmask+0x7f/0xe0
[  492.875587]  ? syscall_exit_to_user_mode+0x86/0x260
[  492.876281]  ? do_syscall_64+0x8d/0x170
[  492.876959]  ? restore_fpregs_from_fpstate+0x47/0xf0
[  492.877649]  ? switch_fpu_return+0x55/0xf0
[  492.878334]  ? syscall_exit_to_user_mode+0x86/0x260
[  492.879028]  ? ret_from_fork+0x29/0x70
[  492.879721]  entry_SYSCALL_64_after_hwframe+0x78/0x80
[  492.880412] RIP: 0033:0x7c26f0ce0b3a
[  492.881111] RSP: 002b:00007c26ee5ffc40 EFLAGS: 00000293 ORIG_RAX: 000000000000004a
[  492.881822] RAX: ffffffffffffffda RBX: 000062cbec60e890 RCX: 00007c26f0ce0b3a
[  492.882541] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000023
[  492.883262] RBP: 000062cbec6330e0 R08: 0000000000000000 R09: 00007c26ee6006c0
[  492.883991] R10: 00007c26f0c6af86 R11: 0000000000000293 R12: 000062cbec230c60
[  492.884725] R13: 0000000000000002 R14: 00007ffdff679500 R15: 00007c26ede00000
[  492.885469]  </TASK>

I was able to also exclude for this to be an hardware issue, since I have attached those disk to another HBA (LSI SAS2308) and I'm seeing the exact issue, additionally, I believe I saw this issue as well when I installed proxmox without ZFS (but with LVM?).

I'm hoping someone can make sense of the call traces posted and/or help me further debug this. I'm very eager getting this problem solved and stop sinking all my time into this.

Thanks!
 
Last edited:

About

The Proxmox community has been around for many years and offers help and support for Proxmox VE, Proxmox Backup Server, and Proxmox Mail Gateway.
We think our community is one of the best thanks to people like you!

Get your subscription!

The Proxmox team works very hard to make sure you are running the best software and getting stable updates and security enhancements, as well as quick enterprise support. Tens of thousands of happy customers have a Proxmox subscription. Get yours easily in our online shop.

Buy now!