A notification wasn't firing. I found the cause, wrote a small fix, deployed it, restarted the service, triggered the condition, and watched.
Nothing.
So I concluded the fix was wrong, reverted it, and went looking for a different cause. I spent most of a day on the different cause. There wasn't one.
The suppression
The notifier had a deduplication window:
DEDUP_WINDOW = timedelta(minutes=5)
def should_send(key: str, now: datetime) -> bool:
last = store.get(key)
if last and now - last < DEDUP_WINDOW:
return False # same alert, too soon
store.set(key, now)
return True
Entirely reasonable. It exists so a flapping condition doesn't send forty emails.
But the dedup key survived the restart — it was in shared storage, deliberately, so a restart couldn't be used to bypass suppression. Which means: my pre-fix test run had already registered the key. Then I deployed, restarted, and re-triggered within the same five minutes.
The fix ran. It computed the right decision. And then the dedup layer, correctly, declined to send a duplicate.
Both layers behaved exactly as designed, and the composition of the two produced a result identical to the bug I was trying to fix.
Why I believed the wrong thing
The observable I was checking — "did a notification arrive" — is downstream of the suppression. It cannot distinguish these three states:
- the fix didn't work
- the fix worked and the send was suppressed
- the fix worked and the send failed for an unrelated reason
I read one silent outcome as one specific cause, because that's the cause I was already thinking about. Reverting was the worst possible move: it removed the correct change and left the key in place, so my next test after the revert was also inside a window, which confirmed my wrong conclusion a second time.
Two consistent negative results, both artifacts of my own test cadence.
What to check instead
Log the suppression, at the point of suppression. If the only trace of a dedup hit is the absence of an email, the layer is invisible during exactly the situations where it matters most.
def should_send(key: str, now: datetime) -> bool:
last = store.get(key)
if last and now - last < DEDUP_WINDOW:
log.info("suppressed", key=key, age_s=(now - last).total_seconds(),
window_s=DEDUP_WINDOW.total_seconds())
return False
store.set(key, now)
return True
One line. It turns my whole wasted day into a log entry that says suppressed key=... age_s=42 window_s=300.
Assert on the decision, not the delivery. The unit under test is "did the notifier decide to send", which is a function you can call. Whether an email arrived is a different question involving four more systems. I had been testing the wrong end of the pipeline because it was the end I could see.
Clear the key, or use a fresh one, when verifying a deploy. Either drop the dedup entry as part of the verification procedure, or trigger with a key that's never been used. Not by shortening the window in production — that changes the behaviour of the thing you're testing.
The general shape
Every idempotency and rate-limiting layer converts a real event into no event. That's the feature. The cost is that "nothing happened" stops being evidence of anything the moment one of those layers sits between you and your observable.
Anywhere you have dedup, debounce, rate limits, at-most-once delivery, or cache-on-negative, post-deploy verification has to either bypass the layer or read a signal from before it. Otherwise the layer will occasionally hand you a confident false negative, and a false negative that arrives twice in a row is extremely convincing.
The tell I now watch for: I got the same negative result twice, quickly. Fast repetition is the condition every suppression layer is built to detect. If two attempts a few minutes apart both showed nothing, the second one is not a confirmation — it's the most likely one to have been swallowed.
Reverting a change because you couldn't see its effect is the failure mode I actually want to name here. Not seeing an effect and having no effect are different findings, and only one of them justifies a revert.
Top comments (0)