Mustafa ERBAY

Posted on Sep 20 Originally published at mustafaerbay.com.tr

55 Seconds in D State, Zero Warnings: khungtaskd's Blind Spots

#linux #kernel #sysctl #storage

My mental model was simple: if a process stays in D state for more than 120 seconds, the kernel shouts INFO: task X blocked for more than 120 seconds and I see it in the journal. Trusting that model, I have spent years waiting for disk failures to announce themselves with "I'll check dmesg, it'll be there." This weekend I wanted to test it on a VPS running Ubuntu 26.04 (kernel 7.0.0-31-generic): I temporarily dropped kernel.hung_task_timeout_secs to 10, froze a linear device-mapper device built on a loop file with dmsetup suspend, and wrote to it with dd ... oflag=direct. dd went into D state immediately, /proc/PID/stack showed submit_bio_wait, kill -9 did nothing. I waited 55 seconds.

Not a single line in dmesg. hung_task_detect_count was zero, hung_task_warnings was still 10.

This post chases that empty dmesg. The answer isn't in one place: the detector is late by design, the block layer dodges it by design, it goes silent after ten warnings, and it never counts killable waits. Yet the same detector has, since 6.15, been telling you who holds the lock; I saw that in the same lab. Every experiment ran on that VPS, and every setting (hung_task_timeout_secs, hung_task_warnings, the loop device, the dm table, the test module) went back to its starting value at the end. The one thing I couldn't undo was hung_task_detect_count; I explain why below.

What the detector actually counts

kernel/hung_task.c is a small file: a single kernel thread called khungtaskd wakes every hung_task_check_interval_secs seconds (or every timeout seconds if that is zero), walks every task and asks task_is_hung() about each one. That function's logic explains the empty dmesg almost on its own:

Two details matter. First, the detector doesn't watch time, it watches the context-switch counter: if a task's nvcsw + nivcsw total hasn't changed between two rounds, it counts as "never ran". Second, last_switch_time is not the moment the task blocked; it's the round in which the detector first saw it sitting still. So if your system says 120 seconds, the first report arrives no earlier than 120 and no later than 240 seconds, and the "blocked for more than N seconds" inside the report counts from that first sighting, not from the real block. I saw this cleanly in the lab: two dd processes blocked at 09:40:30, the first report came 20 seconds later and said "more than 10 seconds".

The documentation summarises it as "When a task in D state did not get scheduled for more than this value report a warning". True but incomplete. The code has three more exceptions, and all three show up in production: tasks waiting in TASK_KILLABLE are skipped (most NFS waits are like that; that's what nfs_wait_bit_killable is for), kernel threads waiting in TASK_IDLE are skipped, and tasks stopped by the freezer are skipped.

The block layer dodges the detector

Here's the real surprise. When I read dd's /proc/PID/status every five seconds, voluntary_ctxt_switches went up by one each time: 1, 2, 3, ... 9. The process showed as "D (disk sleep)", yet every five seconds it woke up and went back into the same wait. Five seconds is exactly half the timeout I had set. Not a coincidence; the wait helper in block/blk.h reads:

static inline void blk_wait_io(struct completion *done)
{
    /* Prevent hang_check timer from firing at us during very long I/O */
    unsigned long timeout = sysctl_hung_task_timeout_secs * HZ / 2;

    if (timeout)
        while (!wait_for_completion_io_timeout(done, timeout))
            ;
    else
        wait_for_completion_io(done);
}

submit_bio_wait calls this; blk_io_schedule builds the same logic on io_schedule_timeout, and iomap's direct I/O path uses that. The comment doesn't hide the intent: to avoid producing hung-task warnings during long I/O, the wait is sliced into timeout/2 pieces. At the end of each slice the task wakes, the counter increments, the detector says "this one ran", and it sleeps again. The result: a process that writes directly to a block device and never gets an answer will not appear in a hung-task report even if the device stays silent for a week. With the default 120 seconds, that means waking every 60 seconds.

That fixed my mental model. The dodge exists only in completion-based waits: the submit_bio_wait path (blkdev_issue_flush, discard, small block-device DIO) and iomap's direct I/O path. Bit-wait based waits, meaning wait_on_buffer, folio_wait_writeback, fsync's filemap_fdatawait, call io_schedule() with no timeout and do get reported. That's why the blocked for more than lines you see on a dying disk are mostly writeback and journal victims: jbd2, kworker, the application calling fsync, the second process trying to write the same file. The process writing straight to the device with O_DIRECT, the most obvious suspect on the scene, isn't on the list. That's exactly why the picture changes from 6.17 on.

On the filesystem path the report comes, but not for who you expect

In the second experiment I put ext4 on the same dm device, mounted it, and suspended the device again. This time I started two writers: A direct (oflag=direct), B buffered. Both fell into D, and this time a report came, for both. But the stacks surprised me:

[<0>] percpu_rwsem_wait+0x163/0x1d0
[<0>] vfs_write+0x427/0x490

Neither had even entered ext4. dmsetup suspend freezes the filesystem on the device by default (the man page says "an attempt will be made to sync it first unless --nolockfs is specified"; LVM snapshots take the same path). On a frozen superblock every write() takes a percpu rw-semaphore via sb_start_write and stops there. That wait lives outside blk_wait_io; it sleeps in TASK_UNINTERRUPTIBLE | TASK_FREEZABLE, and FREEZABLE is not the FROZEN the detector skips, so the detector sees it. Over three rounds, two reports every 10 seconds: hung_task_warnings went from 10 to 8, 6, 4; hung_task_detect_count reached 6; the load average, which had hovered between 0.15 and 0.75 all morning, climbed to 1.27. Two tasks in D, both added to the load average through nr_uninterruptible; the comment at the top of kernel/sched/loadavg.c says so explicitly.

The third experiment used --nolockfs. The filesystem didn't freeze, A took the file's i_rwsem, sent its bio through iomap and started waiting in blk_io_schedule; B asked for i_rwsem to do a buffered write to the same file and queued up behind A. This time the kernel wrote:

INFO: task jbd2/dm-0-8:3790580 blocked for more than 10 seconds.
INFO: task dd:3790596 blocked for more than 10 seconds.
INFO: task dd:3790596 <writer> blocked on an rw-semaphore likely owned by task dd:3790592 <reader>
task:dd              state:D stack:0     pid:3790592 tgid:3790592 ppid:3790552
Call Trace:
 <TASK>
 __schedule+0x2bb/0x650
 schedule+0x27/0xb0
 schedule_timeout+0x88/0x110
 io_schedule_timeout+0x61/0xa0
 blk_io_schedule+0x1e/0x40
 __iomap_dio_rw+0x4a0/0x6e0
 iomap_dio_rw+0x11/0x60
 ext4_dio_write_iter+0x20b/0x3e0

Two facts side by side: B (3790596) is hung, A (3790592) is not; but A owns the lock and has blk_io_schedule in its stack. The detector never counted A as hung in any round (its context-switch counter went from 2 to 15, one tick every five seconds), yet it printed A's stack because A is the owner. The culprit is in the log now; not on the "blocked" line, on the "likely owned by" line.

Who holds the lock: 6.15, 6.16, 6.17

The code producing that line sits under CONFIG_DETECT_HUNG_TASK_BLOCKER and arrived in three pieces: the mutex owner in 6.15, the semaphore's last holder in 6.16, the rw-semaphore owner in 6.17. Each task carries the lock it's blocked on in task->blocker; while writing the report the detector finds the owner and, if the owner isn't hung itself, prints its stack too. The coverage is limited to those three lock types; the percpu rw-semaphore wait in the second experiment got no "likely owned by" line, and couldn't have.

Ubuntu 26.04's kernel package ships the feature enabled (CONFIG_DETECT_HUNG_TASK_BLOCKER=y) and also builds the in-tree test module: samples/hung_task/hung_task_tests.ko. The module exposes four files under debugfs; when two readers open the same file, the first sleeps for 256 seconds and the second drops into D on a mutex. The third experiment had driven the warning budget to zero; I wrote hung_task_warnings back to 10 and ran it:

$ sudo modprobe hung_task_tests && ls /sys/kernel/debug/hung_task/
mutex  rw_semaphore_read  rw_semaphore_write  semaphore
pid 3792666: State: S (sleeping)   wchan=msleep_interruptible
pid 3792669: State: D (disk sleep) wchan=read_dummy_mutex

INFO: task cat:3792669 blocked for more than 10 seconds.
INFO: task cat:3792669 is blocked on a mutex likely owned by task cat:3792666.
task:cat  state:S  pid:3792666 ...
 msleep_interruptible+0x2d/0x60
 read_dummy_mutex+0x49/0xb0 [hung_task_tests]

The owner is in S, sleeping comfortably; the hung cat is in D because of it. These two rounds took hung_task_detect_count from 18 to 20, and the server stayed at that number. On an older kernel you'd find this by dumping stacks with echo w > /proc/sysrq-trigger and matching lock addresses by hand. Four of the seven servers in my fleet are still on 6.8 and 6.14; the line doesn't exist there, and you have to know to look.

The same experiment showed why kill -9 doesn't work. I sent SIGKILL to the hung cat; SigPnd: 0000000000000100 appeared in /proc/PID/status (bit 9, SIGKILL) and the process stayed in D. The moment I released the owner, the waiter took the mutex, returned from the syscall, and the pending signal was handled right then: "Killed". The dd in the first experiment died the same way, but only after dmsetup resume, exit code 137. D state doesn't refuse the signal; it postpones it.

Ten warnings, then silence

I kept the third experiment running for 70 seconds because of hung_task_warnings. Its default is 10 and each report decrements it by one; in my lab two tasks were reported per round, so it dropped by two per round. After the fifth round:

[918718.534763] INFO: task jbd2/dm-0-8:3790580 blocked for more than 51 seconds.
[918718.535570] INFO: task dd:3790596 blocked for more than 51 seconds.
[918718.536710] Future hung task reports are suppressed, see sysctl kernel.hung_task_warnings

That line has existed since 6.3; before that, the silence started without explanation. Once the counter hits zero, khungtaskd keeps scanning and hung_task_detect_count keeps climbing (in the lab it went from 6 to 18, the last round producing no log at all), but not one line gets written. The only way to re-enable it is writing a new value to the sysctl; -1 means unlimited. None of the seven servers in my fleet mentions hung_task under /etc/sysctl.d; all run with 120 seconds and 10 warnings. That this hasn't bitten me yet is not good news: their journal windows (7 to 15 days) contain zero blocked for more than lines, and so does VPS3's kern.log archive going back to 30 August. Either the fleet never had a hung task, or it had one after the ten warnings ran out; the only thing that tells those apart is hung_task_detect_count, and that counter doesn't exist before 6.13.

The counter itself had an interesting journey. It arrived read-only in 6.13; on 7.0, sysctl -w kernel.hung_task_detect_count=0 returns "Operation not permitted" and the file is -r--r--r--. 7.1 opened it for writing, but only zero is accepted; any other value gets EINVAL. The same series added the blocked in I/O wait suffix to the report line (when t->in_iowait is set) and made the counter atomic. hung_task_panic changed meaning in 6.19: previously any non-zero value meant "panic on the first hung task"; now N means panic when N tasks are found in a single scan. hung_task_sys_info (6.19) adds extra dumps such as tasks,mem,timers,locks to the report. I spell them out with versions because none of them applies to my 6.8 servers; anyone reciting release notes from memory will mix them up.

The report's anatomy, and the channel that never goes quiet

The report block itself has grown over the years, and knowing its lines pays off. The first line is the task name, pid and the time since first sighting. The second is a taint status and version, like Not tainted 7.0.0-31-generic #31-Ubuntu; if it says tainted, check which module tainted it before sending the report to a vendor. The third is that famous "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. advice; I've seen servers where someone did exactly that, and disabling the detector doesn't disable the problem. Then the task's stack via sched_show_task, since 6.14 a Blocked by coredump. note where applicable, on 6.15 and later the lock owner and its stack if there is one, and at the very end the list of held locks if lockdep is on.

The silence has one exception, and for anyone building monitoring it's the most valuable piece: the sched:sched_process_hang tracepoint. In the code, the trace_sched_process_hang(t) call sits before the hung_task_warnings check; the event fires every round even after the warning budget is gone. In the lab I enabled it through /sys/kernel/tracing/events/sched/sched_process_hang/enable; the round that printed "Future hung task reports are suppressed" and the silent round after it left four events in the trace; the second pair belongs to the round where dmesg was already empty:

khungtaskd-64  [004]  918718.802653: sched_process_hang: comm=jbd2/dm-0-8 pid=3790580
khungtaskd-64  [004]  918718.803463: sched_process_hang: comm=dd pid=3790596
khungtaskd-64  [004]  918729.042344: sched_process_hang: comm=jbd2/dm-0-8 pid=3790580
khungtaskd-64  [004]  918729.042347: sched_process_hang: comm=dd pid=3790596

A one-liner like bpftrace -e 'tracepoint:sched:sched_process_hang { printf("hung pid=%d\n", args.pid); }' keeps talking where dmesg has gone quiet, and on kernels before 6.13 it also covers the missing hung_task_detect_count.

Where there is no detector at all

I had planned to run the experiment first in the Docker Desktop VM on my Mac, my usual --privileged sysfs lab. /proc/sys/kernel/hung_task_timeout_secs wasn't there. /proc/config.gz makes the reason plain: the linuxkit kernel (6.10.14-linuxkit) is built without CONFIG_DETECT_HUNG_TASK; there is no khungtaskd. A process stuck in D inside a container there stays silent forever. For anyone building their own images or running embedded or minimal kernels, zcat /proc/config.gz | grep DETECT_HUNG_TASK is a ten-second check; in Kconfig the option depends on DEBUG_KERNEL and defaults to whatever SOFTLOCKUP_DETECTOR is.

Questions to ask your own server

What does sysctl kernel.hung_task_warnings say? Below 10 means reports were produced in the past, go find them. Zero means the detector went quiet and your log is incomplete. If you build log-based alerts, raise it; I will. But -1 has a cost: in a storage failure hundreds of tasks drop into D, and every round prints a stack, an owner stack and a lock list for each of them, with no printk rate limiting. To me the sane middle ground is a high but finite number (say 100) under /etc/sysctl.d, refreshed by hand when an incident closes.
On kernel 6.13 or later, watch kernel.hung_task_detect_count; any value above zero is an incident whether or not a warning was written. On 7.1 you can reset it after closing the incident.
In a disk-related hang, the blocked lines show you the writeback and fsync victims; on 6.17 and later look at the process on the likely owned by line. On older kernels dump every D task's stack with echo w > /proc/sysrq-trigger and look for the one with blk_io_schedule or submit_bio_wait in it that is never reported as "blocked"; that one is dodging.
When an NFS mount hangs, the report may not come from the process you expect: the application waiting on an RPC reply sleeps killable and is invisible to the detector; the kworker or fsync waiting for dirty pages to write back is visible. For the application, ps -o stat,wchan and an unexplained rise in load average are your only clues.
Freeze-based backups (fsfreeze, LVM snapshots, a slow backup agent) are the second experiment exactly: a freeze longer than 120 seconds gets every writer reported, burns the ten-warning budget, and leaves the detector mute when the real failure arrives. Put your backup windows next to the decline of hung_task_warnings.
Before lowering hung_task_timeout_secs below 120, do the arithmetic: the first report arrives no earlier than timeout and no later than 2×timeout. Instead of halving the timeout, lower hung_task_check_interval_secs: with timeout=30 and interval=5 the first report arrives in 30 to 35 seconds while the block layer's wake-up slice stays at 15 seconds. The block layer looks only at the timeout, not the interval; a short timeout raises both the false-positive risk and that wake-up traffic.
If you're setting up automatic recovery with kernel panic plus kdump, remember that hung_task_panic has been a threshold since 6.19; don't set it to 1 unless you're happy to reboot over a single NFS thread. The panic_timeout setting from the kdump runbook works together with it.
If a non-root monitoring agent reads dmesg, you'll hit dmesg_restrict; as described in the earlier post, the journal's _TRANSPORT=kernel path is cleaner.

Fixing the model

Let me rewrite the sentence from the top: if a process stays in D state for more than 120 seconds, and it isn't directly waiting on a block I/O at the time, and its wait isn't killable, and the detector was compiled in, and the ten-warning budget isn't spent, the kernel shouts somewhere between 120 and 240 seconds. That sentence is ugly and correct; the old one was pretty and wrong.

The broader lesson: most of the mechanisms we call the kernel's "safety net" have been muted from within to avoid false alarms. The block layer wakes at timeout/2 so a slow disk isn't called hung; the detector won't speak before two rounds; after ten warnings it switches itself off. Each is reasonable on its own. Stacked together, "if it's not in dmesg there's no problem" stops being a diagnosis and becomes a hope. What I took from this lab is to replace the hope with counters: is hung_task_detect_count zero, is hung_task_warnings still 10, is there a surplus in the load average that nr_running doesn't explain. All three are cheap; none of them means dmesg didn't go quiet, they just let you notice that it did.

DEV Community