Skip to content
Jot
Home
Trending
Top
Tags
Groups
Theme
Privacy·Terms
Sign in
Home
Search
Trending
Sign in
Postmortem: 43 minutes of 502s and one very confident regex — Jot

Postmortem: 43 minutes of 502s and one very confident regex

D
Dan Whitlock
·November 17, 2025·1,614 words·9 min read
debuggingpostmortemsretools
☆stars: 7⑂forks: 0

Published with customer names, hostnames and internal service names removed. Everything else is as filed on 15 May 2026, including the parts that make us look slow.

Times are UTC. Owners are initials. I am DW.

There are initials in the timeline because someone has to be findable afterwards, and no initials in the root cause because a person is not a root cause. If the answer to "why did this happen" is a name, the investigation stopped early. This is the eleventh of these I have written. The table is the only part that gets easier.

Impact

Forty three minutes, 09:19:40 to 10:02:50 on Thursday 14 May 2026. The public card gateway returned 502 for 24 of those minutes at 100%, and at between 6% and 98% for the rest. At a steady 780 requests per second, about 1.45 million requests failed.

No money moved incorrectly. The gateway fails ahead of the authorisation call and the idempotency layer sits behind it, so nothing was double charged and nothing was captured twice. Merchants retrying during the window got 502 as well, which is the correct outcome and does not feel like one.

Two merchants missed their settlement batch window and were replayed by hand on 15 May.

Timeline

TimeEventWho saw it
09:11:02Canary of gateway 2026.5.14-3 to 1 of 34 pods. Canary gate green after 4 minutes.pipeline
09:14:30Rollout to the remaining 33 pods, 6 at a time. Completes 09:18:10.pipeline
09:19:20A merchant's daily retry batch starts. Its reference field ends in base64 padding.nobody
09:19:40First 502. Two pods stop answering readiness probes.nobody
09:21:05Autoscaler goes 34 to 41 pods on CPU.nobody
09:22:40502 rate at 6%. Liveness starts restarting pods.nobody
09:23:31Support engineer posts "merchant dashboard is throwing errors" in the help channel.RK
09:25:10Autoscaler at 60, the configured maximum. New pods take traffic and stop answering within about 90 seconds.nobody
09:26:02DW starts looking. Latency panel shows p99 at 2.500s, flat. Read as slow.DW
09:28:44502 rate at 100%.DW
09:30:12DW ties it to the 09:14 rollout. Decision to roll back.DW
09:31:50GatewayErrorRatioHigh pages. The condition had been continuously true since 09:20:50.pager
09:33:05Deploy CLI returns 502. It fetches its token through the gateway.DW
09:36:20Break-glass path located in the runbook. It needs a credential nobody on the call held.DW, MO
09:41:10MO has the credential. kubectl rollout undo issued.MO
09:43:20One pod held on the new image, pulled out of the load balancer, for later analysis.DW
09:44:00First pods back on 2026.5.14-2. They stay up.MO
09:52:1524 of 60 pods on the old image. 502 rate 41%.MO
09:58:30All pods on the old image.MO
10:02:50502 rate at baseline. Mitigated.DW
10:19:00Autoscaler back to 35 pods.nobody
11:48:00CPU profile from the held pod: 96% of samples inside a single regular expression match.AF

Root cause

A validation pattern added to the shared request middleware nests two unbounded quantifiers over overlapping character classes, so rejecting a value costs roughly twice as much for every additional allowed character that precedes the disallowed one, and one merchant's reference format supplies between 34 and 46 of them.

The pattern

^([A-Za-z0-9]+[-_ ]?)+$

The group takes one or more alphanumerics followed by an optional separator. The outer + repeats the group. For a value that is entirely alphanumeric, the number of ways to divide it between repetitions of that group is the number of ordered compositions of its length, 2n−12^{n-1}2n−1. When the value matches, the engine finds one of those divisions immediately and stops. When it does not match, because of a single = at the end, the engine has to try all of them before it can say no. At 32 characters that is 2312^{31}231 divisions, a little over two billion, which is why the number below reads in seconds.

Measured on my laptop, one core, node, on a string of n alphanumerics followed by one =:

ntime to fail
2499 ms
26398 ms
281.62 s
306.46 s
3226.1 s
401.9 hours, extrapolated
465 days, extrapolated

V8 offers no way to abandon a match in progress. Once a worker enters that call, the worker is gone until the process is killed.

The pattern was reviewed by two engineers and shipped with eleven unit tests. All eleven passed in under a millisecond, because all eleven inputs matched. Nobody writes a unit test for a value that gets rejected slowly. That is a property of tests, not of the people who wrote them.

Contributing factors

  1. The middleware runs before routing, on every request, including /healthz. No path through the process skipped it.
  2. Readiness and liveness are served by the same event loop as customer traffic, so a blocked worker and a dead pod are the same signal. Liveness restarted pods, they came back healthy, took traffic, and blocked again. On a dashboard that looks like recovery.
  3. The autoscaler targets CPU. A pegged event loop reads as 100% CPU, so it added pods, and each new pod became another place for a poisoned request to land. We went from 34 pods to 60 and the error rate went up.
  4. The canary window did not contain the traffic that triggers the bug. The batch starts at 09:19 and the canary gate closed at 09:15. We do not replay production traffic against canaries.
  5. The deploy tool authenticates through the gateway. Rolling back the gateway required the gateway to be working.
  6. The break-glass credential was held by two people, neither of them on call. Five minutes of the outage were spent in a direct message.
  7. Bodies and headers are capped at 8 KB. Forty six characters was never going to be caught by a limit that generous, and there was no per field limit at all.

What did not work

The latency panel. The gateway histogram's largest finite bucket boundary is 2.5 seconds, and when a quantile falls in the +Inf bucket, histogram_quantile returns the upper bound of the second highest bucket. That is documented behaviour and it is exactly what happened: the panel read 2.500 for forty three minutes. I looked at it at 09:26 and concluded we were slow. We were not slow, we were stopped. The rate of the +Inf bucket went from about 4 per minute to 61,000 and there was no panel for it.

The alert. GatewayErrorRatioHigh carries for: 10m, and Alertmanager's default group_wait is 30 seconds. The condition became true at 09:20:50 and the page landed at 09:31:50. A support engineer and a dashboard both beat it. The for: 10m was set in 2023 after a month of flapping, which was reasonable then and was still there in May 2026, which is the actual problem.

The logs. We log on response. A request that never responds writes nothing, so the last line from a stalled worker is the line before the middleware. Log volume from the gateway went down for forty three minutes, which is the opposite of what four people were grepping for.

The runbook. Step 2 is "check recent deploys" and links to a board that lists image deploys sorted ascending by start time. The 09:14 rollout was at the bottom of a scrolling list.

What we are changing

Dates are commitments. Two action items from a postmortem in 2024 quietly expired in a tracker, so they live in the document now.

  • Pattern replaced with a length check and one pass over the bytes. No nested quantifiers anywhere in the middleware. DW, 14 May.
  • Per field limit of 64 bytes on merchant references, applied at the edge before validation runs. DW, 15 May.
  • Rollbacks now hold one pod out of the load balancer on the build being rolled back, so it can be profiled. DW, 15 May.
  • Readiness served from a separate process on its own port, so a blocked event loop and a dead pod stop being one signal. AF, 29 May.
  • Autoscaler target moved from CPU to in flight requests per pod, with the scale up stabilisation window set to 120 seconds. AF, 29 May.
  • Buckets added at 5, 10 and 30 seconds, and a +Inf rate panel placed next to every p99 panel we own. RK, 21 May.
  • GatewayErrorRatioHigh moved to for: 2m on a one minute window, plus a new page at 5xx above 25% with for: 0m. DW, 21 May.
  • A backtracking check in CI, failing the build on any pattern it cannot prove linear. We are trialling recheck. MO, 12 June.
  • A deploy path that does not traverse the gateway, credential held by the on call rota rather than by two named people, exercised the first Monday of every month. MO, 12 June.
  • Ten minutes of sampled production traffic replayed against every canary before the gate closes. JS, Q3, not funded, written here so it is on the record.

On this page

  • Impact
  • Timeline
  • Root cause
  • The pattern
  • Contributing factors
  • What did not work
  • What we are changing