DEV Community

How do you debug something that is allowed to be wrong?

Pierre- Laurent Medori on September 11, 2026

Yesterday afternoon a runtime I wrote created 70 paragraphs on the same draft article. It was supposed to create one. The runtime was an experiment...
Collapse
 
_firelinks profile image
Mike Dabydeen

Data, or more precisely the read path. It took me longer than I would like to admit to get there, because my reflex used to be the prompt as well.

The reason it should not be the model is structural, and you name it yourself: every layer above the model is deterministic and checkable in minutes, while the prompt is the only layer where a fix cannot be verified. That is a good enough reason to order the search that way even if the model were the likelier culprit, which your registry suggests it is not.

Your read-after-write finding is the part I would want more people to sit with. A cache that bypasses for exactly one read, with a list call in between resetting it, is a defect that only becomes visible under agent traffic. A person writes and then looks. An agent writes, reads, lists, reads, and does it forty times a minute. The invariant the cache was built on was human pacing, and nothing in the design ever said so out loud. We have hit the same class of problem on shipment status endpoints, where a stale read is a vehicle going to the wrong place rather than a wrong paragraph, so the cost of the gap is easy to explain to people who do not care about caches.

Time to detection as the headline number instead of error rate is what I am taking away from this. Error rate describes the system. Detection time tells you which of your checks are actually running, and two rows having no detector at all is far more actionable than a percentage. Are you capturing that per channel as it happens now, or is it still reconstructed after the fact from transcripts?

Collapse
 
pierrelaurentmedori profile image
Pierre- Laurent Medori

Reconstructed, all of it. The "lived" column was computed on September 3 from three sources that were never meant to answer that question: the transcripts of my scheduled runs, one CSV export of the usage table, and commit dates. Nothing captures a detection timestamp as it happens. The only live detectors are Sentry on unhandled exceptions and the status code in the usage row, and neither carries an outcome. So the number is honest, but it is archaeology.

Live, per channel, would take the two items sitting on the "not built" list. A heartbeat, or rather an expected-runs table diffed every morning, because a run that does not start writes nothing and absence has to be produced by something. And an outcome flag next to the status code, so that a 200 that did the wrong thing is countable at all. With those two, time to detection stops being a spreadsheet and becomes a query: first detection minus first occurrence, grouped by what detected it.

Your framing is better than mine: the cache encoded human pacing as an invariant and never said so. Every TTL is a statement about who is reading. And the shipment example makes the cost legible in a way a wrong paragraph never will.

One question back: on your status endpoints, did the fix land on the read side, a version or generation the reader checks, or did the writer's own reads get a separate path?

Thanks, this one I will keep.

Collapse
 
_firelinks profile image
Mike Dabydeen

Read side, and not a version the reader checks, because in a tracking domain almost nobody is holding one.

Your exchange with Vinh is what makes me say that. Co-commit gives read your writes to a client carrying a version from its own write. On a shipment status endpoint the writer is a scan somewhere in the network, and the reader is a customer, or now an agent polling on its own schedule. Nothing joins them causally. "At least my version" is a sentence only a client holding a version can say, and here almost no client holds one, so the reader outside the chain that Vinh called mundane is the whole traffic profile rather than an edge.

So the read did not get fresher. It got honest about its age. The response carries the time of the underlying scan and the time the view it came from last advanced, kept as two fields on purpose. That lets a caller separate "no movement since 06:12 because nothing has scanned" from "I am handing you a copy and I do not know what has happened since". Those collapse to the same value in a single status field, and operationally they mean opposite things. The second one is what sends a vehicle to the wrong place.

The writer's own reads did get a separate path, but it is the smaller half of the work, and it exists for reconciliation jobs rather than for correctness at the edge.

One push on your table. The rule for a reader outside the chain is tolerated when no write preceded it, which is right for a dashboard and cannot be settled at the read path when the reader acts on what it gets back, because the cache has no idea what the caller is about to do with the answer. Putting the age in the payload moves that judgement to the only layer that knows. It also gives you the detection number on that channel for free, since first occurrence and first observation are both sitting in the response. Given you already log sizes per call, is there room in the usage row for that pair?

Thread Thread
 
pierrelaurentmedori profile image
Pierre- Laurent Medori

Possible, at least half of it. The copy's age I can stamp, since the cache is mine, and an age is not a value, so it fits in the usage row next to the sizes. The time of the underlying change is the other half, and that depends on what the service behind me returns.

Fair push on the table. The row says what I tolerate serving. Whether it is safe to act on is the caller's call, and the age is what lets the caller make it.

Worth testing the next time I run the read-back cycles. It would have replaced the probes: last run, I told the cache from the upstream by re-reading at 1, 3, 10, 30 and 61 seconds. A copy time on each response says which one answered, on the first read.

Honest about its age rather than fresher: that one I am taking away.

Thread Thread
 
_firelinks profile image
Mike Dabydeen

The half you are handing to upstream may be smaller than it looks, because three timestamps are getting collapsed into one.

When the world changed, when you last confirmed with the origin, and when you made the copy. Only the first belongs to the service behind you. The second is yours whatever that service returns, since you know when your fetch succeeded, and it is also the one that decides whether acting is safe. The thing you are protecting a caller from is a change that has already happened and that you have not seen yet. An unseen change can be at most as old as your last confirmation, and that number sits entirely on your side of the boundary.

If you want the change time as well, polling gives you an interval instead of a point. The first fetch that comes back different puts the change somewhere between that fetch and the one before it, so the width is your poll period rather than an unknown. That is worth saying out loud in the row, and it degrades cleanly on the day the service behind you starts stamping its own.

One caution on retiring the probes. A copy time written by your cache attributes staleness to your layer, which is the same boundary you drew for Vinh: the 4 in 50 is yours, the 2 in 50 is in a service you consume. If that service is also handing you a copy, your stamp records when you asked, not when the answer was made, so the ladder is still measuring something the stamp cannot see.

Is the read-back cadence fixed? The interval is only useful if the poll period is a number you can quote.

Thread Thread
 
pierrelaurentmedori profile image
Pierre- Laurent Medori

Not fixed, and on this path nothing polls at all, which I keep losing sight of because we poll in a lot of other places, for historical reasons. The cache goes back upstream on the first call after its 60 seconds, so two confirmations of the same key are at least a minute apart and otherwise set by traffic. No period to quote. A row could carry its own bounds instead, the previous confirmation and this one, but today the previous one expires with its copy.

Agreed on the three timestamps, and the second is already stored. The cache keeps the time the upstream answered and checks its 60 seconds against it. It is just never exposed. Confirmation and copy come apart around a write: the write and the bypassed read after it both go upstream and leave the older copy in place. That is the article's 50 out of 50: the list had seen the delete in 49 of them, and the get behind it was still handed the copy from before.

The caution stands. With that much polling around, what the service behind me returns can itself be a copy with an age of its own. The bound for acting is the age of my confirmation plus the age the answer already had when it reached me. The stamp gives the first term, and the ladder is still what measures the second. The 2 in 50 were bypassed reads served live: a copy time would have said "just fetched" on a wrong answer.

The probes stay. The stamp says whose copy answered, the ladder how far behind it was.

Collapse
 
vinhnguyenthanhdn profile image
Vinh Nguyen

The two sequences differ in two places, so the list is not isolated yet. A is create, read, delete, read; B is create, read, read, delete, list, read, which adds an intervening list and also a second read before the delete - so "a list in between resets it" and "the bypass is spent by whichever read comes first after the write" both predict the 50 out of 50 you measured. The arm that separates them is create, read, read, delete, read with no list in it at all: if that one is still stale, the extra read consumed the bypass and list is innocent. I would want that before picking a fix, because the two readings want different code - one is "stop counting list as a read that resets the bypass", the other needs a generation counter per token - and the 3 in 50 from sequence A is already saying the one-read bypass is not deterministic even in the shape it was built for.

Collapse
 
pierrelaurentmedori profile image
Pierre- Laurent Medori

You're right on both counts, and the sentence in the article is wrong as written. S2 changed two things, and "a list in between resets it" makes the list special. It is not. The bypass is a one-shot flag set by a write and keyed on the token, spent by the next read on that token, whatever the tool. In S2 that read happened to be the list, and the get behind it hit the copy cached before the delete.

I ran your arm this morning, 50 cycles on the same test app, with create, read, delete, read as a same-day control. Create, read, read, delete, read, no list: stale 4 times out of 50, each still there at 1, 3, 10 and 30 seconds and gone at 61. Without any list the one-shot bypass itself misses about one time in twelve, and a miss with a warm cache costs 60 seconds. The control: stale 2 out of 50, gone by the first probe at 1.6 seconds. Those two are not the cache. The upstream had not caught up with the delete yet.

One boundary I should have drawn in the article: I run the MCP server, not every service it calls. The cache and the bypass are mine, so the 4 in 50 is mine to attribute; first suspect, a race between the write returning and the flag landing, and I read that path before touching anything. The sub-second window behind the 2 in 50 lives in a service I consume like any other client. I can name it and measure it, not close it, which is one more reason the verifier has to treat "not found" as unverified rather than as truth.

On the fix we agree. "Don't count list" was never the right code, and a flag with an 8 percent miss rate is not a guarantee. A write generation per token, stamped on the cache entries, is the read-side twin of the version-bound write on my list, and on my side of the boundary it has no window to lose.

Thanks, this is the arm I should have run.

Collapse
 
vinhnguyenthanhdn profile image
Vinh Nguyen

The 4 in 50 is the one number a generation counter does not fix for free. Your own diagnosis of it is a race between the write returning and the flag landing, and a generation stamped by the same post-write path lands on the same schedule: a read arriving inside that window reads the old generation as the current one, the cached entry matches it, and the result looks fresh rather than unverified. Same window, quieter symptom.

What closes it is not generation-instead-of-flag, it is that the delete cannot return until its marker is durable, or that the marker comes out of the same commit as the write itself. Worth pinning down which of those your version is before the miss rate gets read as solved, because a marker that lands late still costs the full 60 seconds you measured, and that failure no longer has a one-shot flag to blame.

Thread Thread
 
pierrelaurentmedori profile image
Pierre- Laurent Medori

Agreed on the stamp. A generation written after the write is the flag with a longer name: same window, and it fails "fresh" where the flag failed "unverified".

So the marker has to come out of the commit itself. The write returns its committed version, the token carries that version forward, and the read no longer asks "what is the current generation" (that lookup is the stale one). It asks "is this cache entry at least the version my write handed me". Below it, or missing, means unverified: refetch. There is no post-write moment left to lag. It also means the delete has to return that version. Today it returns only the policy envelope, so that is part of the change.

Holding the delete until the marker is durable closes the window too, but it taxes every write and leans on a side channel next to the commit. Co-commit keeps one authority. That is the 4 in 50.

The 2 in 50 is not mine to close: a sub-second window in a service I consume and do not run. It stays the verifier's rule: not found is unverified, never truth.

Good catch. The stamp would have shipped looking solved.

Thread Thread
 
vinhnguyenthanhdn profile image
Vinh Nguyen

Co-commit closes it for the writer, agreed. The gap I would still name is the reader who did not do the write: no token, so nothing to compare the entry against, and it falls back to asking what the current version is - which is the lookup you just established is the stale one. The guarantee is scoped to a causal chain starting at a write, and reads outside that chain are back where they started.

That may well be fine if every read on this path is downstream of a write in the same request. Worth checking that it actually holds, because the thing that breaks it is mundane rather than exotic: a second consumer polling the same key on its own schedule.

Not arguing against the change. "At least my version" is just a sentence only a client holding a version can say.

Thread Thread
 
pierrelaurentmedori profile image
Pierre- Laurent Medori

Agreed, and that is the right boundary to name. Co-commit gives read-your-writes to the client holding a version, nothing more. A reader outside that chain gets the 60-second copy, same as today, which is the first row of the table: tolerated when no write preceded it, never when one did, by the same token.

Whether tolerated is acceptable depends entirely on what the reader does with the copy. A poller refreshing a dashboard, fine. An agent that branches on the read is the 70 paragraphs: 25 stale reads in a row, an action on each. Where the reader acts, the copy is not ideal, and the fix there is invalidation on write, which only reaches my side of the boundary.

Lorca had the line for it: universal law is for lackeys, context is for kings. Which is what the table is for.