48-Hour Field Notes: The Job Died at Minute 47 — Now It Leaves a Heartbeat Ledger

What do you actually know at the moment a background job stops? If your honest answer is 'it printed nothing', you are in the same club I have been in twice this month, staring at a log file that ends mid-sentence. This post is the ledger I wrote afterwards, plus the probe I now run before I trust any long batch on a machine I do not own.

What the workload actually was

The job is boring on purpose: about 400 short text items, one model call per item, results appended to a JSONL file. I run it on a free server instance and call a free model, which is the only reason I can afford to run a 20-item probe three times before a real pass. Nothing below depends on a specific model name, and I am deliberately not quoting quota numbers I did not verify myself.

Disclosure: This article was prepared as part of MonkeyCode's product outreach.

The free tier matters here for iteration count, not for savings. Cheap calls mean I get to measure the environment instead of guessing at it, and measurement is the single thing that made this job debuggable.

The 47-minute mystery

My log showed 118 processed items, then nothing. No traceback, no exit code, no OOM message, and the connection had dropped somewhere in the middle of item 119. I spent the first hour blaming the network, the endpoint, and then my own memory usage, which is the usual order of suspects. All three were innocent.

The killer was in my launcher, eleven lines above the python call: timeout 2700 python run_batch.py. I had pasted that line during an unrelated experiment two weeks earlier and never removed it, so my own wrapper politely killed a job that needed three hours. Counting items in a log tells you what happened; it never tells you when the process stopped being alive.

Why the log could not answer the question

• A log line is written by the work, so silence is ambiguous between 'slow' and 'dead'.
• Buffered writes mean the last visible line is not the last completed step.
• Exit codes vanish unless a supervisor captured them somewhere you can read later.

The fix was not more logging. It was three small files whose timestamps and contents can be read by anything, including jq, a shell one-liner, or a confused human at midnight.

Three files that ended the guessing

1. state.json — the set of item keys already finished, written atomically after each success.
2. ledger.jsonl — one append-only record per attempt: key, index, status, elapsed milliseconds.
3. heartbeat — a timestamp refreshed every 15 seconds by a daemon thread, independent of item progress.

Why separate them? Because a heartbeat answers 'is the process alive', the ledger answers 'what did it attempt', and the state answers 'what do I skip on resume'. Merging all three into one file is how you end up with a corrupted checkpoint after a kill.

The harness I now run

This is a trimmed version of the script: I removed my logging adapter and the model client, but the control flow is the one I actually use.

# ledger_job.py — checkpoint, ledger, heartbeat, single-instance lock
import fcntl, hashlib, json, os, pathlib, sys, threading, time

ROOT = pathlib.Path(os.environ.get('JOB_ROOT', './jobstate'))
STATE = ROOT / 'state.json'
LEDGER = ROOT / 'ledger.jsonl'
BEAT = ROOT / 'heartbeat'
LOCK = ROOT / 'run.lock'

def atomic_write(path, text):
    tmp = path.with_name(path.name + '.tmp')
    with open(tmp, 'w', encoding='utf-8') as f:
        f.write(text); f.flush(); os.fsync(f.fileno())
    os.replace(tmp, path)          # atomic only inside one filesystem

def ledger(rec):
    with open(LEDGER, 'a', encoding='utf-8') as f:
        f.write(json.dumps(rec, sort_keys=True) + '\n'); f.flush(); os.fsync(f.fileno())

def key_for(item):
    blob = json.dumps(item, sort_keys=True, separators=(',', ':')).encode()
    return hashlib.sha256(blob).hexdigest()[:16]

def beat(stop, every=15):
    while not stop.wait(every):
        atomic_write(BEAT, '%.0f' % time.time())

def call_model(item):
    raise NotImplementedError('wire up your client here')

def run(items):
    ROOT.mkdir(parents=True, exist_ok=True)
    lock = open(LOCK, 'w')
    try:
        fcntl.flock(lock, fcntl.LOCK_EX | fcntl.LOCK_NB)
    except BlockingIOError:
        sys.exit('another run holds the lock')

    state = json.loads(STATE.read_text()) if STATE.exists() else {'done': {}}
    stop = threading.Event()
    threading.Thread(target=beat, args=(stop,), daemon=True).start()
    try:
        for i, item in enumerate(items):
            k = key_for(item)
            if k in state['done']:
                continue
            t0 = time.time()
            try:
                call_model(item)
            except Exception as exc:
                ledger({'key': k, 'i': i, 'status': 'error', 'err': type(exc).__name__})
                continue
            state['done'][k] = {'i': i}
            atomic_write(STATE, json.dumps(state, sort_keys=True))
            ledger({'key': k, 'i': i, 'status': 'ok', 'ms': int((time.time() - t0) * 1000)})
    finally:
        stop.set()
        atomic_write(BEAT, 'stopped %.0f' % time.time())

Start it detached so a closed laptop cannot send it a hangup:

mkdir -p /var/tmp/job && cd /var/tmp/job
setsid python /srv/batch/ledger_job.py > run.log 2>&1 < /dev/null &
echo $! > runner.pid

Then answer the three questions in under ten seconds each:

jq -r '.status' jobstate/ledger.jsonl | sort | uniq -c

python -c "import time;print(round(time.time()-float(open('jobstate/heartbeat').read()),1),'s since last beat')"

python -c "import json;s=json.load(open('jobstate/state.json'));print(len(s['done']),'items already done')"

Probe the environment in about 30 minutes

I no longer assume anything about how long a step may run on a shared machine, because the assumption is what cost me two evenings. The probe below is cheap and repeatable, and the free-model calls make it practical to repeat.

1. Pick a step size roughly twice your typical real step, so the probe surfaces limits before production does.
2. Launch 20 probe items with the same harness, timestamps included, and log wall clock per item.
3. Watch the heartbeat every 15 seconds from a second shell, and note the last timestamp you saw before silence.
4. Repeat the whole probe three times at different hours, because a single measurement is an anecdote.
5. Record the smallest elapsed time at which any run stopped, then treat half of that number as your checkpoint interval.
6. Re-run once after disconnecting your session deliberately, to confirm what survives a dropped connection.

Why half? Because a checkpoint interval at the observed boundary gives you at most one lost step when the worst happens, and a rule you can state out loud beats a feeling. This is a heuristic, not a guarantee: shared machines change, and the number you measured on Monday is not a contract for Friday.

Decision table

Situation	Ledger	Lock	Notes
Fewer than 50 items, steps under a minute	No	No	Re-running is cheaper than maintaining the harness
Hundreds of items, steps of 10–90 seconds	Yes	Yes	Resume-on-skip is the entire value
The step keeps in-memory state across items	Yes	Yes	Persist that state, not only the keys
Downstream needs exactly-once output	Yes	Yes	Deduplicate on the key at the sink, not in the ledger
The step shells out to a long-lived process	Yes	Yes	A heartbeat proves liveness, not progress

What broke, and what I would repeat

• fsync on every item costs real time on slow disks; I batch nothing and accept it, because a lost checkpoint costs more.
• os.replace is atomic within one filesystem, not across a network mount, so keep JOB_ROOT local to the machine.
• Without flock, two runs will happily double-call your model and double-write your output, and you will blame the model.
• The heartbeat is a liveness signal only; a wedged subprocess keeps beating while doing nothing useful.
• The ledger grows forever, which is fine, because it is also the audit trail I read when a count looks wrong.

Who should skip this

If your script finishes in ninety seconds and is safe to re-run, the state file is pure overhead and a lock is one more thing to forget. If you cannot inspect a ledger on the machine where it runs, the harness will not save you either. And if your pipeline requires strict billing-level exactly-once semantics, this is a starting point for deduplication rather than the solution.

What would change my mind about this setup is a run that dies exactly at the same wall-clock second twice, because that pattern points at something upstream with a fixed timer rather than at my code. Until then, the ledger stays, the launcher gets read line by line, and the heartbeat answers the question I used to answer with a guess.

If you want to run the probe yourself before trusting any of this, the free model access and free server option on MonkeyCode are what I used for the three repeats — measure first, then decide.