The Child Span That Outlived Its Parent

Title Candidates (Ranked)

#	Title
1	The Child Span That Outlived Its Parent
2	The Rollback Made It Worse
3	800ms → 10s: The One-Line PR That Waited Three Weeks to Kill Production
4	Our Dashboards Were Green Because They Were Broken
5	Nine Times the Traffic, Zero New Users
6	The Day We DDoS'd Ourselves With Good Intentions
7	Ghost Requests: Debugging Work Nobody Was Waiting For
8	The Retry Storm Hiding Inside a "Fix the Flaky Test" Commit
9	Every Layer Retried. That Was the Bug.
10	How a Health Check Killed Every Healthy Pod
11	Timeout Inversion: The Cascading Failure Nobody Draws on the Whiteboard
12	We Scaled Up. It Got Worse. Here's Why.
13	The p99 That Couldn't Go Above 3 Seconds
14	A Trace With No Parent: Anatomy of a Two-Hour Outage
15	Your Retries Are a Denial-of-Service Attack Waiting for a Trigger
16	The Backfill, the Planner, and the 34% Error Rate
17	context.Background() Cost Us Two Hours of Uptime
18	Why Your Load Tests Will Never Catch This Bug
19	The Incident That Started Three Weeks Before the Incident
20	Cancellation Is a Feature. We Shipped It Late.

Selected: The Child Span That Outlived Its Parent

Subtitle: A one-line timeout change sat dormant for three weeks, then turned 900 requests per second into 8,100 and took production down with us watching a dashboard that physically could not show the problem.

Cover description: A Jaeger waterfall where the top-level parent span ends cleanly at 3.0 seconds while its child span keeps running, alone, out to 9.8 seconds.

---

The Child Span That Outlived Its Parent

The pager didn't wake me up. The rollback did.

At 10:07 we reverted the only deploy that had touched production that morning, watched the pods cycle, and waited for the graphs to bend back down.

The error rate went from 2.1% to 11%.

Somebody in the incident channel typed: "that's… the opposite."

That was the moment the outage stopped being an outage and became a puzzle. We had done the one thing every runbook tells you to do first, and the system got sicker. For the next forty minutes we chased four different theories, scaled up a service that was already drowning, and posted a status page update we'd have to correct twice.

The real cause had been merged three weeks earlier. One line. Green CI. Two approvals. Title: chore: bump entity-service client timeout to reduce flaky CI.

This is the whole story: the architecture, the timeline to the minute, every hypothesis we got wrong, the code before and after, and the fifteen-plus things it taught a team that thought it already knew how to do retries.

---

Background: What We Were Running

[Project Name] is a document intelligence API. Enterprise customers push contracts, invoices, and statements at us; we return structured fields — parties, dates, amounts, obligations — with confidence scores and character offsets back into the source document.

It is a boring product in the best way. Customers wire it into their own workflows and then forget about it. Which means when we break, we break their pipelines, and their pipelines are usually attached to money.

Scale

Dimension	Value
Enterprise tenants	~4,000
API calls / day	~1.2M
Peak sustained	~900 rps
p50 / p99 latency (steady state)	96 ms / 480 ms
Availability SLO	99.9% monthly (43m 12s error budget)
On-call rotation	6 engineers, follow-the-sun

The stack

• Language: Go
• Runtime: Kubernetes on [Cloud Provider], single primary region + warm standby
• Datastore: PostgreSQL 15 (1 primary, 2 read replicas)
• Cache / rate limiting: Redis 7 (cluster mode, 6 shards)
• Async pipeline: Kafka (12 partitions on the ingest topic)
• Metrics: Prometheus + Grafana
• Tracing: OpenTelemetry SDK → OTel Collector → Jaeger
• Logs: structured JSON → [Cloud Provider] log service
• IaC: Terraform
• CI/CD: GitHub Actions → Argo Rollouts (canary)

The request path

Four services matter for this story.

• edge-gateway — public HTTPS, auth, per-tenant rate limiting, request budget enforcement. 18 pods.
• orchestrator — the brain. Splits a document into work units, calls downstream services, assembles the response. 24 pods.
• entity-service — resolves extracted text spans to canonical entities. Postgres-backed, heavily indexed. 16 pods.
• enrichment — async, Kafka-driven, not on the synchronous path.

The synchronous path is: client → edge-gateway → orchestrator → entity-service → Postgres.

Three hops. That is the entire blast radius of this incident. Everything else — Kafka, Redis, the enrichment workers, the standby region — was a red herring, and we spent real minutes on all of them.

Why it mattered: roughly 60% of our tenants call the synchronous endpoint inline in a user-facing flow. When we add a second of latency, somebody's loan officer is staring at a spinner.

---

Incident Timeline

All times are local. The incident lasted 2h 33m from first symptom to closed. We were above 10% error rate for 47 minutes.

Time	What happened
03:00	A scheduled backfill job starts, adding a locale column to entities and populating it for ~40% of rows. Nobody is awake. Nobody needs to be. It's a backfill.
09:38	Backfill completes. The table is bloated, autovacuum is behind, and the statistics for entities are now describing a table that no longer exists.
09:41	A plan cache invalidation on entity-service causes Postgres to re-plan the hot lookup. The planner, working from stale stats, drops the index scan and picks a bitmap heap scan with a recheck. entity-service p99 climbs from 120 ms to 640 ms. First symptom.
09:44	Grafana warning: gateway_request_duration_seconds p95 above threshold. Warning-level. Nobody pages.
09:47	orchestrator error rate: 0.4% → 2.1%. Still below page threshold.
09:52	Page. edge-gateway 5xx rate crosses 1% for 5 minutes.
09:55	Incident channel opened. IC assigned. Severity set to SEV-2.
09:58	First hypothesis: the 09:20 deploy. It was a copy change to an error message. It is the only thing that changed. It must be the thing that changed.
10:03	Rollback initiated via Argo.
10:07	Rollback completes. Error rate 2.1% → 11%. Severity raised to SEV-1.
10:09	7 orchestrator pods OOMKilled. Memory per pod had gone from 380 MB to 3.8 GB against a 4 Gi limit.
10:12	We scale orchestrator 24 → 60 pods. It seems obvious. It is exactly wrong.
10:15	Error rate 34%.
10:19	Status page: "Elevated error rates."
10:24	Hypothesis: Kafka. Consumer lag is up. (It is up because of the incident, not causing it.)
10:28	Hypothesis: Redis. redis-cli --latency returns a p99 of 0.4 ms across every shard. Ruled out in three minutes.
10:33	Hypothesis: a noisy tenant or an attack. Top tenant is 3% of traffic. Traffic shape is flat. Ruled out.
10:36	Somebody execs into a pod and curls entity-service directly. 610 ms. Slow. Not down. "That's not enough to explain this."
10:41	The trace. Someone pulls a Jaeger waterfall for a failed request. The gateway span ends at 3.0 s. Its child span keeps going to 9.8 s.
10:44	Goroutine dump: 4,180 goroutines per pod parked in httpx.(*Client).Do. Every single one holding a connection slot.
10:47	git log -S "10 * time.Second" -- internal/httpx/
10:49	Root cause identified.
10:52	Mitigation 1: feature flag retries.entity.enabled=false. Takes effect in-process, no restart.
10:53	Effective amplification drops from 9× to 3×. entity-service inbound: 8,100 rps attempted → 2,700.
10:56	Mitigation 2: retries.gateway.enabled=false. Amplification 3× → 1×. entity-service p99 falls to 380 ms.
11:02	Error rate 34% → 4%.
11:04	Hotfix PR opened: explicit budget, context propagation.
11:11	CI green. Canary at 5%.
11:18	Canary healthy. Full rollout.
11:26	Rollout complete. Error rate 0.3%.
11:31	DBA runs ANALYZE entities. entity-service p99: 640 ms → 130 ms. The original trigger is gone.
11:38	Retries re-enabled — with jitter and a retry budget this time.
11:52	Error rate 0.02%. SEV-1 → SEV-3.
12:14	Incident closed.

Read that timeline again and notice something: the thing that broke first (ANALYZE) was fixed second to last, and fixing it wasn't what saved us. The trigger and the cause were different objects.

---

Symptoms

What the pager said

[FIRING:1] GatewayHighErrorRate (edge-gateway prod)
  expr:    sum(rate(gateway_requests_total{status=~"5.."}[5m]))
         / sum(rate(gateway_requests_total[5m])) > 0.01
  value:   0.0173
  for:     5m
  runbook: https://wiki.internal/runbooks/gateway-5xx

What the logs said

orchestrator, thousands of times per second:

{
  "level": "error",
  "ts": "2026-06-11T09:53:41.882Z",
  "service": "orchestrator",
  "trace_id": "4b1c9f2e8a7d6c5b4a39281706f5e4d3",
  "msg": "entity-service: exhausted 3 attempts",
  "err": "Post \"http://entity-service:8080/v1/resolve\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)",
  "doc_id": "doc_01HZX9K2QW",
  "elapsed_ms": 30412
}

elapsed_ms: 30412. Thirty seconds. On a path whose caller gave up after three.

Nobody read that field for fifty-six minutes. It was right there, in every log line, from 09:47 onward. It was the answer. It was drowning in 40,000 lines a minute of the same message.

edge-gateway, at the same moment:

{
  "level": "warn",
  "ts": "2026-06-11T09:53:41.883Z",
  "service": "edge-gateway",
  "trace_id": "4b1c9f2e8a7d6c5b4a39281706f5e4d3",
  "msg": "upstream deadline exceeded",
  "upstream": "orchestrator",
  "budget_ms": 3000,
  "elapsed_ms": 3001
}

Same trace ID. One says 3,001 ms. One says 30,412 ms. Both are true. That contradiction is the bug, sitting in plain text, timestamped one millisecond apart.

What the dashboards said

[Screenshot: Grafana "Gateway Golden Signals" — request rate flat, error rate climbing, p99 latency a perfectly flat line at exactly 3.0s]

Look at that p99 line. It is flat. It is suspiciously flat. It is flat at exactly 3.0 seconds because edge-gateway enforces a 3-second request budget and then records the duration of what it observed. The histogram literally could not represent a value above 3 seconds on that path.

⚠️ This is the part I want you to take away even if you skim the rest.

We had a latency dashboard that was structurally incapable of showing latency above the number that was hurting us. Every second of downstream pain past 3.0 s was rounded down into a bucket labeled "3.0 s" and rendered as a calm horizontal line.

A metric bounded by the failure mode is not a metric. It's a blindfold with axis labels.

[Screenshot: Grafana "Orchestrator Resources" — goroutine count climbing from 240 to 4,180 per pod on a near-vertical slope; memory tracking it exactly]

[Screenshot: Grafana "entity-service Inbound" — request rate stepping 950 → 2,800 → 8,100 rps with no corresponding change in gateway ingress]

That third one should have ended the incident at 09:50. Inbound traffic to an internal service went up 8.5× while public traffic stayed flat. There is only one family of explanations for that. But the panel lived on a dashboard nobody had opened in four months, three clicks away from the one we were staring at.

The numbers, mid-incident

Signal	Steady state	10:15 (peak)
Gateway accepted rps	900	640
entity-service inbound rps	950	8,100 attempted / 1,430 served
entity-service p99	120 ms	6,900 ms
orchestrator goroutines/pod	240	4,180
orchestrator memory/pod	380 MB	3.8 GB → OOMKilled
orchestrator CPU/pod	0.9 / 2 cores	1.98 / 2 cores
Postgres active connections	61 / 200	200 / 200
Gateway 5xx rate	0.04%	34%

What users said

Fourteen support tickets in twenty minutes. The most useful one, from a customer's platform lead:

"Your API is returning 504s but our own timing shows the request completing on your side afterwards — we're seeing duplicate extraction jobs land in our system 8 seconds after we gave up. Are you retrying against us?"

We weren't retrying against them. But she had, in one sentence, described the shape of the entire failure from the outside: work continuing after the requester was gone. It sat unread in the queue until 11:40.

---

Investigation

Here's how the debugging actually went. I'm including the wrong turns because the wrong turns are the interesting part — anyone can look smart in a retrospective.

Step 1: What changed?

The universal first question, and it is a good one. Roughly 70% of incidents are caused by a change, and change is the cheapest thing to check.

$ argocd app history orchestrator
ID  DATE                 REVISION
41  2026-06-11 09:20:14  a3f9c21  fix: clarify 422 error message copy
40  2026-06-09 14:02:51  8e11d4b  feat: add doc_type to response envelope
39  2026-06-06 11:47:03  1c9b7f0  chore: bump otel-go to v1.29.0

One deploy that morning, 32 minutes before first symptom. A copy change. We rolled it back anyway, because 32 minutes is close enough to be suspicious and rollback is supposed to be free.

Rollback is not free. More on that in a minute.

Step 2: Is the datastore healthy?

-- On the entity-service primary
SELECT pid, state, wait_event_type, wait_event,
       now() - query_start AS duration, left(query, 60)
FROM pg_stat_activity
WHERE state <> 'idle'
ORDER BY duration DESC
LIMIT 10;

200 of 200 connections active. Longest query: 1.4 s.

We read this as "Postgres is the victim, it's saturated because everything upstream is hammering it." Which was true. It was also incomplete — we never asked why a query that should take 8 ms was taking 400.

SELECT schemaname, relname, n_live_tup, n_dead_tup,
       last_autovacuum, last_autoanalyze
FROM pg_stat_user_tables
WHERE relname = 'entities';

Had we run that at 10:00 instead of 11:29, we'd have seen last_autoanalyze from the previous evening and n_dead_tup at 22 million. We'd have run ANALYZE, entity latency would have dropped, and the incident would have ended — without us ever finding the real bug. We got lucky by being slow.

Step 3: Kafka

$ kafka-consumer-groups.sh --bootstrap-server $BROKERS \
    --describe --group enrichment-workers

GROUP               TOPIC          PARTITION  CURRENT-OFFSET  LOG-END-OFFSET  LAG
enrichment-workers  doc.ingested   0          8829411         8841002         11591
enrichment-workers  doc.ingested   1          8830155         8841883         11728
...

Lag across all 12 partitions, growing. Alarming.

Then someone asked the right question: "is any of this on the synchronous path?"

No. Kafka feeds enrichment, which is asynchronous. Lag was growing because the whole cluster was starved for CPU. Symptom, not cause. Ruled out at 10:26.

The lesson there is cheap and worth repeating: during an incident, half the alarming graphs are downstream of the actual problem. Before you investigate a red graph, ask whether it is upstream of the user-visible symptom. If it isn't, it can wait.

Step 4: Redis

$ redis-cli -h redis-0 --latency-history -i 5
min: 0, max: 2, avg: 0.34 (5 samples)
min: 0, max: 1, avg: 0.31 (5 samples)

Healthy. Every shard. Three minutes, ruled out.

Step 5: Traffic shape

topk(5,
  sum by (tenant_id) (rate(gateway_requests_total[5m]))
)

Top tenant: 27 rps out of 900. Nothing anomalous. No attack, no runaway client, no thundering herd from a customer's own retry loop. Ruled out at 10:35.

Step 6: Talk to the service directly

$ kubectl exec -it orchestrator-7d9f4b8c6-x2mnq -- \
    curl -s -o /dev/null -w '%{time_total}\n' \
    -X POST http://entity-service:8080/v1/resolve \
    -H 'Content-Type: application/json' \
    -d '{"doc_id":"probe","spans":[]}'
0.610

610 ms. Slow — five times baseline. But we were serving a 3-second budget. A 610 ms dependency does not produce a 34% error rate. This is where we got genuinely stuck, because the arithmetic didn't work, and when the arithmetic doesn't work, one of your assumptions is fiction.

Our fiction: that each user request produced one call to entity-service.

Step 7: The trace

Enough of this. Pull a real failed request end to end.

$ curl -s "http://jaeger-query:16686/api/traces?service=edge-gateway&tags=%7B%22error%22%3A%22true%22%7D&limit=1" \
  | jq -r '.data[0].spans[] | "\(.operationName)\t\(.duration/1000)ms\t\(.startTime)"'

edge-gateway.HandleExtract      3001.4ms   1749631421882000
orchestrator.Extract            3000.1ms   1749631421884000
entity.Resolve                  9812.7ms   1749631421891000
entity.Resolve.attempt.0       10000.2ms   1749631421891000
entity.Resolve.attempt.1        9998.7ms   1749631431894000

Stop. Read the durations.

The parent — the thing representing the actual user, the actual HTTP connection, the actual person waiting — lasted 3,001 ms.

Its child lasted 9,812 ms.

And look at attempt.0: 10,000 ms. Exactly ten seconds. To the millisecond. Nothing in nature is exactly ten seconds. That is a configured value, and it is a value nobody on the call recognized.

[Screenshot: Jaeger waterfall — the top two bars ending flush at 3.0s, a third bar running past them to 9.8s, and two attempt bars below it, each a clean 10-second block]

A child span outliving its parent by 6.8 seconds is not a rendering bug. It means cancellation is not propagating. The gateway hung up. The orchestrator's handler returned. And somewhere underneath, a goroutine was still cheerfully waiting on a socket for a response that no living code path would ever read.

Step 8: Count the ghosts

$ kubectl exec orchestrator-7d9f4b8c6-x2mnq -- \
    curl -s 'localhost:6060/debug/pprof/goroutine?debug=1' | head -20

goroutine profile: total 4183
4102 @ 0x43e5c5 0x40b2f7 0x40aec5 0x7c1f42 0x7c1e08 0x7bfb31 ...
#   0x7c1f41    net/http.(*persistConn).roundTrip+0x201
#   0x7c1e07    net/http.(*Transport).roundTrip+0x7a7
#   0x7bfb30    net/http.(*Client).send+0x150
#   0x7c0442    net/http.(*Client).do+0x902
#   0x9a11c3    internal/httpx.(*Client).Do+0x43
#   0x9a3881    internal/entity.(*Client).Resolve+0x1e1

4,102 of 4,183 goroutines, in one function, waiting on the network. Each holding a connection slot out of a pool of 64. Each holding a request body, a response buffer, and a slice of extracted spans in memory. Multiply by 24 pods.

That's the 3.8 GB. That's the OOMKills. That's the whole thing.

Step 9: git log -S

-S searches history for commits that changed the number of occurrences of a string. It is the single most valuable git flag during an incident and almost nobody uses it.

$ git log -S "10 * time.Second" --oneline -- internal/httpx/
b7c3a91 chore: bump entity-service client timeout to reduce flaky CI

$ git show b7c3a91
commit b7c3a91d4e2f8a6b0c1d3e5f7a9b2c4d6e8f0a12
Date:   Wed May 21 16:42:09 2026 +0000

    chore: bump entity-service client timeout to reduce flaky CI

    Contract tests against the entity-service stub time out roughly 1 in 8
    runs on the shared CI runners. Bumping the default so CI stops paging us.

diff --git a/internal/httpx/defaults.go b/internal/httpx/defaults.go
@@ -12,7 +12,7 @@ import (
 )

-var DefaultTimeout = 800 * time.Millisecond
+var DefaultTimeout = 10 * time.Second

Three weeks earlier. One line. Two approvals. A chore: prefix, which in our repo meant the PR template didn't even ask "what's the blast radius."

10:49. Found it.

---

False Leads

Four of them cost us real time. All four were reasonable. That's what makes them worth writing down.

False lead 1: "It was the deploy" — cost: 9 minutes, made things worse

Why it was plausible: one deploy that morning, 32 minutes before symptoms. Correlation in time is the strongest signal most of us have.

Why it was wrong: the deploy changed a string in an error message. But git diff on the deployed artifact isn't git diff on the config surface — and it definitely isn't a diff of your dependencies' behaviour.

Why the rollback hurt: orchestrator keeps a per-pod in-process LRU cache of resolved entities, ~72% hit rate warm. Rolling back cycled every pod. Cold cache meant hit rate fell to near zero, which meant entity-service traffic tripled, on top of the 9× retry amplification, against a service already at 640 ms p99.

⚠️ Rollback is a state transition, not an undo button.

Rolling back restarts processes. Restarting processes destroys in-memory state. Destroying in-memory state moves load onto exactly the dependency that is already struggling — because that's why the cache exists. During a capacity-shaped incident, "just roll back" can be a load amplifier. Ask what's in memory before you cycle the fleet.

False lead 2: "Scale up" — cost: 11 minutes, made things much worse

Why it was plausible: pods OOMKilling, CPU at 99%, goroutines climbing. Textbook under-provisioning.

Why it was catastrophically wrong: every new orchestrator pod arrived with an empty cache and a fresh 64-connection pool pointed at entity-service. Going 24 → 60 pods didn't add capacity. It added 2,304 more concurrent connections aimed at the bottleneck, and 36 more cold caches.

entity-service inbound went from 2,800 rps to 8,100.

💡 The tell: if scaling a service up makes the downstream worse, the service isn't short on capacity. It's a load amplifier, and you've just turned up the gain.

False lead 3: "Kafka lag" — cost: 4 minutes

Covered above. Real signal, wrong direction of causality. Ask "is this upstream or downstream of the symptom?" before you open the consumer group dashboard.

False lead 4: "The database is the bottleneck" — cost: ~20 minutes of divided attention

Why it was plausible: 200/200 connections. It genuinely looked saturated. Someone spent twenty minutes drafting a plan to bump max_connections and add a PgBouncer tier.

Why it was wrong (and subtle): Postgres was saturated, but by 8,100 rps of requests, ~71% of which had no living caller. We would have been adding connection capacity so the database could more efficiently answer questions nobody was listening to.

The stats problem — the actual trigger — was real, and worth fixing. But fixing it alone would have hidden the bomb. The 10-second timeout would still be sitting there, waiting for the next time any dependency got slow. We'd have had this exact outage again, on a different day, with a different trigger, and no memory of this one.

Fixing the trigger without fixing the amplifier means you've scheduled the incident rather than resolved it.

---

Root Cause

Four things, each individually survivable. Stacked, they were an outage.

1. Timeout inversion

Every hop in a distributed system has a budget. The rule is not complicated:

child_total_budget  <  parent_per_attempt_budget

A downstream call must give up before its caller does. Otherwise the caller abandons the request and the callee keeps working on it — burning CPU, holding connections, writing to the database — for a result that will be discarded.

Our budgets, on the morning of the incident:

edge-gateway  request budget:   3,000 ms
orchestrator  → entity-service: 10,000 ms   ← INVERTED

For three weeks, every timeout on that path was a lie. It never mattered, because entity-service answered in 120 ms and the 10-second ceiling was never approached. The inversion was latent. It needed a trigger, and the trigger was a stale query plan.

2. context.Background() in the retry loop

Go gives you cancellation for free, if you thread it through. The retry wrapper didn't:

req, _ := http.NewRequestWithContext(context.Background(), ...)

That one call severs the request from every deadline, every cancellation, every trace context above it. The caller's ctx was in scope. It was a parameter of the enclosing function. It just wasn't used.

This is why the child span outlived its parent. The gateway timed out. The orchestrator handler returned an error. The HTTP response went out. And underneath, an orphan goroutine kept waiting, because nothing had told it to stop — and nothing could.

3. Retry amplification across layers

• edge-gateway: 3 attempts against orchestrator
• orchestrator: 3 attempts against entity-service

3 × 3 = 9.

Under normal conditions, ~0.04% of requests retry, so amplification is effectively 1.0×. Under failure conditions, 100% of requests retry, and amplification becomes exactly 9×.

That is the property that makes retry storms so vicious: your amplification factor is 1× exactly when you don't need it, and 9× exactly when you can least afford it. It is a load multiplier that activates on distress.

900 rps × 9 = 8,100 rps at a service that tops out around 1,450.

And the backoff had no jitter:

func backoff(attempt int) time.Duration {
    return time.Duration(1<<attempt) * 200 * time.Millisecond
}

200 ms, 400 ms, 800 ms. Deterministic. So every failed request across all 24 pods retried in synchronized waves. Not 8,100 rps smeared evenly — 8,100 rps arriving in pulses, with quiet gaps between. The quiet gaps let entity-service recover just enough to accept the next pulse, which killed it again. A self-sustaining oscillator built out of three lines of arithmetic.

4. The deep health check

The final turn of the screw:

func (h *Health) Ready(w http.ResponseWriter, r *http.Request) {
    if _, err := h.entity.Resolve(r.Context(), "healthcheck", nil); err != nil {
        http.Error(w, "not ready", http.StatusServiceUnavailable)
        return
    }
    w.WriteHeader(http.StatusOK)
}

/readyz called entity-service. Through the same client. Through the same exhausted connection pool.

So when the pool filled, readiness probes hung. Kubernetes marked pods NotReady. It pulled them out of the Service. Traffic concentrated onto the remaining pods. Their pools filled. They went NotReady.

We had built a machine that, on detecting stress, systematically removed healthy capacity until nothing was left.

Why nobody noticed for three weeks

This is the part I find genuinely instructive, because every single defense we had failed for a different reason:

1. The change was to a default. httpx.DefaultTimeout applied only where a service didn't specify a timeout. Two of three services specified one explicitly. Only orchestrator inherited the default. A reviewer looking at the one-line diff would have had to know which callers used httpx.New() with zero options — a fact not visible in the diff, the PR, or any test.

2. CI got greener. The change did exactly what it promised. Flake rate went to zero. The feedback signal pointed the wrong way. We rewarded it.

3. Load tests used a fast stub. Our k6 suite ran against a mock entity-service with a fixed 30 ms response. It could hit 2,000 rps all day. We had never once load-tested the timeout path, because our load tests were designed to measure throughput, and a healthy dependency was a precondition for measuring throughput. We tested the system we hoped for.

4. The dashboard was bounded by the bug. Gateway-observed latency clipped at 3.0 s. Everything past that rendered flat.

5. It needed a trigger it hadn't had yet. Three weeks of entity-service p99 under 150 ms. The bomb needed a dependency to get slow, and nothing had gotten slow yet.

The timeout change didn't cause the outage. It removed the safety mechanism that would have prevented it — and then we waited three weeks for something to test the safety mechanism.

An 800 ms timeout is not a limit on how long you're willing to wait. It's a load-shedding device. It's the thing that says: this dependency is unhealthy, fail fast, drop the work, protect the pool. Raising it to 10 seconds didn't make us more patient. It turned off load shedding.

---

Code Before

Three files. Every one of them passed review.

// internal/httpx/defaults.go
package httpx

import (
    "net/http"
    "time"
)

// DefaultTimeout is applied to any client created without an explicit timeout.
// Bumped from 800ms -> 10s to stop entity-service contract tests from flaking in CI.
var DefaultTimeout = 10 * time.Second

// New returns an HTTP client with sensible defaults.
func New(opts ...Option) *http.Client {
    c := &http.Client{
        Timeout:   DefaultTimeout,
        Transport: defaultTransport(),
    }
    for _, o := range opts {
        o(c)
    }
    return c
}

func defaultTransport() *http.Transport {
    return &http.Transport{
        MaxIdleConns:        256,
        MaxIdleConnsPerHost: 64,
        MaxConnsPerHost:     64, // hard cap: callers block here once exhausted
        IdleConnTimeout:     90 * time.Second,
    }
}

// internal/entity/client.go
package entity

import (
    "bytes"
    "context"
    "encoding/json"
    "fmt"
    "net/http"
    "time"

    "internal/httpx"
)

type Client struct {
    http       *http.Client
    baseURL    string
    maxRetries int
}

func NewClient(baseURL string) *Client {
    return &Client{
        http:       httpx.New(), // inherits DefaultTimeout — now 10s
        baseURL:    baseURL,
        maxRetries: 3,
    }
}

func (c *Client) Resolve(ctx context.Context, docID string, spans []Span) (*Result, error) {
    body, err := json.Marshal(resolveRequest{DocID: docID, Spans: spans})
    if err != nil {
        return nil, err
    }

    var lastErr error
    for attempt := 0; attempt < c.maxRetries; attempt++ {
        // The caller's ctx is right there in the signature. It is never used.
        // Cancellation, deadlines, and trace context all stop at this line.
        req, err := http.NewRequestWithContext(
            context.Background(),
            http.MethodPost,
            c.baseURL+"/v1/resolve",
            bytes.NewReader(body),
        )
        if err != nil {
            return nil, err
        }
        req.Header.Set("Content-Type", "application/json")

        resp, err := c.http.Do(req)
        if err != nil {
            lastErr = err
            time.Sleep(backoff(attempt)) // blocks even if the caller is long gone
            continue
        }

        if resp.StatusCode >= 500 {
            resp.Body.Close()
            lastErr = fmt.Errorf("entity-service: status %d", resp.StatusCode)
            time.Sleep(backoff(attempt)) // retries 500s: amplifies bugs, not blips
            continue
        }

        defer resp.Body.Close()
        var out Result
        if err := json.NewDecoder(resp.Body).Decode(&out); err != nil {
            return nil, err
        }
        return &out, nil
    }

    return nil, fmt.Errorf("entity-service: exhausted %d attempts: %w", c.maxRetries, lastErr)
}

// 200ms, 400ms, 800ms. Identical on every pod. No jitter.
func backoff(attempt int) time.Duration {
    return time.Duration(1<<attempt) * 200 * time.Millisecond
}

// internal/health/health.go
package health

import "net/http"

type Health struct {
    entity EntityResolver
}

// Ready reports whether this pod can serve traffic.
func (h *Health) Ready(w http.ResponseWriter, r *http.Request) {
    // Uses the same client and the same connection pool as production traffic.
    // When the pool is exhausted, this hangs, and Kubernetes evicts a pod
    // whose only problem is that its dependency is slow.
    if _, err := h.entity.Resolve(r.Context(), "healthcheck", nil); err != nil {
        http.Error(w, "not ready", http.StatusServiceUnavailable)
        return
    }
    w.WriteHeader(http.StatusOK)
}

Count the bugs: five in about ninety lines, and not one of them is a typo. Every one is a design decision that looked like an obvious best practice in isolation.

---

Code After

// internal/httpx/budget.go
package httpx

import "time"

// Budget is the timing contract for one hop.
//
// INVARIANT (enforced by TestTimeoutHierarchy):
//     child.Total + child.GuardBand < parent.PerAttempt
//
// Total is authoritative. Attempts are best-effort *within* it: we would
// rather make one attempt and return honestly than make three attempts
// and hand our caller a corpse.
type Budget struct {
    Name        string
    Total       time.Duration
    PerAttempt  time.Duration
    GuardBand   time.Duration // reserved for marshal/unmarshal + response handling
    MaxAttempts int
}

var (
    GatewayRequest = Budget{
        Name:        "gateway.request",
        Total:       3000 * time.Millisecond,
        PerAttempt:  2800 * time.Millisecond,
        GuardBand:   200 * time.Millisecond,
        MaxAttempts: 1, // retries live at exactly one layer, and it is not this one
    }

    EntityResolve = Budget{
        Name:        "entity.resolve",
        Total:       1800 * time.Millisecond,
        PerAttempt:  700 * time.Millisecond,
        GuardBand:   80 * time.Millisecond,
        MaxAttempts: 3,
    }
)

// internal/httpx/client.go
package httpx

import (
    "fmt"
    "net/http"
    "time"
)

// New requires an explicit Budget. There is no default timeout, because a
// default timeout is a decision made by whoever edited a file last, applied
// to callers they have never heard of.
func New(b Budget, opts ...Option) (*http.Client, error) {
    if b.Total <= 0 || b.PerAttempt <= 0 {
        return nil, fmt.Errorf("httpx: budget %q must set Total and PerAttempt", b.Name)
    }
    c := &http.Client{
        // Backstop only. The real deadline rides on the context of every request.
        Timeout:   b.Total,
        Transport: transport(b),
    }
    for _, o := range opts {
        o(c)
    }
    return c, nil
}

func transport(b Budget) *http.Transport {
    return &http.Transport{
        MaxIdleConns:          256,
        MaxIdleConnsPerHost:   64,
        MaxConnsPerHost:       64,
        IdleConnTimeout:       90 * time.Second,
        ResponseHeaderTimeout: b.PerAttempt, // belt and braces
        ExpectContinueTimeout: 1 * time.Second,
    }
}

// internal/httpx/retrybudget.go
package httpx

import (
    "math"
    "sync"
)

// RetryBudget is a token bucket, in the spirit of gRPC's retry throttling.
//
// The idea: a retry is a *loan* against your recent success rate, not a right.
// When everything is healthy, successes keep the bucket full and retries are
// free. When everything is failing, there are no successes, the bucket drains,
// and retries switch themselves off — automatically, exactly when a retry storm
// would otherwise begin.
//
// This is the single control that would have prevented our outage on its own.
type RetryBudget struct {
    mu     sync.Mutex
    tokens float64
    max    float64
    ratio  float64 // tokens returned per success
}

func NewRetryBudget(max, ratio float64) *RetryBudget {
    return &RetryBudget{tokens: max, max: max, ratio: ratio}
}

// Withdraw reports whether a retry is affordable right now.
func (b *RetryBudget) Withdraw() bool {
    b.mu.Lock()
    defer b.mu.Unlock()
    if b.tokens < 1 {
        return false
    }
    b.tokens--
    return true
}

// Deposit credits the bucket after a success.
func (b *RetryBudget) Deposit() {
    b.mu.Lock()
    defer b.mu.Unlock()
    b.tokens = math.Min(b.max, b.tokens+b.ratio)
}

// Tokens exposes the current balance for metrics.
func (b *RetryBudget) Tokens() float64 {
    b.mu.Lock()
    defer b.mu.Unlock()
    return b.tokens
}

// internal/entity/client.go
package entity

import (
    "bytes"
    "context"
    "encoding/json"
    "errors"
    "fmt"
    "math"
    "math/rand"
    "net"
    "net/http"
    "time"

    "internal/httpx"
)

const (
    minAttemptBudget = 120 * time.Millisecond
    baseBackoff      = 40 * time.Millisecond
    maxBackoff       = 400 * time.Millisecond
)

var ErrBreakerOpen = errors.New("entity: circuit breaker open")

type Client struct {
    http        *http.Client
    baseURL     string
    budget      httpx.Budget
    breaker     *httpx.Breaker
    retryBudget *httpx.RetryBudget
    metrics     *Metrics
    tracer      trace.Tracer
}

func NewClient(baseURL string, b httpx.Budget) (*Client, error) {
    hc, err := httpx.New(b)
    if err != nil {
        return nil, err
    }
    return &Client{
        http:    hc,
        baseURL: baseURL,
        budget:  b,
        breaker: httpx.NewBreaker(httpx.BreakerConfig{
            FailureRatio: 0.5,
            MinRequests:  20,
            OpenFor:      5 * time.Second,
            HalfOpenMax:  3,
        }),
        // 100 retry tokens, 0.2 back per success => sustained retry rate
        // can never exceed ~20% of the success rate.
        retryBudget: httpx.NewRetryBudget(100, 0.2),
        metrics:     newMetrics(),
        tracer:      otel.Tracer("entity"),
    }, nil
}

func (c *Client) Resolve(ctx context.Context, docID string, spans []Span) (*Result, error) {
    ctx, span := c.tracer.Start(ctx, "entity.Resolve")
    defer span.End()

    if !c.breaker.Allow() {
        c.metrics.Shed.WithLabelValues("breaker_open").Inc()
        return nil, ErrBreakerOpen
    }

    // Clamp our own ceiling on top of whatever the caller granted us.
    // WithTimeout takes the *earlier* of the two deadlines, so a caller
    // with 400ms left still wins.
    ctx, cancel := context.WithTimeout(ctx, c.budget.Total)
    defer cancel()

    body, err := json.Marshal(resolveRequest{DocID: docID, Spans: spans})
    if err != nil {
        return nil, err
    }

    var lastErr error
    for attempt := 0; attempt < c.budget.MaxAttempts; attempt++ {
        if attempt > 0 {
            if !c.retryBudget.Withdraw() {
                c.metrics.Shed.WithLabelValues("retry_budget").Inc()
                return nil, fmt.Errorf("entity: retry budget exhausted: %w", lastErr)
            }
            if err := sleepCtx(ctx, backoff(attempt)); err != nil {
                return nil, fmt.Errorf("entity: cancelled during backoff: %w", err)
            }
        }

        remaining := timeRemaining(ctx) - c.budget.GuardBand
        if remaining < minAttemptBudget {
            c.metrics.Shed.WithLabelValues("no_budget").Inc()
            return nil, fmt.Errorf("entity: out of budget after %d attempts: %w", attempt, lastErr)
        }

        attemptBudget := min(remaining, c.budget.PerAttempt)
        attemptCtx, cancelAttempt := context.WithTimeout(ctx, attemptBudget)
        res, err := c.doOnce(attemptCtx, body)
        cancelAttempt()

        switch {
        case err == nil:
            c.retryBudget.Deposit()
            c.breaker.RecordSuccess()
            return res, nil

        case ctx.Err() != nil:
            // Our caller gave up, or our total budget expired. Either way the
            // answer is worthless now. Stop. Do not retry a dead request.
            c.breaker.RecordFailure()
            c.metrics.Abandoned.Inc()
            return nil, fmt.Errorf("entity: abandoned after %d attempts: %w", attempt+1, ctx.Err())

        case !isRetryable(err):
            c.breaker.RecordFailure()
            return nil, err

        default:
            lastErr = err
            c.breaker.RecordFailure()
            c.metrics.Retries.WithLabelValues(classify(err)).Inc()
        }
    }

    return nil, fmt.Errorf("entity: failed after %d attempts: %w", c.budget.MaxAttempts, lastErr)
}

func (c *Client) doOnce(ctx context.Context, body []byte) (*Result, error) {
    req, err := http.NewRequestWithContext(
        ctx, // the whole fix, in one identifier
        http.MethodPost,
        c.baseURL+"/v1/resolve",
        bytes.NewReader(body),
    )
    if err != nil {
        return nil, err
    }
    req.Header.Set("Content-Type", "application/json")

    // Tell the server how long we intend to wait. It can shed work it will
    // never be able to deliver in time — the other half of the contract.
    if dl, ok := ctx.Deadline(); ok {
        req.Header.Set("X-Request-Budget-Ms",
            fmt.Sprintf("%d", time.Until(dl).Milliseconds()))
    }

    resp, err := c.http.Do(req)
    if err != nil {
        return nil, err
    }
    defer func() {
        io.Copy(io.Discard, io.LimitReader(resp.Body, 4<<10)) // enable conn reuse
        resp.Body.Close()
    }()

    if resp.StatusCode != http.StatusOK {
        return nil, &statusError{code: resp.StatusCode}
    }

    var out Result
    if err := json.NewDecoder(resp.Body).Decode(&out); err != nil {
        return nil, err
    }
    return &out, nil
}

// isRetryable encodes an opinion: retry congestion, never retry bugs.
func isRetryable(err error) bool {
    if errors.Is(err, context.Canceled) || errors.Is(err, context.DeadlineExceeded) {
        return false
    }
    var se *statusError
    if errors.As(err, &se) {
        // 500 is deliberately absent. A 500 usually means a deterministic
        // server-side bug; retrying it just runs the bug three times.
        return se.code == http.StatusTooManyRequests ||
            se.code == http.StatusServiceUnavailable ||
            se.code == http.StatusGatewayTimeout
    }
    var ne net.Error
    if errors.As(err, &ne) {
        return ne.Timeout()
    }
    return false
}

// backoff: exponential with full jitter. The random draw is the point —
// it is what stops 24 pods from retrying in lockstep.
func backoff(attempt int) time.Duration {
    exp := float64(baseBackoff) * math.Pow(2, float64(attempt-1))
    capped := math.Min(exp, float64(maxBackoff))
    return time.Duration(rand.Float64() * capped)
}

func timeRemaining(ctx context.Context) time.Duration {
    dl, ok := ctx.Deadline()
    if !ok {
        return math.MaxInt64
    }
    return time.Until(dl)
}

func sleepCtx(ctx context.Context, d time.Duration) error {
    t := time.NewTimer(d)
    defer t.Stop()
    select {
    case <-t.C:
        return nil
    case <-ctx.Done():
        return ctx.Err()
    }
}

// internal/health/health.go
package health

import (
    "net/http"
    "sync/atomic"
)

type Health struct {
    started atomic.Bool // set once, after config load and warmup
}

// Ready answers exactly one question: can THIS process serve a request?
//
// It does not ask about dependencies. If entity-service is down, every pod
// is equally unable to serve, and marking them all NotReady removes the
// entire fleet to fix a problem in a different fleet.
//
// Dependency health belongs in alerts, not in readiness probes.
func (h *Health) Ready(w http.ResponseWriter, r *http.Request) {
    if !h.started.Load() {
        http.Error(w, "starting", http.StatusServiceUnavailable)
        return
    }
    w.WriteHeader(http.StatusOK)
}

// Live answers: is this process wedged and in need of a restart?
// Deliberately the cheapest possible check. A liveness probe that can
// fail for external reasons is a fleet-wide kill switch with no owner.
func (h *Health) Live(w http.ResponseWriter, r *http.Request) {
    w.WriteHeader(http.StatusOK)
}

And the test that makes the whole thing hold:

// internal/httpx/hierarchy_test.go
package httpx_test

import (
    "testing"

    "internal/httpx"
)

// TestTimeoutHierarchy fails the build if any hop can outlive its caller.
//
// This test is the actual fix. The code changes above are how we passed it.
func TestTimeoutHierarchy(t *testing.T) {
    hops := []struct {
        name   string
        child  httpx.Budget
        parent httpx.Budget
    }{
        {"gateway -> orchestrator", httpx.OrchestratorDispatch, httpx.GatewayRequest},
        {"orchestrator -> entity", httpx.EntityResolve, httpx.OrchestratorDispatch},
    }

    for _, h := range hops {
        t.Run(h.name, func(t *testing.T) {
            if got, limit := h.child.Total+h.child.GuardBand, h.parent.PerAttempt; got >= limit {
                t.Fatalf(
                    "timeout inversion: %s total budget %s (+guard) >= %s per-attempt budget %s.\n"+
                        "A child that can outlive its parent produces abandoned work under load.\n"+
                        "Either lower %s.Total or raise %s.PerAttempt — but do the arithmetic for "+
                        "the whole chain before you touch either.",
                    h.child.Name, got, h.parent.Name, limit, h.child.Name, h.parent.Name,
                )
            }
            if h.child.PerAttempt > h.child.Total {
                t.Fatalf("%s: PerAttempt %s exceeds Total %s",
                    h.child.Name, h.child.PerAttempt, h.child.Total)
            }
        })
    }
}

Plus a lint rule, because tests catch what you thought to test and linters catch what you didn't:

# .golangci.yml
linters-settings:
  forbidigo:
    forbid:
      - p: 'context\.Background\(\)'
        pkg: '^internal/(entity|orchestrator|gateway|httpx)$'
        msg: >-
          Request-path code must propagate the caller's context.
          context.Background() severs cancellation and produces abandoned
          work under load. See postmortem INC-2026-0611.
      - p: 'context\.TODO\(\)'
        pkg: '^internal/(entity|orchestrator|gateway|httpx)$'
        msg: 'Same as context.Background(). Thread the ctx through.'

That linter message links to the postmortem. Six months from now, someone will hit it, click through, and read this story instead of rediscovering it.

---

Every Change, Explained

defaults.go → budget.go: deleting the default

Before: var DefaultTimeout = 10 * time.Second, a package-level variable any caller inherited silently.

After: New(b Budget) — a required argument that fails at construction.

The point isn't the number. It's where the decision lives. A package-level default means one engineer's edit silently changes behaviour for callers they've never read. Making the budget a required parameter moves the decision to the call site, where the person making it can see what they're deciding for. Compile-time errors are cheaper than incidents.

Total, PerAttempt, GuardBand, and MaxAttempts are separated because they answer four different questions, and collapsing them into one Timeout field was what let us get this wrong in the first place. Total is the promise to the caller. PerAttempt is the load-shedding threshold. GuardBand is honesty about the fact that deserializing a response isn't free.

Cost: zero at runtime.

context.Background() → ctx

The whole outage, in one identifier.

With the caller's context threaded through, http.Client.Do selects on ctx.Done(). When the gateway hangs up, the orchestrator's handler returns, defer cancel() fires, the context closes, and the in-flight request aborts immediately: connection released, goroutine exits, buffers freed, TCP connection torn down so entity-service stops writing a response into a void.

Post-fix, abandoned work went from 71% of entity-service CPU to under 1%. Not by making anything faster. By stopping work nobody wanted.

Cost: one select per request. Approximately free.

Per-attempt deadline derived from remaining budget

remaining := timeRemaining(ctx) - c.budget.GuardBand
attemptBudget := min(remaining, c.budget.PerAttempt)

The old code gave attempt 3 the same 10 seconds as attempt 1, even if the caller had 200 ms left. The new code asks the context how much time actually remains and refuses to start an attempt that cannot finish.

Refusing to start is a feature. An attempt that will be abandoned mid-flight costs the downstream a full request's work and returns nothing. Failing 120 ms early and telling the truth is strictly better than failing 700 ms late having burned a database connection.

Under load, no_budget sheds ~8% of would-be attempts. That 8% is pure waste elimination.

Retry budget

The most important control here, and the one I'd add first if you only add one thing.

Steady state: ~0.04% of requests fail, the bucket stays at 100 tokens, retries are unconstrained, latency is unaffected.

Incident conditions: 100% of requests fail. No successes, no deposits. The bucket drains in ~100 retries — under a second at our volume — and then every subsequent retry is rejected instantly.

Amplification collapses from 9× to 1× automatically, in under a second, without a human, without a deploy, without a feature flag.

The retryBudget.Tokens() gauge is now on the front page of the dashboard. It's the fastest leading indicator we have: it drops before error rates move, because it drops on the first wave of failures.

Cost: one mutex acquisition per retry. Retries are rare. Free.

Full jitter

return time.Duration(rand.Float64() * capped)

Not capped. rand.Float64() * capped. The retry lands somewhere in [0, capped).

This is the "Full Jitter" strategy from the AWS Architecture Blog's exponential backoff work, and the maths is unintuitive until you graph it: full jitter produces fewer total calls and lower completion time than "exponential + small random offset," because it spreads retries across the entire window rather than clustering them at its edge.

Deterministic backoff doesn't reduce load. It schedules load, into synchronized pulses that arrive exactly when the pulse before them has finished doing damage.

isRetryable: retry congestion, never retry bugs

The old code retried any 5xx. A 500 usually means a deterministic server-side bug — a nil dereference on a specific payload, a failed assertion. Retrying it runs the same bug three times and multiplies your error logs by three.

429, 503, 504 mean congestion or transient unavailability: try later, it might work. Those are worth retrying (with a budget, with jitter).

context.Canceled and context.DeadlineExceeded are explicitly non-retryable. Retrying a cancelled request is the definition of abandoned work.

Draining the response body

io.Copy(io.Discard, io.LimitReader(resp.Body, 4<<10))
resp.Body.Close()

A Go footgun that bites everyone once. If you Close() without draining, the connection cannot be reused — it gets closed and a new TCP handshake (plus TLS) happens for the next request. Under load that alone can double your effective connection count.

LimitReader caps how much we're willing to drain: on a 100 MB error response we'd rather burn the connection than the memory.

X-Request-Budget-Ms

Deadline propagation over the wire. The server now knows how long we'll wait and can shed work it can't deliver in time — instead of computing a perfect answer for four seconds and writing it to a closed socket.

This is the second half of the contract. Cancellation is the client's half; budget headers are the server's.

Circuit breaker

ctx cancellation stops individual abandoned requests. The breaker stops us from starting requests against a dependency we already know is failing.

50% failure ratio over a 20-request minimum → open for 5 seconds → half-open, 3 probes → close on success. During the incident, a breaker would have converted a slow cascade into a fast, clean, obvious failure. Fast failures are debuggable. Slow cascades are archaeology.

Shallow health checks

Readiness now answers exactly one question: can this process serve a request? Not "is my dependency happy" — because if the dependency is unhappy, every pod is equally unhappy, and evicting all of them fixes nothing while destroying everything.

Dependency health belongs in alerting, where a human decides. Not in a probe wired to a control loop with the authority to delete your fleet.

---

Performance Comparison

Metric	Before (steady)	During incident (10:15 peak)	After fix
Gateway p50	96 ms	2,410 ms	91 ms
Gateway p95	240 ms	3,000 ms (clipped)	218 ms
Gateway p99	480 ms	3,000 ms (clipped)	390 ms
entity-service p99	120 ms	6,900 ms	130 ms
Gateway accepted rps	900	640	940
entity-service inbound rps	950	8,100 attempted / 1,430 served	970
Retry amplification	1.0×	9.0×	1.0× steady / 1.2× max
Abandoned work (% of entity CPU)	0.3%	71%	0.4%
Error rate (5xx)	0.04%	34%	0.02%
orchestrator CPU / pod	0.9 / 2 cores	1.98 (saturated)	0.8
orchestrator memory / pod	380 MB	3.8 GB (OOMKilled ×7)	410 MB
Goroutines / pod	240	4,180	260
Postgres active conns	61 / 200	200 / 200	58
orchestrator pods	24	60 (thrashing)	24
Hotfix deployment time	—	—	7m 12s (canary → 100%)
Recovery time (flag → <1% err)	—	—	6m
MTTD	—	11m (09:41 → 09:52)	—
MTTI (to root cause)	—	57m (09:52 → 10:49)	—
MTTM (to mitigation)	—	13m (10:49 → 11:02)	—
Total	—	2h 33m	—

Three numbers do the storytelling.

Gateway p99: 480 ms → 390 ms after the fix. We got faster than before the incident, and we didn't optimize anything. We stopped doing work nobody wanted, and the capacity was just sitting there.

MTTI: 57 minutes. Nearly four times our MTTD. We knew something was wrong in eleven minutes and spent an hour arguing with the wrong graphs. That gap is where the improvement is — not in alerting.

Abandoned work: 71%. Seven out of ten CPU cycles in entity-service, at the worst moment of the worst outage of the year, computing answers for callers who had already hung up. That number didn't exist before this incident. We had no way to measure it. It's now an SLI.

---

Architecture Diagram

                          ┌─────────────────────────┐
                          │      API Clients        │
                          │   ~900 rps, 4k tenants  │
                          └────────────┬────────────┘
                                       │ HTTPS
                          ┌────────────▼────────────┐
                          │      edge-gateway       │
                          │   18 pods · auth · RL   │
                          │   Budget: 3,000 ms      │
                          │   Attempts: 3 ◀── (1)   │
                          └────────────┬────────────┘
                                       │
                          ┌────────────▼────────────┐
                          │      orchestrator       │
                          │   24 pods · in-proc LRU │
                          │   72% hit rate (warm)   │
                          └────────────┬────────────┘
                                       │
                       ┌───────────────▼───────────────┐
                       │  entity.Client (per pod)      │
                       │  Timeout: 10,000 ms  ◀── (2)  │
                       │  Attempts: 3         ◀── (3)  │
                       │  Pool cap: 64 conns  ◀── (4)  │
                       │  ctx: Background()   ◀── (5)  │
                       └───────────────┬───────────────┘
                                       │
                          ┌────────────▼────────────┐
                          │     entity-service      │
                          │   16 pods · ~1,450 rps  │
                          └────────────┬────────────┘
                                       │
                          ┌────────────▼────────────┐
                          │   PostgreSQL primary    │
                          │   max_connections: 200  │
                          │   stale stats  ◀── (6)  │
                          └─────────────────────────┘

  ═══════════════ THE CASCADE ═══════════════

  (6) Backfill bloats `entities`, stats go stale, planner drops
      the index scan.                    p99: 120ms → 640ms
                    │
                    ▼
  (2) 10s timeout means nothing sheds. Requests queue instead
      of failing fast.
                    │
                    ▼
  (5) Background() means gateway cancellation never arrives.
      Abandoned goroutines hold connections and memory forever.
                    │
                    ▼
  (4) Pool of 64 fills. New requests block on connection acquire.
      Goroutines: 240 → 4,180/pod.  Memory: 380MB → 3.8GB. OOM.
                    │
                    ▼
  (1)×(3) 3 × 3 = 9× amplification, in lockstep (no jitter).
                          900 rps → 8,100 rps at a 1,450 rps service
                    │
                    ▼
  /readyz uses the same exhausted pool → probes hang → K8s evicts
  healthy pods → load concentrates → remaining pools fill faster.
                    │
                    ▼
                 ██ 34% error rate ██

---

Sequence Diagram

What actually happened to one request. Watch when each participant stops caring.

sequenceDiagram
    autonumber
    participant C as API Client
    participant G as edge-gateway
    participant O as orchestrator
    participant E as entity-service
    participant P as PostgreSQL

    C->>G: POST /v1/extract
    Note over G: budget 3,000ms starts
    G->>O: POST /internal/extract

    O->>E: attempt 0 (ctx = Background, 10s)
    E->>P: SELECT ... FROM entities
    Note over P: seq scan on stale stats — 640ms

    Note over G,O: 3,000ms elapsed
    G--xC: 504 Gateway Timeout
    Note over C: client is GONE

    Note over O: handler returns, ctx cancelled...
    Note over O,E: ...but attempt 0 never saw that ctx

    E-->>O: 200 OK @ 10,000ms
    Note over O: nobody is listening.<br/>Result discarded.

    O->>E: attempt 1 (fresh 10s)
    Note over E,P: repeats the same work<br/>for the same dead caller
    E-->>O: 200 OK @ 20,000ms

    O->>E: attempt 2 (fresh 10s)
    E-->>O: 200 OK @ 30,412ms
    Note over O: "exhausted 3 attempts"<br/>logged 27s after the client left

    rect rgb(255, 235, 235)
    Note over O,P: 30 seconds of CPU, 3 DB queries,<br/>3 connection slots, 1 goroutine —<br/>all for a request that ended at 3.0s
    end

Now the fixed path:

sequenceDiagram
    autonumber
    participant C as API Client
    participant G as edge-gateway
    participant O as orchestrator
    participant E as entity-service
    participant P as PostgreSQL

    C->>G: POST /v1/extract
    Note over G: budget 3,000ms starts
    G->>O: POST /internal/extract (X-Request-Budget-Ms: 2800)

    O->>E: attempt 0 (ctx-bound, 700ms)
    E->>P: SELECT ... FROM entities
    Note over E: 700ms elapsed → context cancelled
    E--xP: query cancelled, conn released
    E--xO: deadline exceeded

    Note over O: retryBudget.Withdraw() → OK<br/>backoff: rand × 40ms

    O->>E: attempt 1 (700ms)
    E--xO: deadline exceeded

    Note over O: remaining budget < 120ms<br/>→ shed, do not start attempt 2

    O--xG: entity unavailable @ 1,780ms
    G--xC: 503 @ 1,790ms

    rect rgb(235, 255, 235)
    Note over C,P: Fails in 1.8s instead of 30s.<br/>Zero abandoned work.<br/>Breaker opens; the next 5s of<br/>requests fail in microseconds.
    end

Compare the shaded boxes. Same broken dependency. Same stale query plan. 30 seconds of waste versus 1.8 seconds of honesty.

---

Flow Diagram

The retry decision, after the fix:

flowchart TD
    A[Resolve called with caller ctx] --> B{Breaker allows?}
    B -- no --> Z1[Return ErrBreakerOpen<br/>~microseconds]
    B -- yes --> C[Clamp ctx to Budget.Total<br/>earlier deadline wins]
    C --> D{Attempt greater than 0?}

    D -- no --> G[Compute remaining budget]
    D -- yes --> E{Retry budget<br/>has a token?}
    E -- no --> Z2[Shed: retry budget exhausted<br/>THIS BREAKS THE STORM]
    E -- yes --> F[Sleep: full jitter,<br/>cancellable]
    F --> G

    G --> H{remaining minus guard<br/>greater than 120ms?}
    H -- no --> Z3[Shed: out of budget<br/>fail honestly, fail early]
    H -- yes --> I[attemptCtx = min of<br/>remaining and PerAttempt]
    I --> J[HTTP request bound to attemptCtx]

    J --> K{Outcome?}
    K -- success --> L[Deposit retry token<br/>Record breaker success]
    L --> Z4[Return result]

    K -- caller ctx done --> M[Record failure<br/>metrics.Abandoned++]
    M --> Z5[Return: abandoned<br/>NEVER retry a dead request]

    K -- non-retryable<br/>4xx / 500 / cancelled --> N[Record failure]
    N --> Z6[Return error<br/>retrying a bug runs the bug 3x]

    K -- retryable<br/>429 / 503 / 504 / net timeout --> O[Record failure<br/>metrics.Retries++]
    O --> P{attempt less than<br/>MaxAttempts?}
    P -- yes --> D
    P -- no --> Z7[Return: attempts exhausted]

    style Z2 fill:#ffe0e0,stroke:#c00,stroke-width:2px
    style Z5 fill:#ffe0e0,stroke:#c00,stroke-width:2px
    style Z4 fill:#e0ffe0,stroke:#0a0,stroke-width:2px

Every red box is an exit that the old code did not have. Every one of them is a place where the system now chooses to stop.

---

Lessons Learned

1. A timeout is a load-shedding device, not a patience setting.
When you raise a timeout, you are not deciding how long you're willing to wait. You are deciding how much abandoned work your system will accumulate before it protects itself. 800ms → 10s didn't make us patient. It disabled load shedding.

2. child.Total < parent.PerAttempt. Write it down. Test it.
Timeout hierarchy is the single most under-enforced invariant in distributed systems. It's arithmetic. It's testable in twenty lines. Almost nobody tests it.

3. Retry at exactly one layer.
Retries multiply. Gateway retries × service retries × client library retries × your customer's retries. Pick one layer — usually the one closest to the failure with the most context — and make every other layer pass errors through. Document which layer it is.

4. Retries without a budget are a DoS you shipped yourself.
Your amplification factor is 1× when healthy and N× when failing. It scales up precisely with distress. Retry budgets make the multiplier self-disarming.

5. Jitter is not a nice-to-have.
Deterministic backoff synchronizes your fleet. You don't reduce load; you schedule it into pulses. Full jitter — rand.Float64() * capped — beats "exponential plus a small random offset" on both total calls and completion time.

6. Never pass context.Background() on a request path.
Ban it with a linter. Put the postmortem link in the error message. This is not a style rule; it's the difference between cancellation working and not existing.

7. A metric bounded by the failure mode is a blindfold.
Our p99 could not exceed 3.0 s because that's where we gave up. The graph was flat, calm, and useless. Instrument the callee's view too, and measure at the layer where the work happens, not just where you stopped waiting for it.

8. A child span outliving its parent is a five-alarm signal.
It has exactly one meaning: cancellation isn't propagating. Alert on it. It's a cheap query and it finds this bug class in every service you own, today, before the incident.

9. Rollback restarts processes. Restarting processes destroys caches.
Rollback is a state transition. During a capacity incident, it can be a load amplifier — because the cache you just flushed existed to protect the thing that's dying.

10. If scaling up makes downstream worse, you're not short on capacity.
You're running a load amplifier and you just turned up the gain. Scale-up is the right move for CPU-bound saturation and the wrong move for amplification. Learn to tell them apart before 10:12 on a Thursday.

11. Readiness probes must be shallow.
A dependency check in /readyz means one sick dependency deletes your entire fleet. Every pod fails the check simultaneously, because every pod has the same dependency. It's a fleet-wide kill switch with no owner.

12. Retry congestion. Never retry bugs.
429/503/504 → transient, retry. 500 → probably deterministic, retrying runs the bug three times and triples your logs while you're trying to read them.

13. A chore: prefix is not a risk assessment.
The most dangerous PRs in your repo are one-line config changes with green CI, because they're the ones nobody thinks about. Our PR template now asks "what is the blast radius if this value is wrong?" for any diff touching a timeout, a pool size, a retry count, or a limit.

14. If your load tests use a fast stub, you're testing the system you hoped for.
We could push 2,000 rps against a 30 ms mock. We had never once exercised the timeout path. Load tests must include a slow dependency, not just a healthy one. Latency injection is a required fixture now.

15. The trigger and the cause are different objects.
Stale stats triggered it. Timeout inversion caused it. Fixing only the trigger schedules a repeat with a different trigger and no memory of this one. Always ask: what turned a bad minute into a bad hour?

16. Measure abandoned work.
% of CPU spent on requests whose caller is gone is an SLI almost nobody has, and it was 71% at our peak. You cannot manage what you can't see, and this one is invisible by construction.

17. During an incident, ask "upstream or downstream?" before you investigate a red graph.
Half the alarming panels are symptoms. Kafka lag cost us four minutes. Postgres saturation cost twenty. Both were real. Neither was causal.

18. git log -S is the most underused command in incident response.
It searches history for when a string appeared or vanished. git log -S "10 * time.Second" took nine seconds and ended the outage. Learn it before you need it.

19. Cheap probes beat clever theories.
kubectl exec + curl at 10:36 gave us the number that broke the arithmetic and forced us onto the right path. We should have run it at 09:56. When the numbers don't add up, stop theorising and go measure something directly.

20. elapsed_ms: 30412 was in every log line for 56 minutes.
The answer was in the logs the entire time, repeated forty thousand times a minute, which is exactly why nobody read it. Volume is a form of concealment. Alert on log field values, not just log rates.

---

Engineering Best Practices

What we changed structurally, beyond the diff.

Observability

Alert on causes, not just symptoms. Gateway 5xx tells you something is wrong; it doesn't tell you what. We added:

# Amplification: are we generating our own traffic?
sum(rate(entity_requests_total[1m]))
  / sum(rate(gateway_requests_total[1m]))
# > 1.5 for 2m => page. This alone would have paged at 09:47.

# Retry budget balance — the fastest leading indicator we have.
min(entity_retry_budget_tokens) < 20

# Abandoned work.
sum(rate(entity_abandoned_total[1m]))
  / sum(rate(entity_requests_total[1m])) > 0.05

# Orphan spans: children outliving parents.
sum(rate(otel_span_orphaned_total[5m])) > 0

That first one is the whole incident in one expression. It would have fired at 09:47 with a runbook titled "You are amplifying your own traffic."

Monitoring

RED at every hop, USE for every resource, and — new — flow ratios between hops. A service's health is not just its own metrics; it's the relationship between its ingress and its egress. Ratio alerts catch amplification. Absolute alerts never will.

Logging

Structured, sampled, and with elapsed_ms promoted to a first-class field that we alert on. count_over_time({service="orchestrator"} | json | elapsed_ms > 5000 [5m]) > 100 would have paged us at 09:48 with a message that named the problem.

Tracing

Head sampling at 1% steady state, 100% tail sampling on error, plus a new collector processor that emits otel_span_orphaned_total whenever a child's end timestamp exceeds its parent's. Cheap to compute, and it finds an entire class of bug.

Feature flags

The flags that saved us (retries.entity.enabled, retries.gateway.enabled) existed by accident, added for a load test eight months earlier. Now every retry policy, every timeout, and every circuit breaker is flag-controlled, evaluated in-process, and verified in a quarterly game day. A flag you haven't flipped in production is a hypothesis, not a control.

💡 Tip: the value of a kill switch is measured in seconds to effect. A flag that requires a deploy is not a kill switch; it's a deploy with extra ceremony. Ours takes effect in under 5 seconds, cluster-wide, no restart.

Retries, backoff, rate limiting, circuit breakers

• Retries: one layer, budgeted, jittered, classified.
• Backoff: full jitter, always.
• Rate limiting: per-tenant at the edge (we had this), plus per-dependency concurrency limits internally (we did not). A semaphore in front of entity-service sized to its actual capacity would have made this incident a partial degradation instead of a collapse.
• Circuit breakers on every cross-service call. Fast, obvious failure beats slow, mysterious cascade.

Caching

The in-process LRU was load-bearing and nobody had written that down. It is now: documented as a capacity dependency, with a cache-hit-rate panel next to the entity-service load panel, and a warm-up path that pre-populates the top 5,000 entities on boot so a rolling restart doesn't triple downstream load.

Deployment, rollback, canary, blue-green

Canary via Argo Rollouts: 5% → 25% → 50% → 100%, with automated analysis on error rate and p99 at each gate. It works well, and it caught nothing here — because the bomb was planted three weeks before the deploy that lit it. Canary analysis validates the change you're shipping. It cannot validate a latent interaction with a future condition.

That's not a criticism of canaries. It's a reminder of their scope. Progressive delivery is not a substitute for invariant testing.

We also added a rollback pre-flight check to the runbook: does this service hold load-bearing in-memory state? If yes, roll back at 10% at a time, not all at once.

---

Testing Strategy

The honest summary: our tests were excellent at validating the system we designed, and blind to the system we ran.

Layer	What we had	What we added
Unit	Table-driven, 84% coverage on entity	TestTimeoutHierarchy (fails the build on inversion); backoff distribution assertions (p95 of 1,000 draws must fall inside the window); isRetryable truth table; retry budget drain/refill under simulated failure
Integration	Testcontainers: Postgres + Redis, happy path	Latency injection. A toxiproxy-fronted entity-service with configurable delay. Assertion: with a 5 s downstream, Resolve returns in under 2 s and issues at most 3 requests
Regression	Per-bug tests	TestClientContextPropagation: cancel the parent ctx mid-flight, assert the downstream stub observes a closed connection within 50 ms. This test fails against every line of the old code
Load	k6, 2,000 rps vs a 30 ms mock	Same, plus a degraded-dependency profile: dependency p99 ramps 100 ms → 2 s over 5 minutes. Assertion: downstream rps must never exceed 1.2× ingress rps
Chaos	None	Monthly game day: inject 800 ms into entity-service in staging under production-shaped load. Pass criteria: error rate stays under 5% and amplification stays under 1.5×. Ran it two weeks after the fix. Passed at 1.08×
Contract	Pact, schema only	Schema plus timing. The consumer contract now declares "I will wait at most 700 ms," and the provider's CI fails if its own p99 SLO exceeds the tightest declared consumer budget
Performance	Nightly benchmark, p99 regression gate	Added BenchmarkResolveUnderDegradation, and a pgbench job that runs EXPLAIN on the hot query and fails if the plan changes
Security	SAST, dependency scan, DAST	Unchanged. Not this incident's story — but a retry storm is a self-inflicted DoS, and it belongs in threat modelling. It's on the model now
Smoke	12 checks post-deploy	Added an amplification check: hit the API 100 times, assert entity-service received under 120 requests
E2E	Playwright, 40 journeys, happy path	Added a degraded-mode journey: with the dependency slow, does the UI show a useful error within 3 s rather than spinning? (It did not. That's a separate fix.)

The one that matters most is the load test change. Assertion: downstream rps must never exceed 1.2× ingress rps. Six words. It catches every bug in this article. It would have caught this one three weeks early, in CI, in a pull request, at 4pm on a Wednesday, for free.

⚠️ The uncomfortable one: our contract tests were what motivated the timeout bump in the first place. A flaky test caused a production outage — not because the test was wrong, but because we fixed the symptom the test was reporting. The stub was slow on shared runners. The right fix was a faster stub or a retry in the test harness. The fix we chose was to make production wait longer.

When a test flakes, ask what it's telling you before you change the number that makes it stop.

---

What We'd Do Differently

Being honest about the parts that still sting.

We should have looked at the trace at 09:56, not 10:41. We had distributed tracing, fully deployed, with error sampling. It sat unused for forty-five minutes while we argued about Kafka. Traces are our best tool and they are not in our muscle memory, because we only touch them during incidents — which is exactly when nobody wants to learn a UI. The fix isn't a better tool. It's putting a trace link in every alert, so opening one requires no decision.

We should not have rolled back. We rolled back a copy change because it was the only thing that had changed. We should have spent ninety seconds reading the diff first. Ninety seconds would have told us a string literal cannot cause a 34% error rate, and would have saved us nine minutes and a fleet-wide cache flush.

We should not have scaled up. Scaling was pure reflex — pods dying, so add pods. Nobody asked what a new pod would do. Adding 36 cold caches and 2,304 connections to a saturated dependency turned a bad incident into our worst of the year. There is now a line in the runbook: before scaling, state out loud what the new instances will do to your dependencies.

We should have had an amplification alert. It's a single PromQL expression, it's four lines long, and it would have named the problem forty minutes before we found it. It didn't exist because nobody had experienced this failure mode. That's the honest reason most alerts don't exist: alerting is a lagging indicator of institutional trauma.

We should have questioned the flat p99 line. Somebody said "p99 is pegged at 3 s" out loud at 10:04. It was treated as "latency is terrible." It should have been treated as "that number is exactly our budget, which means it isn't a measurement, it's a clamp." Real distributions are noisy. A perfectly flat line is not a measurement; it's a wall. Suspicion of round numbers is a genuine debugging skill and we should teach it.

We should have read the support ticket. A customer described the exact failure mode — work continuing after she gave up — in one sentence at 10:11. It was in a Zendesk queue triaged by a rotation that doesn't join incident calls. During a SEV-1, someone should be reading tickets aloud. Customers see things dashboards can't, because they're outside your instrumentation.

And the one I'd undo if I could undo one thing: we should have made the flaky test's real problem visible. That test flaked 1-in-8 for two months before someone got annoyed enough to "fix" it. Two months of a signal saying the entity-service stub is slow under contention. We interpreted a real signal as noise, and the fix for noise is to turn the volume down. That's the meta-lesson: chronic flakiness trains your team to treat true signals as noise. The 10-second timeout wasn't recklessness. It was the accumulated cost of tolerating a flaky test.

---

Key Takeaways

• Timeouts shed load. Raising one doesn't buy patience; it disables a safety mechanism.
• child.Total < parent.PerAttempt. Test the invariant. It's twenty lines and it's the whole fix.
• Retry at one layer. Every additional layer multiplies, and it multiplies hardest when you're already failing.
• Retry budgets self-disarm. No successes, no tokens, no storm. Add this first if you add one thing.
• Full jitter, always. Deterministic backoff schedules load; it doesn't reduce it.
• Never context.Background() on a request path. Lint it. Link the postmortem in the message.
• A child span outliving its parent means cancellation is broken. Alert on it.
• Ratio alerts catch amplification. Absolute alerts never do. downstream_rps / ingress_rps > 1.5.
• Measure abandoned work. Ours was 71% and we had no way to see it.
• A metric clamped by your failure mode is a blindfold. Flat p99 lines are walls, not measurements.
• Shallow readiness probes. Deep ones are fleet-wide kill switches with no owner.
• Retry congestion, never bugs. 500 is usually deterministic. Retrying it runs the bug three times.
• Rollback restarts processes and flushes caches. During a capacity incident, that's an amplifier.
• If scaling up hurts downstream, you're amplifying, not saturating.
• The trigger is not the cause. Ask what turned a bad minute into a bad hour.
• git log -S finds one-line bombs in nine seconds.
• Load-test with a slow dependency, not a fast stub. Otherwise you're testing the system you hoped for.
• Chronic flakiness trains teams to ignore true signals. Ours cost us two hours of uptime.

---

Ending

We closed the incident at 12:14. The postmortem ran three pages and had eleven action items, and every one of them was cheap.

That's the part that stayed with me. Not one fix required a rewrite, a new dependency, a migration, or a quarter of headcount. A required argument instead of a package default. One identifier changed from context.Background() to ctx. A twenty-line test. A four-line PromQL expression. A token bucket that fits on one screen.

We didn't lack the ability to prevent this. We lacked the imagination to prevent it — because none of us had lived it yet. Every control on that list is obvious in hindsight and invisible in foresight, and the only thing that reliably converts the second into the first is somebody's bad Thursday.

So here's mine. Take it. Skip the Thursday.

Go open your code right now and grep for context.Background() on a request path. Open your budget table and check whether any child can outlive its parent. Count how many layers of your stack retry the same call. Look at your latency dashboard and ask whether that p99 line is a measurement or a wall.

You'll find something. Everyone does. That's not an indictment of your team — it's a property of systems that have grown faster than their invariants have been written down.

The best engineers I've worked with aren't the ones who never ship this bug. They're the ones who go looking for it on a quiet afternoon, with nobody paging them, before it's a story.

Be that. The alternative is that you get an article out of it.

---

SEO

SEO Title: Retry Storm Postmortem: How a 10-Second Timeout Caused a Production Cascade

Slug: retry-storm-timeout-inversion-postmortem

Meta Description: A one-line timeout change sat dormant for three weeks, then turned 900 rps into 8,100 and caused a 2h33m outage. Full postmortem: timeout inversion, context propagation, retry budgets, jitter, circuit breakers, and the Go code that fixed it.

Keywords: retry storm, retry amplification, timeout inversion, cascading failure, distributed systems postmortem, context propagation Go, exponential backoff full jitter, retry budget, circuit breaker, load shedding, readiness probe anti-pattern, OpenTelemetry orphan span, Kubernetes OOMKilled, connection pool exhaustion, SRE incident response, production incident postmortem, abandoned work, Prometheus amplification alert, chaos testing latency injection, Jaeger trace debugging

---

DEV.to Tags

#bugsmash #go #devops #sre

Front matter:

---
title: The Child Span That Outlived Its Parent
published: false
description: A one-line timeout change sat dormant for three weeks, then turned 900 rps into 8,100 and took production down while we watched a dashboard that physically could not show the problem.
tags: bugsmash, go, devops, sre
cover_image: 
canonical_url: 
series: Smash Stories
---

Alternates if you want to swap: distributedsystems, kubernetes, postmortem, observability, backend, architecture, programming, webdev, microservices