Hi,
in the last week, after updating to 6.6.92, we’ve encountered a number of VMs reporting temporarily hung tasks blocking the whole system for a few minutes. They unblock by themselves and have similar tracebacks.
The IO PSIs show 100% pressure for that time, but the underlying devices are still processing read and write IO (well within their capacity). I’ve eliminated the underlying storage (Ceph) as the source of problems as I couldn’t find any latency outliers or significant queuing during that time.
I’ve seen somewhat similar reports on 6.6.88 and 6.6.77, but those might have been different outliers.
I’m attaching 3 logs - my intuition and the data so far leads me to consider this might be a kernel bug. I haven’t found a way to reproduce this, yet.
Regards, Christian
On Thu, Jun 12, 2025 at 03:37:10PM +0200, Christian Theune wrote:
Hi,
in the last week, after updating to 6.6.92, we’ve encountered a number of VMs reporting temporarily hung tasks blocking the whole system for a few minutes. They unblock by themselves and have similar tracebacks.
The IO PSIs show 100% pressure for that time, but the underlying devices are still processing read and write IO (well within their capacity). I’ve eliminated the underlying storage (Ceph) as the source of problems as I couldn’t find any latency outliers or significant queuing during that time.
I’ve seen somewhat similar reports on 6.6.88 and 6.6.77, but those might have been different outliers.
I’m attaching 3 logs - my intuition and the data so far leads me to consider this might be a kernel bug. I haven’t found a way to reproduce this, yet.
From a first glance, these machines are struggling because IO contention as you mentioned, more often than not they seem to be stalling waiting for log space to be freed, so any operation in the FS gets throttled while the journal isn't written back. If you have a small enough journal it will need to issue IO often enough to cause IO contention. So, I'd point it to a slow storage or small enough log area (or both).
There has been a few improvements though during Linux 6.9 on the log performance, but I can't tell if you have any of those improvements around.
I'd suggest you trying to run a newer upstream kernel, otherwise you'll get very limited support from the upstream community. If you can't, I'd suggest you reporting this issue to your vendor, so they can track what you are/are not using in your current kernel.
FWIW, I'm not sure if NixOS uses linux-stable kernels or not. If that's the case, running a newer kernel suggestion is still valid.
Carlos
Regards, Christian
-- Christian Theune · ct@flyingcircus.io · +49 345 219401 0 Flying Circus Internet Operations GmbH · https://flyingcircus.io Leipziger Str. 70/71 · 06108 Halle (Saale) · Deutschland HR Stendal HRB 21169 · Geschäftsführer: Christian Theune, Christian Zagrodnick
Jun 10 16:03:08 machine1 kernel: INFO: task xfsaild/vda1:188 blocked for more than 122 seconds. Jun 10 16:03:08 machine1 kernel: Not tainted 6.6.92 #1-NixOS Jun 10 16:03:08 machine1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 10 16:03:08 machine1 kernel: task:xfsaild/vda1 state:D stack:0 pid:188 ppid:2 flags:0x00004000 Jun 10 16:03:08 machine1 kernel: Call Trace: Jun 10 16:03:08 machine1 kernel: <TASK> Jun 10 16:03:08 machine1 kernel: __schedule+0x3fc/0x1440 Jun 10 16:03:08 machine1 kernel: schedule+0x5e/0xe0 Jun 10 16:03:08 machine1 kernel: schedule_timeout+0x159/0x170 Jun 10 16:03:08 machine1 kernel: wait_for_completion+0x8a/0x160 Jun 10 16:03:08 machine1 kernel: __flush_workqueue+0x157/0x440 Jun 10 16:03:08 machine1 kernel: ? finish_task_switch.isra.0+0x94/0x300 Jun 10 16:03:08 machine1 kernel: xlog_cil_push_now.isra.0+0x5e/0xa0 [xfs] Jun 10 16:03:08 machine1 kernel: xlog_cil_force_seq+0x69/0x250 [xfs] Jun 10 16:03:08 machine1 kernel: ? __timer_delete_sync+0x7d/0xe0 Jun 10 16:03:08 machine1 kernel: xfs_log_force+0x7e/0x240 [xfs] Jun 10 16:03:08 machine1 kernel: xfsaild+0x17d/0x870 [xfs] Jun 10 16:03:08 machine1 kernel: ? __set_cpus_allowed_ptr_locked+0xf4/0x1c0 Jun 10 16:03:08 machine1 kernel: ? __pfx_xfsaild+0x10/0x10 [xfs] Jun 10 16:03:08 machine1 kernel: kthread+0xe8/0x120 Jun 10 16:03:08 machine1 kernel: ? __pfx_kthread+0x10/0x10 Jun 10 16:03:08 machine1 kernel: ret_from_fork+0x34/0x50 Jun 10 16:03:08 machine1 kernel: ? __pfx_kthread+0x10/0x10 Jun 10 16:03:08 machine1 kernel: ret_from_fork_asm+0x1b/0x30 Jun 10 16:03:08 machine1 kernel: </TASK> Jun 10 16:03:08 machine1 kernel: INFO: task systemd-journal:407 blocked for more than 122 seconds. Jun 10 16:03:08 machine1 kernel: Not tainted 6.6.92 #1-NixOS Jun 10 16:03:08 machine1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 10 16:03:08 machine1 kernel: task:systemd-journal state:D stack:0 pid:407 ppid:1 flags:0x00000002 Jun 10 16:03:08 machine1 kernel: Call Trace: Jun 10 16:03:08 machine1 kernel: <TASK> Jun 10 16:03:08 machine1 kernel: __schedule+0x3fc/0x1440 Jun 10 16:03:08 machine1 kernel: ? __mod_memcg_lruvec_state+0x58/0xb0 Jun 10 16:03:08 machine1 kernel: schedule+0x5e/0xe0 Jun 10 16:03:08 machine1 kernel: xlog_grant_head_wait+0xba/0x220 [xfs] Jun 10 16:03:08 machine1 kernel: xlog_grant_head_check+0xdf/0x110 [xfs] Jun 10 16:03:08 machine1 kernel: xfs_log_reserve+0xc4/0x1f0 [xfs] Jun 10 16:03:08 machine1 kernel: xfs_trans_reserve+0x138/0x170 [xfs] Jun 10 16:03:08 machine1 kernel: xfs_trans_alloc+0xe5/0x230 [xfs] Jun 10 16:03:08 machine1 kernel: xfs_vn_update_time+0x90/0x1b0 [xfs] Jun 10 16:03:08 machine1 kernel: file_update_time+0x61/0x90 Jun 10 16:03:08 machine1 kernel: __xfs_filemap_fault.constprop.0+0xd4/0x1d0 [xfs] Jun 10 16:03:08 machine1 kernel: do_page_mkwrite+0x50/0xb0 Jun 10 16:03:08 machine1 kernel: do_wp_page+0x431/0xb80 Jun 10 16:03:08 machine1 kernel: ? filename_lookup+0xe8/0x200 Jun 10 16:03:08 machine1 kernel: ? __pte_offset_map+0x1b/0x190 Jun 10 16:03:08 machine1 kernel: __handle_mm_fault+0xbcf/0xd90 Jun 10 16:03:08 machine1 kernel: handle_mm_fault+0x17f/0x370 Jun 10 16:03:08 machine1 kernel: do_user_addr_fault+0x1ee/0x630 Jun 10 16:03:08 machine1 kernel: exc_page_fault+0x71/0x160 Jun 10 16:03:08 machine1 kernel: asm_exc_page_fault+0x26/0x30 Jun 10 16:03:08 machine1 kernel: RIP: 0033:0x7fc7798def5f Jun 10 16:03:08 machine1 kernel: RSP: 002b:00007ffd050a0ee0 EFLAGS: 00010246 Jun 10 16:03:08 machine1 kernel: RAX: 00007fc767892d68 RBX: 000055d3034cd900 RCX: 00007fc77999d300 Jun 10 16:03:08 machine1 kernel: RDX: 0000000000000000 RSI: 00007fc767892d68 RDI: 000055d3034cd900 Jun 10 16:03:08 machine1 kernel: RBP: 0000000002bc3c40 R08: 00000000000000c9 R09: 000055d3034cd938 Jun 10 16:03:08 machine1 kernel: R10: 0000000000000000 R11: 0000000000000000 R12: 00007ffd050a1b00 Jun 10 16:03:08 machine1 kernel: R13: 00000000001df770 R14: 00007ffd050a10a8 R15: 00007ffd050a10a0 Jun 10 16:03:08 machine1 kernel: </TASK> Jun 10 16:03:08 machine1 kernel: INFO: task systemd-timesyn:804 blocked for more than 122 seconds. Jun 10 16:03:08 machine1 kernel: Not tainted 6.6.92 #1-NixOS Jun 10 16:03:08 machine1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 10 16:03:08 machine1 kernel: task:systemd-timesyn state:D stack:0 pid:804 ppid:1 flags:0x00000002 Jun 10 16:03:08 machine1 kernel: Call Trace: Jun 10 16:03:08 machine1 kernel: <TASK> Jun 10 16:03:08 machine1 kernel: __schedule+0x3fc/0x1440 Jun 10 16:03:08 machine1 kernel: schedule+0x5e/0xe0 Jun 10 16:03:08 machine1 kernel: xlog_grant_head_wait+0xba/0x220 [xfs] Jun 10 16:03:08 machine1 kernel: xlog_grant_head_check+0xdf/0x110 [xfs] Jun 10 16:03:08 machine1 kernel: xfs_log_reserve+0xc4/0x1f0 [xfs] Jun 10 16:03:08 machine1 kernel: xfs_trans_reserve+0x138/0x170 [xfs] Jun 10 16:03:08 machine1 kernel: xfs_trans_alloc+0xe5/0x230 [xfs] Jun 10 16:03:08 machine1 kernel: xfs_trans_alloc_ichange+0x85/0x200 [xfs] Jun 10 16:03:08 machine1 kernel: xfs_setattr_nonsize+0x9a/0x390 [xfs] Jun 10 16:03:08 machine1 kernel: notify_change+0x1f5/0x4c0 Jun 10 16:03:08 machine1 kernel: ? vfs_utimes+0x141/0x270 Jun 10 16:03:08 machine1 kernel: vfs_utimes+0x141/0x270 Jun 10 16:03:08 machine1 kernel: do_utimes+0xf8/0x160 Jun 10 16:03:08 machine1 kernel: __x64_sys_utimensat+0xa1/0xf0 Jun 10 16:03:08 machine1 kernel: do_syscall_64+0x39/0x90 Jun 10 16:03:08 machine1 kernel: entry_SYSCALL_64_after_hwframe+0x78/0xe2 Jun 10 16:03:08 machine1 kernel: RIP: 0033:0x7f0c14f0ae53 Jun 10 16:03:08 machine1 kernel: RSP: 002b:00007fff88b9d388 EFLAGS: 00000206 ORIG_RAX: 0000000000000118 Jun 10 16:03:08 machine1 kernel: RAX: ffffffffffffffda RBX: 0000000000000011 RCX: 00007f0c14f0ae53 Jun 10 16:03:08 machine1 kernel: RDX: 0000000000000000 RSI: 00007f0c15320f09 RDI: 0000000000000011 Jun 10 16:03:08 machine1 kernel: RBP: 0000000000000000 R08: 00000000ffffffff R09: 00000000ffffffff Jun 10 16:03:08 machine1 kernel: R10: 0000000000001000 R11: 0000000000000206 R12: 000055aa6cdbc000 Jun 10 16:03:08 machine1 kernel: R13: 00000000ffffffff R14: ffffffffffffffff R15: 00000000ffffffff Jun 10 16:03:08 machine1 kernel: </TASK> Jun 10 16:03:08 machine1 kernel: INFO: task filebeat:1200 blocked for more than 122 seconds. Jun 10 16:03:08 machine1 kernel: Not tainted 6.6.92 #1-NixOS Jun 10 16:03:08 machine1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 10 16:03:08 machine1 kernel: task:filebeat state:D stack:0 pid:1200 ppid:1 flags:0x00000002 Jun 10 16:03:08 machine1 kernel: Call Trace: Jun 10 16:03:08 machine1 kernel: <TASK> Jun 10 16:03:08 machine1 kernel: __schedule+0x3fc/0x1440 Jun 10 16:03:08 machine1 kernel: ? ip6_input_finish+0x48/0x70 Jun 10 16:03:11 machine1 kernel: ? _copy_to_iter+0x62/0x4b0 Jun 10 16:03:11 machine1 kernel: ? free_unref_page_commit+0x76/0x180 Jun 10 16:03:11 machine1 kernel: schedule+0x5e/0xe0 Jun 10 16:03:11 machine1 kernel: xlog_grant_head_wait+0xba/0x220 [xfs] Jun 10 16:03:11 machine1 kernel: xlog_grant_head_check+0xdf/0x110 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_log_reserve+0xc4/0x1f0 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_trans_reserve+0x138/0x170 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_trans_alloc+0xe5/0x230 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_vn_update_time+0x90/0x1b0 [xfs] Jun 10 16:03:11 machine1 kernel: kiocb_modified+0x9b/0xd0 Jun 10 16:03:11 machine1 kernel: xfs_file_write_checks+0x1dd/0x280 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_file_buffered_write+0x60/0x2b0 [xfs] Jun 10 16:03:11 machine1 kernel: ? selinux_file_permission+0x119/0x160 Jun 10 16:03:11 machine1 kernel: vfs_write+0x24f/0x430 Jun 10 16:03:11 machine1 kernel: ksys_write+0x6f/0xf0 Jun 10 16:03:11 machine1 kernel: do_syscall_64+0x39/0x90 Jun 10 16:03:11 machine1 kernel: entry_SYSCALL_64_after_hwframe+0x78/0xe2 Jun 10 16:03:11 machine1 kernel: RIP: 0033:0x116ac4e Jun 10 16:03:11 machine1 kernel: RSP: 002b:000000c000925600 EFLAGS: 00000212 ORIG_RAX: 0000000000000001 Jun 10 16:03:11 machine1 kernel: RAX: ffffffffffffffda RBX: 0000000000000006 RCX: 000000000116ac4e Jun 10 16:03:11 machine1 kernel: RDX: 0000000000000175 RSI: 000000c000602000 RDI: 0000000000000006 Jun 10 16:03:11 machine1 kernel: RBP: 000000c000925640 R08: 0000000000000000 R09: 0000000000000000 Jun 10 16:03:11 machine1 kernel: R10: 0000000000000000 R11: 0000000000000212 R12: 000000c000925770 Jun 10 16:03:11 machine1 kernel: R13: 0000000000000010 R14: 000000c00044ea80 R15: 000000c00066c7e0 Jun 10 16:03:11 machine1 kernel: </TASK> Jun 10 16:03:11 machine1 kernel: INFO: task slapd:1168 blocked for more than 122 seconds. Jun 10 16:03:11 machine1 kernel: Not tainted 6.6.92 #1-NixOS Jun 10 16:03:11 machine1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 10 16:03:11 machine1 kernel: task:slapd state:D stack:0 pid:1168 ppid:1 flags:0x00000002 Jun 10 16:03:11 machine1 kernel: Call Trace: Jun 10 16:03:11 machine1 kernel: <TASK> Jun 10 16:03:11 machine1 kernel: __schedule+0x3fc/0x1440 Jun 10 16:03:11 machine1 kernel: schedule+0x5e/0xe0 Jun 10 16:03:11 machine1 kernel: xlog_grant_head_wait+0xba/0x220 [xfs] Jun 10 16:03:11 machine1 kernel: xlog_grant_head_check+0xdf/0x110 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_log_reserve+0xc4/0x1f0 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_trans_reserve+0x138/0x170 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_trans_alloc+0xe5/0x230 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_vn_update_time+0x90/0x1b0 [xfs] Jun 10 16:03:11 machine1 kernel: file_update_time+0x61/0x90 Jun 10 16:03:11 machine1 kernel: __xfs_filemap_fault.constprop.0+0xd4/0x1d0 [xfs] Jun 10 16:03:11 machine1 kernel: do_page_mkwrite+0x50/0xb0 Jun 10 16:03:11 machine1 kernel: do_wp_page+0x431/0xb80 Jun 10 16:03:11 machine1 kernel: ? __pte_offset_map+0x1b/0x190 Jun 10 16:03:11 machine1 kernel: __handle_mm_fault+0xbcf/0xd90 Jun 10 16:03:11 machine1 kernel: handle_mm_fault+0x17f/0x370 Jun 10 16:03:11 machine1 kernel: do_user_addr_fault+0x1ee/0x630 Jun 10 16:03:11 machine1 kernel: exc_page_fault+0x71/0x160 Jun 10 16:03:11 machine1 kernel: asm_exc_page_fault+0x26/0x30 Jun 10 16:03:11 machine1 kernel: RIP: 0033:0x4d0c04 Jun 10 16:03:11 machine1 kernel: RSP: 002b:00007efe565fd2a0 EFLAGS: 00010246 Jun 10 16:03:11 machine1 kernel: RAX: 000000000000a50b RBX: 00007efe4811ddd0 RCX: 0000000000000000 Jun 10 16:03:11 machine1 kernel: RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000 Jun 10 16:03:11 machine1 kernel: RBP: 0000000039dfec40 R08: 0000000000000000 R09: 0000000000000000 Jun 10 16:03:11 machine1 kernel: R10: 0000000000000000 R11: 0000000000000000 R12: 00007efe9377d080 Jun 10 16:03:11 machine1 kernel: R13: 0000000000020000 R14: 000000000000048b R15: 00007efe9377d000 Jun 10 16:03:11 machine1 kernel: </TASK> Jun 10 16:03:11 machine1 kernel: INFO: task slapd:1253 blocked for more than 122 seconds. Jun 10 16:03:11 machine1 kernel: Not tainted 6.6.92 #1-NixOS Jun 10 16:03:11 machine1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 10 16:03:11 machine1 kernel: task:slapd state:D stack:0 pid:1253 ppid:1 flags:0x00000002 Jun 10 16:03:11 machine1 kernel: Call Trace: Jun 10 16:03:11 machine1 kernel: <TASK> Jun 10 16:03:11 machine1 kernel: __schedule+0x3fc/0x1440 Jun 10 16:03:11 machine1 kernel: schedule+0x5e/0xe0 Jun 10 16:03:11 machine1 kernel: xlog_grant_head_wait+0xba/0x220 [xfs] Jun 10 16:03:11 machine1 kernel: xlog_grant_head_check+0xdf/0x110 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_log_reserve+0xc4/0x1f0 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_trans_reserve+0x138/0x170 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_trans_alloc+0xe5/0x230 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_vn_update_time+0x90/0x1b0 [xfs] Jun 10 16:03:11 machine1 kernel: file_update_time+0x61/0x90 Jun 10 16:03:11 machine1 kernel: __xfs_filemap_fault.constprop.0+0xd4/0x1d0 [xfs] Jun 10 16:03:11 machine1 kernel: do_page_mkwrite+0x50/0xb0 Jun 10 16:03:11 machine1 kernel: do_wp_page+0x431/0xb80 Jun 10 16:03:11 machine1 kernel: ? __pte_offset_map+0x1b/0x190 Jun 10 16:03:11 machine1 kernel: __handle_mm_fault+0xbcf/0xd90 Jun 10 16:03:11 machine1 kernel: handle_mm_fault+0x17f/0x370 Jun 10 16:03:11 machine1 kernel: do_user_addr_fault+0x1ee/0x630 Jun 10 16:03:11 machine1 kernel: exc_page_fault+0x71/0x160 Jun 10 16:03:11 machine1 kernel: asm_exc_page_fault+0x26/0x30 Jun 10 16:03:11 machine1 kernel: RIP: 0033:0x4d0c04 Jun 10 16:03:11 machine1 kernel: RSP: 002b:00007efe47ffe2a0 EFLAGS: 00010246 Jun 10 16:03:11 machine1 kernel: RAX: 000000000000a50b RBX: 00007efe40013590 RCX: 0000000000000000 Jun 10 16:03:11 machine1 kernel: RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000 Jun 10 16:03:11 machine1 kernel: RBP: 0000000039dfec40 R08: 0000000000000000 R09: 0000000000000000 Jun 10 16:03:11 machine1 kernel: R10: 0000000000000000 R11: 0000000000000000 R12: 00007efe9377d100 Jun 10 16:03:11 machine1 kernel: R13: 0000000000020000 R14: 000000000000048b R15: 00007efe9377d000 Jun 10 16:03:11 machine1 kernel: </TASK> Jun 10 16:03:11 machine1 kernel: INFO: task slapd:2783 blocked for more than 122 seconds. Jun 10 16:03:11 machine1 kernel: Not tainted 6.6.92 #1-NixOS Jun 10 16:03:11 machine1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 10 16:03:11 machine1 kernel: task:slapd state:D stack:0 pid:2783 ppid:1 flags:0x00000002 Jun 10 16:03:11 machine1 kernel: Call Trace: Jun 10 16:03:11 machine1 kernel: <TASK> Jun 10 16:03:11 machine1 kernel: __schedule+0x3fc/0x1440 Jun 10 16:03:11 machine1 kernel: schedule+0x5e/0xe0 Jun 10 16:03:11 machine1 kernel: xlog_grant_head_wait+0xba/0x220 [xfs] Jun 10 16:03:11 machine1 kernel: xlog_grant_head_check+0xdf/0x110 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_log_reserve+0xc4/0x1f0 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_trans_reserve+0x138/0x170 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_trans_alloc+0xe5/0x230 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_vn_update_time+0x90/0x1b0 [xfs] Jun 10 16:03:11 machine1 kernel: file_update_time+0x61/0x90 Jun 10 16:03:11 machine1 kernel: __xfs_filemap_fault.constprop.0+0xd4/0x1d0 [xfs] Jun 10 16:03:11 machine1 kernel: do_page_mkwrite+0x50/0xb0 Jun 10 16:03:11 machine1 kernel: do_wp_page+0x431/0xb80 Jun 10 16:03:11 machine1 kernel: ? __pte_offset_map+0x1b/0x190 Jun 10 16:03:11 machine1 kernel: __handle_mm_fault+0xbcf/0xd90 Jun 10 16:03:11 machine1 kernel: handle_mm_fault+0x17f/0x370 Jun 10 16:03:11 machine1 kernel: do_user_addr_fault+0x1ee/0x630 Jun 10 16:03:11 machine1 kernel: exc_page_fault+0x71/0x160 Jun 10 16:03:11 machine1 kernel: asm_exc_page_fault+0x26/0x30 Jun 10 16:03:11 machine1 kernel: RIP: 0033:0x4d0c04 Jun 10 16:03:11 machine1 kernel: RSP: 002b:00007efe44df92a0 EFLAGS: 00010246 Jun 10 16:03:11 machine1 kernel: RAX: 000000000000a50b RBX: 00007efe38132790 RCX: 0000000000000000 Jun 10 16:03:11 machine1 kernel: RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000 Jun 10 16:03:11 machine1 kernel: RBP: 0000000039dfec40 R08: 0000000000000000 R09: 0000000000000000 Jun 10 16:03:11 machine1 kernel: R10: 0000000000000000 R11: 0000000000000000 R12: 00007efe9377d180 Jun 10 16:03:11 machine1 kernel: R13: 0000000000020000 R14: 000000000000048b R15: 00007efe9377d000 Jun 10 16:03:11 machine1 kernel: </TASK> Jun 10 16:03:11 machine1 kernel: INFO: task slapd:2787 blocked for more than 122 seconds. Jun 10 16:03:11 machine1 kernel: Not tainted 6.6.92 #1-NixOS Jun 10 16:03:11 machine1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 10 16:03:11 machine1 kernel: task:slapd state:D stack:0 pid:2787 ppid:1 flags:0x00000002 Jun 10 16:03:11 machine1 kernel: Call Trace: Jun 10 16:03:11 machine1 kernel: <TASK> Jun 10 16:03:11 machine1 kernel: __schedule+0x3fc/0x1440 Jun 10 16:03:11 machine1 kernel: ? raw6_local_deliver+0x12a/0x250 Jun 10 16:03:11 machine1 kernel: schedule+0x5e/0xe0 Jun 10 16:03:11 machine1 kernel: xlog_grant_head_wait+0xba/0x220 [xfs] Jun 10 16:03:11 machine1 kernel: xlog_grant_head_check+0xdf/0x110 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_log_reserve+0xc4/0x1f0 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_trans_reserve+0x138/0x170 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_trans_alloc+0xe5/0x230 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_vn_update_time+0x90/0x1b0 [xfs] Jun 10 16:03:11 machine1 kernel: file_update_time+0x61/0x90 Jun 10 16:03:11 machine1 kernel: __xfs_filemap_fault.constprop.0+0xd4/0x1d0 [xfs] Jun 10 16:03:11 machine1 kernel: do_page_mkwrite+0x50/0xb0 Jun 10 16:03:11 machine1 kernel: do_wp_page+0x431/0xb80 Jun 10 16:03:11 machine1 kernel: ? __pte_offset_map+0x1b/0x190 Jun 10 16:03:11 machine1 kernel: __handle_mm_fault+0xbcf/0xd90 Jun 10 16:03:11 machine1 kernel: handle_mm_fault+0x17f/0x370 Jun 10 16:03:11 machine1 kernel: do_user_addr_fault+0x1ee/0x630 Jun 10 16:03:11 machine1 kernel: exc_page_fault+0x71/0x160 Jun 10 16:03:11 machine1 kernel: asm_exc_page_fault+0x26/0x30 Jun 10 16:03:11 machine1 kernel: RIP: 0033:0x4d0c04 Jun 10 16:03:11 machine1 kernel: RSP: 002b:00007efe3d0fa2a0 EFLAGS: 00010246 Jun 10 16:03:11 machine1 kernel: RAX: 000000000000a50b RBX: 00007efe34013c80 RCX: 0000000000000000 Jun 10 16:03:11 machine1 kernel: RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000 Jun 10 16:03:11 machine1 kernel: RBP: 0000000039dfec40 R08: 0000000000000000 R09: 0000000000000000 Jun 10 16:03:11 machine1 kernel: R10: 0000000000000000 R11: 0000000000000000 R12: 00007efe9377d1c0 Jun 10 16:03:11 machine1 kernel: R13: 0000000000020000 R14: 000000000000048b R15: 00007efe9377d000 Jun 10 16:03:11 machine1 kernel: </TASK> Jun 10 16:03:11 machine1 kernel: INFO: task slapd:2791 blocked for more than 122 seconds. Jun 10 16:03:11 machine1 kernel: Not tainted 6.6.92 #1-NixOS Jun 10 16:03:11 machine1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 10 16:03:11 machine1 kernel: task:slapd state:D stack:0 pid:2791 ppid:1 flags:0x00000002 Jun 10 16:03:11 machine1 kernel: Call Trace: Jun 10 16:03:11 machine1 kernel: <TASK> Jun 10 16:03:11 machine1 kernel: __schedule+0x3fc/0x1440 Jun 10 16:03:11 machine1 kernel: schedule+0x5e/0xe0 Jun 10 16:03:11 machine1 kernel: xlog_grant_head_wait+0xba/0x220 [xfs] Jun 10 16:03:11 machine1 kernel: xlog_grant_head_check+0xdf/0x110 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_log_reserve+0xc4/0x1f0 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_trans_reserve+0x138/0x170 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_trans_alloc+0xe5/0x230 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_vn_update_time+0x90/0x1b0 [xfs] Jun 10 16:03:11 machine1 kernel: file_update_time+0x61/0x90 Jun 10 16:03:11 machine1 kernel: __xfs_filemap_fault.constprop.0+0xd4/0x1d0 [xfs] Jun 10 16:03:11 machine1 kernel: do_page_mkwrite+0x50/0xb0 Jun 10 16:03:11 machine1 kernel: do_wp_page+0x431/0xb80 Jun 10 16:03:11 machine1 kernel: ? __pte_offset_map+0x1b/0x190 Jun 10 16:03:11 machine1 kernel: __handle_mm_fault+0xbcf/0xd90 Jun 10 16:03:11 machine1 kernel: handle_mm_fault+0x17f/0x370 Jun 10 16:03:11 machine1 kernel: do_user_addr_fault+0x1ee/0x630 Jun 10 16:03:11 machine1 kernel: exc_page_fault+0x71/0x160 Jun 10 16:03:11 machine1 kernel: asm_exc_page_fault+0x26/0x30 Jun 10 16:03:11 machine1 kernel: RIP: 0033:0x4d0c04 Jun 10 16:03:11 machine1 kernel: RSP: 002b:00007efe2ddea250 EFLAGS: 00010246 Jun 10 16:03:11 machine1 kernel: RAX: 000000000000a50b RBX: 00007efe28203aa0 RCX: 0000000000000000 Jun 10 16:03:11 machine1 kernel: RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000 Jun 10 16:03:11 machine1 kernel: RBP: 0000000039dfec40 R08: 0000000000000000 R09: 0000000000000000 Jun 10 16:03:11 machine1 kernel: R10: 0000000000000000 R11: 0000000000000000 R12: 00007efe9377d240 Jun 10 16:03:11 machine1 kernel: R13: 0000000000020000 R14: 000000000000048b R15: 00007efe9377d000 Jun 10 16:03:11 machine1 kernel: </TASK> Jun 10 16:03:11 machine1 kernel: INFO: task slapd:2792 blocked for more than 122 seconds. Jun 10 16:03:11 machine1 kernel: Not tainted 6.6.92 #1-NixOS Jun 10 16:03:11 machine1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 10 16:03:11 machine1 kernel: task:slapd state:D stack:0 pid:2792 ppid:1 flags:0x00000002 Jun 10 16:03:11 machine1 kernel: Call Trace: Jun 10 16:03:11 machine1 kernel: <TASK> Jun 10 16:03:11 machine1 kernel: __schedule+0x3fc/0x1440 Jun 10 16:03:11 machine1 kernel: schedule+0x5e/0xe0 Jun 10 16:03:11 machine1 kernel: xlog_grant_head_wait+0xba/0x220 [xfs] Jun 10 16:03:11 machine1 kernel: xlog_grant_head_check+0xdf/0x110 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_log_reserve+0xc4/0x1f0 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_trans_reserve+0x138/0x170 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_trans_alloc+0xe5/0x230 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_vn_update_time+0x90/0x1b0 [xfs] Jun 10 16:03:11 machine1 kernel: file_update_time+0x61/0x90 Jun 10 16:03:11 machine1 kernel: __xfs_filemap_fault.constprop.0+0xd4/0x1d0 [xfs] Jun 10 16:03:11 machine1 kernel: do_page_mkwrite+0x50/0xb0 Jun 10 16:03:11 machine1 kernel: do_wp_page+0x431/0xb80 Jun 10 16:03:11 machine1 kernel: ? __pte_offset_map+0x1b/0x190 Jun 10 16:03:11 machine1 kernel: __handle_mm_fault+0xbcf/0xd90 Jun 10 16:03:11 machine1 kernel: handle_mm_fault+0x17f/0x370 Jun 10 16:03:11 machine1 kernel: do_user_addr_fault+0x1ee/0x630 Jun 10 16:03:11 machine1 kernel: exc_page_fault+0x71/0x160 Jun 10 16:03:11 machine1 kernel: asm_exc_page_fault+0x26/0x30 Jun 10 16:03:11 machine1 kernel: RIP: 0033:0x4d0c04 Jun 10 16:03:11 machine1 kernel: RSP: 002b:00007efe2d5fa2a0 EFLAGS: 00010246 Jun 10 16:03:11 machine1 kernel: RAX: 000000000000a50b RBX: 00007efe34135cb0 RCX: 0000000000000000 Jun 10 16:03:11 machine1 kernel: RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000 Jun 10 16:03:11 machine1 kernel: RBP: 0000000039dfec40 R08: 0000000000000000 R09: 0000000000000000 Jun 10 16:03:11 machine1 kernel: R10: 0000000000000000 R11: 0000000000000000 R12: 00007efe9377d2c0 Jun 10 16:03:11 machine1 kernel: R13: 0000000000020000 R14: 000000000000048b R15: 00007efe9377d000 Jun 10 16:03:11 machine1 kernel: </TASK> Jun 10 16:03:11 machine1 kernel: Future hung task reports are suppressed, see sysctl kernel.hung_task_warnings Jun 10 16:03:11 machine1 systemd[1]: systemd-journald.service: Watchdog timeout (limit 3min)! Jun 10 16:03:11 machine1 systemd[1]: systemd-journald.service: Killing process 407 (systemd-journal) with signal SIGABRT. Jun 10 16:03:11 machine1 systemd[1]: Starting Serial console liveness marker... Jun 10 16:03:11 machine1 systemd[1]: Starting Logrotate Service... Jun 10 16:03:11 machine1 systemd[1]: serial-console-liveness.service: Deactivated successfully. Jun 10 16:03:11 machine1 systemd[1]: Finished Serial console liveness marker. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Process 407 (systemd-journal) of user 0 terminated abnormally with signal 6/ABRT, processing... Jun 10 16:03:11 machine1 systemd[1]: logrotate.service: Deactivated successfully. Jun 10 16:03:11 machine1 systemd[1]: Finished Logrotate Service. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Process 407 (systemd-journal) of user 0 dumped core. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Coredump diverted to /var/lib/systemd/coredump/core.systemd-journal.0.42b57193ad0b49a48e0dd3e3abe28b31.407.1749564188000000.zst Jun 10 16:03:11 machine1 systemd-coredump[274177]: Module libzstd.so.1 without build-id. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Module libaudit.so.1 without build-id. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Module libattr.so.1 without build-id. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Module libseccomp.so.2 without build-id. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Module libpam.so.0 without build-id. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Module libcrypt.so.2 without build-id. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Module libcap.so.2 without build-id. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Module libacl.so.1 without build-id. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Stack trace of thread 407: Jun 10 16:03:11 machine1 systemd-coredump[274177]: #0 0x00007fc77968b4c0 n/a (libsystemd-shared-256.so + 0x8b4c0) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #1 0x00007fc7798decb4 journal_file_append_data (libsystemd-shared-256.so + 0x2decb4) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #2 0x00007fc7798df3f5 journal_file_append_entry (libsystemd-shared-256.so + 0x2df3f5) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #3 0x000055d2da095ff3 server_dispatch_message_real (systemd-journald + 0x11ff3) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #4 0x000055d2da08e6a0 dev_kmsg_record (systemd-journald + 0xa6a0) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #5 0x000055d2da08ec53 server_read_dev_kmsg (systemd-journald + 0xac53) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #6 0x00007fc77990b223 source_dispatch (libsystemd-shared-256.so + 0x30b223) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #7 0x00007fc77990b518 sd_event_dispatch (libsystemd-shared-256.so + 0x30b518) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #8 0x00007fc77990c040 sd_event_run (libsystemd-shared-256.so + 0x30c040) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #9 0x000055d2da08d60a main (systemd-journald + 0x960a) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #10 0x00007fc77943227e __libc_start_call_main (libc.so.6 + 0x2a27e) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #11 0x00007fc779432339 __libc_start_main@@GLIBC_2.34 (libc.so.6 + 0x2a339) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #12 0x000055d2da08db45 _start (systemd-journald + 0x9b45) Jun 10 16:03:11 machine1 systemd-coredump[274177]: Stack trace of thread 274174: Jun 10 16:03:11 machine1 systemd-coredump[274177]: #0 0x00007fc77950d6ea fsync (libc.so.6 + 0x1056ea) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #1 0x00007fc779739519 journal_file_set_offline_internal (libsystemd-shared-256.so + 0x139519) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #2 0x00007fc779739880 journal_file_set_offline_thread (libsystemd-shared-256.so + 0x139880) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #3 0x00007fc779498af3 start_thread (libc.so.6 + 0x90af3) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #4 0x00007fc779517d34 __clone (libc.so.6 + 0x10fd34) Jun 10 16:03:11 machine1 systemd-coredump[274177]: ELF object binary architecture: AMD x86-64 Jun 10 16:03:11 machine1 systemd[1]: systemd-journald.service: Main process exited, code=dumped, status=6/ABRT Jun 10 16:03:11 machine1 systemd[1]: systemd-journald.service: Failed with result 'watchdog'. Jun 10 16:03:11 machine1 systemd[1]: systemd-journald.service: Consumed 2min 32.716s CPU time, 1.1G memory peak, 28.3M read from disk, 53.8G written to disk. Jun 10 16:03:11 machine1 systemd[1]: run-credentials-systemd\x2djournald.service.mount: Deactivated successfully. Jun 10 16:03:11 machine1 systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. Jun 10 16:03:11 machine1 systemd[1]: Starting Journal Service... Jun 10 16:03:11 machine1 systemd-journald[274205]: Collecting audit messages is enabled. Jun 10 16:03:11 machine1 systemd-journald[274205]: File /var/log/journal/04256dcb074d45a997c6639bd2b566bb/system.journal corrupted or uncleanly shut down, renaming and replacing. Jun 10 16:03:11 machine1 systemd[1]: Started Journal Service. Jun 10 16:03:11 machine1 systemd-journald[274205]: File /var/log/journal/04256dcb074d45a997c6639bd2b566bb/user-31004.journal corrupted or uncleanly shut down, renaming and replacing. Jun 10 16:04:32 machine1 systemd[1]: fc-agent.service: Deactivated successfully. Jun 10 16:04:32 machine1 systemd[1]: Finished Flying Circus Management Task. Jun 10 16:04:32 machine1 systemd[1]: fc-agent.service: Consumed 25.773s CPU time, 1.6G memory peak, 18.5M read from disk, 479.4M written to disk, 125.2K incoming IP traffic, 20.8K o> Jun 10 16:03:11 machine1 kernel: RBP: 0000000039dfec40 R08: 0000000000000000 R09: 0000000000000000 Jun 10 16:03:11 machine1 kernel: R10: 0000000000000000 R11: 0000000000000000 R12: 00007efe9377d1c0 Jun 10 16:03:11 machine1 kernel: R13: 0000000000020000 R14: 000000000000048b R15: 00007efe9377d000 Jun 10 16:03:11 machine1 kernel: </TASK> Jun 10 16:03:11 machine1 kernel: INFO: task slapd:2791 blocked for more than 122 seconds. Jun 10 16:03:11 machine1 kernel: Not tainted 6.6.92 #1-NixOS Jun 10 16:03:11 machine1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 10 16:03:11 machine1 kernel: task:slapd state:D stack:0 pid:2791 ppid:1 flags:0x00000002 Jun 10 16:03:11 machine1 kernel: Call Trace: Jun 10 16:03:11 machine1 kernel: <TASK> Jun 10 16:03:11 machine1 kernel: __schedule+0x3fc/0x1440 Jun 10 16:03:11 machine1 kernel: schedule+0x5e/0xe0 Jun 10 16:03:11 machine1 kernel: xlog_grant_head_wait+0xba/0x220 [xfs] Jun 10 16:03:11 machine1 kernel: xlog_grant_head_check+0xdf/0x110 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_log_reserve+0xc4/0x1f0 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_trans_reserve+0x138/0x170 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_trans_alloc+0xe5/0x230 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_vn_update_time+0x90/0x1b0 [xfs] Jun 10 16:03:11 machine1 kernel: file_update_time+0x61/0x90 Jun 10 16:03:11 machine1 kernel: __xfs_filemap_fault.constprop.0+0xd4/0x1d0 [xfs] Jun 10 16:03:11 machine1 kernel: do_page_mkwrite+0x50/0xb0 Jun 10 16:03:11 machine1 kernel: do_wp_page+0x431/0xb80 Jun 10 16:03:11 machine1 kernel: ? __pte_offset_map+0x1b/0x190 Jun 10 16:03:11 machine1 kernel: __handle_mm_fault+0xbcf/0xd90 Jun 10 16:03:11 machine1 kernel: handle_mm_fault+0x17f/0x370 Jun 10 16:03:11 machine1 kernel: do_user_addr_fault+0x1ee/0x630 Jun 10 16:03:11 machine1 kernel: exc_page_fault+0x71/0x160 Jun 10 16:03:11 machine1 kernel: asm_exc_page_fault+0x26/0x30 Jun 10 16:03:11 machine1 kernel: RIP: 0033:0x4d0c04 Jun 10 16:03:11 machine1 kernel: RSP: 002b:00007efe2ddea250 EFLAGS: 00010246 Jun 10 16:03:11 machine1 kernel: RAX: 000000000000a50b RBX: 00007efe28203aa0 RCX: 0000000000000000 Jun 10 16:03:11 machine1 kernel: RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000 Jun 10 16:03:11 machine1 kernel: RBP: 0000000039dfec40 R08: 0000000000000000 R09: 0000000000000000 Jun 10 16:03:11 machine1 kernel: R10: 0000000000000000 R11: 0000000000000000 R12: 00007efe9377d240 Jun 10 16:03:11 machine1 kernel: R13: 0000000000020000 R14: 000000000000048b R15: 00007efe9377d000 Jun 10 16:03:11 machine1 kernel: </TASK> Jun 10 16:03:11 machine1 kernel: INFO: task slapd:2792 blocked for more than 122 seconds. Jun 10 16:03:11 machine1 kernel: Not tainted 6.6.92 #1-NixOS Jun 10 16:03:11 machine1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 10 16:03:11 machine1 kernel: task:slapd state:D stack:0 pid:2792 ppid:1 flags:0x00000002 Jun 10 16:03:11 machine1 kernel: Call Trace: Jun 10 16:03:11 machine1 kernel: <TASK> Jun 10 16:03:11 machine1 kernel: __schedule+0x3fc/0x1440 Jun 10 16:03:11 machine1 kernel: schedule+0x5e/0xe0 Jun 10 16:03:11 machine1 kernel: xlog_grant_head_wait+0xba/0x220 [xfs] Jun 10 16:03:11 machine1 kernel: xlog_grant_head_check+0xdf/0x110 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_log_reserve+0xc4/0x1f0 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_trans_reserve+0x138/0x170 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_trans_alloc+0xe5/0x230 [xfs] Jun 10 16:03:11 machine1 kernel: xfs_vn_update_time+0x90/0x1b0 [xfs] Jun 10 16:03:11 machine1 kernel: file_update_time+0x61/0x90 Jun 10 16:03:11 machine1 kernel: __xfs_filemap_fault.constprop.0+0xd4/0x1d0 [xfs] Jun 10 16:03:11 machine1 kernel: do_page_mkwrite+0x50/0xb0 Jun 10 16:03:11 machine1 kernel: do_wp_page+0x431/0xb80 Jun 10 16:03:11 machine1 kernel: ? __pte_offset_map+0x1b/0x190 Jun 10 16:03:11 machine1 kernel: __handle_mm_fault+0xbcf/0xd90 Jun 10 16:03:11 machine1 kernel: handle_mm_fault+0x17f/0x370 Jun 10 16:03:11 machine1 kernel: do_user_addr_fault+0x1ee/0x630 Jun 10 16:03:11 machine1 kernel: exc_page_fault+0x71/0x160 Jun 10 16:03:11 machine1 kernel: asm_exc_page_fault+0x26/0x30 Jun 10 16:03:11 machine1 kernel: RIP: 0033:0x4d0c04 Jun 10 16:03:11 machine1 kernel: RSP: 002b:00007efe2d5fa2a0 EFLAGS: 00010246 Jun 10 16:03:11 machine1 kernel: RAX: 000000000000a50b RBX: 00007efe34135cb0 RCX: 0000000000000000 Jun 10 16:03:11 machine1 kernel: RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000 Jun 10 16:03:11 machine1 kernel: RBP: 0000000039dfec40 R08: 0000000000000000 R09: 0000000000000000 Jun 10 16:03:11 machine1 kernel: R10: 0000000000000000 R11: 0000000000000000 R12: 00007efe9377d2c0 Jun 10 16:03:11 machine1 kernel: R13: 0000000000020000 R14: 000000000000048b R15: 00007efe9377d000 Jun 10 16:03:11 machine1 kernel: </TASK> Jun 10 16:03:11 machine1 kernel: Future hung task reports are suppressed, see sysctl kernel.hung_task_warnings Jun 10 16:03:11 machine1 systemd[1]: systemd-journald.service: Watchdog timeout (limit 3min)! Jun 10 16:03:11 machine1 systemd[1]: systemd-journald.service: Killing process 407 (systemd-journal) with signal SIGABRT. Jun 10 16:03:11 machine1 systemd[1]: Starting Serial console liveness marker... Jun 10 16:03:11 machine1 systemd[1]: Starting Logrotate Service... Jun 10 16:03:11 machine1 systemd[1]: serial-console-liveness.service: Deactivated successfully. Jun 10 16:03:11 machine1 systemd[1]: Finished Serial console liveness marker. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Process 407 (systemd-journal) of user 0 terminated abnormally with signal 6/ABRT, processing... Jun 10 16:03:11 machine1 systemd[1]: logrotate.service: Deactivated successfully. Jun 10 16:03:11 machine1 systemd[1]: Finished Logrotate Service. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Process 407 (systemd-journal) of user 0 dumped core. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Coredump diverted to /var/lib/systemd/coredump/core.systemd-journal.0.42b57193ad0b49a48e0dd3e3abe28b31.407.1749564188000000.zst Jun 10 16:03:11 machine1 systemd-coredump[274177]: Module libzstd.so.1 without build-id. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Module libaudit.so.1 without build-id. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Module libattr.so.1 without build-id. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Module libseccomp.so.2 without build-id. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Module libpam.so.0 without build-id. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Module libcrypt.so.2 without build-id. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Module libcap.so.2 without build-id. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Module libacl.so.1 without build-id. Jun 10 16:03:11 machine1 systemd-coredump[274177]: Stack trace of thread 407: Jun 10 16:03:11 machine1 systemd-coredump[274177]: #0 0x00007fc77968b4c0 n/a (libsystemd-shared-256.so + 0x8b4c0) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #1 0x00007fc7798decb4 journal_file_append_data (libsystemd-shared-256.so + 0x2decb4) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #2 0x00007fc7798df3f5 journal_file_append_entry (libsystemd-shared-256.so + 0x2df3f5) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #3 0x000055d2da095ff3 server_dispatch_message_real (systemd-journald + 0x11ff3) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #4 0x000055d2da08e6a0 dev_kmsg_record (systemd-journald + 0xa6a0) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #5 0x000055d2da08ec53 server_read_dev_kmsg (systemd-journald + 0xac53) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #6 0x00007fc77990b223 source_dispatch (libsystemd-shared-256.so + 0x30b223) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #7 0x00007fc77990b518 sd_event_dispatch (libsystemd-shared-256.so + 0x30b518) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #8 0x00007fc77990c040 sd_event_run (libsystemd-shared-256.so + 0x30c040) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #9 0x000055d2da08d60a main (systemd-journald + 0x960a) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #10 0x00007fc77943227e __libc_start_call_main (libc.so.6 + 0x2a27e) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #11 0x00007fc779432339 __libc_start_main@@GLIBC_2.34 (libc.so.6 + 0x2a339) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #12 0x000055d2da08db45 _start (systemd-journald + 0x9b45) Jun 10 16:03:11 machine1 systemd-coredump[274177]: Stack trace of thread 274174: Jun 10 16:03:11 machine1 systemd-coredump[274177]: #0 0x00007fc77950d6ea fsync (libc.so.6 + 0x1056ea) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #1 0x00007fc779739519 journal_file_set_offline_internal (libsystemd-shared-256.so + 0x139519) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #2 0x00007fc779739880 journal_file_set_offline_thread (libsystemd-shared-256.so + 0x139880) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #3 0x00007fc779498af3 start_thread (libc.so.6 + 0x90af3) Jun 10 16:03:11 machine1 systemd-coredump[274177]: #4 0x00007fc779517d34 __clone (libc.so.6 + 0x10fd34) Jun 10 16:03:11 machine1 systemd-coredump[274177]: ELF object binary architecture: AMD x86-64
Jun 11 15:07:13 machine2 kernel: INFO: task kcompactd0:45 blocked for more than 122 seconds. Jun 11 15:07:13 machine2 kernel: Not tainted 6.6.92 #1-NixOS Jun 11 15:07:13 machine2 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 11 15:07:13 machine2 kernel: task:kcompactd0 state:D stack:0 pid:45 ppid:2 flags:0x00004000 Jun 11 15:07:13 machine2 kernel: Call Trace: Jun 11 15:07:13 machine2 kernel: <TASK> Jun 11 15:07:13 machine2 kernel: __schedule+0x3fc/0x1440 Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: schedule+0x5e/0xe0 Jun 11 15:07:13 machine2 kernel: io_schedule+0x46/0x80 Jun 11 15:07:13 machine2 kernel: folio_wait_bit_common+0x13d/0x360 Jun 11 15:07:13 machine2 kernel: ? __pfx_wake_page_function+0x10/0x10 Jun 11 15:07:13 machine2 kernel: migrate_pages_batch+0x5c9/0xb90 Jun 11 15:07:13 machine2 kernel: ? __pfx_compaction_free+0x10/0x10 Jun 11 15:07:13 machine2 kernel: ? __pfx_compaction_alloc+0x10/0x10 Jun 11 15:07:13 machine2 kernel: ? __pfx_remove_migration_pte+0x10/0x10 Jun 11 15:07:13 machine2 kernel: migrate_pages+0xbdc/0xd50 Jun 11 15:07:13 machine2 kernel: ? __pfx_compaction_alloc+0x10/0x10 Jun 11 15:07:13 machine2 kernel: ? __pfx_compaction_free+0x10/0x10 Jun 11 15:07:13 machine2 kernel: compact_zone+0x831/0xf30 Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: proactive_compact_node+0x85/0xe0 Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: kcompactd+0x387/0x460 Jun 11 15:07:13 machine2 kernel: ? __pfx_autoremove_wake_function+0x10/0x10 Jun 11 15:07:13 machine2 kernel: ? __pfx_kcompactd+0x10/0x10 Jun 11 15:07:13 machine2 kernel: kthread+0xe8/0x120 Jun 11 15:07:13 machine2 kernel: ? __pfx_kthread+0x10/0x10 Jun 11 15:07:13 machine2 kernel: ret_from_fork+0x34/0x50 Jun 11 15:07:13 machine2 kernel: ? __pfx_kthread+0x10/0x10 Jun 11 15:07:13 machine2 kernel: ret_from_fork_asm+0x1b/0x30 Jun 11 15:07:13 machine2 kernel: </TASK> Jun 11 15:07:13 machine2 kernel: INFO: task xfsaild/vda1:221 blocked for more than 122 seconds. Jun 11 15:07:13 machine2 kernel: Not tainted 6.6.92 #1-NixOS Jun 11 15:07:13 machine2 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 11 15:07:13 machine2 kernel: task:xfsaild/vda1 state:D stack:0 pid:221 ppid:2 flags:0x00004000 Jun 11 15:07:13 machine2 kernel: Call Trace: Jun 11 15:07:13 machine2 kernel: <TASK> Jun 11 15:07:13 machine2 kernel: __schedule+0x3fc/0x1440 Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: schedule+0x5e/0xe0 Jun 11 15:07:13 machine2 kernel: schedule_timeout+0x159/0x170 Jun 11 15:07:13 machine2 kernel: wait_for_completion+0x8a/0x160 Jun 11 15:07:13 machine2 kernel: __flush_workqueue+0x157/0x440 Jun 11 15:07:13 machine2 kernel: ? finish_task_switch.isra.0+0x94/0x300 Jun 11 15:07:13 machine2 kernel: xlog_cil_push_now.isra.0+0x5e/0xa0 [xfs] Jun 11 15:07:13 machine2 kernel: xlog_cil_force_seq+0x69/0x250 [xfs] Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: ? __timer_delete_sync+0x7d/0xe0 Jun 11 15:07:13 machine2 kernel: xfs_log_force+0x7e/0x240 [xfs] Jun 11 15:07:13 machine2 kernel: xfsaild+0x17d/0x870 [xfs] Jun 11 15:07:13 machine2 kernel: ? __pfx_xfsaild+0x10/0x10 [xfs] Jun 11 15:07:13 machine2 kernel: kthread+0xe8/0x120 Jun 11 15:07:13 machine2 kernel: ? __pfx_kthread+0x10/0x10 Jun 11 15:07:13 machine2 kernel: ret_from_fork+0x34/0x50 Jun 11 15:07:13 machine2 kernel: ? __pfx_kthread+0x10/0x10 Jun 11 15:07:13 machine2 kernel: ret_from_fork_asm+0x1b/0x30 Jun 11 15:07:13 machine2 kernel: </TASK> Jun 11 15:07:13 machine2 kernel: INFO: task journal-offline:804376 blocked for more than 122 seconds. Jun 11 15:07:13 machine2 kernel: Not tainted 6.6.92 #1-NixOS Jun 11 15:07:13 machine2 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 11 15:07:13 machine2 kernel: task:journal-offline state:D stack:0 pid:804376 ppid:1 flags:0x00004002 Jun 11 15:07:13 machine2 kernel: Call Trace: Jun 11 15:07:13 machine2 kernel: <TASK> Jun 11 15:07:13 machine2 kernel: __schedule+0x3fc/0x1440 Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: ? psi_task_switch+0xb7/0x200 Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: schedule+0x5e/0xe0 Jun 11 15:07:13 machine2 kernel: schedule_timeout+0x159/0x170 Jun 11 15:07:13 machine2 kernel: wait_for_completion+0x8a/0x160 Jun 11 15:07:13 machine2 kernel: __flush_workqueue+0x157/0x440 Jun 11 15:07:13 machine2 kernel: ? __folio_batch_release+0x1f/0x60 Jun 11 15:07:13 machine2 kernel: xlog_cil_push_now.isra.0+0x5e/0xa0 [xfs] Jun 11 15:07:13 machine2 kernel: xlog_cil_force_seq+0x69/0x250 [xfs] Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: xfs_log_force_seq+0x75/0x180 [xfs] Jun 11 15:07:13 machine2 kernel: xfs_file_fsync+0x1a9/0x2b0 [xfs] Jun 11 15:07:13 machine2 kernel: __x64_sys_fsync+0x3b/0x70 Jun 11 15:07:13 machine2 kernel: do_syscall_64+0x39/0x90 Jun 11 15:07:13 machine2 kernel: entry_SYSCALL_64_after_hwframe+0x78/0xe2 Jun 11 15:07:13 machine2 kernel: RIP: 0033:0x7f208f90d6ea Jun 11 15:07:13 machine2 kernel: RSP: 002b:00007f208effed70 EFLAGS: 00000246 ORIG_RAX: 000000000000004a Jun 11 15:07:13 machine2 kernel: RAX: ffffffffffffffda RBX: 00005573438972c0 RCX: 00007f208f90d6ea Jun 11 15:07:13 machine2 kernel: RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000020 Jun 11 15:07:13 machine2 kernel: RBP: 00007f208fd77700 R08: 0000000000000000 R09: 00007f208efff6c0 Jun 11 15:07:13 machine2 kernel: R10: 00007f208f898886 R11: 0000000000000246 R12: fffffffffffffe90 Jun 11 15:07:13 machine2 kernel: R13: 0000000000000000 R14: 00007fff9b527620 R15: 00007f208fef3000 Jun 11 15:07:13 machine2 kernel: </TASK> Jun 11 15:07:13 machine2 kernel: INFO: task journal-offline:804377 blocked for more than 122 seconds. Jun 11 15:07:13 machine2 kernel: Not tainted 6.6.92 #1-NixOS Jun 11 15:07:13 machine2 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 11 15:07:13 machine2 kernel: task:journal-offline state:D stack:0 pid:804377 ppid:1 flags:0x00004002 Jun 11 15:07:13 machine2 kernel: Call Trace: Jun 11 15:07:13 machine2 kernel: <TASK> Jun 11 15:07:13 machine2 kernel: __schedule+0x3fc/0x1440 Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: ? psi_task_switch+0xb7/0x200 Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: schedule+0x5e/0xe0 Jun 11 15:07:13 machine2 kernel: schedule_timeout+0x159/0x170 Jun 11 15:07:13 machine2 kernel: wait_for_completion+0x8a/0x160 Jun 11 15:07:13 machine2 kernel: __flush_workqueue+0x157/0x440 Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: xlog_cil_push_now.isra.0+0x5e/0xa0 [xfs] Jun 11 15:07:13 machine2 kernel: xlog_cil_force_seq+0x69/0x250 [xfs] Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: xfs_log_force_seq+0x75/0x180 [xfs] Jun 11 15:07:13 machine2 kernel: xfs_file_fsync+0x1a9/0x2b0 [xfs] Jun 11 15:07:13 machine2 kernel: __x64_sys_fsync+0x3b/0x70 Jun 11 15:07:13 machine2 kernel: do_syscall_64+0x39/0x90 Jun 11 15:07:13 machine2 kernel: entry_SYSCALL_64_after_hwframe+0x78/0xe2 Jun 11 15:07:13 machine2 kernel: RIP: 0033:0x7f208f90d6ea Jun 11 15:07:13 machine2 kernel: RSP: 002b:00007f20847fed70 EFLAGS: 00000246 ORIG_RAX: 000000000000004a Jun 11 15:07:13 machine2 kernel: RAX: ffffffffffffffda RBX: 0000557343889080 RCX: 00007f208f90d6ea Jun 11 15:07:13 machine2 kernel: RDX: 0000000000000000 RSI: 0000000000000000 RDI: 000000000000002b Jun 11 15:07:13 machine2 kernel: RBP: 00007f208fd77700 R08: 0000000000000000 R09: 00007f20847ff6c0 Jun 11 15:07:13 machine2 kernel: R10: 00007f208f898886 R11: 0000000000000246 R12: fffffffffffffe90 Jun 11 15:07:13 machine2 kernel: R13: 0000000000000000 R14: 00007fff9b527620 R15: 00007f208fef3000 Jun 11 15:07:13 machine2 kernel: </TASK> Jun 11 15:07:13 machine2 kernel: INFO: task kworker/u9:0:795821 blocked for more than 122 seconds. Jun 11 15:07:13 machine2 kernel: Not tainted 6.6.92 #1-NixOS Jun 11 15:07:13 machine2 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 11 15:07:13 machine2 kernel: task:kworker/u9:0 state:D stack:0 pid:795821 ppid:2 flags:0x00004000 Jun 11 15:07:13 machine2 kernel: Workqueue: xfs-cil/vda1 xlog_cil_push_work [xfs] Jun 11 15:07:13 machine2 kernel: Call Trace: Jun 11 15:07:13 machine2 kernel: <TASK> Jun 11 15:07:13 machine2 kernel: __schedule+0x3fc/0x1440 Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: ? kick_pool+0x5a/0xf0 Jun 11 15:07:13 machine2 kernel: ? __queue_work.part.0+0x1a5/0x390 Jun 11 15:07:13 machine2 kernel: schedule+0x5e/0xe0 Jun 11 15:07:13 machine2 kernel: xlog_state_get_iclog_space+0x107/0x2c0 [xfs] Jun 11 15:07:13 machine2 kernel: ? __pfx_default_wake_function+0x10/0x10 Jun 11 15:07:13 machine2 kernel: xlog_write+0x7a/0x470 [xfs] Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: ? merge+0x42/0xc0 Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: ? xlog_cil_order_write+0x9a/0x170 [xfs] Jun 11 15:07:13 machine2 kernel: ? __pfx_xlog_cil_order_cmp+0x10/0x10 [xfs] Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: xlog_cil_push_work+0x72c/0x8f0 [xfs] Jun 11 15:07:13 machine2 kernel: process_one_work+0x18d/0x3a0 Jun 11 15:07:13 machine2 kernel: worker_thread+0x28c/0x3b0 Jun 11 15:07:13 machine2 kernel: ? __pfx_worker_thread+0x10/0x10 Jun 11 15:07:13 machine2 kernel: kthread+0xe8/0x120 Jun 11 15:07:13 machine2 kernel: ? __pfx_kthread+0x10/0x10 Jun 11 15:07:13 machine2 kernel: ret_from_fork+0x34/0x50 Jun 11 15:07:13 machine2 kernel: ? __pfx_kthread+0x10/0x10 Jun 11 15:07:13 machine2 kernel: ret_from_fork_asm+0x1b/0x30 Jun 11 15:07:13 machine2 kernel: </TASK> Jun 11 15:07:13 machine2 kernel: INFO: task kworker/2:0:800877 blocked for more than 122 seconds. Jun 11 15:07:13 machine2 kernel: Not tainted 6.6.92 #1-NixOS Jun 11 15:07:13 machine2 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 11 15:07:13 machine2 kernel: task:kworker/2:0 state:D stack:0 pid:800877 ppid:2 flags:0x00004000 Jun 11 15:07:13 machine2 kernel: Workqueue: xfs-sync/vda1 xfs_log_worker [xfs] Jun 11 15:07:13 machine2 kernel: Call Trace: Jun 11 15:07:13 machine2 kernel: <TASK> Jun 11 15:07:13 machine2 kernel: __schedule+0x3fc/0x1440 Jun 11 15:07:13 machine2 kernel: ? ttwu_do_activate+0x64/0x230 Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: schedule+0x5e/0xe0 Jun 11 15:07:13 machine2 kernel: schedule_timeout+0x159/0x170 Jun 11 15:07:13 machine2 kernel: wait_for_completion+0x8a/0x160 Jun 11 15:07:13 machine2 kernel: __flush_workqueue+0x157/0x440 Jun 11 15:07:13 machine2 kernel: ? update_load_avg+0x7e/0x7b0 Jun 11 15:07:13 machine2 kernel: xlog_cil_push_now.isra.0+0x5e/0xa0 [xfs] Jun 11 15:07:13 machine2 kernel: xlog_cil_force_seq+0x69/0x250 [xfs] Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: ? kfree_rcu_monitor+0x32c/0x550 Jun 11 15:07:13 machine2 kernel: xfs_log_force+0x7e/0x240 [xfs] Jun 11 15:07:13 machine2 kernel: xfs_log_worker+0x3f/0xd0 [xfs] Jun 11 15:07:13 machine2 kernel: process_one_work+0x18d/0x3a0 Jun 11 15:07:13 machine2 kernel: worker_thread+0x28c/0x3b0 Jun 11 15:07:13 machine2 kernel: ? __pfx_worker_thread+0x10/0x10 Jun 11 15:07:13 machine2 kernel: kthread+0xe8/0x120 Jun 11 15:07:13 machine2 kernel: ? __pfx_kthread+0x10/0x10 Jun 11 15:07:13 machine2 kernel: ret_from_fork+0x34/0x50 Jun 11 15:07:13 machine2 kernel: ? __pfx_kthread+0x10/0x10 Jun 11 15:07:13 machine2 kernel: ret_from_fork_asm+0x1b/0x30 Jun 11 15:07:13 machine2 kernel: </TASK> Jun 11 15:07:13 machine2 kernel: INFO: task kworker/u9:1:802505 blocked for more than 122 seconds. Jun 11 15:07:13 machine2 kernel: Not tainted 6.6.92 #1-NixOS Jun 11 15:07:13 machine2 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 11 15:07:13 machine2 kernel: task:kworker/u9:1 state:D stack:0 pid:802505 ppid:2 flags:0x00004000 Jun 11 15:07:13 machine2 kernel: Workqueue: writeback wb_workfn (flush-253:0) Jun 11 15:07:13 machine2 kernel: Call Trace: Jun 11 15:07:13 machine2 kernel: <TASK> Jun 11 15:07:13 machine2 kernel: __schedule+0x3fc/0x1440 Jun 11 15:07:13 machine2 kernel: schedule+0x5e/0xe0 Jun 11 15:07:13 machine2 kernel: schedule_timeout+0x159/0x170 Jun 11 15:07:13 machine2 kernel: wait_for_completion+0x8a/0x160 Jun 11 15:07:13 machine2 kernel: __flush_workqueue+0x157/0x440 Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: xlog_cil_push_now.isra.0+0x5e/0xa0 [xfs] Jun 11 15:07:13 machine2 kernel: xlog_cil_force_seq+0x69/0x250 [xfs] Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: ? xfs_btree_insert+0x10f/0x290 [xfs] Jun 11 15:07:13 machine2 kernel: xfs_log_force+0x7e/0x240 [xfs] Jun 11 15:07:13 machine2 kernel: xfs_buf_lock+0xf2/0x100 [xfs] Jun 11 15:07:13 machine2 kernel: xfs_buf_find_lock+0x5b/0x120 [xfs] Jun 11 15:07:13 machine2 kernel: xfs_buf_get_map+0x1ab/0xa10 [xfs] Jun 11 15:07:13 machine2 kernel: xfs_trans_get_buf_map+0x11e/0x1d0 [xfs] Jun 11 15:07:13 machine2 kernel: xfs_free_agfl_block+0xcd/0x100 [xfs] Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: xfs_agfl_free_finish_item+0x176/0x190 [xfs] Jun 11 15:07:13 machine2 kernel: xfs_defer_finish_noroll+0x196/0x720 [xfs] Jun 11 15:07:13 machine2 kernel: __xfs_trans_commit+0x1f0/0x3e0 [xfs] Jun 11 15:07:13 machine2 kernel: xfs_bmapi_convert_one_delalloc+0x351/0x490 [xfs] Jun 11 15:07:13 machine2 kernel: xfs_bmapi_convert_delalloc+0x43/0x60 [xfs] Jun 11 15:07:13 machine2 kernel: xfs_map_blocks+0x25b/0x430 [xfs] Jun 11 15:07:13 machine2 kernel: iomap_do_writepage+0x23a/0x880 Jun 11 15:07:13 machine2 kernel: write_cache_pages+0x142/0x3b0 Jun 11 15:07:13 machine2 kernel: ? __pfx_iomap_do_writepage+0x10/0x10 Jun 11 15:07:13 machine2 kernel: ? throtl_add_bio_tg+0x35/0x90 Jun 11 15:07:13 machine2 kernel: iomap_writepages+0x20/0x50 Jun 11 15:07:13 machine2 kernel: xfs_vm_writepages+0x67/0xa0 [xfs] Jun 11 15:07:13 machine2 kernel: do_writepages+0xcf/0x1f0 Jun 11 15:07:13 machine2 kernel: __writeback_single_inode+0x3d/0x370 Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: writeback_sb_inodes+0x1f5/0x4c0 Jun 11 15:07:13 machine2 kernel: __writeback_inodes_wb+0x4c/0xf0 Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: wb_writeback+0x2d6/0x340 Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: wb_workfn+0x35b/0x520 Jun 11 15:07:13 machine2 kernel: ? __schedule+0x404/0x1440 Jun 11 15:07:13 machine2 kernel: process_one_work+0x18d/0x3a0 Jun 11 15:07:13 machine2 kernel: worker_thread+0x28c/0x3b0 Jun 11 15:07:13 machine2 kernel: ? __pfx_worker_thread+0x10/0x10 Jun 11 15:07:13 machine2 kernel: kthread+0xe8/0x120 Jun 11 15:07:13 machine2 kernel: ? __pfx_kthread+0x10/0x10 Jun 11 15:07:13 machine2 kernel: ret_from_fork+0x34/0x50 Jun 11 15:07:13 machine2 kernel: ? __pfx_kthread+0x10/0x10 Jun 11 15:07:13 machine2 kernel: ret_from_fork_asm+0x1b/0x30 Jun 11 15:07:13 machine2 kernel: </TASK> Jun 11 15:07:13 machine2 kernel: INFO: task kworker/u9:3:803550 blocked for more than 122 seconds. Jun 11 15:07:13 machine2 kernel: Not tainted 6.6.92 #1-NixOS Jun 11 15:07:13 machine2 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 11 15:07:13 machine2 kernel: task:kworker/u9:3 state:D stack:0 pid:803550 ppid:2 flags:0x00004000 Jun 11 15:07:13 machine2 kernel: Workqueue: xfs-cil/vda1 xlog_cil_push_work [xfs] Jun 11 15:07:13 machine2 kernel: Call Trace: Jun 11 15:07:13 machine2 kernel: <TASK> Jun 11 15:07:13 machine2 kernel: __schedule+0x3fc/0x1440 Jun 11 15:07:13 machine2 kernel: schedule+0x5e/0xe0 Jun 11 15:07:13 machine2 kernel: xlog_cil_order_write+0x134/0x170 [xfs] Jun 11 15:07:13 machine2 kernel: ? __pfx_default_wake_function+0x10/0x10 Jun 11 15:07:13 machine2 kernel: xlog_cil_push_work+0x5ab/0x8f0 [xfs] Jun 11 15:07:13 machine2 kernel: process_one_work+0x18d/0x3a0 Jun 11 15:07:13 machine2 kernel: worker_thread+0x28c/0x3b0 Jun 11 15:07:13 machine2 kernel: ? __pfx_worker_thread+0x10/0x10 Jun 11 15:07:13 machine2 kernel: kthread+0xe8/0x120 Jun 11 15:07:13 machine2 kernel: ? __pfx_kthread+0x10/0x10 Jun 11 15:07:13 machine2 kernel: ret_from_fork+0x34/0x50 Jun 11 15:07:13 machine2 kernel: ? __pfx_kthread+0x10/0x10 Jun 11 15:07:13 machine2 kernel: ret_from_fork_asm+0x1b/0x30 Jun 11 15:07:13 machine2 kernel: </TASK> Jun 11 15:07:13 machine2 kernel: INFO: task nix-build:803925 blocked for more than 122 seconds. Jun 11 15:07:13 machine2 kernel: Not tainted 6.6.92 #1-NixOS Jun 11 15:07:13 machine2 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 11 15:07:13 machine2 kernel: task:nix-build state:D stack:0 pid:803925 ppid:803923 flags:0x00004002 Jun 11 15:07:13 machine2 kernel: Call Trace: Jun 11 15:07:13 machine2 kernel: <TASK> Jun 11 15:07:13 machine2 kernel: __schedule+0x3fc/0x1440 Jun 11 15:07:13 machine2 kernel: ? srso_return_thunk+0x5/0x5f Jun 11 15:07:13 machine2 kernel: ? submit_bio_noacct+0x256/0x5a0 Jun 11 15:07:13 machine2 kernel: schedule+0x5e/0xe0 Jun 11 15:07:13 machine2 kernel: xlog_wait_on_iclog+0x174/0x190 [xfs] Jun 11 15:07:13 machine2 kernel: ? __pfx_default_wake_function+0x10/0x10 Jun 11 15:07:13 machine2 kernel: xfs_log_force_seq+0x91/0x180 [xfs] Jun 11 15:07:13 machine2 kernel: xfs_file_fsync+0x1a9/0x2b0 [xfs] Jun 11 15:07:13 machine2 kernel: __x64_sys_fdatasync+0x52/0xa0 Jun 11 15:07:13 machine2 kernel: do_syscall_64+0x39/0x90 Jun 11 15:07:13 machine2 kernel: entry_SYSCALL_64_after_hwframe+0x78/0xe2 Jun 11 15:07:13 machine2 kernel: RIP: 0033:0x7fceaeb0d20a Jun 11 15:07:13 machine2 kernel: RSP: 002b:00007fce93ffdb60 EFLAGS: 00000246 ORIG_RAX: 000000000000004b Jun 11 15:07:13 machine2 kernel: RAX: ffffffffffffffda RBX: 0000559f4c37e6a8 RCX: 00007fceaeb0d20a Jun 11 15:07:13 machine2 kernel: RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000007 Jun 11 15:07:13 machine2 kernel: RBP: 0000559f4c37e618 R08: 0000000000000000 R09: 00000000000013bb Jun 11 15:07:13 machine2 kernel: R10: 0000559f4c3a51d0 R11: 0000000000000246 R12: 0000000000000008 Jun 11 15:07:13 machine2 kernel: R13: 0000559f4c33a828 R14: 00007fce93ffdc20 R15: 0000000000000000 Jun 11 15:07:13 machine2 kernel: </TASK> Jun 11 15:07:13 machine2 kernel: INFO: task nix:804252 blocked for more than 122 seconds. Jun 11 15:07:13 machine2 kernel: Not tainted 6.6.92 #1-NixOS Jun 11 15:07:13 machine2 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 11 15:07:13 machine2 kernel: task:nix state:D stack:0 pid:804252 ppid:804251 flags:0x00000002 Jun 11 15:07:13 machine2 kernel: Call Trace: Jun 11 15:07:13 machine2 kernel: <TASK> Jun 11 15:07:13 machine2 kernel: __schedule+0x3fc/0x1440 Jun 11 15:07:13 machine2 kernel: ? kmem_cache_alloc+0x19d/0x390 Jun 11 15:07:13 machine2 kernel: ? xlog_ticket_alloc+0x2d/0xb0 [xfs] Jun 11 15:07:13 machine2 kernel: schedule+0x5e/0xe0 Jun 11 15:07:13 machine2 kernel: schedule_preempt_disabled+0x15/0x30 Jun 11 15:07:13 machine2 kernel: rwsem_down_write_slowpath+0x1f3/0x640 Jun 11 15:07:13 machine2 kernel: ? xfs_trans_alloc+0xe5/0x230 [xfs] Jun 11 15:07:13 machine2 kernel: down_write+0x6b/0x70 Jun 11 15:07:13 machine2 kernel: xfs_trans_alloc_ichange+0x9d/0x200 [xfs] Jun 11 15:07:13 machine2 kernel: xfs_setattr_nonsize+0x9a/0x390 [xfs] Jun 11 15:07:13 machine2 kernel: notify_change+0x1f5/0x4c0 Jun 11 15:07:13 machine2 kernel: ? chown_common+0x22a/0x240 Jun 11 15:07:13 machine2 kernel: chown_common+0x22a/0x240 Jun 11 15:07:13 machine2 kernel: ksys_fchown+0x85/0xd0 Jun 11 15:07:13 machine2 kernel: __x64_sys_fchown+0x17/0x30 Jun 11 15:07:13 machine2 kernel: do_syscall_64+0x39/0x90 Jun 11 15:07:13 machine2 kernel: entry_SYSCALL_64_after_hwframe+0x78/0xe2 Jun 11 15:07:13 machine2 kernel: RIP: 0033:0x7f3debd05ddb Jun 11 15:07:13 machine2 kernel: RSP: 002b:00007ffd20bf1c58 EFLAGS: 00000246 ORIG_RAX: 000000000000005d Jun 11 15:07:13 machine2 kernel: RAX: ffffffffffffffda RBX: 0000563449847d9d RCX: 00007f3debd05ddb Jun 11 15:07:13 machine2 kernel: RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000007 Jun 11 15:07:13 machine2 kernel: RBP: 0000000000080006 R08: 0000000000000001 R09: 0000000000000000 Jun 11 15:07:13 machine2 kernel: R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000007 Jun 11 15:07:13 machine2 kernel: R13: 0000000000020042 R14: 000056344985f8e8 R15: 0000000000000000 Jun 11 15:07:13 machine2 kernel: </TASK> Jun 11 15:07:13 machine2 kernel: Future hung task reports are suppressed, see sysctl kernel.hung_task_warnings Jun 11 15:07:13 machine2 systemd[1]: systemd-journald.service: Watchdog timeout (limit 3min)! Jun 11 15:07:13 machine2 systemd[1]: systemd-journald.service: Killing process 474 (systemd-journal) with signal SIGABRT. Jun 11 15:07:13 machine2 systemd-coredump[804693]: Process 474 (systemd-journal) of user 0 terminated abnormally with signal 6/ABRT, processing... Jun 11 15:07:13 machine2 systemd-coredump[804693]: Process 474 (systemd-journal) of user 0 dumped core. Jun 11 15:07:13 machine2 systemd-coredump[804693]: Coredump diverted to /var/lib/systemd/coredump/core.systemd-journal.0.be2bc38389c9490cb71c3494a7469dc7.474.1749647228000000.zst Jun 11 15:07:13 machine2 systemd-coredump[804693]: Module libzstd.so.1 without build-id. Jun 11 15:07:13 machine2 systemd-coredump[804693]: Module libaudit.so.1 without build-id. Jun 11 15:07:13 machine2 systemd-coredump[804693]: Module libattr.so.1 without build-id. Jun 11 15:07:13 machine2 systemd-coredump[804693]: Module libseccomp.so.2 without build-id. Jun 11 15:07:13 machine2 systemd-coredump[804693]: Module libpam.so.0 without build-id. Jun 11 15:07:13 machine2 systemd-coredump[804693]: Module libcrypt.so.2 without build-id. Jun 11 15:07:13 machine2 systemd-coredump[804693]: Module libcap.so.2 without build-id. Jun 11 15:07:13 machine2 systemd-coredump[804693]: Module libacl.so.1 without build-id. Jun 11 15:07:13 machine2 systemd-coredump[804693]: Stack trace of thread 474: Jun 11 15:07:13 machine2 systemd-coredump[804693]: #0 0x00007f208f89513e __futex_abstimed_wait_common (libc.so.6 + 0x8d13e) Jun 11 15:07:13 machine2 systemd-coredump[804693]: #1 0x00007f208f89a5f3 __pthread_clockjoin_ex (libc.so.6 + 0x925f3) Jun 11 15:07:13 machine2 systemd-coredump[804693]: #2 0x00007f208fcd65ee journal_file_set_offline_thread_join (libsystemd-shared-256.so + 0x2d65ee) Jun 11 15:07:13 machine2 systemd-coredump[804693]: #3 0x00007f208fcd66d4 journal_file_set_online (libsystemd-shared-256.so + 0x2d66d4) Jun 11 15:07:13 machine2 systemd-coredump[804693]: #4 0x00007f208fcd95a7 journal_file_append_object (libsystemd-shared-256.so + 0x2d95a7) Jun 11 15:07:13 machine2 systemd-coredump[804693]: #5 0x00007f208fcdeb0f journal_file_append_data (libsystemd-shared-256.so + 0x2deb0f)
Jun 12 14:41:26 machine3 kernel: INFO: task ib_io_wr-7:4619 blocked for more than 122 seconds. Jun 12 14:41:26 machine3 kernel: Not tainted 6.6.92 #1-NixOS Jun 12 14:41:26 machine3 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 12 14:41:26 machine3 kernel: task:ib_io_wr-7 state:D stack:0 pid:4619 ppid:1 flags:0x00004002 Jun 12 14:41:26 machine3 kernel: Call Trace: Jun 12 14:41:26 machine3 kernel: <TASK> Jun 12 14:41:26 machine3 kernel: __schedule+0x3fc/0x1440 Jun 12 14:41:26 machine3 kernel: schedule+0x5e/0xe0 Jun 12 14:41:26 machine3 kernel: xlog_wait_on_iclog+0x174/0x190 [xfs] Jun 12 14:41:26 machine3 kernel: ? __pfx_default_wake_function+0x10/0x10 Jun 12 14:41:26 machine3 kernel: xfs_log_force_seq+0x91/0x180 [xfs] Jun 12 14:41:26 machine3 kernel: xfs_file_fsync+0x1a9/0x2b0 [xfs] Jun 12 14:41:26 machine3 kernel: __x64_sys_fsync+0x3b/0x70 Jun 12 14:41:26 machine3 kernel: do_syscall_64+0x39/0x90 Jun 12 14:41:26 machine3 kernel: entry_SYSCALL_64_after_hwframe+0x78/0xe2 Jun 12 14:41:26 machine3 kernel: RIP: 0033:0x7f4dd8f0d6ea Jun 12 14:41:26 machine3 kernel: RSP: 002b:00007f4bb8ff62a0 EFLAGS: 00000246 ORIG_RAX: 000000000000004a Jun 12 14:41:26 machine3 kernel: RAX: ffffffffffffffda RBX: 000000000000001d RCX: 00007f4dd8f0d6ea Jun 12 14:41:26 machine3 kernel: RDX: 0000000000000000 RSI: 0000000000000000 RDI: 000000000000001d Jun 12 14:41:26 machine3 kernel: RBP: 00007f4bb8ff8530 R08: 0000000000000000 R09: 00000000000020ad Jun 12 14:41:26 machine3 kernel: R10: 0000000000000000 R11: 0000000000000246 R12: 00007f4dc6641b70 Jun 12 14:41:26 machine3 kernel: R13: 0000000000000000 R14: 00007f4dc6641f80 R15: 00000000046f7c08 Jun 12 14:41:26 machine3 kernel: </TASK> Jun 12 14:41:26 machine3 kernel: INFO: task ib_log_flush:4700 blocked for more than 122 seconds. Jun 12 14:41:26 machine3 kernel: Not tainted 6.6.92 #1-NixOS Jun 12 14:41:26 machine3 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 12 14:41:26 machine3 kernel: task:ib_log_flush state:D stack:0 pid:4700 ppid:1 flags:0x00004002 Jun 12 14:41:26 machine3 kernel: Call Trace: Jun 12 14:41:26 machine3 kernel: <TASK> Jun 12 14:41:26 machine3 kernel: __schedule+0x3fc/0x1440 Jun 12 14:41:26 machine3 kernel: ? __folio_batch_release+0x1f/0x60 Jun 12 14:41:26 machine3 kernel: schedule+0x5e/0xe0 Jun 12 14:41:26 machine3 kernel: xlog_wait_on_iclog+0x174/0x190 [xfs] Jun 12 14:41:26 machine3 kernel: ? __pfx_default_wake_function+0x10/0x10 Jun 12 14:41:26 machine3 kernel: xfs_log_force_seq+0x91/0x180 [xfs] Jun 12 14:41:26 machine3 kernel: xfs_file_fsync+0x1a9/0x2b0 [xfs] Jun 12 14:41:26 machine3 kernel: __x64_sys_fsync+0x3b/0x70 Jun 12 14:41:26 machine3 kernel: do_syscall_64+0x39/0x90 Jun 12 14:41:26 machine3 kernel: entry_SYSCALL_64_after_hwframe+0x78/0xe2 Jun 12 14:41:26 machine3 kernel: RIP: 0033:0x7f4dd8f0d6ea Jun 12 14:41:26 machine3 kernel: RSP: 002b:00007f4b94b89690 EFLAGS: 00000246 ORIG_RAX: 000000000000004a Jun 12 14:41:26 machine3 kernel: RAX: ffffffffffffffda RBX: 00007f4b94b8b930 RCX: 00007f4dd8f0d6ea Jun 12 14:41:26 machine3 kernel: RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000018 Jun 12 14:41:26 machine3 kernel: RBP: 00007f4b94b8b920 R08: 0000000000000000 R09: 0000000000000000 Jun 12 14:41:26 machine3 kernel: R10: 0000000000000000 R11: 0000000000000246 R12: 00000000046f4498 Jun 12 14:41:26 machine3 kernel: R13: 0000000000000000 R14: 00007f4dc50be340 R15: 00000000046f7c08 Jun 12 14:41:26 machine3 kernel: </TASK> Jun 12 14:41:26 machine3 kernel: INFO: task ib_log_writer:4702 blocked for more than 122 seconds. Jun 12 14:41:26 machine3 kernel: Not tainted 6.6.92 #1-NixOS Jun 12 14:41:26 machine3 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 12 14:41:26 machine3 kernel: task:ib_log_writer state:D stack:0 pid:4702 ppid:1 flags:0x00000002 Jun 12 14:41:26 machine3 kernel: Call Trace: Jun 12 14:41:26 machine3 kernel: <TASK> Jun 12 14:41:26 machine3 kernel: __schedule+0x3fc/0x1440 Jun 12 14:41:26 machine3 kernel: ? kmem_cache_alloc+0x19d/0x390 Jun 12 14:41:26 machine3 kernel: ? xlog_ticket_alloc+0x2d/0xb0 [xfs] Jun 12 14:41:26 machine3 kernel: schedule+0x5e/0xe0 Jun 12 14:41:26 machine3 kernel: schedule_preempt_disabled+0x15/0x30 Jun 12 14:41:26 machine3 kernel: rwsem_down_write_slowpath+0x1f3/0x640 Jun 12 14:41:26 machine3 kernel: ? xfs_trans_alloc+0xe5/0x230 [xfs] Jun 12 14:41:26 machine3 kernel: down_write+0x6b/0x70 Jun 12 14:41:26 machine3 kernel: xfs_vn_update_time+0xa1/0x1b0 [xfs] Jun 12 14:41:26 machine3 kernel: kiocb_modified+0x9b/0xd0 Jun 12 14:41:26 machine3 kernel: xfs_file_write_checks+0x1dd/0x280 [xfs] Jun 12 14:41:26 machine3 kernel: xfs_file_buffered_write+0x60/0x2b0 [xfs] Jun 12 14:41:26 machine3 kernel: ? selinux_file_permission+0x119/0x160 Jun 12 14:41:26 machine3 kernel: vfs_write+0x24f/0x430 Jun 12 14:41:26 machine3 kernel: __x64_sys_pwrite64+0xa4/0xd0 Jun 12 14:41:26 machine3 kernel: do_syscall_64+0x39/0x90 Jun 12 14:41:26 machine3 kernel: entry_SYSCALL_64_after_hwframe+0x78/0xe2 Jun 12 14:41:26 machine3 kernel: RIP: 0033:0x7f4dd8eee02f Jun 12 14:41:26 machine3 kernel: RSP: 002b:00007f4b93b87280 EFLAGS: 00000246 ORIG_RAX: 0000000000000012 Jun 12 14:41:26 machine3 kernel: RAX: ffffffffffffffda RBX: 00007f4b9b7f0c00 RCX: 00007f4dd8eee02f Jun 12 14:41:26 machine3 kernel: RDX: 0000000000000200 RSI: 00007f4b9b7f0c00 RDI: 0000000000000018 Jun 12 14:41:26 machine3 kernel: RBP: 00007f4b93b895a0 R08: 0000000000000000 R09: 00007f4b93b895dc Jun 12 14:41:26 machine3 kernel: R10: 0000000000f71e00 R11: 0000000000000246 R12: 0000000000f71e00 Jun 12 14:41:26 machine3 kernel: R13: 00007f4b9b7f0c00 R14: 00000000046f7be8 R15: 00007f4dc4307210 Jun 12 14:41:26 machine3 kernel: </TASK> Jun 12 14:41:26 machine3 kernel: INFO: task connection:87027 blocked for more than 122 seconds. Jun 12 14:41:26 machine3 kernel: Not tainted 6.6.92 #1-NixOS Jun 12 14:41:26 machine3 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 12 14:41:26 machine3 kernel: task:connection state:D stack:0 pid:87027 ppid:1 flags:0x00004002 Jun 12 14:41:26 machine3 kernel: Call Trace: Jun 12 14:41:26 machine3 kernel: <TASK> Jun 12 14:41:26 machine3 kernel: __schedule+0x3fc/0x1440 Jun 12 14:41:26 machine3 kernel: ? __folio_batch_release+0x1f/0x60 Jun 12 14:41:26 machine3 kernel: schedule+0x5e/0xe0 Jun 12 14:41:26 machine3 kernel: xlog_wait_on_iclog+0x174/0x190 [xfs] Jun 12 14:41:26 machine3 kernel: ? __pfx_default_wake_function+0x10/0x10 Jun 12 14:41:26 machine3 kernel: xfs_log_force_seq+0x91/0x180 [xfs] Jun 12 14:41:26 machine3 kernel: xfs_file_fsync+0x1a9/0x2b0 [xfs] Jun 12 14:41:26 machine3 kernel: __x64_sys_fdatasync+0x52/0xa0 Jun 12 14:41:26 machine3 kernel: do_syscall_64+0x39/0x90 Jun 12 14:41:26 machine3 kernel: entry_SYSCALL_64_after_hwframe+0x78/0xe2 Jun 12 14:41:26 machine3 kernel: RIP: 0033:0x7f4dd8f0d20a Jun 12 14:41:26 machine3 kernel: RSP: 002b:00007f4b8a05b540 EFLAGS: 00000246 ORIG_RAX: 000000000000004b Jun 12 14:41:26 machine3 kernel: RAX: ffffffffffffffda RBX: 00007f4b8a05b620 RCX: 00007f4dd8f0d20a Jun 12 14:41:26 machine3 kernel: RDX: 0000000000000000 RSI: 0000000000000000 RDI: 000000000000003d Jun 12 14:41:26 machine3 kernel: RBP: 00007f4b8a05b610 R08: 0000000000000000 R09: 0000000000000000 Jun 12 14:41:26 machine3 kernel: R10: 0000000000000000 R11: 0000000000000246 R12: 000000000000003d Jun 12 14:41:26 machine3 kernel: R13: 0000000000000010 R14: 0000000000000000 R15: 00000000046e5f20 Jun 12 14:41:26 machine3 kernel: </TASK> Jun 12 14:41:26 machine3 kernel: INFO: task kworker/u5:2:80717 blocked for more than 122 seconds. Jun 12 14:41:26 machine3 kernel: Not tainted 6.6.92 #1-NixOS Jun 12 14:41:26 machine3 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 12 14:41:26 machine3 kernel: task:kworker/u5:2 state:D stack:0 pid:80717 ppid:2 flags:0x00004000 Jun 12 14:41:26 machine3 kernel: Workqueue: xfs-cil/vda1 xlog_cil_push_work [xfs] Jun 12 14:41:26 machine3 kernel: Call Trace: Jun 12 14:41:26 machine3 kernel: <TASK> Jun 12 14:41:26 machine3 kernel: __schedule+0x3fc/0x1440 Jun 12 14:41:26 machine3 kernel: schedule+0x5e/0xe0 Jun 12 14:41:26 machine3 kernel: xlog_cil_order_write+0x134/0x170 [xfs] Jun 12 14:41:26 machine3 kernel: ? __pfx_default_wake_function+0x10/0x10 Jun 12 14:41:26 machine3 kernel: xlog_cil_push_work+0x5ab/0x8f0 [xfs] Jun 12 14:41:26 machine3 kernel: process_one_work+0x18d/0x3a0 Jun 12 14:41:26 machine3 kernel: worker_thread+0x28c/0x3b0 Jun 12 14:41:26 machine3 kernel: ? __pfx_worker_thread+0x10/0x10 Jun 12 14:41:26 machine3 kernel: kthread+0xe8/0x120 Jun 12 14:41:26 machine3 kernel: ? __pfx_kthread+0x10/0x10 Jun 12 14:41:26 machine3 kernel: ret_from_fork+0x34/0x50 Jun 12 14:41:26 machine3 kernel: ? __pfx_kthread+0x10/0x10 Jun 12 14:41:26 machine3 kernel: ret_from_fork_asm+0x1b/0x30 Jun 12 14:41:26 machine3 kernel: </TASK> Jun 12 14:41:26 machine3 kernel: INFO: task kworker/u5:3:81267 blocked for more than 122 seconds. Jun 12 14:41:26 machine3 kernel: Not tainted 6.6.92 #1-NixOS Jun 12 14:41:26 machine3 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 12 14:41:26 machine3 kernel: task:kworker/u5:3 state:D stack:0 pid:81267 ppid:2 flags:0x00004000 Jun 12 14:41:26 machine3 kernel: Workqueue: xfs-cil/vda1 xlog_cil_push_work [xfs] Jun 12 14:41:26 machine3 kernel: Call Trace: Jun 12 14:41:26 machine3 kernel: <TASK> Jun 12 14:41:26 machine3 kernel: __schedule+0x3fc/0x1440 Jun 12 14:41:26 machine3 kernel: ? __schedule+0x404/0x1440 Jun 12 14:41:26 machine3 kernel: ? select_task_rq_fair+0x6e5/0x1b30 Jun 12 14:41:26 machine3 kernel: schedule+0x5e/0xe0 Jun 12 14:41:26 machine3 kernel: xlog_cil_order_write+0x134/0x170 [xfs] Jun 12 14:41:26 machine3 kernel: ? __pfx_default_wake_function+0x10/0x10 Jun 12 14:41:26 machine3 kernel: xlog_cil_push_work+0x5ab/0x8f0 [xfs] Jun 12 14:41:26 machine3 kernel: process_one_work+0x18d/0x3a0 Jun 12 14:41:26 machine3 kernel: worker_thread+0x28c/0x3b0 Jun 12 14:41:26 machine3 kernel: ? __pfx_worker_thread+0x10/0x10 Jun 12 14:41:26 machine3 kernel: kthread+0xe8/0x120 Jun 12 14:41:26 machine3 kernel: ? __pfx_kthread+0x10/0x10 Jun 12 14:41:26 machine3 kernel: ret_from_fork+0x34/0x50 Jun 12 14:41:26 machine3 kernel: ? __pfx_kthread+0x10/0x10 Jun 12 14:41:26 machine3 kernel: ret_from_fork_asm+0x1b/0x30 Jun 12 14:41:26 machine3 kernel: </TASK> Jun 12 14:41:26 machine3 kernel: INFO: task kworker/u6:3:83203 blocked for more than 122 seconds. Jun 12 14:41:26 machine3 kernel: Not tainted 6.6.92 #1-NixOS Jun 12 14:41:26 machine3 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 12 14:41:26 machine3 kernel: task:kworker/u6:3 state:D stack:0 pid:83203 ppid:2 flags:0x00004000 Jun 12 14:41:26 machine3 kernel: Workqueue: xfs-cil/vda1 xlog_cil_push_work [xfs] Jun 12 14:41:26 machine3 kernel: Call Trace: Jun 12 14:41:26 machine3 kernel: <TASK> Jun 12 14:41:26 machine3 kernel: __schedule+0x3fc/0x1440 Jun 12 14:41:26 machine3 kernel: ? blk_mq_submit_bio+0x27b/0x660 Jun 12 14:41:26 machine3 kernel: schedule+0x5e/0xe0 Jun 12 14:41:26 machine3 kernel: xlog_state_get_iclog_space+0x107/0x2c0 [xfs] Jun 12 14:41:26 machine3 kernel: ? __pfx_default_wake_function+0x10/0x10 Jun 12 14:41:26 machine3 kernel: xlog_write_get_more_iclog_space+0xde/0x110 [xfs] Jun 12 14:41:26 machine3 kernel: xlog_write+0x34c/0x470 [xfs] Jun 12 14:41:26 machine3 kernel: xlog_cil_push_work+0x72c/0x8f0 [xfs] Jun 12 14:41:26 machine3 kernel: process_one_work+0x18d/0x3a0 Jun 12 14:41:26 machine3 kernel: worker_thread+0x28c/0x3b0 Jun 12 14:41:26 machine3 kernel: ? __pfx_worker_thread+0x10/0x10 Jun 12 14:41:26 machine3 kernel: kthread+0xe8/0x120 Jun 12 14:41:26 machine3 kernel: ? __pfx_kthread+0x10/0x10 Jun 12 14:41:26 machine3 kernel: ret_from_fork+0x34/0x50 Jun 12 14:41:26 machine3 kernel: ? __pfx_kthread+0x10/0x10 Jun 12 14:41:26 machine3 kernel: ret_from_fork_asm+0x1b/0x30 Jun 12 14:41:26 machine3 kernel: </TASK> Jun 12 14:41:26 machine3 kernel: INFO: task kworker/u5:0:85256 blocked for more than 122 seconds. Jun 12 14:41:26 machine3 kernel: Not tainted 6.6.92 #1-NixOS Jun 12 14:41:26 machine3 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 12 14:41:26 machine3 kernel: task:kworker/u5:0 state:D stack:0 pid:85256 ppid:2 flags:0x00004000 Jun 12 14:41:26 machine3 kernel: Workqueue: xfs-cil/vda1 xlog_cil_push_work [xfs] Jun 12 14:41:26 machine3 kernel: Call Trace: Jun 12 14:41:26 machine3 kernel: <TASK> Jun 12 14:41:26 machine3 kernel: __schedule+0x3fc/0x1440 Jun 12 14:41:26 machine3 kernel: schedule+0x5e/0xe0 Jun 12 14:41:26 machine3 kernel: xlog_cil_order_write+0x134/0x170 [xfs] Jun 12 14:41:26 machine3 kernel: ? __pfx_default_wake_function+0x10/0x10 Jun 12 14:41:26 machine3 kernel: xlog_cil_push_work+0x5ab/0x8f0 [xfs] Jun 12 14:41:26 machine3 kernel: process_one_work+0x18d/0x3a0 Jun 12 14:41:26 machine3 kernel: worker_thread+0x28c/0x3b0 Jun 12 14:41:26 machine3 kernel: ? __pfx_worker_thread+0x10/0x10 Jun 12 14:41:26 machine3 kernel: kthread+0xe8/0x120 Jun 12 14:41:26 machine3 kernel: ? __pfx_kthread+0x10/0x10 Jun 12 14:41:26 machine3 kernel: ret_from_fork+0x34/0x50 Jun 12 14:41:26 machine3 kernel: ? __pfx_kthread+0x10/0x10 Jun 12 14:41:26 machine3 kernel: ret_from_fork_asm+0x1b/0x30 Jun 12 14:41:26 machine3 kernel: </TASK> Jun 12 14:41:26 machine3 kernel: INFO: task kworker/u5:1:86241 blocked for more than 122 seconds. Jun 12 14:41:26 machine3 kernel: Not tainted 6.6.92 #1-NixOS Jun 12 14:41:26 machine3 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 12 14:41:26 machine3 kernel: task:kworker/u5:1 state:D stack:0 pid:86241 ppid:2 flags:0x00004000 Jun 12 14:41:26 machine3 kernel: Workqueue: xfs-cil/vda1 xlog_cil_push_work [xfs] Jun 12 14:41:26 machine3 kernel: Call Trace: Jun 12 14:41:26 machine3 kernel: <TASK> Jun 12 14:41:26 machine3 kernel: __schedule+0x3fc/0x1440 Jun 12 14:41:26 machine3 kernel: schedule+0x5e/0xe0 Jun 12 14:41:26 machine3 kernel: xlog_cil_order_write+0x134/0x170 [xfs] Jun 12 14:41:26 machine3 kernel: ? __pfx_default_wake_function+0x10/0x10 Jun 12 14:41:26 machine3 kernel: xlog_cil_push_work+0x5ab/0x8f0 [xfs] Jun 12 14:41:26 machine3 kernel: process_one_work+0x18d/0x3a0 Jun 12 14:41:26 machine3 kernel: worker_thread+0x28c/0x3b0 Jun 12 14:41:26 machine3 kernel: ? __pfx_worker_thread+0x10/0x10 Jun 12 14:41:26 machine3 kernel: kthread+0xe8/0x120 Jun 12 14:41:26 machine3 kernel: ? __pfx_kthread+0x10/0x10 Jun 12 14:41:26 machine3 kernel: ret_from_fork+0x34/0x50 Jun 12 14:41:26 machine3 kernel: ? __pfx_kthread+0x10/0x10 Jun 12 14:41:26 machine3 kernel: ret_from_fork_asm+0x1b/0x30 Jun 12 14:41:26 machine3 kernel: </TASK> Jun 12 14:41:26 machine3 kernel: INFO: task kworker/u6:4:86403 blocked for more than 122 seconds. Jun 12 14:41:26 machine3 kernel: Not tainted 6.6.92 #1-NixOS Jun 12 14:41:26 machine3 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jun 12 14:41:26 machine3 kernel: task:kworker/u6:4 state:D stack:0 pid:86403 ppid:2 flags:0x00004000 Jun 12 14:41:26 machine3 kernel: Workqueue: xfs-cil/vda1 xlog_cil_push_work [xfs] Jun 12 14:41:26 machine3 kernel: Call Trace: Jun 12 14:41:26 machine3 kernel: <TASK> Jun 12 14:41:26 machine3 kernel: __schedule+0x3fc/0x1440 Jun 12 14:41:26 machine3 kernel: schedule+0x5e/0xe0 Jun 12 14:41:26 machine3 kernel: xlog_state_get_iclog_space+0x107/0x2c0 [xfs] Jun 12 14:41:26 machine3 kernel: ? load_balance+0x175/0xfd0 Jun 12 14:41:26 machine3 kernel: ? __pfx_default_wake_function+0x10/0x10 Jun 12 14:41:26 machine3 kernel: xlog_write+0x7a/0x470 [xfs] Jun 12 14:41:26 machine3 kernel: ? __pfx_xlog_cil_order_cmp+0x10/0x10 [xfs] Jun 12 14:41:26 machine3 kernel: ? merge+0x66/0xc0 Jun 12 14:41:26 machine3 kernel: ? xlog_cil_order_write+0x9a/0x170 [xfs] Jun 12 14:41:26 machine3 kernel: ? __pfx_xlog_cil_order_cmp+0x10/0x10 [xfs] Jun 12 14:41:26 machine3 kernel: xlog_cil_push_work+0x72c/0x8f0 [xfs] Jun 12 14:41:26 machine3 kernel: process_one_work+0x18d/0x3a0 Jun 12 14:41:26 machine3 kernel: worker_thread+0x28c/0x3b0 Jun 12 14:41:26 machine3 kernel: ? __pfx_worker_thread+0x10/0x10 Jun 12 14:41:26 machine3 kernel: kthread+0xe8/0x120 Jun 12 14:41:26 machine3 kernel: ? __pfx_kthread+0x10/0x10 Jun 12 14:41:26 machine3 kernel: ret_from_fork+0x34/0x50 Jun 12 14:41:26 machine3 kernel: ? __pfx_kthread+0x10/0x10 Jun 12 14:41:26 machine3 kernel: ret_from_fork_asm+0x1b/0x30 Jun 12 14:41:26 machine3 kernel: </TASK>
On 16. Jun 2025, at 10:50, Carlos Maiolino cem@kernel.org wrote:
On Thu, Jun 12, 2025 at 03:37:10PM +0200, Christian Theune wrote:
Hi,
in the last week, after updating to 6.6.92, we’ve encountered a number of VMs reporting temporarily hung tasks blocking the whole system for a few minutes. They unblock by themselves and have similar tracebacks.
The IO PSIs show 100% pressure for that time, but the underlying devices are still processing read and write IO (well within their capacity). I’ve eliminated the underlying storage (Ceph) as the source of problems as I couldn’t find any latency outliers or significant queuing during that time.
I’ve seen somewhat similar reports on 6.6.88 and 6.6.77, but those might have been different outliers.
I’m attaching 3 logs - my intuition and the data so far leads me to consider this might be a kernel bug. I haven’t found a way to reproduce this, yet.
From a first glance, these machines are struggling because IO contention as you mentioned, more often than not they seem to be stalling waiting for log space to be freed, so any operation in the FS gets throttled while the journal isn't written back. If you have a small enough journal it will need to issue IO often enough to cause IO contention. So, I'd point it to a slow storage or small enough log area (or both).
Yeah, my current analysis didn’t show any storage performance issues. I’ll revisit this once more to make sure I’m not missing anything. We’ve previously had issues in this area that turned out to be kernel bugs. We didn’t change anything regarding journal sizes and only a recent kernel upgrade seemed to be relevant.
There has been a few improvements though during Linux 6.9 on the log performance, but I can't tell if you have any of those improvements around. I'd suggest you trying to run a newer upstream kernel, otherwise you'll get very limited support from the upstream community. If you can't, I'd suggest you reporting this issue to your vendor, so they can track what you are/are not using in your current kernel.
Yeah, we’ve started upgrading selected/affected projects to 6.12, to see whether this improves things.
FWIW, I'm not sure if NixOS uses linux-stable kernels or not. If that's the case, running a newer kernel suggestion is still valid.
We’re running the NixOS mainline versions which are very vanilla. There are very very 4 small patches that only fix up things around building and binary paths for helpers to call to adapt them to the nix environment.
Christian
On Mon, Jun 16, 2025 at 10:59:34AM +0200, Christian Theune wrote:
On 16. Jun 2025, at 10:50, Carlos Maiolino cem@kernel.org wrote:
On Thu, Jun 12, 2025 at 03:37:10PM +0200, Christian Theune wrote:
Hi,
in the last week, after updating to 6.6.92, we’ve encountered a number of VMs reporting temporarily hung tasks blocking the whole system for a few minutes. They unblock by themselves and have similar tracebacks.
The IO PSIs show 100% pressure for that time, but the underlying devices are still processing read and write IO (well within their capacity). I’ve eliminated the underlying storage (Ceph) as the source of problems as I couldn’t find any latency outliers or significant queuing during that time.
I’ve seen somewhat similar reports on 6.6.88 and 6.6.77, but those might have been different outliers.
I’m attaching 3 logs - my intuition and the data so far leads me to consider this might be a kernel bug. I haven’t found a way to reproduce this, yet.
From a first glance, these machines are struggling because IO contention as you mentioned, more often than not they seem to be stalling waiting for log space to be freed, so any operation in the FS gets throttled while the journal isn't written back. If you have a small enough journal it will need to issue IO often enough to cause IO contention. So, I'd point it to a slow storage or small enough log area (or both).
Yeah, my current analysis didn’t show any storage performance issues. I’ll revisit this once more to make sure I’m not missing anything. We’ve previously had issues in this area that turned out to be kernel bugs. We didn’t change anything regarding journal sizes and only a recent kernel upgrade seemed to be relevant.
You mentioned you saw PSI showing a huge pressure ration, during the time, which might be generated by the journal writeback and giving it's a SYNC write, IOs will stall if your storage can't write it fast enough. IIRC, most of the threads from the logs you shared were waiting for log space to be able to continue, which causes the log to flush things to disk and of course increase IO usage. If your storage can't handle these IO bursts, then you'll get the stalls you're seeing. I am not discarding a possibility you are hitting a bug here, but it so far seems your storage is not being able to service IOs fast enough to avoid such IO stalls, or something else throttling IOs, XFS seems just the victim.
Can you share the xfs_info of one of these filesystems? I'm curious about the FS geometry.
There has been a few improvements though during Linux 6.9 on the log performance, but I can't tell if you have any of those improvements around. I'd suggest you trying to run a newer upstream kernel, otherwise you'll get very limited support from the upstream community. If you can't, I'd suggest you reporting this issue to your vendor, so they can track what you are/are not using in your current kernel.
Yeah, we’ve started upgrading selected/affected projects to 6.12, to see whether this improves things.
Good enough.
FWIW, I'm not sure if NixOS uses linux-stable kernels or not. If that's the case, running a newer kernel suggestion is still valid.
We’re running the NixOS mainline versions which are very vanilla. There are very very 4 small patches that only fix up things around building and binary paths for helpers to call to adapt them to the nix environment.
I see. There were some improvements in the newer versions, so if you can rule out any possibly fixed bug is worth it.
Christian
-- Christian Theune · ct@flyingcircus.io · +49 345 219401 0 Flying Circus Internet Operations GmbH · https://flyingcircus.io Leipziger Str. 70/71 · 06108 Halle (Saale) · Deutschland HR Stendal HRB 21169 · Geschäftsführer: Christian Theune, Christian Zagrodnick
On 16. Jun 2025, at 11:47, Carlos Maiolino cem@kernel.org wrote:
On Mon, Jun 16, 2025 at 10:59:34AM +0200, Christian Theune wrote:
On 16. Jun 2025, at 10:50, Carlos Maiolino cem@kernel.org wrote:
On Thu, Jun 12, 2025 at 03:37:10PM +0200, Christian Theune wrote:
Hi,
in the last week, after updating to 6.6.92, we’ve encountered a number of VMs reporting temporarily hung tasks blocking the whole system for a few minutes. They unblock by themselves and have similar tracebacks.
The IO PSIs show 100% pressure for that time, but the underlying devices are still processing read and write IO (well within their capacity). I’ve eliminated the underlying storage (Ceph) as the source of problems as I couldn’t find any latency outliers or significant queuing during that time.
I’ve seen somewhat similar reports on 6.6.88 and 6.6.77, but those might have been different outliers.
I’m attaching 3 logs - my intuition and the data so far leads me to consider this might be a kernel bug. I haven’t found a way to reproduce this, yet.
From a first glance, these machines are struggling because IO contention as you mentioned, more often than not they seem to be stalling waiting for log space to be freed, so any operation in the FS gets throttled while the journal isn't written back. If you have a small enough journal it will need to issue IO often enough to cause IO contention. So, I'd point it to a slow storage or small enough log area (or both).
Yeah, my current analysis didn’t show any storage performance issues. I’ll revisit this once more to make sure I’m not missing anything. We’ve previously had issues in this area that turned out to be kernel bugs. We didn’t change anything regarding journal sizes and only a recent kernel upgrade seemed to be relevant.
You mentioned you saw PSI showing a huge pressure ration, during the time, which might be generated by the journal writeback and giving it's a SYNC write, IOs will stall if your storage can't write it fast enough. IIRC, most of the threads from the logs you shared were waiting for log space to be able to continue, which causes the log to flush things to disk and of course increase IO usage. If your storage can't handle these IO bursts, then you'll get the stalls you're seeing. I am not discarding a possibility you are hitting a bug here, but it so far seems your storage is not being able to service IOs fast enough to avoid such IO stalls, or something else throttling IOs, XFS seems just the victim.
Yeah, it’s annoying, I know. To paraphrase "any sufficiently advanced bug is indistinguishable from slow storage”. ;)
As promised, I’ll dive deeper into the storage performance analysis, all telemetry so far was completely innocuous, but it’s a complex layering of SSDs → Ceph → Qemu … Usually if we have performance issues then the metrics reflect this quite obviously and will affect many machines at the same time. As this has always just affected one single VM at a time but spread over time my gut feeling is a bit more on the side of “it might be maybe a bug”. As those things tend to be hard/nasty to diagnose I wanted to raise the flag early on to see whether other’s might be having an “aha” moment if they’re experiencing something similar.
I’ll get back to you in 2-3 days with results from the storage analysis.
Can you share the xfs_info of one of these filesystems? I'm curious about the FS geometry.
Sure:
# xfs_info / meta-data=/dev/disk/by-label/root isize=512 agcount=21, agsize=655040 blks = sectsz=512 attr=2, projid32bit=1 = crc=1 finobt=1, sparse=1, rmapbt=0 = reflink=1 bigtime=1 inobtcount=1 nrext64=0 = exchange=0 data = bsize=4096 blocks=13106171, imaxpct=25 = sunit=0 swidth=0 blks naming =version 2 bsize=4096 ascii-ci=0, ftype=1, parent=0 log =internal log bsize=4096 blocks=16384, version=2 = sectsz=512 sunit=0 blks, lazy-count=1 realtime =none extsz=4096 blocks=0, rtextents=0
# xfs_info /tmp/ meta-data=/dev/vdb1 isize=512 agcount=8, agsize=229376 blks = sectsz=512 attr=2, projid32bit=1 = crc=1 finobt=1, sparse=1, rmapbt=0 = reflink=0 bigtime=0 inobtcount=0 nrext64=0 = exchange=0 data = bsize=4096 blocks=1833979, imaxpct=25 = sunit=1024 swidth=1024 blks naming =version 2 bsize=4096 ascii-ci=0, ftype=1, parent=0 log =internal log bsize=4096 blocks=2560, version=2 = sectsz=512 sunit=8 blks, lazy-count=1 realtime =none extsz=4096 blocks=0, rtextents=0
There has been a few improvements though during Linux 6.9 on the log performance, but I can't tell if you have any of those improvements around. I'd suggest you trying to run a newer upstream kernel, otherwise you'll get very limited support from the upstream community. If you can't, I'd suggest you reporting this issue to your vendor, so they can track what you are/are not using in your current kernel.
Yeah, we’ve started upgrading selected/affected projects to 6.12, to see whether this improves things.
Good enough.
FWIW, I'm not sure if NixOS uses linux-stable kernels or not. If that's the case, running a newer kernel suggestion is still valid.
We’re running the NixOS mainline versions which are very vanilla. There are very very 4 small patches that only fix up things around building and binary paths for helpers to call to adapt them to the nix environment.
I see. There were some improvements in the newer versions, so if you can rule out any possibly fixed bug is worth it.
Christian
-- Christian Theune · ct@flyingcircus.io · +49 345 219401 0 Flying Circus Internet Operations GmbH · https://flyingcircus.io Leipziger Str. 70/71 · 06108 Halle (Saale) · Deutschland HR Stendal HRB 21169 · Geschäftsführer: Christian Theune, Christian Zagrodnick
On Mon, Jun 16, 2025 at 12:09:21PM +0200, Christian Theune wrote:
On 16. Jun 2025, at 11:47, Carlos Maiolino cem@kernel.org wrote:
On Mon, Jun 16, 2025 at 10:59:34AM +0200, Christian Theune wrote:
On 16. Jun 2025, at 10:50, Carlos Maiolino cem@kernel.org wrote:
On Thu, Jun 12, 2025 at 03:37:10PM +0200, Christian Theune wrote:
Hi,
in the last week, after updating to 6.6.92, we’ve encountered a number of VMs reporting temporarily hung tasks blocking the whole system for a few minutes. They unblock by themselves and have similar tracebacks.
The IO PSIs show 100% pressure for that time, but the underlying devices are still processing read and write IO (well within their capacity). I’ve eliminated the underlying storage (Ceph) as the source of problems as I couldn’t find any latency outliers or significant queuing during that time.
I’ve seen somewhat similar reports on 6.6.88 and 6.6.77, but those might have been different outliers.
I’m attaching 3 logs - my intuition and the data so far leads me to consider this might be a kernel bug. I haven’t found a way to reproduce this, yet.
From a first glance, these machines are struggling because IO contention as you mentioned, more often than not they seem to be stalling waiting for log space to be freed, so any operation in the FS gets throttled while the journal isn't written back. If you have a small enough journal it will need to issue IO often enough to cause IO contention. So, I'd point it to a slow storage or small enough log area (or both).
Yeah, my current analysis didn’t show any storage performance issues. I’ll revisit this once more to make sure I’m not missing anything. We’ve previously had issues in this area that turned out to be kernel bugs. We didn’t change anything regarding journal sizes and only a recent kernel upgrade seemed to be relevant.
You mentioned you saw PSI showing a huge pressure ration, during the time, which might be generated by the journal writeback and giving it's a SYNC write, IOs will stall if your storage can't write it fast enough. IIRC, most of the threads from the logs you shared were waiting for log space to be able to continue, which causes the log to flush things to disk and of course increase IO usage. If your storage can't handle these IO bursts, then you'll get the stalls you're seeing. I am not discarding a possibility you are hitting a bug here, but it so far seems your storage is not being able to service IOs fast enough to avoid such IO stalls, or something else throttling IOs, XFS seems just the victim.
Yeah, it’s annoying, I know. To paraphrase "any sufficiently advanced bug is indistinguishable from slow storage”. ;)
As promised, I’ll dive deeper into the storage performance analysis, all telemetry so far was completely innocuous, but it’s a complex layering of SSDs → Ceph → Qemu … Usually if we have performance issues then the metrics reflect this quite obviously and will affect many machines at the same time. As this has always just affected one single VM at a time but spread over time my gut feeling is a bit more on the side of “it might be maybe a bug”. As those things tend to be hard/nasty to diagnose I wanted to raise the flag early on to see whether other’s might be having an “aha” moment if they’re experiencing something similar.
I’ll get back to you in 2-3 days with results from the storage analysis.
Can you share the xfs_info of one of these filesystems? I'm curious about the FS geometry.
Sure:
# xfs_info / meta-data=/dev/disk/by-label/root isize=512 agcount=21, agsize=655040 blks = sectsz=512 attr=2, projid32bit=1 = crc=1 finobt=1, sparse=1, rmapbt=0 = reflink=1 bigtime=1 inobtcount=1 nrext64=0 = exchange=0 data = bsize=4096 blocks=13106171, imaxpct=25 = sunit=0 swidth=0 blks naming =version 2 bsize=4096 ascii-ci=0, ftype=1, parent=0 log =internal log bsize=4096 blocks=16384, version=2 = sectsz=512 sunit=0 blks, lazy-count=1 realtime =none extsz=4096 blocks=0, rtextents=0
This seems to have been extended a few times, but nothing out-of-reality. Looks fine, but, is this one of the filesystems where you are facing the problem? I'm surprised this is the root FS, do you have that much IO into the rootFS?
# xfs_info /tmp/ meta-data=/dev/vdb1 isize=512 agcount=8, agsize=229376 blks = sectsz=512 attr=2, projid32bit=1 = crc=1 finobt=1, sparse=1, rmapbt=0 = reflink=0 bigtime=0 inobtcount=0 nrext64=0 = exchange=0 data = bsize=4096 blocks=1833979, imaxpct=25 = sunit=1024 swidth=1024 blks naming =version 2 bsize=4096 ascii-ci=0, ftype=1, parent=0 log =internal log bsize=4096 blocks=2560, version=2 = sectsz=512 sunit=8 blks, lazy-count=1 realtime =none extsz=4096 blocks=0, rtextents=0
This is worrisome. Your journal size is 10MiB, this can easily keep stalling IO waiting for log space to be freed, depending on the nature of the machine this can be easily triggered. I'm curious though how you made this FS, because 2560 is below the minimal log size that xfsprogs allows since (/me goes look into git log) 2022, xfsprogs 5.15.
FWIW, one of the reasons the minimum journal log size has been increased is the latency/stalls that happens when waiting for free log space, which is exactly the symptom you've been seeing.
I'd suggest you to check the xfsprogs commit below if you want more details, but if this is one of the filesystems where you see the stalls, this might very well be the cause:
commit cdfa467edd2d1863de067680b0a3ec4458e5ff4a Author: Eric Sandeen sandeen@redhat.com Date: Wed Apr 6 16:50:31 2022 -0400
mkfs: increase the minimum log size to 64MB when possible
There has been a few improvements though during Linux 6.9 on the log performance, but I can't tell if you have any of those improvements around. I'd suggest you trying to run a newer upstream kernel, otherwise you'll get very limited support from the upstream community. If you can't, I'd suggest you reporting this issue to your vendor, so they can track what you are/are not using in your current kernel.
Yeah, we’ve started upgrading selected/affected projects to 6.12, to see whether this improves things.
Good enough.
FWIW, I'm not sure if NixOS uses linux-stable kernels or not. If that's the case, running a newer kernel suggestion is still valid.
We’re running the NixOS mainline versions which are very vanilla. There are very very 4 small patches that only fix up things around building and binary paths for helpers to call to adapt them to the nix environment.
I see. There were some improvements in the newer versions, so if you can rule out any possibly fixed bug is worth it.
Christian
-- Christian Theune · ct@flyingcircus.io · +49 345 219401 0 Flying Circus Internet Operations GmbH · https://flyingcircus.io Leipziger Str. 70/71 · 06108 Halle (Saale) · Deutschland HR Stendal HRB 21169 · Geschäftsführer: Christian Theune, Christian Zagrodnick
-- Christian Theune · ct@flyingcircus.io · +49 345 219401 0 Flying Circus Internet Operations GmbH · https://flyingcircus.io Leipziger Str. 70/71 · 06108 Halle (Saale) · Deutschland HR Stendal HRB 21169 · Geschäftsführer: Christian Theune, Christian Zagrodnick
On 16. Jun 2025, at 14:15, Carlos Maiolino cem@kernel.org wrote:
On Mon, Jun 16, 2025 at 12:09:21PM +0200, Christian Theune wrote:
# xfs_info /tmp/ meta-data=/dev/vdb1 isize=512 agcount=8, agsize=229376 blks = sectsz=512 attr=2, projid32bit=1 = crc=1 finobt=1, sparse=1, rmapbt=0 = reflink=0 bigtime=0 inobtcount=0 nrext64=0 = exchange=0 data = bsize=4096 blocks=1833979, imaxpct=25 = sunit=1024 swidth=1024 blks naming =version 2 bsize=4096 ascii-ci=0, ftype=1, parent=0 log =internal log bsize=4096 blocks=2560, version=2 = sectsz=512 sunit=8 blks, lazy-count=1 realtime =none extsz=4096 blocks=0, rtextents=0
This is worrisome. Your journal size is 10MiB, this can easily keep stalling IO waiting for log space to be freed, depending on the nature of the machine this can be easily triggered. I'm curious though how you made this FS, because 2560 is below the minimal log size that xfsprogs allows since (/me goes look into git log) 2022, xfsprogs 5.15.
FWIW, one of the reasons the minimum journal log size has been increased is the latency/stalls that happens when waiting for free log space, which is exactly the symptom you've been seeing.
I'd suggest you to check the xfsprogs commit below if you want more details, but if this is one of the filesystems where you see the stalls, this might very well be the cause:
Interesting catch! I’ll double check this against our fleet and the affected machines and will dive into the traffic patterns of the specific underlying devices.
This filesystem is used for /tmp and is getting created fresh after a “cold boot” from our hypervisor. It could be that a number of VMs have only seen warm reboots for a couple of years but get kernel upgrades with warm reboots quite regularly. We’re in the process of changing the /tmp filesystem creation to happen fresh during initrd so that the VM internal xfsprogs will more closely match the guest kernel.
On 17. Jun 2025, at 07:44, Christian Theune ct@flyingcircus.io wrote:
On 16. Jun 2025, at 14:15, Carlos Maiolino cem@kernel.org wrote:
On Mon, Jun 16, 2025 at 12:09:21PM +0200, Christian Theune wrote:
# xfs_info /tmp/ meta-data=/dev/vdb1 isize=512 agcount=8, agsize=229376 blks = sectsz=512 attr=2, projid32bit=1 = crc=1 finobt=1, sparse=1, rmapbt=0 = reflink=0 bigtime=0 inobtcount=0 nrext64=0 = exchange=0 data = bsize=4096 blocks=1833979, imaxpct=25 = sunit=1024 swidth=1024 blks naming =version 2 bsize=4096 ascii-ci=0, ftype=1, parent=0 log =internal log bsize=4096 blocks=2560, version=2 = sectsz=512 sunit=8 blks, lazy-count=1 realtime =none extsz=4096 blocks=0, rtextents=0
This is worrisome. Your journal size is 10MiB, this can easily keep stalling IO waiting for log space to be freed, depending on the nature of the machine this can be easily triggered. I'm curious though how you made this FS, because 2560 is below the minimal log size that xfsprogs allows since (/me goes look into git log) 2022, xfsprogs 5.15.
FWIW, one of the reasons the minimum journal log size has been increased is the latency/stalls that happens when waiting for free log space, which is exactly the symptom you've been seeing.
I'd suggest you to check the xfsprogs commit below if you want more details, but if this is one of the filesystems where you see the stalls, this might very well be the cause:
Interesting catch! I’ll double check this against our fleet and the affected machines and will dive into the traffic patterns of the specific underlying devices.
This filesystem is used for /tmp and is getting created fresh after a “cold boot” from our hypervisor. It could be that a number of VMs have only seen warm reboots for a couple of years but get kernel upgrades with warm reboots quite regularly. We’re in the process of changing the /tmp filesystem creation to happen fresh during initrd so that the VM internal xfsprogs will more closely match the guest kernel.
I’ve checked the log size. A number of machines with very long uptimes have this outdated 10 MiB size. Many machines with less uptime have larger sizes (multiple hundred megabytes). Checking our codebase we let xfsprogs do their thing and don’t fiddle with the defaults.
The log sizes of the affected machines weren’t all set to 10 MiB - even machines with larger sizes were affected.
I’ll follow up - as promised - with further analysis whether IO starvation from the underlying storage may have occured.
Christian
On Tue, Jun 17, 2025 at 01:54:43PM +0200, Christian Theune wrote:
On 17. Jun 2025, at 07:44, Christian Theune ct@flyingcircus.io wrote:
On 16. Jun 2025, at 14:15, Carlos Maiolino cem@kernel.org wrote:
On Mon, Jun 16, 2025 at 12:09:21PM +0200, Christian Theune wrote:
# xfs_info /tmp/ meta-data=/dev/vdb1 isize=512 agcount=8, agsize=229376 blks = sectsz=512 attr=2, projid32bit=1 = crc=1 finobt=1, sparse=1, rmapbt=0 = reflink=0 bigtime=0 inobtcount=0 nrext64=0 = exchange=0 data = bsize=4096 blocks=1833979, imaxpct=25 = sunit=1024 swidth=1024 blks naming =version 2 bsize=4096 ascii-ci=0, ftype=1, parent=0 log =internal log bsize=4096 blocks=2560, version=2 = sectsz=512 sunit=8 blks, lazy-count=1 realtime =none extsz=4096 blocks=0, rtextents=0
This is worrisome. Your journal size is 10MiB, this can easily keep stalling IO waiting for log space to be freed, depending on the nature of the machine this can be easily triggered. I'm curious though how you made this FS, because 2560 is below the minimal log size that xfsprogs allows since (/me goes look into git log) 2022, xfsprogs 5.15.
FWIW, one of the reasons the minimum journal log size has been increased is the latency/stalls that happens when waiting for free log space, which is exactly the symptom you've been seeing.
I'd suggest you to check the xfsprogs commit below if you want more details, but if this is one of the filesystems where you see the stalls, this might very well be the cause:
Interesting catch! I’ll double check this against our fleet and the affected machines and will dive into the traffic patterns of the specific underlying devices.
This filesystem is used for /tmp and is getting created fresh after a “cold boot” from our hypervisor. It could be that a number of VMs have only seen warm reboots for a couple of years but get kernel upgrades with warm reboots quite regularly. We’re in the process of changing the /tmp filesystem creation to happen fresh during initrd so that the VM internal xfsprogs will more closely match the guest kernel.
I’ve checked the log size. A number of machines with very long uptimes have this outdated 10 MiB size. Many machines with less uptime have larger sizes (multiple hundred megabytes). Checking our codebase we let xfsprogs do their thing and don’t fiddle with the defaults.
The log sizes of the affected machines weren’t all set to 10 MiB - even machines with larger sizes were affected.
Bear in mind that this was the worst one you sent me, just because the other FS had a larger log, it doesn't mean it's enough or it won't face the same problems too, IIRC, the other configuration FS you sent, had a 64MiB log. xfsprogs has a default log size based on the FS size, so it won't take too much disk space for just the log, but the default may not be enough. This of course is speculation from my part giving the logs you provided, but might be worth to test your VMs with larger log sizes.
I’ll follow up - as promised - with further analysis whether IO starvation from the underlying storage may have occured.
Christian
-- Christian Theune · ct@flyingcircus.io · +49 345 219401 0 Flying Circus Internet Operations GmbH · https://flyingcircus.io Leipziger Str. 70/71 · 06108 Halle (Saale) · Deutschland HR Stendal HRB 21169 · Geschäftsführer: Christian Theune, Christian Zagrodnick
On Mon, Jun 16, 2025 at 12:09:21PM +0200, Christian Theune wrote:
Can you share the xfs_info of one of these filesystems? I'm curious about the FS geometry.
Sure:
# xfs_info / meta-data=/dev/disk/by-label/root isize=512 agcount=21, agsize=655040 blks = sectsz=512 attr=2, projid32bit=1 = crc=1 finobt=1, sparse=1, rmapbt=0 = reflink=1 bigtime=1 inobtcount=1 nrext64=0 = exchange=0 data = bsize=4096 blocks=13106171, imaxpct=25 = sunit=0 swidth=0 blks naming =version 2 bsize=4096 ascii-ci=0, ftype=1, parent=0 log =internal log bsize=4096 blocks=16384, version=2 = sectsz=512 sunit=0 blks, lazy-count=1 realtime =none extsz=4096 blocks=0, rtextents=0
From the logs, it was /dev/vda1 that was getting hung up, so I'm going to assume the workload is hitting the root partition, not:
# xfs_info /tmp/ meta-data=/dev/vdb1 isize=512 agcount=8, agsize=229376 blks
... this one that has a small log.
IOWs, I don't think the log size is a contributing factor here.
The indication from the logs is that the system is hung up waiting on slow journal writes. e.g. there are processes hung waiting for transaction reservations (i.e. no journal space available). Journal space is backed up on metadata writeback trying to force the journal to stable storage (which is blocked waiting for journal IO completion so it can issue more journal IO) and getting blocked so it can't make progress, either.
I think part of the issue is that journal writes issue device cache flushes and FUA writes, both of which require written data to be on stable storage before returning.
All this points to whatever storage is backing these VMs is extremely slow at guaranteeing persistence of data and eventually it can't keep up with the application making changes to the filesystem. When the journal IO latency gets high enough you start to see things backing up and stall warnings appearing.
IOWs, this does not look like a filesystem issue from the information presented, just storage that can't keep up with the rate at which the filesystem can make modifications in memory. When the fs finally starts to throttle on the slow storage, that's when you notice just how slow the storage actually is...
[ Historical note: this is exactly the sort of thing we have seen for years with hardware RAID5/6 adapters with large amounts of NVRAM and random write workloads. They run as fast as NVRAM can sink the 4kB random writes, then when the NVRAM fills, they have to wait for hundreds of MB of cached 4kB random writes to be written to the RAID5/6 luns at 50-100 IOPS. This causes the exact same "filesystem is hung" symptoms as you are describing in this thread. ]
There has been a few improvements though during Linux 6.9 on the log performance, but I can't tell if you have any of those improvements around. I'd suggest you trying to run a newer upstream kernel, otherwise you'll get very limited support from the upstream community. If you can't, I'd suggest you reporting this issue to your vendor, so they can track what you are/are not using in your current kernel.
Yeah, we’ve started upgrading selected/affected projects to 6.12, to see whether this improves things.
Keep in mind that if the problem is persistent write performance of the storage, upgrading the kernel will not make it go away. It may make it worse, because other optimisations we've made in the mean time could mean the journal fills faster and pushes into the persistent IO backlog latency issue sooner and more frequently....
-Dave.
On 18. Jun 2025, at 00:28, Dave Chinner david@fromorbit.com wrote:
On Mon, Jun 16, 2025 at 12:09:21PM +0200, Christian Theune wrote:
Can you share the xfs_info of one of these filesystems? I'm curious about the FS geometry.
Sure:
# xfs_info / meta-data=/dev/disk/by-label/root isize=512 agcount=21, agsize=655040 blks = sectsz=512 attr=2, projid32bit=1 = crc=1 finobt=1, sparse=1, rmapbt=0 = reflink=1 bigtime=1 inobtcount=1 nrext64=0 = exchange=0 data = bsize=4096 blocks=13106171, imaxpct=25 = sunit=0 swidth=0 blks naming =version 2 bsize=4096 ascii-ci=0, ftype=1, parent=0 log =internal log bsize=4096 blocks=16384, version=2 = sectsz=512 sunit=0 blks, lazy-count=1 realtime =none extsz=4096 blocks=0, rtextents=0
From the logs, it was /dev/vda1 that was getting hung up, so I'm going to assume the workload is hitting the root partition, not:
# xfs_info /tmp/ meta-data=/dev/vdb1 isize=512 agcount=8, agsize=229376 blks
... this one that has a small log.
IOWs, I don't think the log size is a contributing factor here.
The indication from the logs is that the system is hung up waiting on slow journal writes. e.g. there are processes hung waiting for transaction reservations (i.e. no journal space available). Journal space is backed up on metadata writeback trying to force the journal to stable storage (which is blocked waiting for journal IO completion so it can issue more journal IO) and getting blocked so it can't make progress, either.
I think part of the issue is that journal writes issue device cache flushes and FUA writes, both of which require written data to be on stable storage before returning.
All this points to whatever storage is backing these VMs is extremely slow at guaranteeing persistence of data and eventually it can't keep up with the application making changes to the filesystem. When the journal IO latency gets high enough you start to see things backing up and stall warnings appearing.
IOWs, this does not look like a filesystem issue from the information presented, just storage that can't keep up with the rate at which the filesystem can make modifications in memory. When the fs finally starts to throttle on the slow storage, that's when you notice just how slow the storage actually is...
[ Historical note: this is exactly the sort of thing we have seen for years with hardware RAID5/6 adapters with large amounts of NVRAM and random write workloads. They run as fast as NVRAM can sink the 4kB random writes, then when the NVRAM fills, they have to wait for hundreds of MB of cached 4kB random writes to be written to the RAID5/6 luns at 50-100 IOPS. This causes the exact same "filesystem is hung" symptoms as you are describing in this thread. ]
Yeah, I’m very wary of reporting these tracebacks as potential bugs because of them easily being just a hint on slow storage. My problem here is that I can’t point to anything that says the storage would have been slow.
I’ve gone through all metrics and logs on the KVM servers as well as the Ceph servers and they’ve been performing completely at baseline level regarding errors, queues, iops, latency.
I’ve done a measurement to try to emulate those accesses by running
$ fio --rw=randrw --name=synctest --bs=4k --direct=1 --numjobs=1 --ioengine=libaio --iodepth=1 --runtime=600 --write_barrier=1 --size=60m
I hope this is sufficiently comparable behaviour (maybe with a different read/write ratio instead of 0.5?) to what XFS log flushing does. This resulted in [1].
My interpretation of this measurement (and the VM showed no illnes while this was running over 10 minutes): the VM is throttled at 250 IOPs and is reporting back after 10 minutes of 4k random writes with average IOPS of exactly 250. The latencies are a bit varied, this could be due to Qemu throttling. The max latency was 133ms, the average 2ms. This is on a 10g storage network with Ceph that requires another network roundtrip for replication before ACKing a write.
There is one more (somewhat far fetched thing) I could pull in here: out of 11 VMs that have seen that are exhibiting those symptoms I have seen two (including one already running on 6.12 at that time) that did log a stacktrace[2] that reminded me of the memory/folio issue we debugged late last year / earlier this year (https://lkml.org/lkml/2024/9/12/1472)) … maybe it’s worthwhile to consider whether this might be related. The outside symptoms are similar: it recovers on its own at some point and I can’t show any issue with the underlying storage at all.
I’m out of ideas for now, I’ll keep thinking about this. If anyone has any pointer for further tests in any direction, I’m open to anything. ;)
Thanks for all the help so far, Christian
[1] The test results:
synctest: (g=0): rw=randrw, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=1 fio-3.38 Starting 1 process Jobs: 1 (f=1): [m(1)][100.0%][r=484KiB/s,w=517KiB/s][r=121,w=129 IOPS][eta 00m:00s] synctest: (groupid=0, jobs=1): err= 0: pid=655973: Wed Jun 18 09:28:31 2025 read: IOPS=122, BW=489KiB/s (501kB/s)(29.9MiB/62557msec) slat (usec): min=8, max=1096, avg=22.94, stdev=24.68 clat (usec): min=285, max=133773, avg=2745.14, stdev=2723.35 lat (usec): min=296, max=133812, avg=2768.08, stdev=2723.35 clat percentiles (usec): | 1.00th=[ 416], 5.00th=[ 506], 10.00th=[ 611], 20.00th=[ 832], | 30.00th=[ 1713], 40.00th=[ 2540], 50.00th=[ 2737], 60.00th=[ 3458], | 70.00th=[ 3621], 80.00th=[ 3785], 90.00th=[ 4555], 95.00th=[ 4817], | 99.00th=[ 6063], 99.50th=[ 7898], 99.90th=[ 22676], 99.95th=[ 78119], | 99.99th=[133694] bw ( KiB/s): min= 304, max= 608, per=99.90%, avg=489.79, stdev=59.34, samples=125 iops : min= 76, max= 152, avg=122.45, stdev=14.83, samples=125 write: IOPS=123, BW=493KiB/s (504kB/s)(30.1MiB/62557msec); 0 zone resets slat (usec): min=11, max=1102, avg=25.54, stdev=23.33 clat (usec): min=1434, max=140566, avg=5337.34, stdev=7163.78 lat (usec): min=1453, max=140651, avg=5362.88, stdev=7164.02 clat percentiles (usec): | 1.00th=[ 1713], 5.00th=[ 1926], 10.00th=[ 2114], 20.00th=[ 2868], | 30.00th=[ 3720], 40.00th=[ 4080], 50.00th=[ 4490], 60.00th=[ 5014], | 70.00th=[ 5276], 80.00th=[ 5866], 90.00th=[ 6652], 95.00th=[ 8979], | 99.00th=[ 33162], 99.50th=[ 64750], 99.90th=[ 99091], 99.95th=[111674], | 99.99th=[141558] bw ( KiB/s): min= 336, max= 672, per=99.86%, avg=492.93, stdev=60.30, samples=125 iops : min= 84, max= 168, avg=123.23, stdev=15.08, samples=125 lat (usec) : 500=2.28%, 750=6.19%, 1000=2.66% lat (msec) : 2=9.39%, 4=40.59%, 10=36.82%, 20=1.26%, 50=0.41% lat (msec) : 100=0.34%, 250=0.05% cpu : usr=0.17%, sys=0.73%, ctx=15398, majf=0, minf=11 IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0% submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% issued rwts: total=7655,7705,0,0 short=0,0,0,0 dropped=0,0,0,0 latency : target=0, window=0, percentile=100.00%, depth=1
Run status group 0 (all jobs): READ: bw=489KiB/s (501kB/s), 489KiB/s-489KiB/s (501kB/s-501kB/s), io=29.9MiB (31.4MB), run=62557-62557msec WRITE: bw=493KiB/s (504kB/s), 493KiB/s-493KiB/s (504kB/s-504kB/s), io=30.1MiB (31.6MB), run=62557-62557msec
Disk stats (read/write): vda: ios=7662/7865, sectors=61856/71089, merge=0/5, ticks=21263/105909, in_queue=127177, util=98.62% ctheune@hannover96stag00:~/ > fio --rw=randrw --name=synctest --bs=4k --direct=1 --numjobs=1 --ioengine=libaio --iodepth=1 --runtime=600 --write_barrier=1 --size=60m --time_based synctest: (g=0): rw=randrw, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=1 fio-3.38 Starting 1 process Jobs: 1 (f=1): [m(1)][100.0%][r=408KiB/s,w=344KiB/s][r=102,w=86 IOPS][eta 00m:00s] synctest: (groupid=0, jobs=1): err= 0: pid=656097: Wed Jun 18 09:38:54 2025 read: IOPS=121, BW=485KiB/s (496kB/s)(284MiB/600006msec) slat (usec): min=7, max=1126, avg=23.70, stdev=22.33 clat (usec): min=99, max=128424, avg=2834.26, stdev=1977.13 lat (usec): min=299, max=128439, avg=2857.97, stdev=1975.91 clat percentiles (usec): | 1.00th=[ 416], 5.00th=[ 519], 10.00th=[ 660], 20.00th=[ 1516], | 30.00th=[ 2442], 40.00th=[ 2638], 50.00th=[ 2802], 60.00th=[ 3523], | 70.00th=[ 3654], 80.00th=[ 3818], 90.00th=[ 4555], 95.00th=[ 4752], | 99.00th=[ 5211], 99.50th=[ 7308], 99.90th=[12125], 99.95th=[23725], | 99.99th=[71828] bw ( KiB/s): min= 64, max= 672, per=100.00%, avg=485.12, stdev=75.21, samples=1199 iops : min= 16, max= 168, avg=121.27, stdev=18.80, samples=1199 write: IOPS=120, BW=481KiB/s (493kB/s)(282MiB/600006msec); 0 zone resets slat (usec): min=10, max=1168, avg=26.84, stdev=22.15 clat (usec): min=1193, max=307265, avg=5397.02, stdev=8361.82 lat (usec): min=1343, max=307308, avg=5423.86, stdev=8362.12 clat percentiles (usec): | 1.00th=[ 1729], 5.00th=[ 1975], 10.00th=[ 2245], 20.00th=[ 3097], | 30.00th=[ 3884], 40.00th=[ 4178], 50.00th=[ 4621], 60.00th=[ 5014], | 70.00th=[ 5276], 80.00th=[ 5800], 90.00th=[ 6456], 95.00th=[ 7898], | 99.00th=[ 32900], 99.50th=[ 66847], 99.90th=[132645], 99.95th=[154141], | 99.99th=[170918] bw ( KiB/s): min= 56, max= 672, per=99.91%, avg=481.74, stdev=74.40, samples=1199 iops : min= 14, max= 168, avg=120.43, stdev=18.60, samples=1199 lat (usec) : 100=0.01%, 250=0.01%, 500=2.08%, 750=4.49%, 1000=2.13% lat (msec) : 2=8.44%, 4=42.49%, 10=38.81%, 20=0.89%, 50=0.31% lat (msec) : 100=0.24%, 250=0.11%, 500=0.01% cpu : usr=0.20%, sys=0.75%, ctx=145300, majf=0, minf=12 IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0% submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% issued rwts: total=72728,72217,0,0 short=0,0,0,0 dropped=0,0,0,0 latency : target=0, window=0, percentile=100.00%, depth=1
Run status group 0 (all jobs): READ: bw=485KiB/s (496kB/s), 485KiB/s-485KiB/s (496kB/s-496kB/s), io=284MiB (298MB), run=600006-600006msec WRITE: bw=481KiB/s (493kB/s), 481KiB/s-481KiB/s (493kB/s-493kB/s), io=282MiB (296MB), run=600006-600006msec
Disk stats (read/write): vda: ios=72722/74795, sectors=582248/768053, merge=0/67, ticks=206476/860665, in_queue=1067364, util=98.78%
[2] second type of hung tasks that I considered unrelated so far
May 17 03:30:23 kernel: INFO: task kworker/u18:2:19320 blocked for more than 122 seconds. May 17 03:30:23 kernel: Not tainted 6.12.28 #1-NixOS May 17 03:30:23 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. May 17 03:30:23 kernel: task:kworker/u18:2 state:D stack:0 pid:19320 tgid:19320 ppid:2 flags:0x00004000 May 17 03:30:23 kernel: Workqueue: writeback wb_workfn (flush-253:0) May 17 03:30:23 kernel: Call Trace: May 17 03:30:23 kernel: <TASK> May 17 03:30:23 kernel: __schedule+0x442/0x12d0 May 17 03:30:23 kernel: schedule+0x27/0xf0 May 17 03:30:23 kernel: io_schedule+0x46/0x70 May 17 03:30:23 kernel: folio_wait_bit_common+0x13f/0x340 May 17 03:30:23 kernel: ? __pfx_wake_page_function+0x10/0x10 May 17 03:30:23 kernel: writeback_iter+0x1ec/0x2d0 May 17 03:30:23 kernel: iomap_writepages+0x74/0x9e0 May 17 03:30:23 kernel: ? virtqueue_add_split+0xb1/0x7a0 [virtio_ring] May 17 03:30:23 kernel: ? virtqueue_add_split+0x2af/0x7a0 [virtio_ring] May 17 03:30:23 kernel: xfs_vm_writepages+0x67/0xa0 [xfs] May 17 03:30:23 kernel: do_writepages+0x8a/0x290 May 17 03:30:23 kernel: ? enqueue_hrtimer+0x35/0x90 May 17 03:30:23 kernel: ? hrtimer_start_range_ns+0x2b7/0x450 May 17 03:30:23 kernel: __writeback_single_inode+0x3d/0x350 May 17 03:30:23 kernel: ? wbc_detach_inode+0x116/0x250 May 17 03:30:23 kernel: writeback_sb_inodes+0x228/0x4e0 May 17 03:30:23 kernel: __writeback_inodes_wb+0x4c/0xf0 May 17 03:30:23 kernel: wb_writeback+0x1ac/0x330 May 17 03:30:23 kernel: ? get_nr_inodes+0x3b/0x60 May 17 03:30:23 kernel: wb_workfn+0x357/0x460 May 17 03:30:23 kernel: process_one_work+0x192/0x3b0 May 17 03:30:23 kernel: worker_thread+0x230/0x340 May 17 03:30:23 kernel: ? __pfx_worker_thread+0x10/0x10 May 17 03:30:23 kernel: kthread+0xd0/0x100 May 17 03:30:23 kernel: ? __pfx_kthread+0x10/0x10 May 17 03:30:23 kernel: ret_from_fork+0x34/0x50 May 17 03:30:23 kernel: ? __pfx_kthread+0x10/0x10 May 17 03:30:23 kernel: ret_from_fork_asm+0x1a/0x30 May 17 03:30:23 kernel: </TASK> May 17 03:30:23 kernel: INFO: task nix:21146 blocked for more than 122 seconds. May 17 03:30:23 kernel: Not tainted 6.12.28 #1-NixOS May 17 03:30:23 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. May 17 03:30:23 kernel: task:nix state:D stack:0 pid:21146 tgid:21146 ppid:21145 flags:0x00000002 May 17 03:30:23 kernel: Call Trace: May 17 03:30:23 kernel: <TASK> May 17 03:30:23 kernel: __schedule+0x442/0x12d0 May 17 03:30:23 kernel: ? xas_load+0xd/0xe0 May 17 03:30:23 kernel: ? xa_load+0x77/0xb0 May 17 03:30:23 kernel: schedule+0x27/0xf0 May 17 03:30:23 kernel: io_schedule+0x46/0x70 May 17 03:30:23 kernel: folio_wait_bit_common+0x13f/0x340 May 17 03:30:23 kernel: ? __pfx_wake_page_function+0x10/0x10 May 17 03:30:23 kernel: folio_wait_writeback+0x2b/0x90 May 17 03:30:23 kernel: truncate_inode_partial_folio+0x5e/0x1c0 May 17 03:30:23 kernel: truncate_inode_pages_range+0x1de/0x410 May 17 03:30:23 kernel: truncate_pagecache+0x47/0x60 May 17 03:30:23 kernel: xfs_setattr_size+0xf6/0x3c0 [xfs] May 17 03:30:23 kernel: xfs_vn_setattr+0x85/0x150 [xfs] May 17 03:30:23 kernel: notify_change+0x301/0x500 May 17 03:30:23 kernel: ? do_truncate+0x98/0xf0 May 17 03:30:23 kernel: do_truncate+0x98/0xf0 May 17 03:30:23 kernel: do_ftruncate+0x104/0x170 May 17 03:30:23 kernel: do_sys_ftruncate+0x3d/0x80 May 17 03:30:23 kernel: do_syscall_64+0xb7/0x210 May 17 03:30:23 kernel: entry_SYSCALL_64_after_hwframe+0x77/0x7f May 17 03:30:23 kernel: RIP: 0033:0x7f87aeb0d75b May 17 03:30:23 kernel: RSP: 002b:00007ffddbfc04b8 EFLAGS: 00000213 ORIG_RAX: 000000000000004d May 17 03:30:23 kernel: RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f87aeb0d75b May 17 03:30:23 kernel: RDX: 0000000000000000 RSI: 0000000000000003 RDI: 0000000000000008 May 17 03:30:23 kernel: RBP: 0000557d5dd46498 R08: 0000000000000000 R09: 0000000000000000 May 17 03:30:23 kernel: R10: 0000000000000000 R11: 0000000000000213 R12: 0000000000000008 May 17 03:30:23 kernel: R13: 0000557d5dcd2aa0 R14: 0000557d5dd46468 R15: 0000000000000008 May 17 03:30:23 kernel: </TASK>
May 17 03:32:26 kernel: INFO: task kworker/u18:2:19320 blocked for more than 245 seconds. May 17 03:32:26 kernel: Not tainted 6.12.28 #1-NixOS May 17 03:32:26 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. May 17 03:32:26 kernel: task:kworker/u18:2 state:D stack:0 pid:19320 tgid:19320 ppid:2 flags:0x00004000 May 17 03:32:26 kernel: Workqueue: writeback wb_workfn (flush-253:0) May 17 03:32:26 kernel: Call Trace: May 17 03:32:26 kernel: <TASK> May 17 03:32:26 kernel: __schedule+0x442/0x12d0 May 17 03:32:26 kernel: schedule+0x27/0xf0 May 17 03:32:26 kernel: io_schedule+0x46/0x70 May 17 03:32:26 kernel: folio_wait_bit_common+0x13f/0x340 May 17 03:32:26 kernel: ? __pfx_wake_page_function+0x10/0x10 May 17 03:32:26 kernel: writeback_iter+0x1ec/0x2d0 May 17 03:32:26 kernel: iomap_writepages+0x74/0x9e0 May 17 03:32:26 kernel: ? virtqueue_add_split+0xb1/0x7a0 [virtio_ring] May 17 03:32:26 kernel: ? virtqueue_add_split+0x2af/0x7a0 [virtio_ring] May 17 03:32:26 kernel: xfs_vm_writepages+0x67/0xa0 [xfs] May 17 03:32:26 kernel: do_writepages+0x8a/0x290 May 17 03:32:26 kernel: ? enqueue_hrtimer+0x35/0x90 May 17 03:32:26 kernel: ? hrtimer_start_range_ns+0x2b7/0x450 May 17 03:32:26 kernel: __writeback_single_inode+0x3d/0x350 May 17 03:32:26 kernel: ? wbc_detach_inode+0x116/0x250 May 17 03:32:26 kernel: writeback_sb_inodes+0x228/0x4e0 May 17 03:32:26 kernel: __writeback_inodes_wb+0x4c/0xf0 May 17 03:32:26 kernel: wb_writeback+0x1ac/0x330 May 17 03:32:26 kernel: ? get_nr_inodes+0x3b/0x60 May 17 03:32:26 kernel: wb_workfn+0x357/0x460 May 17 03:32:26 kernel: process_one_work+0x192/0x3b0 May 17 03:32:26 kernel: worker_thread+0x230/0x340 May 17 03:32:26 kernel: ? __pfx_worker_thread+0x10/0x10 May 17 03:32:26 kernel: kthread+0xd0/0x100 May 17 03:32:26 kernel: ? __pfx_kthread+0x10/0x10 May 17 03:32:26 kernel: ret_from_fork+0x34/0x50 May 17 03:32:26 kernel: ? __pfx_kthread+0x10/0x10 May 17 03:32:26 kernel: ret_from_fork_asm+0x1a/0x30 May 17 03:32:26 kernel: </TASK> May 17 03:32:26 kernel: INFO: task nix:21146 blocked for more than 245 seconds. May 17 03:32:26 kernel: Not tainted 6.12.28 #1-NixOS May 17 03:32:26 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. May 17 03:32:26 kernel: task:nix state:D stack:0 pid:21146 tgid:21146 ppid:21145 flags:0x00000002 May 17 03:32:26 kernel: Call Trace: May 17 03:32:26 kernel: <TASK> May 17 03:32:26 kernel: __schedule+0x442/0x12d0 May 17 03:32:26 kernel: ? xas_load+0xd/0xe0 May 17 03:32:26 kernel: ? xa_load+0x77/0xb0 May 17 03:32:26 kernel: schedule+0x27/0xf0 May 17 03:32:26 kernel: io_schedule+0x46/0x70 May 17 03:32:26 kernel: folio_wait_bit_common+0x13f/0x340 May 17 03:32:26 kernel: ? __pfx_wake_page_function+0x10/0x10 May 17 03:32:26 kernel: folio_wait_writeback+0x2b/0x90 May 17 03:32:26 kernel: truncate_inode_partial_folio+0x5e/0x1c0 May 17 03:32:26 kernel: truncate_inode_pages_range+0x1de/0x410 May 17 03:32:26 kernel: truncate_pagecache+0x47/0x60 May 17 03:32:26 kernel: xfs_setattr_size+0xf6/0x3c0 [xfs] May 17 03:32:26 kernel: xfs_vn_setattr+0x85/0x150 [xfs] May 17 03:32:26 kernel: notify_change+0x301/0x500 May 17 03:32:26 kernel: ? do_truncate+0x98/0xf0 May 17 03:32:26 kernel: do_truncate+0x98/0xf0 May 17 03:32:26 kernel: do_ftruncate+0x104/0x170 May 17 03:32:26 kernel: do_sys_ftruncate+0x3d/0x80 May 17 03:32:26 kernel: do_syscall_64+0xb7/0x210 May 17 03:32:26 kernel: entry_SYSCALL_64_after_hwframe+0x77/0x7f May 17 03:32:26 kernel: RIP: 0033:0x7f87aeb0d75b May 17 03:32:26 kernel: RSP: 002b:00007ffddbfc04b8 EFLAGS: 00000213 ORIG_RAX: 000000000000004d May 17 03:32:26 kernel: RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f87aeb0d75b May 17 03:32:26 kernel: RDX: 0000000000000000 RSI: 0000000000000003 RDI: 0000000000000008 May 17 03:32:26 kernel: RBP: 0000557d5dd46498 R08: 0000000000000000 R09: 0000000000000000 May 17 03:32:26 kernel: R10: 0000000000000000 R11: 0000000000000213 R12: 0000000000000008 May 17 03:32:26 kernel: R13: 0000557d5dcd2aa0 R14: 0000557d5dd46468 R15: 0000000000000008 May 17 03:32:26 kernel: </TASK>
May 17 03:34:29 kernel: INFO: task kworker/u18:2:19320 blocked for more than 368 seconds. May 17 03:34:29 kernel: Not tainted 6.12.28 #1-NixOS May 17 03:34:29 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. May 17 03:34:29 kernel: task:kworker/u18:2 state:D stack:0 pid:19320 tgid:19320 ppid:2 flags:0x00004000 May 17 03:34:29 kernel: Workqueue: writeback wb_workfn (flush-253:0) May 17 03:34:29 kernel: Call Trace: May 17 03:34:29 kernel: <TASK> May 17 03:34:29 kernel: __schedule+0x442/0x12d0 May 17 03:34:29 kernel: schedule+0x27/0xf0 May 17 03:34:29 kernel: io_schedule+0x46/0x70 May 17 03:34:29 kernel: folio_wait_bit_common+0x13f/0x340 May 17 03:34:29 kernel: ? __pfx_wake_page_function+0x10/0x10 May 17 03:34:29 kernel: writeback_iter+0x1ec/0x2d0 May 17 03:34:29 kernel: iomap_writepages+0x74/0x9e0 May 17 03:34:29 kernel: ? virtqueue_add_split+0xb1/0x7a0 [virtio_ring] May 17 03:34:29 kernel: ? virtqueue_add_split+0x2af/0x7a0 [virtio_ring] May 17 03:34:29 kernel: xfs_vm_writepages+0x67/0xa0 [xfs] May 17 03:34:29 kernel: do_writepages+0x8a/0x290 May 17 03:34:29 kernel: ? enqueue_hrtimer+0x35/0x90 May 17 03:34:29 kernel: ? hrtimer_start_range_ns+0x2b7/0x450 May 17 03:34:29 kernel: __writeback_single_inode+0x3d/0x350 May 17 03:34:29 kernel: ? wbc_detach_inode+0x116/0x250 May 17 03:34:29 kernel: writeback_sb_inodes+0x228/0x4e0 May 17 03:34:29 kernel: __writeback_inodes_wb+0x4c/0xf0 May 17 03:34:29 kernel: wb_writeback+0x1ac/0x330 May 17 03:34:29 kernel: ? get_nr_inodes+0x3b/0x60 May 17 03:34:29 kernel: wb_workfn+0x357/0x460 May 17 03:34:29 kernel: process_one_work+0x192/0x3b0 May 17 03:34:29 kernel: worker_thread+0x230/0x340 May 17 03:34:29 kernel: ? __pfx_worker_thread+0x10/0x10 May 17 03:34:29 kernel: kthread+0xd0/0x100 May 17 03:34:29 kernel: ? __pfx_kthread+0x10/0x10 May 17 03:34:29 kernel: ret_from_fork+0x34/0x50 May 17 03:34:29 kernel: ? __pfx_kthread+0x10/0x10 May 17 03:34:29 kernel: ret_from_fork_asm+0x1a/0x30 May 17 03:34:29 kernel: </TASK> May 17 03:34:29 kernel: INFO: task nix:21146 blocked for more than 368 seconds. May 17 03:34:29 kernel: Not tainted 6.12.28 #1-NixOS May 17 03:34:29 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. May 17 03:34:29 kernel: task:nix state:D stack:0 pid:21146 tgid:21146 ppid:21145 flags:0x00000002 May 17 03:34:29 kernel: Call Trace: May 17 03:34:29 kernel: <TASK> May 17 03:34:29 kernel: __schedule+0x442/0x12d0 May 17 03:34:29 kernel: ? xas_load+0xd/0xe0 May 17 03:34:29 kernel: ? xa_load+0x77/0xb0 May 17 03:34:29 kernel: schedule+0x27/0xf0 May 17 03:34:29 kernel: io_schedule+0x46/0x70 May 17 03:34:29 kernel: folio_wait_bit_common+0x13f/0x340 May 17 03:34:29 kernel: ? __pfx_wake_page_function+0x10/0x10 May 17 03:34:29 kernel: folio_wait_writeback+0x2b/0x90 May 17 03:34:29 kernel: truncate_inode_partial_folio+0x5e/0x1c0 May 17 03:34:29 kernel: truncate_inode_pages_range+0x1de/0x410 May 17 03:34:29 kernel: truncate_pagecache+0x47/0x60 May 17 03:34:29 kernel: xfs_setattr_size+0xf6/0x3c0 [xfs] May 17 03:34:29 kernel: xfs_vn_setattr+0x85/0x150 [xfs] May 17 03:34:29 kernel: notify_change+0x301/0x500 May 17 03:34:29 kernel: ? do_truncate+0x98/0xf0 May 17 03:34:29 kernel: do_truncate+0x98/0xf0 May 17 03:34:29 kernel: do_ftruncate+0x104/0x170 May 17 03:34:29 kernel: do_sys_ftruncate+0x3d/0x80 May 17 03:34:29 kernel: do_syscall_64+0xb7/0x210 May 17 03:34:29 kernel: entry_SYSCALL_64_after_hwframe+0x77/0x7f May 17 03:34:29 kernel: RIP: 0033:0x7f87aeb0d75b May 17 03:34:29 kernel: RSP: 002b:00007ffddbfc04b8 EFLAGS: 00000213 ORIG_RAX: 000000000000004d May 17 03:34:29 kernel: RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f87aeb0d75b May 17 03:34:29 kernel: RDX: 0000000000000000 RSI: 0000000000000003 RDI: 0000000000000008 May 17 03:34:29 kernel: RBP: 0000557d5dd46498 R08: 0000000000000000 R09: 0000000000000000 May 17 03:34:29 kernel: R10: 0000000000000000 R11: 0000000000000213 R12: 0000000000000008 May 17 03:34:29 kernel: R13: 0000557d5dcd2aa0 R14: 0000557d5dd46468 R15: 0000000000000008 May 17 03:34:29 kernel: </TASK>
On Wed, Jun 18, 2025 at 03:01:26PM +0200, Christian Theune wrote:
On 18. Jun 2025, at 00:28, Dave Chinner david@fromorbit.com wrote:
On Mon, Jun 16, 2025 at 12:09:21PM +0200, Christian Theune wrote:
Can you share the xfs_info of one of these filesystems? I'm curious about the FS geometry.
Sure:
# xfs_info / meta-data=/dev/disk/by-label/root isize=512 agcount=21, agsize=655040 blks = sectsz=512 attr=2, projid32bit=1 = crc=1 finobt=1, sparse=1, rmapbt=0 = reflink=1 bigtime=1 inobtcount=1 nrext64=0 = exchange=0 data = bsize=4096 blocks=13106171, imaxpct=25 = sunit=0 swidth=0 blks naming =version 2 bsize=4096 ascii-ci=0, ftype=1, parent=0 log =internal log bsize=4096 blocks=16384, version=2 = sectsz=512 sunit=0 blks, lazy-count=1 realtime =none extsz=4096 blocks=0, rtextents=0
From the logs, it was /dev/vda1 that was getting hung up, so I'm going to assume the workload is hitting the root partition, not:
# xfs_info /tmp/ meta-data=/dev/vdb1 isize=512 agcount=8, agsize=229376 blks
... this one that has a small log.
IOWs, I don't think the log size is a contributing factor here.
The indication from the logs is that the system is hung up waiting on slow journal writes. e.g. there are processes hung waiting for transaction reservations (i.e. no journal space available). Journal space is backed up on metadata writeback trying to force the journal to stable storage (which is blocked waiting for journal IO completion so it can issue more journal IO) and getting blocked so it can't make progress, either.
I think part of the issue is that journal writes issue device cache flushes and FUA writes, both of which require written data to be on stable storage before returning.
All this points to whatever storage is backing these VMs is extremely slow at guaranteeing persistence of data and eventually it can't keep up with the application making changes to the filesystem. When the journal IO latency gets high enough you start to see things backing up and stall warnings appearing.
IOWs, this does not look like a filesystem issue from the information presented, just storage that can't keep up with the rate at which the filesystem can make modifications in memory. When the fs finally starts to throttle on the slow storage, that's when you notice just how slow the storage actually is...
[ Historical note: this is exactly the sort of thing we have seen for years with hardware RAID5/6 adapters with large amounts of NVRAM and random write workloads. They run as fast as NVRAM can sink the 4kB random writes, then when the NVRAM fills, they have to wait for hundreds of MB of cached 4kB random writes to be written to the RAID5/6 luns at 50-100 IOPS. This causes the exact same "filesystem is hung" symptoms as you are describing in this thread. ]
Yeah, I’m very wary of reporting these tracebacks as potential bugs because of them easily being just a hint on slow storage. My problem here is that I can’t point to anything that says the storage would have been slow.
I’ve gone through all metrics and logs on the KVM servers as well as the Ceph servers and they’ve been performing completely at baseline level regarding errors, queues, iops, latency.
I’ve done a measurement to try to emulate those accesses by running
$ fio --rw=randrw --name=synctest --bs=4k --direct=1 --numjobs=1 --ioengine=libaio --iodepth=1 --runtime=600 --write_barrier=1 --size=60m
I hope this is sufficiently comparable behaviour (maybe with a different read/write ratio instead of 0.5?) to what XFS log flushing does. This resulted in [1].
Not really comparable. "write-barrier" is not the option for data integrity - fdatasync=8 would be closer, but even that doesn't replicate the cache flush/fua write pattern of journal IOs.
Also, journals are write only and sequential, not random. The iodepth is typically 8 when fully busy, and the IO size ranges from single sector to logbsize (from /proc/mounts) depending on the workload.
Metadata writeback to clear the journal, OTOH, is larger random 4kB writes with no data integrity implied (the journal cache flush mechanism I mention above handles that).
My interpretation of this measurement (and the VM showed no illnes while this was running over 10 minutes): the VM is throttled at 250 IOPs and is reporting back after 10 minutes of 4k random writes with average IOPS of exactly 250. The latencies are a bit varied, this could be due to Qemu throttling. The max latency was 133ms, the average 2ms. This is on a 10g storage network with Ceph that requires another network roundtrip for replication before ACKing a write.
Oh. Ceph.
Slow random write performance on ceph rbd devices seem to be a recurring problem - the filesystem is way faster than the storage, and by the time the filesystem throttles on journal space (even with small logs), the backlog of IO cannot be drained very quickly and so everything stalls.
IOWs, a hard cap of 250 random 4kB write IOPS is extremely slow and a likely cause of your random stall problems. When you have lots of dirty metadata in memory, then it can take minutes of IO for writeback to free journal space to allow progress to be made again.
For example, modify an inode (e.g. chmod), and that only takes ~250 bytes of journal space to record. So a 10MB journal can hold ~40,000 dirty inodes. If we assume that there maximum locality in these inodes (i.e. best case writeback IO patterns) we have ~1300 x 16kB writes to perform to empty the journal.
Hence there's up to 10-15s of writeback IO to "unstall" a small journal. Worst case, it's one 16kB write per inode, and that means potential for multiple minutes of writeback to unstall a 10MB journal. Now consider a 64MB journal, and the potential stalls waiting on metadata writeback are much, much worse...
These stalls will come and go with workload peaks. The filesystem can soak up some of the peak into memory and the journal, then it throttles to storage speed and that's where the hung task warnings fire. Once the storage catches up, everything goes back to "normal" latencies.
I’m out of ideas for now, I’ll keep thinking about this. If anyone has any pointer for further tests in any direction, I’m open to anything. ;)
Don't use hard throttling on IOPS rates. Measure IO rates over a longer period of time (e.g. rolling average over a minute) so that the storage can rapidly sink the short term IO peaks that occur when the workload runs the journal out of space and the fs throttles it whilst metadata writeback makes progress.
-Dave.
Ouch, thanks for that explanation. I now get why and how this really is either a log-related or even general dirty/writeback flushing issue. We definitely have some quite sub-optimal settings here - so I’m revisiting our dirty/writeback settings and XFS journal sizes. My understanding is that (in our situation) those should be sized based on the backing storage performance - so typically we’ll end up with fixed sizes independent of the available RAM or volume size that will guarantee an upper bound for worst case of flushing/processing.
However, I’m still a bit puzzled why this has escalated to user-visible incidents in the last weeks - we’ve been running with those sub-optimal settings for a very long time and haven’t had these issues before.
I took some time to educate myself further around the writeback behaviour and noticed the special relationship with that keeps getting mentioned between writeback and cgroups and those are in play with our setup, so maybe it’s worth another look.
Whenever this issue hits us, the system is running one of two system management tasks where one performs garbage collection on the nix store (which typically contains multiple generations of all packages on the system) and the other builds out a new system config. Those jobs are run in separate cgroups and throttled at 31 RW IOPS (12.5% of 250) and 188 RW IOPS (75% of 250). Those jobs aren’t time critical at all, so we want to leave sufficient IOPS to not starve the actual workload.
Those jobs run relatively often without causing issues, but then they’re also lazy. Still, even when they do work they do not always cause those issues. If they do, then i can see a sudden spike in our telemetry for dirty pages (around 300-400 MiB typically) followed by a jump in writeback pages (which is typically a bit higher: around 200 MiB more than dirty pages).
So far so good - that’s expected behaviour: one of the jobs might be deleting a lot of files - so that’s lots of metadata operations in the journal, and the other typically extracts archives, so many new files with different sizes.
Here’s why I think there might be a bug lurking (or I’m still missing something):
When the journal in a volume is relatively small (10 MiB) but the amount of data in writeback is around 450 MiB this indicates regular file content being flushed. I only see 3 mib/s at around 100 iops (indicating average 32k writes).
The 100 IOPS is a weird number here. Especially as at this time customer traffic is impacted and apparently completely stalled. My impression from reading about the writeback mechanisms and your description of journal flushes was that none of the flushing operations should cause a full stall until the caches or journal is empty, but allow traffic to trickle, roughly at the backing storage speed. Of course, if the system adds more traffic then is being written out then it would still starve.
(I’m guessing that the journal flush doesn’t go through the writeback cache. So maybe the journal isn’t really involved here at all.)
So, could it be that there is some (faulty) relationship with the cgroup throttling interacting with the writeback and/or journal flush that causes a) the available IOPS from the backing storage not being properly used and b) other traffic being stalled that shouldn’t be?
How would I go about proving that?
I tried again to replicate the worst case traffic patterns and ran
fio --rw=randwrite --name=synctest --bs=512 --direct=1 --numjobs=1 --ioengine=libaio --iodepth=8 --runtime=600 --fdatasync=8 --size=10m
which gave me consistent ~250 IOPS and finished in around 80 seconds.
I’m going to try to find a machine that exhibits the issues most often and will a) apply lower bounds for the writeback cache, b) remove the cgroup limits and c) both.
Thanks again, Christian
On 18. Jun 2025, at 23:54, Dave Chinner david@fromorbit.com wrote:
On Wed, Jun 18, 2025 at 03:01:26PM +0200, Christian Theune wrote:
[…] Yeah, I’m very wary of reporting these tracebacks as potential bugs because of them easily being just a hint on slow storage. My problem here is that I can’t point to anything that says the storage would have been slow.
I’ve gone through all metrics and logs on the KVM servers as well as the Ceph servers and they’ve been performing completely at baseline level regarding errors, queues, iops, latency.
I’ve done a measurement to try to emulate those accesses by running
$ fio --rw=randrw --name=synctest --bs=4k --direct=1 --numjobs=1 --ioengine=libaio --iodepth=1 --runtime=600 --write_barrier=1 --size=60m
I hope this is sufficiently comparable behaviour (maybe with a different read/write ratio instead of 0.5?) to what XFS log flushing does. This resulted in [1].
Not really comparable. "write-barrier" is not the option for data integrity - fdatasync=8 would be closer, but even that doesn't replicate the cache flush/fua write pattern of journal IOs.
Also, journals are write only and sequential, not random. The iodepth is typically 8 when fully busy, and the IO size ranges from single sector to logbsize (from /proc/mounts) depending on the workload.
Metadata writeback to clear the journal, OTOH, is larger random 4kB writes with no data integrity implied (the journal cache flush mechanism I mention above handles that).
My interpretation of this measurement (and the VM showed no illnes while this was running over 10 minutes): the VM is throttled at 250 IOPs and is reporting back after 10 minutes of 4k random writes with average IOPS of exactly 250. The latencies are a bit varied, this could be due to Qemu throttling. The max latency was 133ms, the average 2ms. This is on a 10g storage network with Ceph that requires another network roundtrip for replication before ACKing a write.
Oh. Ceph.
Slow random write performance on ceph rbd devices seem to be a recurring problem - the filesystem is way faster than the storage, and by the time the filesystem throttles on journal space (even with small logs), the backlog of IO cannot be drained very quickly and so everything stalls.
IOWs, a hard cap of 250 random 4kB write IOPS is extremely slow and a likely cause of your random stall problems. When you have lots of dirty metadata in memory, then it can take minutes of IO for writeback to free journal space to allow progress to be made again.
For example, modify an inode (e.g. chmod), and that only takes ~250 bytes of journal space to record. So a 10MB journal can hold ~40,000 dirty inodes. If we assume that there maximum locality in these inodes (i.e. best case writeback IO patterns) we have ~1300 x 16kB writes to perform to empty the journal.
Hence there's up to 10-15s of writeback IO to "unstall" a small journal. Worst case, it's one 16kB write per inode, and that means potential for multiple minutes of writeback to unstall a 10MB journal. Now consider a 64MB journal, and the potential stalls waiting on metadata writeback are much, much worse...
These stalls will come and go with workload peaks. The filesystem can soak up some of the peak into memory and the journal, then it throttles to storage speed and that's where the hung task warnings fire. Once the storage catches up, everything goes back to "normal" latencies.
I’m out of ideas for now, I’ll keep thinking about this. If anyone has any pointer for further tests in any direction, I’m open to anything. ;)
Don't use hard throttling on IOPS rates. Measure IO rates over a longer period of time (e.g. rolling average over a minute) so that the storage can rapidly sink the short term IO peaks that occur when the workload runs the journal out of space and the fs throttles it whilst metadata writeback makes progress.
-Dave.
Dave Chinner david@fromorbit.com
linux-stable-mirror@lists.linaro.org