DEV Community

Remdore
Remdore

Posted on AI-assisted

Your zero-downtime deploy is probably fine. Check your p99 before you believe it.

Nginx retries mask dropped requests

I went looking for dropped requests during a rolling restart and found something more annoying than dropped requests: a deploy that looks perfect and isn't.

Setup is deliberately boring. Two Node/Express replicas behind nginx, ten clients hammering an endpoint that takes three seconds, docker stop on one replica halfway through. The app is the version most of us have shipped at some point, with no signal handling at all:

app.get('/work', async (req, res) => {
  await new Promise(r => setTimeout(r, 3000));
  res.json({ ok: true, pid: process.pid });
});

app.listen(8080);
Enter fullscreen mode Exit fullscreen mode

No SIGTERM handler. Docker sends the signal, Node exits, and anything mid-flight dies with it. I expected a pile of 502s.

total=65 ok=65 failed=0
Enter fullscreen mode Exit fullscreen mode

Zero. Three runs, zero every time.

The failure was there, nginx just paid for it

The requests did die. nginx caught the upstream connection dropping before any response headers had gone out, so it quietly opened a connection to the other replica and ran the whole thing again. The client never knew.

That behaviour is proxy_next_upstream, it's on by default, and I want to be fair to it because it is doing exactly what you'd want a reverse proxy to do when a backend disappears mid-request. It is also the reason your dashboard can report a flawless deploy while the thing being deployed is quietly broken, which is a strange position for a metric to be in.

The only place it shows up is latency:

naive app:     p50 = 3.01s    p99 = 5.94s
graceful app:  p50 = 3.02s    p99 = 3.04s
Enter fullscreen mode Exit fullscreen mode

Same zero-error result, same load, same everything. The affected requests took twice as long, because they were executed twice. If you are watching error rate you see nothing. If you are watching p99 you see a spike at every deploy that you have probably learned to ignore.

Three seconds of extra latency is survivable. Doing the work twice might not be, and that depends entirely on what the work is: a retried search query costs you nothing, a retried outbound email costs you a duplicate, and a retried payment authorisation costs you a phone call from someone in finance. nginx has no idea which of those it just re-ran.

Take the safety net away

Plenty of setups don't have that retry. A Kubernetes Service is iptables or IPVS, and it does not re-run your request. An L4 load balancer won't. A client talking straight to your app certainly won't. Once headers are on the wire, even nginx can't.

Same test, proxy_next_upstream off:

naive app:     5 / 70 requests failed   (7%)
Enter fullscreen mode Exit fullscreen mode

There is the pile of 502s I went looking for. Nothing about the app changed. The only difference is whether something upstream was covering for it.

The fix, and why it is only most of a fix

The app-level fix is the one everybody writes about. Stop accepting new connections, let the in-flight ones finish, then exit:

const server = app.listen(8080);

process.on('SIGTERM', () => {
  server.close(() => process.exit(0));
});
Enter fullscreen mode Exit fullscreen mode

Same test:

naive:     5 / 70 failed
graceful:  1 / 71 failed
Enter fullscreen mode Exit fullscreen mode

Better. Not fixed. That last failure is stubborn, it showed up on all three runs, and it is the interesting one.

The in-flight requests are safe now. What's left is the requests arriving in the gap between server.close() and the load balancer working out that this instance is gone, and during that gap nginx is still holding the address in its upstream list, so it does the reasonable thing and opens a fresh connection to a socket that has just stopped accepting them, which produces a 502 for a client who did nothing wrong.

No amount of application code fixes that. The app has already done the right thing. The load balancer is the one still pointing at it.

Take it out of rotation first

Remove the instance from the load balancer, give the change a second to settle, and only then send SIGTERM:

graceful + drained from the LB first:   0 / 70 failed   (3 runs)
Enter fullscreen mode Exit fullscreen mode

That's the whole ordering. Stop routing to it, then stop it. In Kubernetes this is what a preStop hook buys you, and it is why preStop: sleep 5 looks like a hack and isn't. The sleep isn't for your app, which is already finished. It's to let the endpoint removal propagate before the container goes away.

What I got wrong on the way

My first attempt at the drain test came back with 3, 1 and 1 failures, and I nearly wrote a paragraph explaining that draining doesn't help as much as you'd hope.

It was my bug. I had mounted nginx.conf read-only, so the command that swapped in the drained config failed without complaining, no drain ever happened, and what I had actually done was run the same test twice and then write an explanation for the difference between two identical things. With a writable mount it's zero out of seventy, three runs in a row.

Worth saying out loud because the failure mode is so ordinary: my test harness was broken in a way that produced plausible numbers.

The whole thing

                                        failed/total    p50      p99

naive,     nginx retry on (default)         0 / 65      3.01s    5.94s
graceful,  nginx retry on                   0 / 70      3.02s    3.04s
naive,     no retry                         5 / 70      3.01s    3.05s
graceful,  no retry                         1 / 71      3.02s    3.05s
graceful + drained from LB first            0 / 70      3.02s    3.05s
Enter fullscreen mode Exit fullscreen mode

Three runs of each, identical every run.

What I'd check on Monday

Error rate is not going to tell you whether you have this. If there is a retrying proxy in front of your app, error rate is exactly the metric that will hide it.

Look at p99 during a deploy instead. A tail that roughly doubles for a few seconds and then settles back is the signature, because that is the shape of a request being run, killed, and run again somewhere else.

Then check the two halves separately, because they fail independently. Does your app have a SIGTERM handler that finishes in-flight work? And does your platform stop routing to the instance before it sends that signal? The first without the second still leaks requests, just fewer of them.

All of it runs on a laptop. Two containers, nginx, and a load generator that counts outcomes. No cloud account and nothing to sign up for.

Top comments (7)

Collapse
 
vinhnguyenthanhdn profile image
Vinh Nguyen

The p99 signature is real but its visibility is set by your harness, not by the defect. The retried requests are the ones in flight on the replica you killed, so the count is bounded by concurrency — five here, which is exactly the 5 / 70 your no-retry row measured — while the denominator grows with the window you percentile over. That makes the affected fraction D / 2T for request duration D and window T, independent of load: 3 / (2 × 19.5) = 7.7% on your run, matching the 7% you measured, but 0.5% over a five-minute dashboard bucket.

So p99 only sees this while T < D / 0.02 — 150 seconds for a 3-second endpoint, and 5 seconds for a 100ms one. Your two setup choices that look incidental, a deliberately slow endpoint and a ~20-second run, are what put the signal above the p99 line. On a normal endpoint at normal aggregation the doubled requests are still all there as a fixed count, so what survives the averaging is a count of responses past roughly 2× p50, not the tail percentile itself.

Collapse
 
remdore profile image
Remdore

That's right, and it's a cleaner way to put it than I managed. The slow endpoint and the short run weren't picked to make p99 light up, but that is what they did, and I should have said so.

The fixed count is the useful framing for anyone with a real 100 ms endpoint. The number of doubled requests is set by how many were in flight on the replica at the moment it died, not by traffic, so it won't grow with the window and it won't move a five-minute percentile.

Two places it survives without any maths. nginx writes every upstream it tried into $upstream_addr, comma separated, so a retried request shows up in the access log as two addresses and an $upstream_status of "502, 200". Count the lines with a comma in them and you have the exact number, no window involved. And if you don't have the logs, a response time histogram will show a small second lump at roughly 2× p50 around each deploy, which no percentile will ever tell you about.

Collapse
 
mickyarun profile image
arun rajkumar

Worth adding for anyone about to go and check their own config: nginx will not retry POST and friends unless you have put non_idempotent into proxy_next_upstream. The trap is that the safety is coming from the method, not from what the handler actually did. A GET that writes gets retried happily, and if that three second handler had already moved money before the replica died, it moves it again and the dashboard still reads 65 ok, 0 failed.

Same root from the readiness side if it's useful: dev.to/mickyarun/your-health-check...

Collapse
 
remdore profile image
Remdore

Yes, and it cuts both ways for my test. I used GET on purpose so nginx would retry, and I didn't say that anywhere. Make /work a POST and the first row of that table goes from 0 failed to 5 failed on the default config, no non_idempotent needed. So the zero-error result isn't only about the proxy being in front, it's about the method.

Your scenario is the one that bothered me too. The retry fires when the upstream connection dies before headers go out, and a handler that has committed a transfer and is about to respond is exactly that. From nginx's side it looks the same as a handler that never got started. The graceful shutdown fixes it by letting the response leave, and that's the real argument for it, more than the error count.

Collapse
 
mridul_it_is profile image
Mridul Tiwari

daymn , I never would have known this without this article, what about when I am using LB controller instead, does draining happens there?

Collapse
 
remdore profile image
Remdore

Depends what's behind it. If you mean the Kubernetes Service itself, no. That's iptables or IPVS and it never retries. Kill a pod with a request in flight and the client gets a reset.

What you do get is the drain, sort of. When a pod goes Terminating it's pulled out of Endpoints and the SIGTERM is sent at the same time. Nothing waits for the first to finish before the second starts. If a cloud LB controller is in front, that's one more hop, because the controller has to see the endpoint change and then deregister the target with the load balancer, and that takes a few seconds on a good day.

So draining does happen there, it just starts at the same moment as the shutdown rather than before it. The preStop sleep is how you make the app wait long enough for it to catch up.

Collapse
 
mridul_it_is profile image
Mridul Tiwari

got it