48-Hour Field Notes: My Heartbeat Detector Called a Suspended Laptop a Crash

Have you ever opened a heartbeat log after a long run and found a gap that made no sense at all? Mine said ninety minutes of silence, and I burned a whole morning blaming a crash, then a reboot, then a rate limit that never existed. The job itself finished fine; the timeline I built around it was fiction.

I keep these field notes because the same class of bug keeps returning in different clothes. This one is about elapsed time, and about what happens when you record it on one host and interpret it somewhere else.

The setup: one producer, two hosts, one lid

The producer was a small Python loop that appended one JSONL line every five seconds and called fsync on every line. I parked it on a remote box so that my laptop's sleep schedule would stop being part of the experiment, which I assumed was the whole fix. The judge was a second script running on my laptop: it read the JSONL file and labeled each gap between consecutive beats.

That split felt clean for about a day. The problem is that the judge could only see three numbers per row, and two of them were quietly meaningless outside the machine that wrote them.

Here is the shape of the failure, minus the drama:

• The producer wrote realtime (wall clock), clock_monotonic, and seq into every beat.
• The judge computed gaps as cur.realtime - prev.realtime and flagged anything above 60 seconds.
• A 90-minute gap appeared, and the judge printed PRODUCER_CRASH.
• The producer was never down, and its seq counter had not skipped a single value.

The last bullet is the tell, and I ignored it for hours because the timestamp looked authoritative. If seq is contiguous but the wall clock jumped, the process did not die; the clock moved under it.

Why a wall clock cannot tell you why nothing happened

A wall-clock delta is a single scalar, and several completely different events produce the same scalar. Suspending a host, freezing a process with SIGSTOP, stepping the clock with NTP, and pausing a container in a cgroup freezer all show up as "a lot of seconds passed." Only the monotonic family of clocks can separate them, because each one has a different opinion about what time is.

On Linux the useful distinction is this: CLOCK_MONOTONIC stops advancing while the system is suspended, and CLOCK_BOOTTIME keeps counting through suspend. That single difference turns an ambiguous gap into a labeled one, and it is the reason the detector below asks for both.

I also made a second mistake, and it was worse than the first. I compared clock_monotonic values from the producer with elapsed values measured on my laptop, which is a category error. Monotonic clocks share a reference point only within one boot of one host; across hosts or across a reboot, subtracting them produces a number with no meaning.

The 20-minute reproduction

You do not need a lab. You need a shell, a suspend-capable machine, and about twenty minutes. Run the producer locally first so that you can trigger both failure modes on purpose:

1. Start the producer in the background: python3 clocklog.py heartbeat.jsonl lid-test &
2. Let it beat for 60 seconds, then capture the PID: PID=$!
3. Freeze it to simulate a starved or frozen process: kill -STOP $PID, wait 60 seconds, then kill -CONT $PID
4. Let it beat normally for another 60 seconds, then suspend the whole host for a few minutes: sudo systemctl suspend
5. Wake the machine, give the producer 60 seconds, then stop it: kill $PID
6. Classify the file: python3 gapcheck.py heartbeat.jsonl

If your platforms behave the way the Linux documentation describes, step 3 produces a PROCESS_NOT_SCHEDULED label and step 4 produces HOST_SUSPENDED, even though both gaps look alike in wall-clock seconds. If step 4 does not produce that label, stop and read the mapping on your own platform before you build anything on top of this.

Two supporting checks are worth running while the evidence is fresh:

• journalctl -k -b | grep -iE 'suspend|resume' confirms that the kernel agreed the host slept.
• curl -sI https://example.com | grep -i '^date:' gives you a wall clock owned by somebody else, which is often the fastest way to spot a host clock that drifted.

The artifact: log several clocks, classify later

The producer writes every clock it can read into each beat, so the classification decision happens after the fact instead of inside the hot path. Note the getattr guards: CLOCK_BOOTTIME is a Linux constant, and on macOS or Windows the script has to degrade instead of crashing.

#!/usr/bin/env python3
"""Heartbeat producer: one JSONL row per beat, several clocks per row."""
from __future__ import annotations

import json
import os
import socket
import sys
import time
import uuid
from datetime import datetime, timezone

EXTRA_CLOCKS = {
    "clock_boottime": getattr(time, "CLOCK_BOOTTIME", None),
    "clock_monotonic_raw": getattr(time, "CLOCK_MONOTONIC_RAW", None),
}


def boot_id() -> str:
    try:
        with open("/proc/sys/kernel/random/boot_id", encoding="ascii") as fh:
            return fh.read().strip()
    except OSError:
        return "unavailable"


def read_clocks() -> dict[str, float]:
    clocks = {"clock_monotonic": time.monotonic()}
    for name, const in EXTRA_CLOCKS.items():
        if const is None:
            continue
        try:
            clocks[name] = time.clock_gettime(const)
        except (OSError, ValueError):
            continue
    return clocks


def beat(run_id: str, seq: int, note: str) -> dict:
    row = {
        "run_id": run_id,
        "seq": seq,
        "note": note,
        "host": socket.gethostname(),
        "pid": os.getpid(),
        "boot_id": boot_id(),
        "realtime": time.time(),
        "realtime_iso": datetime.now(timezone.utc).isoformat(timespec="milliseconds"),
        "perf_counter": time.perf_counter(),
    }
    row.update(read_clocks())
    return row


def main(path: str, note: str = "", interval: float = 5.0) -> None:
    run_id = uuid.uuid4().hex[:12]
    seq = 0
    with open(path, "a", encoding="utf-8") as fh:
        while True:
            fh.write(json.dumps(beat(run_id, seq, note), sort_keys=True) + "\n")
            fh.flush()
            os.fsync(fh.fileno())  # a killed beat must not take the last line with it
            seq += 1
            time.sleep(interval)


if __name__ == "__main__":
    out = sys.argv[1] if len(sys.argv) > 1 else "heartbeat.jsonl"
    tag = sys.argv[2] if len(sys.argv) > 2 else ""
    main(out, tag)

The judge is deliberately dumb and rule-ordered, because the order of the checks is the whole argument. A reboot beats a suspend, a suspend beats a stall, and a stall beats a clock step.

#!/usr/bin/env python3
"""Classify gaps between heartbeats from one producer run."""
from __future__ import annotations

import json
import sys


def load(path):
    rows = []
    with open(path, encoding="utf-8") as fh:
        for line in fh:
            line = line.strip()
            if line:
                rows.append(json.loads(line))
    return rows


def classify(prev, cur, stall=90.0, step=2.0):
    wall = cur["realtime"] - prev["realtime"]
    mono = cur["clock_monotonic"] - prev["clock_monotonic"]
    boot = cur.get("clock_boottime")
    boot_delta = None if boot is None else boot - prev["clock_boottime"]

    if cur["boot_id"] != prev["boot_id"]:
        return "REBOOT", (wall, mono, boot_delta)
    if wall < -step:
        return "CLOCK_STEP_BACKWARD", (wall, mono, boot_delta)
    if boot_delta is not None and (boot_delta - mono) > stall:
        return "HOST_SUSPENDED", (wall, mono, boot_delta)
    if mono > stall:
        return "PROCESS_NOT_SCHEDULED", (wall, mono, boot_delta)
    if abs(wall - mono) > step:
        return "WALL_CLOCK_STEP", (wall, mono, boot_delta)
    return "OK", (wall, mono, boot_delta)


def fmt(value):
    return "n/a" if value is None else f"{value:8.2f}"


if __name__ == "__main__":
    last = {}
    for row in load(sys.argv[1]):
        key = row["run_id"]
        prev = last.get(key)
        if prev is not None:
            label, (wall, mono, boot) = classify(prev, row)
            print(
                f"{key} seq {prev['seq']}->{row['seq']} {label:<22}"
                f" wall={wall:8.2f} mono={mono:8.2f} boot={fmt(boot)}"
            )
        last[key] = row

Which clock answers which question

Most teams reach for whatever timestamp is closest to hand. This is the table I now keep next to the logger:

Question	Use	Do not use
How long did this function take?	time.perf_counter()	time.time()
How long has this process been alive, excluding suspend?	time.monotonic()	time.time()
How long has the host been up, including suspend?	CLOCK_BOOTTIME, /proc/uptime	time.monotonic()
Did the host reboot?	/proc/sys/kernel/random/boot_id	an uptime heuristic
Which host did something first?	wall clock plus an independent source	any monotonic clock
Why is there a gap?	the difference between monotonic and boottime	wall-clock seconds

One footnote on containers, since it bit me during review: /proc/uptime and boot_id come from the kernel that the container shares, so inside a container they describe the host, not the container's own start time. Verify that on your runtime before you draw conclusions from a short-lived container's uptime.

Where MonkeyCode's free server and free models fit

My original goal was to remove my laptop from the experiment, and the producer loop above is exactly the kind of small, long-running process that does not belong on a laptop lid. MonkeyCode's free server option is where I parked it, which changed the question from "did my machine sleep" to "did the producer itself stall" — one variable instead of two. Disclosure: This article was prepared as part of MonkeyCode's product outreach.

The free model access was useful for a narrower job: arguing with my own rule ordering. I asked it to propose cases where PROCESS_NOT_SCHEDULED and HOST_SUSPENDED would be confusable, then kept a suggestion only if removing it made a test case fail. That gate matters, because a plausible rule that no test defends is just another version of the wall-clock bug I started with. If you want to try the same split, the producer above is small enough to move between hosts in an afternoon; availability and quota terms live on MonkeyCode's side, not in this post, so check them before you depend on any of it.

Limitations and who should not do this

This workflow is narrow on purpose, and it is the wrong tool for several reasonable situations:

• If everything you measure happens in one process on one machine over short spans, perf_counter is enough and this logger is dead weight.
• If you need sub-millisecond ordering across hosts, stop here; NTP will not give it to you, and you need a real time-distribution setup instead.
• If you are building an audit or billing trail, do not treat these clocks as proof; reconcile against the platform's own accounting.
• If you cannot reproduce the suspend or freeze case on demand, you cannot trust the labels, because you never saw the rule fire.
• If you need contractual uptime, specific hardware, or long-lived state that you cannot rebuild, a free tier is not the right home for the only copy of your data.

The last point is the one I would defend hardest. Free capacity is excellent for a heartbeat producer that you can throw away and restart; it is a poor place for a ledger you cannot recreate.

What I would repeat, and what I would skip

I would repeat the two-clock beat, the ordered rules, and the deliberate reproduction, because together they turned an argument about causes into a lookup. I would skip the wall-clock-only detector entirely, and I would stop subtracting monotonic values across hosts the first time I noticed they disagreed.

If you take one thing from these field notes, make it this: before you explain a gap, ask which clock produced it and which host owns that clock. The gap is usually real, but the story attached to it often belongs to the wrong machine.