DEV Community

Cogumellum
Cogumellum

Posted on AI-assisted

Our System Crashed at 14:22: It Wasn't the Database

Our System Crashed at 14:22: It Wasn't the Database

TL;DR: During peak concurrent load, our 5-minute cache unexpectedly evicted keys early due to lock contention. The solution was migrating to asynchronous stale-while-revalidate with an in-memory semaphore. The diff took 18 lines and cut our p99 latency from 1.8s down to 240ms.

What Broke in Production

Last Tuesday, our primary streaming endpoint started throwing sporadic timeouts.
Measured impact:

  • p99 Latency: jumped from 280ms to 3,400ms.
  • 504 Error Rate: reached 4.2% across an 18-minute window.
  • Connection Pool: 100% saturated.

What We Thought Happened (The Wrong Hypothesis)

Our initial instinct was to blame upstream LLM provider throttling. It looked like classic HTTP 429 backpressure. We restarted Celery workers, but within 90 seconds the pool was choking again.

The Actual Root Cause

The culprit was an internal thundering herd problem. When 300 concurrent requests hit an expired cache key at second 300, every single worker triggered the identical upstream recomputation query at the same instant.

[Request A] ──┐
[Request B] ──┼─► [Expired Cache Key] ──► 300 simultaneous upstream calls
[Request C] ──┘
Enter fullscreen mode Exit fullscreen mode

The Code Fix

Instead of recomputing synchronously inside the request thread, we implemented non-blocking lock acquisition that serves stale data while a single detached coroutine refreshes the cache in the background:

import asyncio

async def get_with_revalidation(cache, lock, key: str, factory_coro):
    data, expired = await cache.get_stale(key)
    if expired and not await lock.is_locked(key):
        asyncio.create_task(revalidate_background(cache, lock, key, factory_coro))
    return data or await factory_coro()

async def revalidate_background(cache, lock, key: str, factory_coro):
    async with lock.acquire(key):
        fresh = await factory_coro()
        await cache.set(key, fresh, ttl=300)
Enter fullscreen mode Exit fullscreen mode

When NOT to Use This

If your system handles strict financial balances or ledger transactions where 2-second stale reads cause double spends, do not use stale-while-revalidate. In our case, serving model metadata and prompt routing rules, the trade-off is safe and highly recommended.

Reproduction & Benchmarks

We documented the full Locust load-test harness and synthetic workload in our open engineering runbook:

  • Test methodology: GitHub/BeefAPI Gateway
  • Production implementation: gateway de alta resiliência e medição de tokens para LLMs.

Top comments (8)

Collapse
 
_firelinks profile image
Mike Dabydeen •

The diagnosis is the hard part and you got it: the herd was the cause and the cache was only where it surfaced. Four things about the code as posted, roughly in order of what they would cost you.

The check and the acquire are not atomic. not await lock.is_locked(key) and async with lock.acquire(key) are separated by a task spawn, so under the same 300 concurrent requests a lot of them can see an unlocked key and each schedule a revalidation. Those then serialise on the lock rather than firing together, which changes the shape of the load and not the volume, since upstream still gets called once per task. The line that fixes it goes inside the lock: after acquiring, read the key again and return without calling the factory if somebody already refreshed it. Single flight is the second check, not the lock.

Cold keys still take the old path. return data or await factory_coro() means that when there is no stale value at all, every concurrent request computes inline, which is the original incident. That state is not rare: every deploy that clears the cache, every eviction under memory pressure, and the first traffic to any new key. Stale while revalidate protects you from expiry, not from absence. Separately, data or treats an empty dict or a zero as a miss, so a legitimately falsy cached value recomputes on every request forever.

An in-memory semaphore is per process. You restarted Celery workers, so there is more than one process and probably more than one pod, and a lock local to a process divides the herd by the worker count rather than reducing it to one. The single detached coroutine is one per worker. That may well be fine at your scale, but it is worth writing down, because the number of upstream calls under the fix is now a capacity input that moves every time you scale out.

The last one is small and bites at the worst moment. asyncio.create_task with no reference kept can be collected mid flight. The Python docs are explicit that the loop holds only weak references and that a task not referenced elsewhere "may get garbage collected at any time, even before it's done". The failure mode is a revalidation that silently never finishes, so the key stays stale past its TTL and nothing logs anything. Keep the task in a set and discard it in a done callback, or use a TaskGroup.

One question on the numbers. Is the 240ms p99 measured on a warm cache, and do you have the equivalent for the first minute after a deploy? That second number is the one your fix does not currently move.

Collapse
 
cogumellum profile image
Cogumellum • AI-assisted

You're right on all four, and the p99 question cuts straight to the part of the post I under-sold.

1. Non-atomic check/acquire. Correct, and it's the bug I'd flag first if I were reviewing my own diff. not await lock.is_locked(key) and async with lock.acquire(key) are separated by a task spawn, so under the 300-request burst a large fraction observe an unlocked key and each schedules a revalidation. They then serialise on the lock, which reshapes the load without reducing it — upstream still sees one call per task. The fix is the second check inside the lock:

async with lock.acquire(key):
    fresh = await cache.get(key)
    if fresh is not None and not is_stale(fresh):
        return fresh.value
    return await factory_coro()
Enter fullscreen mode Exit fullscreen mode

Single-flight is the check inside the lock. The lock only makes the check safe.

2. Cold keys and falsy values. Agreed on both, and they're the same root cause: conflating absence with expiry. return data or await factory_coro() fires the factory inline whenever there's no stale value at all — which is every deploy that clears the cache, every eviction under memory pressure, and the first traffic to any new key. That's the original incident, just triggered by a different event. Stale-while-revalidate protects against expiry, not absence; absence needs its own path (block on the lock, or serve a short-TTL placeholder). Separately, data or ... treats {} and 0 as misses, so a legitimately falsy cached value recomputes forever. is None is the check I should have written.

3. Process-local semaphore. Also correct, and I should have written the number down. We ran N Celery workers across M pods; a process-local lock divides the herd by N×M rather than collapsing it to one. The fix's upstream call count is a capacity input that moves every time we scale out. A Redis lock or a distributed single-flight would pin it at one, at the cost of a round trip on the hot path and a new failure mode when Redis is the thing that's degraded. At our scale the per-process version was the right trade, but it was an implicit one, and implicit trades are how you get a second incident.

4. create_task and GC. This one I'd genuinely missed the sharp edge of. The loop holds only weak references, so a task with no strong reference can be collected mid-flight — a revalidation that silently never completes, the key stays stale past TTL, and nothing logs. Keeping the task in a module-level set with a done_callback that discards it, or a TaskGroup where the structure allows, is the fix. It's the kind of bug that only shows up under load, which is exactly when you can't afford it.

5. The p99. Honest answer: 240ms was warm cache. The number I should have led with is the first minute after a deploy — cold cache, empty keys, the path your point 2 describes. That was ~1.8s p99, and it's the number the fix as posted does not move, because the cold path still computes inline. The stale-while-revalidate change helps expiry; the cold-key path needs the lock-and-block treatment before it helps absence. That's the follow-up PR, and your comment is why it's already written.

Thanks for the review. The four points are the difference between a fix that survives the next deploy and one that survives the next deploy and the one after.

Collapse
 
_firelinks profile image
Mike Dabydeen •

The follow up PR is where I would slow down, because lock and block on a cold key has the signature of the original incident.

Your 14:22 symptom was a saturated pool. If 300 requests land on a cold key and 299 of them wait on the lock, they hold 299 request slots for the length of the rebuild, and at roughly 1.8 seconds that is the pool again, arrived at politely. Blocking is only safe with a deadline on the wait that is shorter than the caller's timeout, plus a decision about what you return when the deadline passes.

That inequality is the part living outside your service. If the client gives up at one second and the cold rebuild takes nearly two, the caller times out and retries into a key that is still being built, so the queue refills as fast as it drains and no rebuild gets to publish before the next wave lands. Worth measuring the client timeout against your cold number before the PR ships, because the fix is safe only if one of those is larger than the other, and neither of them is in the diff.

The deploy case might not need the cold path at all. A deploy clears the cache as a side effect rather than as a requirement. If the key carries the serialization shape instead of the build, a release that does not change the value format inherits the warm cache, and the fleet wide cold start stops being an event you have to survive. What is left for the cold path is evictions and genuinely new keys, and those trickle in rather than arriving from every pod at once.

That is also where your point three and your point five meet. On a deploy every pod is cold at the same moment and each one holds its own process local lock, so upstream sees N times M rebuilds per key at exactly the moment nothing is warm anywhere. Is the flush deliberate, or does the key just include the build?

Thread Thread
 
cogumellum profile image
Cogumellum • AI-assisted

The deadline point is the one I'd concede hardest, because it's not in the diff and it decides whether the cold path is safe at all. If the client gives up at 1s and the rebuild is ~1.8s, every waiter times out and retries into a key still being built — the queue refills as fast as it drains, which is the 14:22 shape with extra steps. So the wait needs a deadline strictly shorter than the caller's timeout, plus a defined fallback when it passes (error, or an empty-but-valid response).

On the deploy case: agreed, clearing the cache is a side effect, not a requirement. Keying on the serialization shape rather than a blanket flush is the better move. What I'd check before shipping: the actual client timeout, and whether the cold rebuild is really ~1.8s or that was the herd number.

Thread Thread
 
_firelinks profile image
Mike Dabydeen •

Two things about the deadline, because I think it is doing less work than it looks.

Whose timeout is it? A cache fill path usually sits behind more than one caller, and their budgets are not the same. A browser will wait thirty seconds where an internal caller gives you one. Set the wait below the shortest and you fail the callers who would happily have waited. Set it below the longest and the impatient ones still time out into a key that is still building. The deadline is a property of the request rather than of the cache, so the version that works is the caller passing its remaining budget in and the waiter honouring it. That hands you the fallback for free, since a request arriving with less budget than the rebuild needs can be answered immediately instead of queued.

The second one is that a deadline bounds how long each waiter waits. It does not bound how many arrive. A waiter that gives up at 1s still retries, so the queue refills exactly as you describe. What stops it is what the retry meets: if it finds the lock held and takes the fallback straight away instead of joining the wait, arrivals stop converting into waiters. The deadline caps the damage per request and the lock check caps the rate.

On your last question, I would not trust 1.8s either, and not only because it might be the herd number. A cold rebuild measured during a herd is competing with everything else the herd woke up. The only clean reading is one key on an idle system.

Thread Thread
 
cogumellum profile image
Cogumellum • AI-assisted

The budget-passing point lands, and it exposes something I glossed: I was treating the deadline as a cache property when it's a request property. A single constant can't be right for both a browser and an internal caller, and picking one just moves which cohort times out. Passing remaining budget in and answering immediately when it's below the rebuild cost is cleaner, and it makes the fallback a decision rather than an exception path.

On the second: agreed, the deadline bounds waiters, not arrivals. The lock-held-and-take-fallback-immediately branch is what actually stops the refill, and that's the piece my diff never had. Worth being explicit that the fallback must be cheap and non-blocking, otherwise it just relocates the queue.

Collapse
 
raknaos profile image
Raknaos •

The 18-line diff and the p99 drop are the satisfying part. The part I'd stare at is what an in-memory semaphore becomes the moment the box runs more than one worker process: each worker holds its own budget, so the upstream sees permits × workers concurrent rebuilds. Scaling out to absorb load quietly re-scales the herd, and no single process logs anything wrong.

Did you write the permit count down as a function of worker count, or pin the rebuild path to one process? Your line about upstream calls becoming a capacity input is the sentence most cache fixes earn and almost nobody publishes.

Some comments may only be visible to logged-in visitors. Sign in to view all comments.