Vasyl’s Dev Notes

Three weeks ago I wrote about an hour where nothing crashed and my CPU sat at 390%. A user’s PDF fell through my LLM router onto a CPU-only Ollama container instead of GPT-4.1. Forty-two seconds per page. One hundred and six pages.

Zero exceptions. Zero error logs. Zero OpenAI traffic. Zero alerts.

The fix for the bug was one config block. But the fix for the class of bug is different, and it took me until this week to build it. Because the real problem wasn’t the missing route. It was that my system had no way to make a sound when it did the wrong thing successfully.

Every monitoring stack has a blind spot shaped like “it worked”

Here’s the thing about that incident that still bothers me. I had observability. OpenTelemetry, wired since last year: traces, metrics, structured logs, an Aspire dashboard, the whole thing.

And when I went to look at what it had recorded during the incident, the answer was nothing. Not “nothing useful.” Nothing at all. The OTLP exporter was pointed at http://aspire-dashboard:18889, and the Aspire container is profile-gated — it doesn’t run in production. Every span my API and Worker had ever produced in prod had been fired into a closed socket and dropped.

So: two silences stacked on top of each other. The router failed quietly, and the thing that was supposed to notice was itself quietly not running. That’s the actual lesson, and it’s less glamorous than “add error tracking”: observability you never read is indistinguishable from observability you never installed.

The fix: make the router say why

Someone commented on the original post with a suggestion I keep thinking about: emit the resolved provider as a span attribute. Simple idea, and it’s exactly right — but implementing it exposed why the bug was invisible in the first place.

Here’s what route resolution looked like:

var registryKey = RegistryKey(featureTag);
var configKey = !string.IsNullOrWhiteSpace(featureTag)
    ? config[$"Ai:Routes:{featureTag}"]
    : null;
var key = registryKey ?? configKey ?? config["Ai:DefaultProvider"] ?? "openai";

Look at that last line. It produces a string. And that string is identical whether an operator deliberately routed this task to Ollama, or whether nobody configured anything and it fell off the end of the chain onto the default.

The ?? chain doesn’t just fail to record intent. It actively destroys it. There is no logging you can add downstream to recover it, because by then the information is gone.

So the chain had to return two things instead of one:

private RouteDecision ResolveRoute(string? featureTag)
{
    var matched = RegistryKey(featureTag) ?? ConfigRouteKey(featureTag);
    return matched is not null
        ? new RouteDecision(matched, RouteReason.RouteMatched)
        : new RouteDecision(config["Ai:DefaultProvider"] ?? "openai",
                            RouteReason.DefaultFallback);
}

The resolved key is byte-for-byte what it was before — I locked that with a theory test over every precedence case, because a refactor that quietly changes which model serves your users is a worse bug than the one you’re fixing. What’s new is the second field. Every LLM call now tags its span:

span.SetTag("ai.task", featureTag ?? "unknown");
span.SetTag("ai.provider.resolved", key);
span.SetTag("ai.provider.reason", RouteReasonNames.For(reason));
   // "route_matched" | "default_fallback"

“Which model actually answered this, and did anyone choose it on purpose?” is now a question you answer from a trace instead of from a CPU graph.

Not every fallback is a bug. Some are.

Tags are passive. You have to go look at them, and nobody goes and looks. So the second half is an alert — but alerting on every default_fallback would be useless, because for most features falling back to the default provider is the normal, correct, intended path.

What makes a fallback a defect is the cost of the task. A cheap tag landing on the default is fine. pdf.parse landing on the default means a multi-minute GPU-class vision job just got handed to a CPU container. That’s never intentional. So it’s config:

"Ai": {
  "RouteAlarm": {
    "AlertOnDefaultRouteFor": [ "pdf.parse", "rag.summarize", "podcast.script" ],
    "CooldownMinutes": 60
  }
}

The arithmetic that turns an alert into spam

Now the part I nearly got wrong.

pdf.parse doesn’t resolve a route once per book. It resolves once per page, with a parallelism of six. My first version would have turned that 106-page incident into 106 identical Sentry events — six of them landing in the same second.

That’s not a monitoring system. That’s a way to teach yourself to ignore your monitoring system. So every alarm goes through a throttle keyed on (task, provider, reason):

public static bool ShouldFire(DateTimeOffset now, DateTimeOffset? lastFired, TimeSpan cooldown)
    => lastFired is not { } last || now - last >= cooldown;

The important detail is that the first hit always fires immediately. A cooldown that also delays the first event would mean a bad deploy goes unreported for an hour — which defeats the purpose. First page: alert. Pages 2 through 106: silence. One event per hour per distinct problem after that.

There’s a test for exactly this, and it’s my favourite one in the PR:

[Fact]
public void TryEnter_RepeatedWithinCooldown_ClaimsOnce()
{
    var throttle = new AlarmThrottle(TimeSpan.FromMinutes(60));
    var claims = 0;

    // One page-parallel PDF book's worth of calls.
    for (var i = 0; i < 106; i++)
        if (throttle.TryEnter("pdf.parse|ollama", T0.AddSeconds(i)))
            claims++;

    Assert.Equal(1, claims);
}

The number 106 in that test isn’t arbitrary. It’s the book from the incident.

The other silence: failures that return successfully

While I was in there I found a second one, and it’s the same species of bug.

My Ollama client swallows everything — non-2xx, timeouts, transport errors — and returns an empty, zero-token, zero-cost response. That behaviour is load-bearing; callers depend on getting a response object rather than an exception. But it means my LLM tracing layer, which faithfully records every call, sees a successful call that happened to produce no text. A dead Ollama and a model with nothing to say are the same row in my database.

I didn’t change the swallow. I added one line to each of the three catch blocks:

catch (TaskCanceledException)
{
    _logger.LogWarning("Ollama request timed out after {Seconds}s", _timeoutSeconds);
    LlmFailureAlarm.Capture("ollama", request.FeatureTag, LlmFailureAlarm.ReasonTimeout);
    return Empty();
}

Same throttle. Tagged with the task and the provider, so the Sentry issue answers “which feature, on which model, is broken?” without opening a trace.

One seam for every agent

I run three production agents — Enrichment, Librarian, Tutor — plus a study-buddy and a few crews. I wanted a span per agent run: model, tokens, cost, outcome.

The temptation is to instrument each agent. Don’t. They all delegate to one loop, and RunAsync is a pure pass-through to StreamAsync, so a single using covers all of them:

using var trace = TraceScope
    .Start("agent.run", "ai.agent")
    .SetTag("agent.name", input.FeatureTag);

Two things I learned here. First: using is legal inside a C# iterator, and it disposes on normal completion, on yield break, on a throw, and when the consumer abandons the enumerator. That last case is the one that matters for a streaming agent — a reader closing the tab shouldn’t leave a span open forever.

Second: the outcome defaults to "error" and is only upgraded to "completed" or "budget_exhausted" at the three terminal paths. Default-to-failure means an exception I didn’t anticipate is still recorded correctly, without a catch block. Optimistic defaults are how spans start lying to you.

The decision I expected to go the other way

I already had OpenTelemetry spans. Sentry ships an OpenTelemetry integration. Obviously you bridge them and instrument once, right?

I read the docs expecting to confirm that plan, and didn’t. Two reasons.

The Sentry.OpenTelemetry bridge is deprecated upstream — its own documentation page says so. Its replacement, Sentry.OpenTelemetry.Exporter, is an OTLP exporter pointed at Sentry’s ingest endpoint, which is still in open beta. Fine, betas are fine.

The disqualifier is architectural: spans leaving through the OpenTelemetry SDK never pass through Sentry’s BeforeSend hook. And my OTel pipeline puts two things on every span that must not leave my infrastructure:

• http.client_ip, set by my own ASP.NET Core enrichment — a reader’s raw IP.
• SetDbStatementForText = true on the EF Core instrumentation — full SQL text, on a database of books people are reading.

There’s no hook to strip those on the way out. Losing the scrubbing hook isn’t a tradeoff I get to make on a reading app.

So I dual-write instead. A tiny TraceScope opens an Activity (which flows to OTLP exactly as before) and a Sentry span, and fans tags to both. The existing OpenTelemetry pipeline gained exactly one line — registering the new ActivitySource. Everything Sentry receives goes through my scrubber.

The general form: when two observability backends can share instrumentation, check whether they also share the egress path. If one of them bypasses your redaction, “instrument once” is buying convenience with somebody’s IP address.

Allowlist, not denylist

My scrubber drops every tag that isn’t explicitly blessed:

public static readonly FrozenSet<string> AllowedTagKeys = new[]
{
    "ai.task", "ai.provider", "ai.provider.resolved", "ai.provider.reason", "ai.failure",
    "agent.name", "agent.model", "agent.outcome",
    "rag.kind", "rag.book_id", "rag.outcome",
    "outcome", "environment", "release", "server_name", "transaction",
}.ToFrozenSet(StringComparer.OrdinalIgnoreCase);

A denylist stops the leaks you remembered to enumerate. An allowlist stops the ones you didn’t. Six months from now somebody — possibly me — writes span.SetTag("prompt", userText) while debugging, and it dies at the edge whether or not a reviewer catches it in the diff.

Around it: no default PII, request bodies never read (my uploads are books, my POST bodies are reader prompts), auth headers stripped, free text run through an email/phone redactor and truncated, breadcrumb data bags dropped whole. Client-error exceptions — not-found, validation, budget-exceeded — are filtered out, so ordinary 4xx traffic never becomes a page.

And sampling is deliberately lopsided: HTTP transactions at 20%, health checks at 0%, but agent runs and RAG indexing at 100%. They happen a few times an hour and they’re the entire reason I installed this. Sampling them at 20% would throw away four of every five traces I built the thing to see.

Verify it, don’t assume it

Unit tests prove my scrubber returns the right object. They do not prove that what arrives at Sentry is scrubbed. So I sent real events at the real DSN and read them back in the UI.

Good news: a prompt tag I planted was gone. A response extra arrived as [redacted]. An exception message containing an email arrived as synthetic failure for [redacted-email]. My admin session cookie — the request genuinely carried one — was absent from the captured headers. Release and environment tags were correct, which means the GIT_SHA build arg plumbing works.

Less obvious news: the event still showed a city. Sentry infers coarse geography from the ingest connection IP at their edge — it isn’t in my payload and I can’t scrub it, because it’s derived after my code is done. In production that resolves to my datacenter rather than a reader, so it’s harmless here. But I’d never have known if I’d stopped at green tests.

And then the part that justified the whole exercise. My scrubber leaked.

I pointed my local Worker at the branch build, and it immediately hit a real failure — I hadn’t started the Ollama container, so the metadata backfill threw 38 transport errors. Good: that’s precisely the invisible-failure class I’d built this for. One Sentry event arrived, tagged ai.provider=ollama, ai.task=bookmeta, ai.failure=transport. Thirty-eight failures, one event. The throttle worked on real traffic.

But scrolling down that event’s breadcrumb trail, there it was:

Microsoft.EntityFrameworkCore.Database.Command
  Executed DbCommand (1ms) [Parameters=[], CommandType='Text']
  SELECT m.feature_tag AS "FeatureTag", m.provider_key AS "ProviderKey"
  FROM models AS m WHERE m.status = 'Primary'

SQL. In Sentry. In an event produced by the integration whose headline feature is that it doesn’t ship SQL to Sentry.

My breadcrumb scrubber nulled the structured data bag, which is where you’d expect structured fields to live. EF Core doesn’t put the query there. It interpolates it into the breadcrumb message. So the exact leak I’d rejected an entire integration path to avoid walked back in through the logging pipeline, past a scrubber I’d written specifically to stop it, and my unit tests were green the whole time — because they asserted that ScrubBreadcrumb returns an object with Data == null, which it faithfully did.

The fix is to drop EF Core command breadcrumbs entirely rather than redact them. A breadcrumb saying “a query ran” is not worth the risk of sending query text about what people are reading to a third party. Then I re-ran it and read the next live event: no DbCommand, no SQL.

One more thing worth checking in your own setup: my API has an exception middleware that catches everything and returns a 500. Which means unhandled exceptions never propagate to Sentry’s ASP.NET middleware at all — they arrive only through the ILogger integration, from that middleware’s own LogError. The captured event confirms it: logger: Api.Middleware.ExceptionMiddleware, mechanism: SentryLogger. If I’d assumed the middleware path worked and never tested it, I’d have had error tracking that reported nothing and a dashboard that looked healthy. Which is, you’ll notice, exactly the bug I started with.

Then production found the leak I thought I’d fixed

I shipped it. Fourteen hours later I opened the issue feed, and the very first real production event was carrying this:

INSERT INTO reading_progresses (id, chapter_id, edition_id, locator,
  max_chapter_number, percent, site_id, updated_at, user_id) VALUES (@p0, …)

Same leak. Different door.

I had fixed EF Core breadcrumbs. But EF Core also logs a failed command at Error level, and Sentry’s ILogger integration turns any Error into an event — where the SQL rides in the event message instead. Two channels, one shared wrong assumption: that the SQL lived in the structured data bag. It never did. EF interpolates the statement into the human-readable text on both paths, and I had only looked at one of them.

To be precise about the exposure, because vagueness here would be self-serving: no parameter values ever left the process. EnableSensitiveDataLogging is off, so EF renders @p0 and '?', and Npgsql writes “Detail redacted as it may contain sensitive data” on its own inner exception. What left was statement shape and schema — table and column names. No book text, no reader identity. Still a promise the previous section makes and breaks.

The fix drops EF Core command events outright rather than redacting them, and that’s the part worth arguing: dropping loses no signal. The same failure is already reported by the exception middleware with a full stack trace, the Npgsql SQLSTATE and the violated constraint name. Everything I need to debug it; none of the SQL.

So the generalisable form, and I’d underline this one: a scrubber written against one egress path will be bypassed by the next one. This integration rejected Sentry’s OpenTelemetry exporter specifically because it bypasses BeforeSend — and then shipped with two log-pipeline channels doing exactly that from the inside. Unit tests were green through both. They asserted the scrubber’s behaviour on the input shape I imagined, not on what the SDK actually assembles.

What it caught in twenty-four hours

I’d written a list of predictions here before deploying. I’m keeping the format honest and replacing it with what actually happened, because that’s the only version worth anything.

The OpenAI account was out of credits. HTTP 429 (insufficient_quota: credit_balance_exhausted) on /translate and /explain. Translation, word explanation, book chat, RAG answers, PDF parsing — the entire paid surface — had been failing for readers for twelve hours. There is no version of my logs where I would have noticed that before someone complained.

Readers were losing their place in books. PUT /me/progress was throwing 23505: duplicate key value violates unique constraint "ix_reading_progresses_user_id_site_id_edition_id" — ten times in four hours, from real users, returning a 500 and dropping the saved position. Textbook read-then-insert with no concurrency control: one reader legitimately produces overlapping writes (a 30-second session heartbeat, a sendBeacon on unload, an offline-queue flush, a second device), both requests see no row, both INSERT, and the loser violates the unique index. The window is milliseconds wide, which is why it never shows up in a test and only appears under real traffic.

Look at the shape of those two. Neither of them crashes anything. The credits failure returns a clean HTTP error to a client that shrugs. The progress bug returns a 500 on a background save nobody watches. That is what failure looks like in an LLM pipeline: a chain of components that each cheerfully return something plausible when they’re misconfigured — and plausible is the hardest thing in the world to alert on.

And the third catch was its own leak, which I’d argue is the most useful of the lot. A monitoring system whose first act is to indict itself is one you can start trusting.

The fourth one needs its own section, because it wasn’t a bug in the pipeline at all.

The tag said environment: Production. It was a laptop.

One of the issues in that first day showed a dead Ollama starving a metadata pipeline. Thirty events, zero users affected, tagged Production. I read it as an outage and started writing the fix.

It wasn’t production. A dev .env with ASPNETCORE_ENVIRONMENT=Production, plus the production DSN I’d just pasted in to verify the integration, is all it takes — and every dashboard downstream inherits the lie. What broke the spell wasn’t tooling. It was sshing into the box and finding the container healthy with four weeks of uptime, zero matching rows in the database, and a release tag for a commit that had never been deployed.

An environment tag is a claim a process makes about itself, not a fact. The fix is to make the claim checkable: SENTRY_RELEASE comes from the GIT_SHA build arg, so every CI-built image has one and no dotnet run ever does. A Production claim without a release is now reported as production-unverified. A rename, not a drop — the event is still worth having, it just isn’t allowed to masquerade.

Then the fix found a hole in itself

The hardening still shipped, because the gap it closes is real whoever tripped over it: nothing probed provider reachability at startup, a dead provider cost up to 50 × 90 s of wall-clock per worker start, and — worst — the enrichment service stamps Completed, not Failed, on an empty result, so an outage would quietly drain the queue into “done, nothing filled”.

Then the first live run found a hole in my own fix. The startup probe opens the circuit on a one-minute backoff; the backfill worker only wakes after a two-minute start delay. By then the circuit is legitimately half-open, and my single up-front gate waved the whole batch through. Adding a per-book re-check turned 38 calls into one:

Metadata backfill: enriching 38 user books
Metadata backfill: aborting after 0 enriched / 1 failed — provider 'ollama'
  is unavailable; the remaining candidates stay queued

Same lesson as the SQL leak, twice in one week: tests check what you imagined; a live run checks what’s there.

Five things I’d tell past me

Instrument decisions, not just outcomes. Logging “used provider ollama” would not have caught this. Logging “used provider ollama because nothing was configured” would have caught it on page one.

Count your alert’s fan-out before you ship it. Any alarm on a per-item hot path needs the arithmetic done in advance. One event per book is monitoring; 106 is training yourself to filter the sender.

Assume your redaction has a second door. Enumerate every path by which data leaves the process — not just the one you designed the scrubber against — and then go read a real captured payload, because that is the only test that covers the paths you forgot.

Treat an environment tag as a claim, not a fact. The tag said Production; the sender was a laptop. Make the claim checkable — my release tag now exists only when CI built the image, and a Production claim without one gets renamed instead of believed.

Check that your telemetry has a reader. The most expensive part of that outage wasn’t the missing route — it was a year of spans exported into a container that wasn’t running. Nobody alerts on silence, including the silence of your own monitoring.

The code is open, in four parts: the integration, the first leak it found in itself, the reader-facing race it found in me, and the readiness probe, the circuit breaker, and the environment-tag fix. TextStack is a free reading app I build in .NET. Sentry is a no-op there without a DSN, so the whole thing is inert for anyone who clones it — which felt like the only decent default for something that ships errors to a third party.