A CLI I use ships a systemd user timer that runs a maintenance pass every twelve minutes. It normally takes about 1.4 seconds. One morning it had been running for eighteen, holding roughly a full core the whole time.
The obvious move is strace -p. It was not available:
/proc/sys/kernel/yama/ptrace_scope was 1, and I did not want to
escalate to root just to look. It turns out you do not need to. Everything below is readable
by the process owner with no privilege at all, and it is enough to distinguish a busy loop
from real work.
Where the time goes
Fields 14 and 15 of /proc/<pid>/stat are user and system time in clock
ticks. Sampling them a few seconds apart:
utime 7796 -> 8024 (+2.3 s in userspace)
stime 70429 -> 72607 (+21.8 s in the kernel)Roughly ninety percent of the CPU was being spent inside the kernel. That already rules out a compute loop in application code. Something was calling a syscall, over and over.
The measurement that settles it
/proc/<pid>/status carries two counters that answer the question directly:
voluntary_ctxt_switches: 2726 delta over 3 s: 0
nonvoluntary_ctxt_switches: 51937A voluntary context switch is the process giving up the CPU because it blocked, waiting on a socket, a lock or a timer. A nonvoluntary one is the scheduler taking the CPU away because the process would not stop.
Zero voluntary switches over three seconds means the process never blocked once. A healthy
event loop is almost entirely voluntary switches: it calls epoll_wait, sleeps
until something happens, wakes up. A process burning kernel time while never blocking is
calling a syscall that returns immediately, in a tight loop. That is the whole
diagnosis, and it costs one file read.
Ruling out real work
Two more counters, to be sure it was not doing something useful very fast:
/proc/<pid>/io:syscradvanced by 1 read in five seconds. No I/O./proc/<pid>/statfield 10, minor faults: 0 in five seconds. Not allocating, so not even churning garbage./proc/<pid>/sched:se.avg.util_avg 1011out of 1024. Saturating its core.
No I/O, no allocation, no blocking, all kernel time. It was spinning on a non-blocking syscall, the classic shape of an event loop polling with a zero timeout. RSS was flat at 136 MB throughout, so it was not a leak either.
Why nothing stopped it
The unit was Type=oneshot. For oneshot services systemd defaults
TimeoutStartUSec to infinity, so a hung run is never reaped.
Worse, because the unit stays in activating (start) forever, the timer cannot
fire again, so the maintenance it was supposed to perform had also silently stopped.
The journal made the pattern obvious once I looked: of 1315 recorded runs, 1313 took between
1.3 and 1.5 seconds. The two outliers were this one and an earlier one that ran 53 minutes
and only ended because logout sent it SIGTERM.
The fix
A drop-in rather than an edit to the unit file, because the CLI rewrites its own unit when it reconciles the schedule:
[Service]
TimeoutStartSec=180
RuntimeMaxSec=180
CPUQuota=50%180 rather than 120 seconds: the post-boot run legitimately takes about 99 seconds of wall time on 1.3 seconds of CPU while it waits for the network, and a tighter ceiling would kill a healthy run. The quota bounds the damage of the next hang to half a core instead of a whole one.
None of this fixes the underlying bug, which is upstream’s. It converts an unbounded failure into a bounded one, which is usually the part you own.
The short version
- stime ≫ utime: the loop is in syscalls, not your code.
- voluntary_ctxt_switches not advancing: it never blocks. This is the tell.
- syscr and minflt flat: it is not doing work, fast or otherwise.
- Type=oneshot has no start timeout by default. Give every timer-driven unit a
RuntimeMaxSec.