joshday.io
Monitors that measure the wrong thing

A freshness check with a fallback reads deletion as health

A liveness check that falls back to a proxy goes green on the one failure it exists to catch: the thing it watches being gone.

A weekly job on one of my own automation setups got removed from the scheduler, and the daily health check that exists to notice exactly that stayed quiet for about a month.

The check never errored. It had a fallback, and the fallback did its job a little too well.

Here is the mechanism. It is short, and I suspect it lives in more places than mine.

The shape

A freshness check asks “did job X run on schedule?” and answers by reading X’s own record. Reading a file can fail for dull reasons, so I gave the check a plan B: when the record is unreadable, look at the newest modified time across a folder of files. That was meant to cover a transient read failure.

The trouble is the most likely reason a record becomes unreadable: X was deleted. And in my case that folder gets a file written every night by a different job, so the proxy always read under a day old.

So the moment X disappears, the check quietly stops measuring X and starts measuring its neighbors. The status stays green. The one event the check exists to catch is the one event it can no longer see. Dang…so that happened.

Two smaller things hid the same problem in the same setup. A backup job that reran the primary stamped completion under the primary’s name, so in a week when the primary hung, the record still said healthy. And when a cleanup job finally killed a stalled run after about 20 hours, the history showed exit code 1 with last activity 18 seconds after start. That reads as a crash at startup. It was really a run waiting on a prompt nobody was there to answer.

Three different symptoms, one habit: a record that says something true about a neighbor gets read as a statement about the subject.

The tell

The check’s detail string changed method. It literally printed the word FALLBACK while the status stayed OK. And nobody goes reading the detail on a green row.

A method change on a liveness check is itself the alarm. If a check can switch from “ask the subject” to “ask something nearby”, that switch deserves at least as much noise as a failure, because from then on the check is answering a different question than the one on its label.

The other two had tells too. A completion stamped under the wrong name looks like a primary with a suspiciously good record. A run that took 20 hours and shows 18 seconds of activity was never a crash at startup. It was waiting.

The fix

  • When a liveness check cannot find its subject, it returns FAIL with “subject missing”. Not a proxy reading.
  • The proxy stays, as a separate informational signal that can never turn the check green. It is still handy in the failure message: “record gone, folder fresh” tells you the box is up and the job is not.
  • A fallback lane records completion under its own name. Otherwise a primary that fails every week looks healthy whenever the fallback succeeds.
  • A reaper that kills a stalled process records why, so run history keeps the difference between a stall and a crash.

None of this is hard. It is just the opposite of what feels responsible while you are writing the fallback.

Try it

The example below is new, written for this post, not lifted from the real setup. It simulates a weekly job’s record plus a neighbor file that is 3 hours old, and runs both versions of the check through three situations.

const fs = require("fs");
const os = require("os");
const path = require("path");


const HOUR = 60 * 60 * 1000;
const MAX_AGE = 8 * 24 * HOUR; // weekly job plus a day of slack


function readLastRun(recordPath) {
  try {
    return Date.parse(JSON.parse(fs.readFileSync(recordPath, "utf8")).lastRun);
  } catch {
    return null; // missing, unreadable, or not JSON
  }
}


function newestMtime(dir) {
  return Math.max(...fs.readdirSync(dir).map((f) => fs.statSync(path.join(dir, f)).mtimeMs));
}


const hours = (ms) => Math.round(ms / HOUR);


// The version I shipped: if the record is unreadable, ask the neighbors.
function checkFreshnessWithFallback(recordPath, neighborDir, now) {
  const lastRun = readLastRun(recordPath);
  if (lastRun !== null) {
    const age = now - lastRun;
    return { status: age <= MAX_AGE ? "OK" : "FAIL", detail: `record says last run ${hours(age)}h ago` };
  }
  const age = now - newestMtime(neighborDir);
  return { status: age <= MAX_AGE ? "OK" : "FAIL", detail: `FALLBACK newest file in folder is ${hours(age)}h old` };
}


// The fixed version: no record means no job. The proxy is reported, never graded.
function checkFreshness(recordPath, neighborDir, now) {
  const lastRun = readLastRun(recordPath);
  const proxy = `(info only) newest file in folder is ${hours(now - newestMtime(neighborDir))}h old`;
  if (lastRun === null) {
    return { status: "FAIL", detail: `subject missing: no readable record. ${proxy}` };
  }
  const age = now - lastRun;
  return { status: age <= MAX_AGE ? "OK" : "FAIL", detail: `record says last run ${hours(age)}h ago` };
}


// --- simulation ---------------------------------------------------------
const root = fs.mkdtempSync(path.join(os.tmpdir(), "fresh-"));
const recordPath = path.join(root, "weekly-report.json");
const neighborDir = path.join(root, "outputs");
fs.mkdirSync(neighborDir);


const now = Date.now();


// A different nightly job wrote this file 3 hours ago.
const neighbor = path.join(neighborDir, "nightly.log");
fs.writeFileSync(neighbor, "ok\n");
fs.utimesSync(neighbor, new Date(now - 3 * HOUR), new Date(now - 3 * HOUR));


const scenarios = [
  ["healthy", () => fs.writeFileSync(recordPath, JSON.stringify({ lastRun: new Date(now - 72 * HOUR).toISOString() }))],
  ["stale", () => fs.writeFileSync(recordPath, JSON.stringify({ lastRun: new Date(now - 30 * 24 * HOUR).toISOString() }))],
  ["job deleted", () => fs.rmSync(recordPath, { force: true })],
];


const versions = [
  ["fallback", checkFreshnessWithFallback],
  ["fixed", checkFreshness],
];


console.log("scenario".padEnd(13) + "version".padEnd(10) + "status".padEnd(8) + "detail");
for (const [name, setup] of scenarios) {
  setup();
  for (const [label, fn] of versions) {
    const r = fn(recordPath, neighborDir, now);
    console.log(name.padEnd(13) + label.padEnd(10) + r.status.padEnd(8) + r.detail);
  }
}


fs.rmSync(root, { recursive: true, force: true });

Output, as printed:

scenario     version   status  detail
healthy      fallback  OK      record says last run 72h ago
healthy      fixed     OK      record says last run 72h ago
stale        fallback  FAIL    record says last run 720h ago
stale        fixed     FAIL    record says last run 720h ago
job deleted  fallback  OK      FALLBACK newest file in folder is 3h old
job deleted  fixed     FAIL    subject missing: no readable record. (info only) newest file in folder is 3h old

Read the first four rows twice. With a record present, the shipped version behaves perfectly, including failing a stale job. Any test I would have written for it created the record first, so any test I would have written passed. Only the last pair differs, and the difference is the whole story: OK on one side, FAIL on the other, for the same deleted job and the same fresh neighbor.

The shipped version even tells you what it did. It just says it in the detail column, where nobody looks.

More notes

Retrieval and knowledge store

A cap applied before the filter starves the rows you wanted

A result cap fills with the majority before it reaches your rows, and the page still looks full. Put the filter inside the query and test a busy range.