Twenty-six alerts, one locked door

Wegweiser reads its own logs the way it reads yours. Overnight it filed twenty-six separate bug reports. Every one of them was the same locked door.

This is the account of what was behind it, because the shape of the mistake is one every MSP knows: a single fault arriving as a page of alerts, and the alert you read first pointing somewhere the fault is not.

One fault, twenty-six reports

Wegweiser keeps a warm local copy of its own configuration, so that a blink from the primary secret store does not take the product down with it. A daily job walks every secret and writes it into that copy.

Somewhere in a routine change, the directory holding the key to that local copy stopped being reachable by the service that needs it. The key itself was untouched and perfectly correct. The door in front of it was not.

So the daily job asked to write one hundred and four secrets and was refused one hundred and four times. Each refusal named the secret it was refusing, which meant our triage saw one hundred and four different messages rather than one problem, and grouped them into twenty-six distinct reports. Not one of the twenty-six said why.

That is the multiplication every alerting system does at least once. The fix is the obvious one once you have seen it: report the cause, once, and keep the per-item detail for whoever is genuinely debugging a single item. One dead dependency is one incident, not one incident per thing that depended on it.

The alert that pointed the wrong way

The twenty-seventh report was worse than the twenty-six, and it is the reason this is a post rather than a line in a changelog.

When the product starts, it looks for its database address in each configured store in turn. At half past eight that evening, two startups found nothing, and logged this:

DatabaseUrl not found in any secret backend after 3 attempts;
  Infisical=miss; LocalVault=miss; Environment=miss

Read that as an engineer holding a pager and it says one thing: the secret is gone, go and restore it. It was not gone. It is still there, and always was. The local copy was never asked a question it failed to answer, because it could not be opened to be asked.

An empty answer from a store that is working and an empty answer from a store that never opened are different facts, and they had been reported with the same word. That is an alert doing worse than nothing, because it is confidently sending you away from the fault.

Both halves are fixed. A store that could not open now says so in the chain, and when a key cannot be read, the reason travels with the failure:

LocalVault write rejected - cannot read vault keyfile
  /etc/wegweiser/vault.key: [Errno 13] Permission denied

That is a sentence an operator can act on without opening any code.

What it cost, honestly

Nothing, and very nearly a great deal.

The primary store kept serving throughout, so the product stayed up and no customer data was touched. What had quietly gone was the fallback - the thing whose entire job is to be there on the day the primary is not. For one day, a blink from the primary would have been an outage instead of a non-event. That evening two startups landed in exactly such a blink and could not start.

A warm standby you have stopped testing is not a standby. The reason this one went unnoticed is that three of the four ways it can fail were logged below the level anything collects, and the fourth was the only one anybody ever saw. The fixes above are, in total, about making the quiet three audible.

An analysis that runs out of time is allowed to finish

The same day, a separate piece of work landed that you will notice more directly.

Analyses run in batches with a hard ceiling on how long the batch may take. Ten analyses, each one a real call to a model whose latency nobody controls. A batch was limited by how many items it took on, and by nothing at all in the way of time, so a batch of ten slow ones simply ran past its ceiling and was killed outright.

Killed outright is the operative phrase. Not interrupted, not asked to wrap up. The work in progress had already been marked as being in progress, and there was nothing left running to unmark it, so it stayed that way until an hourly sweep came past and abandoned it. Twenty-one times since June, and the sweep was always the thing that noticed.

Three changes, all in the same direction:

A batch keeps its own clock. Before starting another analysis it asks whether there is time to finish it, and it answers with the slowest one it has actually done this run rather than an average. If there is not, it stops. The rest stay queued and run on the next pass, a minute later.

An analysis that is interrupted tidies up after itself. If one single analysis outruns the limit on its own, it now releases what it was holding and comes back on the next run, instead of sitting in Processing for up to an hour.

The weekly fleet roll-up got the same treatment, where it had a cap on how many summaries it would write and no cap on how long it would spend writing them.

What you see is duller than what you saw before, which is the point. Fewer analyses stuck part-done on a device page. Fewer health scores frozen at yesterday's number because the job that was going to refresh them did not survive. A batch that runs out of road now says so and finishes the rest shortly after, rather than being cut off mid-sentence and cleaned up by something else an hour later.

The thread running through both

An alert that fires twenty-six times for one fault trains you to stop reading it. An alert that names the wrong cause is worse, because you do read it, and then you go and look in the wrong place.

Both of those were ours this week, in our own logs, found by our own triage. They are the same bug the industry ships constantly, and the standard we are holding ourselves to is the one we are selling: an alert should tell you what is wrong, once, in words that name the thing you have to go and fix.