DEV Community

Daniel Bitengo
Daniel Bitengo

Posted on

The day my monitoring tool caught itself lying

For eight minutes it was the best thing I'd ever shipped. Then I opened the history and found a trace that had been running since 1970.

It's 11th July 4am. I'm running a real Claude Code session through Reeve for the first time ever. Everything before this had been deterministic mocks. Mocks are predictable and fast, real Claude Code is slow and messy. I can see the trace tree growing, the streaming panel filling, the cost ticker climbing. It ran for eight minutes.

The crime scene

I was playing around with Reeve to see how the rest of the features behaved. Were they behaving as intended or did they go rogue?

The History view showed five traces for one turn.

Each of them had almost nothing in it. The costs read $0.021, $0.022, $0.003, and $0.000.

The fifth row showed a duration of 29728854m08s. It took me a moment to work out what that was. Twenty-nine million minutes is about fifty-six years.

I was certain agents did not exist fifty-six years ago. The internet itself was young. I did not exist fifty-six years ago. And my parents didn't even know the other partner existed fifty-six years ago. Better yet, how could a session that began its journey ten minutes ago give birth to traces fifty-six years older than itself?

The health score in the sidebar read 100, HEALTHY.

Reeve's history view at 03:57, showing five traces with costs of $0.021, $0.022, $0.003 and $0.000, one with a duration of 29728854m08s, and a health score of 100.

Someone to blame

At first I was just confused, wondering if my eyes were playing tricks on me. Then came that unmistakable adrenaline flush where the body starts heating up, and I could feel my ears getting hot.

I looked back at the screen: it still read $0.764. I checked the store: still $0.093. There had to be someone to blame, didn't there? At first the display was to blame. Maybe it double counted. Maybe some rounding issue or error. Except its arithmetic checked out.

Then there was the store, which proved faithful to the mission. Every span in there was intact, priced correct, consistent. Just... few. And for a turn I had personally watched run about thirty round trips, three spans were just not it.

Then I consulted the very thing that's supposed to be telling you the system knows what went wrong; the error log. Guess what? It was empty. So somewhere in my pipeline, spans were dying without so much as a whisper, and the pipeline thought everything was fine.

Two witnesses

The existence of the two numbers was an accident; I never intended for the ticker to exist. Lucky me, while accidents mean bad news elsewhere, some accidents occur just to save me.

The ticker and the store do not count the same event. The ticker is first in line and it counts the spans as they enter the pipeline. The store counts what survives to the end. So I had built two witnesses without meaning to, and here they were standing at the opposite ends of the same river.

Their disagreement was therefore a testimony. $0.76 walked in, $0.09 walked out. The pipeline was silently eating sixty-seven cents worth of spans somewhere in the middle, and had probably been doing it for a long time and getting away with it.

Suddenly, the question was very narrow: what happens between arrival and storage?

One of the witnesses, the ticker, was just nine hours old at the time it was giving its testimony. Had the session run a day earlier, nothing would have surfaced the crime, and the culprit would have just gotten away with it and probably never been caught until a user ran into it.

The waiting room

I read the finalizer like a fire warden reviewing an emergency protocol. Every trace in the assembler carries its spans in a map. So when a trace completes, the finalize path walks the map and saves every span. Clean, obvious, correct.

Except, a trace carries a second container. For context, Reeve has a convention where the root span of a turn is emitted last. Completion is keyed off the root, so root-last means that when the root lands, all the work is already in. Good convention. Still true. But it has a consequence: during a live turn, every child span arrives before its parent exists. Those children wait in a holding area, a map called pending_attachment, until the root shows up to adopt them.

So the finalize path iterated the first container. But nobody, on any path, ever saved the second container. The waiting room was never on the evacuation plan.

A conspiracy of three

That alone shouldn't have mattered. The root arrives, the children get adopted, everyone gets saved. And so for the waiting room to burn, something has to finalize the trace while spans are still waiting. What could possibly declare a trace dead in the middle of a turn?

A conspiracy of three decisions, each defensible on its own.

One: root emits last. Already covered above. Genuinely the right call.

Two: the assembler had a thirty second idle timeout. An agent that stops sending spans is probably dead, and a dead agent's trace should be closed out instead of haunting the screen forever. Also reasonable.

Three: language models stream. A single response could take sixty or ninety seconds, and spans are only emitted when the stream finishes.

Read those again in order. During a long response, the wire is live, tokens are flowing, the model is mid-sentence. But no spans arrive because spans arrive at stream end. Thirty seconds of that and the idle timeout declares death. The trace is finalized as interrupted. The finalizer saves the adopted spans and drops the waiting room. Then the stream ends, new spans arrive for a trace that no longer exists, a fresh trace starts, and the cycle repeats.

What survived to storage was whatever happened to be adopted at the moment of the last flush: the final two chat spans and a tool call. Nine cents worth.

And the fifty-six years? A flush with nothing adopted had no spans left to compute a start time from, so it defaulted to zero, and zero, in Unix time, is January 1970.

Older than the proxy

Then the true blast radius came into focus. None of the three conspirators is the proxy. Root-last is universal; SDK agents emit their task roots last too. The idle timeout is older than the proxy. Which means this is a bug that did not ship with the feature I was testing that morning. It had been in Reeve since version 0.1. Every agent that ever went quiet mid-turn had been losing spans the entire time, and no test, no demo ever said so. The only reason I found it was that two subsystems that could disagree finally got a session slow enough and long enough to disagree about.

The fix

The fix wasn't clever at all, and I mean that as a compliment. It has three parts and one sentence of intent: a span that entered the pipeline must reach storage.

Every path that finalizes a trace now iterates both containers, the adopted and the waiting. The proxy marks a trace as actively streaming while a round trip is still in-flight, so the timeout now knows the difference between a model mid-sentence and a dead agent; the timeout now requires evidence of death and not the absence of convenient signals. And the start times fall back to the earliest span anywhere in the trace, waiting room included, which retired the fifty-six year uptimes.

What it bought me

The general lesson costs me nothing to state and everything to practice: your happy path and your flush path must enumerate the same state. Every timeout handler, every shutdown hook, every error path that ends a thing early has to know about every container the thing keeps. Any container the finalizer does not iterate is a silent data grave, and it will stay silent until the day something counts at the front door and disagrees.

Which is the real takeaway. The ticker and the store now agree, to the cent. But I'm keeping both counts forever, because the disagreement was the entire detection mechanism. If two parts of your machine could plausibly count the same thing from different vantage points, let them both count. Redundancy of witnesses is not a waste.

The day they disagree will be the most valuable day your system ever gives you.

Reeve is open source, one Rust binary, Apache 2.0: https://github.com/Dancode-188/reeve. The bug above is issue #182.

Top comments (0)