DEV Community

Srinivas Kondepudi
Srinivas Kondepudi

Posted on

I wrote the check that catches this bug. The check had the bug.

Chron

We build Chron, a tool that records AI coding sessions locally so there is an audit trail of what an agent actually did. The records are hash chained, they live on your own machine, and nothing leaves it on its own.

The principle has not moved since the first release: Chron records what happened, it does not certify that what happened was correct.

So the release I shipped this week closed exactly one defect. A reviewer found it. No test failed, because no test drove the path it was on. Then I wrote a check to make sure it could not come back, and the check I wrote had the same defect in it. Twice.

That second part is the interesting part, so this post is mostly about that.

The original defect

Chron scans recorded messages for secrets. One function writes the detections, and it has exactly two callers.

One of them reported a failure properly: a bounded reason, a line on the audit channel, a structured event. The other looked like this.

setImmediate(() => writeDetections(db, session, id, content)
  .catch(() => undefined));
Enter fullscreen mode Exit fullscreen mode

A scan that failed on that path was indistinguishable from a message that contained no secrets. You get an acknowledged message, a stored row, and silence. Silence is what a clean scan looks like too.

That is the single confusion the product exists to prevent, and it had already been removed once, on the other path. One rule, two places, fixed in one.

The fix is small. The reporting moved into a shared function and both call sites go through it.

What matters is why it is a function and not a second copy. Two inline blocks satisfy every behavioural test you can write and then drift apart on the next edit. Behaviour cannot see a copy. So alongside the thirteen behavioural tests there is one structural test that reads the source file and asserts there is exactly one reporter, that both callers go through it, and that the string catch(() => undefined) does not appear.

I am not thrilled about a test that greps its own source. I have not found a better way to assert "there is one of these, not two".

Then I wrote the check, and the check was wrong

The behavioural tests run against the repository. We also have a packaged gate that installs the built tarball and drives it over the wire, because a test that imports your source does not prove the thing you shipped works.

That gate forces a real failure from outside the package: it drops the detections table from a contained database between the session being created and the message being logged. The scan then runs, finds a secret, and cannot write it. Then the gate reads what the audit line says about it.

The gate covered one of the two entry points. So the packaged check was confirming the path that already worked, and saying nothing about the path that did not. A probe that exercises one of two entry points is the same defect it exists to catch.

I caught that one myself while preparing the release and extended it to drive both tools. Then review found two more, both in the code I had just written.

A missing cause passed. The check tested that the audit line did not contain insert into or params:, and reported that absence as "it names a cause".

// before
if (/insert into/i.test(line) || /\bparams:/i.test(line)) {
  failures.push('the audit line carries the statement');
} else {
  notes.push('it names a cause');  // it has not established this
}
Enter fullscreen mode Exit fullscreen mode

A line that ends at the colon with nothing after it satisfies that. The reviewer deleted the cause from both audit lines, ran the probe, and it exited zero and reported that both entry points named a cause.

The gate drops the table itself, so it knows what the driver has to say. It now requires that string, and selects the line by the message id the call returned rather than taking the first failure line it finds, so one line cannot satisfy both entry points.

// after
const EXPECTED_CAUSE = 'no such table: secrets_detected';
const idPrefix = probe.messageId.slice(0, 8);
const auditLines = probe.slice.split('\n')
  .filter(l => /secret scan FAILED/.test(l) && l.includes(`message ${idPrefix}`));

if (!auditLines[0].includes(EXPECTED_CAUSE)) {
  probe.failures.push('the audit line does not name the cause');
}
Enter fullscreen mode Exit fullscreen mode

The statement check stayed, independently. A line can name the cause and still carry the statement after it.

The second verdict depended on the first. Grading used one shared failure list, and the loop appended each tool's failures to it before grading the next.

// before
for (const probe of ENTRY_POINTS) {
  failures.push(...probe.failures);
  entry_points[probe.tool] = { ok: failures.length === 0 };
}
Enter fullscreen mode Exit fullscreen mode

The reviewer substituted a bad diagnostic for the first tool and left the second intact. Both were reported failed. A verdict that moves when another verdict moves is not a verdict, and in a gate that exists to attribute a failure to a specific path, it is worse than no verdict: it tells you both paths are broken when one of them is fine, and next time you will believe it in the other direction.

Failures that belong to the run, the server being unreachable or the table being undroppable, now sit in their own list. Each entry point reads that list and its own, and nothing from the other tool.

The thing that actually found these

Neither of those was found by reading the code. Both were found by breaking the product on purpose and watching the check pass.

That is a habit worth naming, because it is cheap and almost nobody does it: a check is not coverage until you have watched it fail against a known bad artifact. Writing a test that passes tells you the test can pass. It tells you nothing about whether it can fail, and a test that cannot fail is a comment.

So every check in this release has a row in a table saying what it looked like disarmed.

Disarmed Result
Reporting removed from the second entry point 5 unit tests fail
Reporting removed from the first 6 unit tests fail, including an older one
Reporting removed, packaged probe rerun exits 1, first path passes, second fails with "no audit line names message ..."
Cause stripped from the audit line, both paths exits 1, both fail, where the previous version of the check passed
Reporting removed from the first path only exits 1, first false, second true, where the coupled version reported both false

The last two rows are the two findings above. Each was confirmed to fail where the version before it passed. The fix was then restored and everything rerun to a clean pass, because a disarm you do not re-arm is just a broken build.

Five minutes each. Both of the review findings were defects I could not see by reading, in code I had written that morning with this exact bug class in mind.

What the fixed reporter deliberately does not say

It names what failed and nothing more. It does not say the message was clean, and it does not say the message was captured in full.

Capture, detection and withholding are three separate facts. A completed scan with no findings does not establish that nothing was withheld upstream, and it does not establish that capture was complete. An absent record on its own cannot establish that nothing happened. For an audit tool, collapsing those three into one green mark is the whole failure mode, and it is tempting every single time because one green mark reads so much better than three qualified ones.

The diagnostic is also bounded and redacted, for a reason worth repeating: the driver's own error message was the entire failing statement, 53,132 characters for one batch, with a params: line carrying the values being written. The honest short answer is the cause one field deeper. If no usable cause exists, the reporter says the driver reported no cause, rather than falling back to the statement.

One release mechanic, since it is the same lesson

The runtime change needed its own version number, and not for tidiness.

Pushing it under the previous version would have skipped the npm publish, correctly, because the registry already has that version. But the workflow also syncs the rebuilt output to a public mirror and commits it as a release of whatever the package file says. The mirror would then carry code labelled with a version that differs from the one on npm under that same label.

Nothing would have failed. Both steps would have been green. The artifact and its label would just have stopped meaning the same thing, which for anything you expect people to verify is the only thing that matters.

The question worth asking

For every green mark your build produces, there is a version of this question: have you ever seen it red?

Not "could it go red in principle". Have you broken the thing it watches, on purpose, and watched it fail with a message that points at the right place?

If you have not, you do not know what it checks. I had written mine that same morning, with this bug class in mind, and I was wrong about two of them.

Top comments (0)