Back to Blog
Insights

The Failures That Log Success: Four Silent Defects Found Across Seven Apps in One Week

An error is a gift. It has a timestamp, a stack, and a place to start looking. Every developer says they hate them and every developer would rather have one than the alternative, which is a system that finishes cleanly, returns 200, writes a reassuring line to the log, and did not do the thing.

In one week at the end of August we found four of those across a fleet of seven Shopify apps. None of them threw. None of them appeared in an error rate. Three of them had been sitting there for some time, and one had not run yet at all — it was waiting to do nothing on a Monday morning. What follows is each of them, what made it invisible, and the one structural change that makes the category harder to repeat. If you run more than one service, the last section is the part worth stealing.

One: The Error That Would Not Say Who

Two uninstall webhooks arrived four days apart and logged, in full: post-auth error: Response 500.

That line is not wrong. There was a 500, and it is a known one — when a shop uninstalls, the framework tries to refresh an expiring offline token against a token that has just been revoked, and it throws. Our wrapper catches that, runs a fallback cleanup, and returns 200 to Shopify, which is exactly right: a webhook endpoint that returns 500 gets retried and eventually gets you removed from the delivery list. The swallow is correct. The handling is correct.

The defect was that afterwards, nobody could tell which store had uninstalled.

And here is the part that stings. The shop domain was on the request the entire time, in an HMAC-verified header. The wrapper was already reading it — it needs it to run the fallback cleanup. It read the value, used it, and never put it in the log line. The information was in the function's own scope and simply never made it into the sentence.

The failure was the silence, not the exception

It is easy to read this as "an error was swallowed." It was not: the exception was handled deliberately and correctly. What was lost was the identity attached to it. A correctly-handled error that cannot be attributed to anything is an event you can count and never act on, which over time is indistinguishable from noise. All seven apps share that wrapper, so all seven now name the shop, include the response body, log the fallback cleanup succeeding, and shout when the header is missing — because a cleanup that got skipped should be louder than one that worked.

Two: The Erasure That Left a Row Behind

This one was found by accident, while reading the same files for the first problem, and it is the most serious of the four.

Shopify sends a shop/redact webhook when a merchant's data must be erased. Ours handled it and logged erasing all shop data. The log line was accurate about intent and wrong about outcome: in all seven apps it left the subscription mirror row alive, and in five of them it left the app settings row too. We confirmed it in production rather than inferring it — a mirror row with an active paid status survived its own redact, and was still sitting there afterward.

What makes this instructive rather than merely embarrassing is why that row exists. The mirror is deliberately designed to survive an uninstall. It carries the flag that records whether a shop has already used its free trial, and if uninstalling wiped it, uninstall-and-reinstall would be a free trial generator. Surviving uninstall is a feature.

But redact is not uninstall. Uninstall is a business event; redact is a legal erasure mandate. And a row keyed by the merchant's own domain is, unambiguously, shop data. The correct answer turned out not to be "make the mirror survive less" or "make redact delete more" in general, but to separate the two paths on purpose: uninstall purges sessions only; redact erases every shop-keyed model. Two webhooks that look adjacent, with deliberately different jobs.

Why a log line is not evidence

“Erasing all shop data” was written by a developer describing what the function was for. Nothing checked that the sentence and the behaviour still matched, and over time and across seven codebases they drifted apart. A log line is a claim, and an unverified claim in a log is worse than no line at all, because it converts a question into a false answer.

Three: The Mailer That Would Have Sent Nothing

The third one had not failed yet. It was scheduled to fail politely the following Monday.

One app had just gained a monthly compliance statement — an email summarising a merchant's verification log. The mailer was written to degrade gracefully: if SMTP is not configured, log SMTP not configured, send nothing, throw nothing. That is a reasonable design in isolation. It means a missing credential in a development environment does not crash a scheduled job.

The credential was missing in production. So the first run would have sent zero emails, and every other line in that job's log would have looked completely healthy: shops processed, statements generated, run completed. One quiet line in the middle, indistinguishable from a dev-environment message, standing between a feature and its entire purpose.

The detail that generalises past this one bug: a deploy dry run could not have caught it. A dry run skips the transport, which is the whole point of a dry run — and it is exactly why a dry run is a check on your intent to deploy, not on whether the deployed thing works. We have written before about the gap between a service being enabled and a service being alive. This is the same gap, one layer up.

The fix location mattered as much as the fix. The credential block went into the deploy master rather than being added by hand to the live environment file, because the master regenerates that file on every deploy and would have silently overwritten a hand fix on the next update. A repair that the next deploy erases is not a repair; it is a delay with a false sense of completion attached.

Four: The Retry With No Way to Stop

The last one is small and worth the paragraph because of its shape.

A scheduled monitoring job classifies failures as permanent or transient: a store that is gone forever should be dropped, a store that timed out should be retried tomorrow. A shop whose session records had disappeared — uninstalled at some point with the webhook missed — threw a session-not-found error that matched none of the permanent-failure patterns. So it was transient. So it would be retried. Tomorrow, and the day after, and every day after that, forever, quietly, in a job whose summary line would report a small number of failures every morning and never change.

Session-not-found is now permanent. But the general lesson is about the default: an unrecognised failure classified as “retry” produces an infinite loop, while an unrecognised failure classified as “stop” produces an alert. Both defaults are wrong sometimes. Only one of them is wrong quietly.

What the Four Have in Common

Line them up and the pattern is not really about logging.

What each one produced

  • A correct 200, and no attribution
  • A log line describing an erasure that partly happened
  • A healthy job summary with nothing sent
  • A daily failure count that never changed

What each one needed

  • The identity that was already in scope
  • A check that behaviour still matches the claim
  • A test that exercises the transport
  • A default that stops rather than loops

Every one of them was a place where the system had the information it needed and did not use it. The shop domain was in the request. The list of models was in the schema. The absent credential was in the environment. The unmatched error string was in the exception. None of these required a new signal; they required something to look at a signal already present and compare it against a promise.

The Move Worth Stealing: Re-derive, Don't Restate

The fix that matters most here is not any of the four. It is the test written for the second one, and the idea behind it applies to almost any codebase.

The obvious way to test an erasure routine is to list the models it should delete and assert it deletes them. That test passes forever and protects nothing, because the day someone adds a new table to a schema, the test does not know the table exists. The list in the test is a restatement of the schema, and restatements go stale silently — which is the exact failure mode this whole article is about.

So the test reads each app's schema directly and re-derives which models are shop-keyed, then asserts that the erasure covers every one of them. Add a model to any of the seven schemas and the test fails until its erasure line exists. Nobody has to remember. The test also pins two things that would otherwise be silent: an erasure aimed at a renamed model (which, inside a handler that deliberately returns 200 on error, would void the erasure without a sound), and the fact that uninstall keeps the mirror row — so a future well-meaning developer cannot "complete" the uninstall path and hand out free trials.

The general rule

If a test contains a list that also exists somewhere else in your codebase, the test is a copy and the copy will rot. Read the source of truth at test time and derive the list. It is usually five extra lines, and it converts a check that guards today into one that guards every day after.

The Honest Part

Three of these had been live for a while. The redact gap in particular was a legal-obligation path that logged the right sentence and did the wrong thing, across every app we run, and we found it by reading adjacent code for an unrelated reason rather than by any deliberate audit. There is no version of this article where that is a good look, and pretending otherwise would be its own kind of silent failure.

What we would defend is the response: production was checked rather than assumed, the fix went to the shared wrapper so all seven apps got it at once, the fix location was chosen so the next deploy could not undo it, and the test that pins it derives from the schema rather than repeating it. That last one is the only part that makes next time genuinely less likely.

The lesson we would actually press on anyone running a fleet: go and grep your own codebase for log lines that describe an outcome. Every “erasing…”, “sent…”, “cleaned up…”, “completed…”. Each one is a claim somebody made about behaviour at the moment they wrote it, and nothing in your test suite is checking that the sentence is still true. Ours were mostly fine. The interesting ones were not.

Previous: Payout Guard vs the Payouts Page All Articles