The load was forty and the box was idle

The alert came in mid-afternoon on a Tuesday, which was notable mainly because production surprises during business hours are somehow worse than 2am ones. At 2am you have the full pathetic dignity of the nocturnal responder: coffee, silence, everyone else asleep. At 2pm you have an open Slack with twenty people watching you figure it out in real time.

The alert was load average. Threshold was 16.0 on an eight-core box. The actual value was 47.8.

My assumption, before I logged in, was obvious: something was burning CPU. Runaway query, a loop gone infinite, a deploy that went wrong. Load of 47 on eight cores means the box is being asked to do six times more work than it can handle. You SSH in, find the pig with top, kill it. Five minutes, alert resolves.

I SSH’d in and ran top.

top - 14:32:07 up 83 days, 11:43,  1 user,  load average: 47.81, 46.44, 44.29
Tasks: 287 total,   1 running,  254 sleeping,  32 stopped,   0 zombie
%Cpu(s):  0.2 us,  0.4 sy,  0.0 ni, 97.8 id,  1.4 wa,  0.0 hi,  0.2 si

Ninety-seven percent idle. One process running: top itself.

The load average was 47 and the box was doing almost nothing.

What load average actually counts

If you have worked with Linux for long enough you know this, but it did not click for me until something like this happened: load average does not count processes using CPU. It counts processes that want to run and cannot, plus processes that are in uninterruptible sleep.

The first part is what most people think of: runnable processes sitting in the scheduler’s run queue, waiting for a CPU core to become available. If you have eight cores and sixteen processes that all want CPU, load is 16 and the machine is genuinely saturated.

The second part is the one that surprises people. Uninterruptible sleep is state D in ps. A process in D state is not using CPU. It is blocked inside the kernel, waiting for something, and it cannot be woken up by a signal. Not SIGTERM, not SIGKILL. Nothing. The kernel will not deliver signals to a D-state process because the process is inside a kernel code path and interrupting it there would corrupt kernel data structures.

Load average counts those processes as if they were runnable. They show up in the average. Forty-seven is a terrifying number until you find out that it is thirty-two processes in D state and a box with almost no CPU load. Then it becomes a different kind of terrifying.

Finding the D-state processes

ps aux | awk '$8 ~ /D/'

This filters ps output by the stat column. The eighth field, D for uninterruptible sleep. Thirty-two processes, all belonging to the application user, all with the same parent PID (the web server worker manager), all with the same command: the app worker process name.

The question was what they were waiting on. D-state processes do not tell you why they are in D state from ps alone. For that, you look at /proc/<pid>/wchan, which reports the kernel function the process is sleeping inside:

for pid in $(ps aux | awk '$8 ~ /D/ {print $2}'); do
    echo "$pid: $(cat /proc/$pid/wchan 2>/dev/null)"
done

14392: nfs_wait_bit_killable
14401: nfs_wait_bit_killable
14407: nfs_wait_bit_killable
14413: nfs_wait_bit_killable
...

All thirty-two of them, same kernel function. nfs_wait_bit_killable is the sleep point inside the kernel’s NFS client code where a process waits for a response from the NFS server. All thirty-two workers were blocked waiting for a response that was not coming.

mount | grep nfs

192.168.10.20:/exports/uploads on /data/uploads type nfs (rw,relatime,vers=3,...)

There was the mount. /data/uploads was NFS from a separate file server on the same rack.

What the NFS server was doing

I could reach the NFS server. SSH’d in fine. Filesystem was mounted and accessible locally. df, ls /exports/uploads: all fine. The underlying data was not corrupted and the server had not crashed.

What had crashed was rpc.nfsd, the NFS daemon itself. The service had died three hours earlier, which explained why the workers had been quietly accumulating in D state all afternoon instead of all at once. Each new incoming web request that touched /data/uploads blocked. The workers stacked up until there were thirty-two of them, which was the full worker pool, and then no new requests could be handled at all.

The NFS server’s storage was fine. The NFS service itself was not running. From the client’s perspective, that is indistinguishable from a network partition: packets go out, no reply comes back, the kernel keeps waiting, the process stays in D.

Restarting the NFS daemon on the server was the obvious fix, and it was the right fix, but it was not the first thing I did, because thirty-two processes in D state on the client is not something that automatically resolves when the server comes back. They might. Or they might not. NFS clients have their own retry logic and timeouts, and with NFS v3 and a hard mount (which this was), the client will retry indefinitely. But I had a box with forty-eight load average that was not serving any traffic, and I needed it serving traffic before I was willing to trust that “restart the server, wait five minutes, see what happens” would leave the workers in a useful state.

You cannot kill a D-state process

This matters enough to say explicitly, because I have watched people try it. SIGKILL is not a signal the process receives. It is a flag that the scheduler checks when it next runs the process. If the process is in D state, the scheduler does not run it, so the flag sits there, and nothing happens. The process does not die. It does not become a zombie. It stays in D state until the kernel is done with whatever it is waiting for.

This is the same category as the unkillable process I wrote about in September, except in that case the solution was waiting for the I/O to complete. NFS hangs are different: the I/O will never complete if the server does not respond. You cannot kill your way out of this. You have to fix the thing the processes are waiting for.

Or unmount it.

The lazy unmount

umount -f -l /data/uploads

-f is force: tell the kernel to abort pending NFS operations rather than wait for them to complete. -l is lazy: detach the mount from the namespace immediately, even if there are still open file descriptors pointing to it. The combination tells the kernel: stop waiting, detach the mount, hand back errors to everything that was blocking on it.

Within about five seconds, all thirty-two D-state processes woke up. Their NFS operations returned EIO. The application code was not expecting EIO on a file write and did not handle it gracefully, so the workers crashed. The worker manager saw them crash and restarted them. The restarted workers had no /data/uploads to mount because I had unmounted it. They tried to open upload paths, failed with ENOENT, logged errors, and dropped back to idle.

Load average dropped to 0.4 within thirty seconds.

The box was serving traffic again, with uploads broken but everything else functional. That is a tolerable degraded state. Uploads erroring is a recoverable problem. The box being completely offline is not.

Restoring service

On the NFS server: systemctl start nfs-server. The daemon came up, the exports were visible, everything looked fine locally.

Back on the client:

mount -t nfs 192.168.10.20:/exports/uploads /data/uploads

Mounted clean. Wrote a test file to verify the round-trip worked. Restarted the application to clear the error state the workers had gotten into. Within two minutes of remounting, uploads were working again.

Total time from alert to full recovery: about eighteen minutes. The actual fix took maybe six of those minutes. The rest was figuring out what was happening.

The monitoring gap

The NFS daemon dying three hours before anything paged is the thing I was annoyed about afterward. Not at the NFS server: services crash, that happens. At the monitoring.

The load average alert was the right alert in a world where load average means CPU saturation. It is a mediocre alert for NFS hangs because it only fires after enough workers have accumulated in D state to push the average over the threshold. Thirty-two workers had to get stuck before anything paged. While they were stacking up, the first twenty-four request failures were invisible. This is the same failure mode as inode exhaustion and conntrack overflow: the top-level metric looks fine, the system is broken underneath it, and nothing pages until the application starts throwing errors.

What would have caught this faster:

# Detect D-state processes by wchan category
ps -eo pid,wchan | awk '$2 ~ /nfs_wait/ {count++} END {if (count > 0) print count " processes in NFS wait"}'

Alert on any count above zero. One process stuck in nfs_wait_bit_killable is already a problem worth looking at. Thirty-two means you are already offline.

The more useful check is at the mount level: nfsstat -m shows per-mount statistics including the retransmission count. A mount that is actively retransmitting but not getting responses is a hung mount, before any worker has stacked up in D state.

nfsstat -m | grep -A 5 'uploads'

If the retrans counter is incrementing with no corresponding ops, the server is not responding. That is a page-worthy condition independent of whether load average has climbed yet.

Hard mounts and the philosophy

NFS mounts come in two flavors: soft and hard. A soft mount gives up and returns an error to the application after a configurable number of retransmission attempts. A hard mount retries forever, blocking the process in D state until the server responds.

System administrators have strong opinions about this, and they are all correct in context. Soft mounts return errors to applications that applications rarely handle well. Hard mounts block processes indefinitely but at least they do not silently corrupt data by returning partial writes. For a filesystem holding uploads, hard mounts are defensible. The decision was made by someone who thought about it, and the reasoning was not wrong.

The part that was missing was a monitoring check that caught “server is not responding” at the NFS level, before the application level paid the price.

I added nfsstat -m to the monitoring check run on this box’s cron. The NFS daemon has not crashed since, which is the more statistically common outcome. The check has fired exactly once, during a scheduled maintenance window where the file server was briefly offline. That time, the alert came in before any workers stacked up, and I remounted before the application noticed.

That is the best outcome from an incident: the monitoring learns something and never has to learn it again.

Load average

The number is not lying to you. Forty-seven processes that cannot make forward progress is a valid measure of system distress. The system was distressed. It just was not CPU-distressed. It was NFS-distressed, which looks identical from the top of the number but is diagnosed completely differently.

uptime or top, then ps aux | awk '$8 ~ /D/'. If you have D-state processes, the load number is probably right for the wrong reasons. Find the wchan and you know exactly what they are waiting for. Then go fix that thing.

The CPU interpretation of load average is almost always correct. Almost always is not always.