How an Unpropagated gRPC Deadline Turned a Traffic Spike Into a Retry Storm That Exhausted Our Feature Store

14:32 UTC. PagerDuty: "p99 latency on /recommendations: 9.4s (threshold 1.5s)." Two minutes earlier it had been 240ms. Nobody had deployed anything since the previous afternoon.

the setup

reco-svc renders the "recommended for you" module on the homepage. For every request it makes one blocking call over gRPC to feature-svc, an internal service that joins a user's recent activity against a precomputed embedding table and returns a feature vector. feature-svc is a plain synchronous gRPC server: grpc.server(futures.ThreadPoolExecutor(max_workers=32)), 32 worker threads, one request per thread for the duration of the handler.

Three weeks earlier, feature-svc had picked up a new input to that vector: a "session affinity score" that needed an extra join against a rolling 30-minute activity window. It made recommendations measurably better in the offline eval, and it moved the handler's typical latency from p50 120ms / p99 280ms to p50 210ms / p99 340ms. Still comfortably under reco-svc's 300ms client-side deadline on a normal day, so nobody flagged it as a capacity change. It was a quality improvement that happened to spend most of the margin between "usually fine" and "right at the edge."

the scramble

An email campaign had gone out at 14:30 UTC. Click-through drove homepage traffic to roughly 4.2x baseline for about forty minutes, entirely expected and sized for in advance. First theory: reco-svc's own Postgres pool was the bottleneck, since it also reads user history for the fallback path. SELECT count(*) FROM pg_stat_activity WHERE state = 'active' showed nothing unusual, connections nowhere near the pool limit.

Second theory: feature-svc's Redis layer, which caches the embedding lookups, was thrashing under the extra load. Cache hit rate was steady at 98.1%, identical to the daily average. Redis wasn't struggling either.

Fifteen minutes in, with the two obvious suspects cleared, someone pulled up feature-svc's own dashboard instead of guessing from reco-svc's side of the call.

the hunt

feature-svc exports a gauge for active worker threads. It had been pinned at 32 out of 32 since roughly 14:34, four minutes after the campaign send, and hadn't moved since.

14:20  grpc_server_workers_active 6
14:25  grpc_server_workers_active 9
14:30  grpc_server_workers_active 14
14:34  grpc_server_workers_active 32
14:36  grpc_server_workers_active 32
14:40  grpc_server_workers_active 32
14:45  grpc_server_workers_active 32

Fully saturated and flat is a different shape than "busy." Busy under load usually still shows some churn as requests finish and new ones take their place. Flat at the ceiling for ten straight minutes meant requests were entering the pool and not leaving it. A py-spy dump against a feature-svc pod confirmed it: 32 threads, all inside compute_features, several of them showing wall-clock time in the handler well past a full second.

def compute_features(self, request, context):
    activity = fetch_recent_activity(request.user_id)          # ~40ms
    embeddings = fetch_embeddings(request.user_id)              # redis, ~5ms
    affinity = compute_session_affinity(activity, embeddings)   # pandas merge, 150-900ms
    return build_feature_vector(embeddings, affinity)

Nothing in that handler ever looked at context again after receiving it. On reco-svc's side, the client's 300ms deadline was tripping constantly under the spike, since the new feature had already pushed p99 latency close to the ceiling before any extra load showed up. Every DEADLINE_EXCEEDED triggered a client-side retry, per the channel's default service config: three attempts, 50ms initial backoff, no jitter.

Here's where the two problems compounded. reco-svc gave up on a slow call at 300ms and fired a retry almost immediately. feature-svc had no idea the original caller was gone. It kept running compute_session_affinity to completion anyway, because nothing in the handler ever checked context.is_active(), and the pandas merge underneath it doesn't know how to cancel itself. That thread stayed occupied until the abandoned work finished, sometimes 900ms later, while the retry landed on the pool as a brand-new request competing for one of the already-shrinking set of free workers. Demand went up, effective capacity went down, and neither side of that could see the other happening.

the find

Root cause: a deadline set on the client had no representation on the server at all. context carries the deadline and cancellation state across the wire, but compute_features never consulted it, so work kept running long after the only caller waiting on it had already stopped waiting and asked again. Combined with a retry policy that added load back onto the server within 50ms of the failure it was reacting to, the system had no mechanism to shed the requests nobody wanted anymore, and every retry made the queue feeding the thread pool longer instead of shorter.

The session affinity feature didn't cause the incident by itself. It removed the margin that had been quietly absorbing the fact that deadline propagation was never implemented in the first place. The traffic spike was just the first time that margin ran out.

the fix

First, the handler checks whether the caller is still there before doing the expensive part of the work, and again at the one natural break point in the middle of it.

def compute_features(self, request, context):
    if not context.is_active():
        context.abort(grpc.StatusCode.CANCELLED, "caller already gone")

    activity = fetch_recent_activity(request.user_id)
    embeddings = fetch_embeddings(request.user_id)

    if not context.is_active():
        context.abort(grpc.StatusCode.CANCELLED, "caller already gone")

    affinity = compute_session_affinity(activity, embeddings)
    return build_feature_vector(embeddings, affinity)

This alone frees threads faster once a caller has already given up, but it doesn't stop a saturated pool from accepting more work than it can finish. Second change: reject new requests outright once the pool is near capacity, instead of letting them queue behind work that may already be abandoned.

_active = threading.Semaphore(28)  # leave headroom below max_workers=32

def compute_features(self, request, context):
    if not _active.acquire(blocking=False):
        context.abort(grpc.StatusCode.RESOURCE_EXHAUSTED, "at capacity")
    try:
        return _compute_features_inner(request, context)
    finally:
        _active.release()

Third, reco-svc's retry policy stopped amplifying load during exactly the window when the server was struggling most.

{
  "methodConfig": [{
    "name": [{ "service": "feature.FeatureService" }],
    "retryPolicy": {
      "maxAttempts": 2,
      "initialBackoff": "0.1s",
      "maxBackoff": "1s",
      "backoffMultiplier": 2.0,
      "retryableStatusCodes": ["UNAVAILABLE", "DEADLINE_EXCEEDED"]
    }
  }]
}

Two attempts instead of three, a slower and growing backoff instead of a flat 50ms, and a RESOURCE_EXHAUSTED response now fails fast on the client without triggering another retry at all, since it isn't in the retryable list. A caller that gets told "at capacity" gives up and falls back immediately, instead of adding to the exact queue that just rejected it.

the aftermath

No request failed outright. reco-svc's own timeout falls back to a static trending list when feature-svc doesn't answer in time, so the visible damage was 3,100 homepage loads with degraded, non-personalized recommendations rather than an outage. The gauge for active workers is now on the same dashboard as request rate, specifically so "flat at the ceiling" stands out against "busy and churning" at a glance instead of needing a py-spy dump to notice the difference.

The semaphore's headroom of four threads below max_workers is deliberate: it gives the pool room to drain abandoned work without ever fully saturating, so the gauge has somewhere to fall before it hits the ceiling again.