A service burns a core and gets killed: find out why in ten minutes

A service that restarts itself for no visible reason is usually doing something expensive in a loop. You do not need to guess: a running Node process can be profiled live, without a rebuild and without a restart, and the answer fits on one screen.

What you get. A repeatable method to tell "the machine is too small" from "the program is spinning", a 20-line profiling script, and the second trap we hit on the way: the hypervisor quietly taking back the memory you had just added.

1. Read the symptoms before touching anything

systemctl --user status the-service      # restart count, "oom-kill" in the result
journalctl -k | grep -i "out of memory"  # who the kernel chose to kill
free -m; cat /proc/swaps                 # is the swap already full?
ps -eo pid,pcpu,rss,args --sort=-rss | head

Our case: the service was killed by the kernel six times in one morning, swap was full, and the server process sat at one full core with 1.4 GB resident. A memory-hungry neighbour would not explain a core at 100 %: something was computing.

2. Profile the live process

Node opens its inspector when it receives SIGUSR1. A short script can attach to it, record ten seconds of CPU, and print where the time went. No debugger UI, no restart:

kill -USR1 <pid>
node profile.mjs 10

The script is about twenty lines: list http://127.0.0.1:9229/json/list, open the WebSocket it returns, send Profiler.enable and Profiler.start, wait, send Profiler.stop, then add up timeDeltas per function. Report two numbers per function: self time (where the CPU really is) and inclusive time (which caller is responsible).

Self time alone points at the database driver or the garbage collector, which is where every program ends up. The inclusive column is the useful one: it showed 34 % of all time under a single function, performRefresh.

3. Follow the caller up to the schedule

That function re-read and re-validated a plugin catalogue and wrote it back to SQLite. It should have run every two hours. Reading the code that arms the timer showed the delay was computed from the last attempt stored in the database:

delay = lastAttempt === null ? 0 : max(0, INTERVAL - (now - lastAttempt))

In our configuration the catalogue had no remote address, so the refresh returned early and never recorded an attempt. Two hours after the first start, now - lastAttempt exceeded the interval for good, the delay became 0, and the timer re-armed itself immediately, forever. One core, constant writes, steady memory growth, then the kernel's OOM killer.

The fix is one line: with no remote catalogue, wait one interval. To stop the bleeding before a build, set the stored timestamp to now (it holds for one interval), then patch the code.

4. The second thief: ballooning

We had given the virtual machine 2 GB more memory, and an hour later it again showed less than it had. Cause: the hypervisor's balloon driver lets the host reclaim guest memory when the host itself is under pressure, down to the configured minimum.

qm config <vmid> | grep -E "memory|balloon"
qm set <vmid> --balloon 0     # fixed memory; takes effect at the next start

For a VM that must keep a service up, fixed memory is the honest setting: a balloon that shrinks a guest which is already swapping only moves the failure somewhere harder to see.

Traps

swapon --show and several storage commands print nothing, not an error, when run without privileges; read /proc/swaps instead.

A fix that lives only in a deployed build is lost at the next build. Put it in the patch set that produces the build, with a test that fails without it, then ship that build.

Profiling costs a few percent of one core for the duration. Do it on a service that is already struggling, not as a routine.

Related: Inari, self-hosted (the app in this story), Proxmox, and the glossary.

Found this useful? Tell us what to measure next.