Change #1244799 merged by jenkins-bot:

[operations/deployment-charts@master] Revert "mw-debug: Pilot new drain configuration"

https://gerrit.wikimedia.org/r/1244799

The drain-envoy.sh hook script assumes the envoy admin interface is available via a TCP listener, but in our production envoy config, it's only available via UDS (at /var/run/envoy/admin.sock). The script needs updated to reflect / support that.

Change #1244807 had a related patch set uploaded (by Scott French; author: Scott French):

[operations/deployment-charts@master] mediawiki: refresh mesh.deployment 1.3.2

https://gerrit.wikimedia.org/r/1244807

Now that I think about it, interacting with envoy via UDS is going to be a bit of a pain without pulling in additional dependencies that we probably don't want in practice.

The alternative would be to set mesh.admin.bind_tcp: true to restore the previous behavior. That seems to do the right thing, though I'll have to look more closely into the rationale for that change and in order to evaluate whether it makes sense to go the UDS route.

Change #1244807 merged by jenkins-bot:

[operations/deployment-charts@master] mediawiki: refresh mesh.deployment 1.3.2

https://gerrit.wikimedia.org/r/1244807

swfrench opened https://gitlab.wikimedia.org/repos/sre/envoy-drain-tool/-/merge_requests/1

Initial implementation: envoy drain tool

Change #1247185 had a related patch set uploaded (by Scott French; author: Scott French):

[operations/docker-images/production-images@master] envoy: Support using envoy-drain-tool

https://gerrit.wikimedia.org/r/1247185

swfrench merged https://gitlab.wikimedia.org/repos/sre/envoy-drain-tool/-/merge_requests/1

Initial implementation: envoy drain tool

Change #1247185 merged by Scott French:

[operations/docker-images/production-images@master] envoy: Support using envoy-drain-tool

https://gerrit.wikimedia.org/r/1247185

Change #1248889 had a related patch set uploaded (by Scott French; author: Scott French):

[operations/deployment-charts@master] mw-debug: Pilot new drain configuration

https://gerrit.wikimedia.org/r/1248889

Alright, I believe we're in a good spot to start testing again first thing next week.

At a high level, I'd like to proceed in a couple of steps:

1. Deploy https://gerrit.wikimedia.org/r/1248889 in mw-debug to perform basic testing - i.e., verify drain and shutdown sequencing implements the expected behavior, and there are no "obvious" surprises w.r.t. ATS <> mw-debug interactions during pod shutdown (i.e., downstream errors).
2. Test the same settings in a limited context (e.g., canary) on mw-web (primary client: ATS) and mw-api-int (primary client: envoy), while monitoring downstream error rates and sequencing-related errors raised within the pod - i.e., MediaWiki errors interacting with the service mesh. This is probably also a good time to do two things:
   • Bump envoy's shutdown delay to the full 8s, since if the inbound listener drain has the intended effect, then the rationale for envoy's shorter 7s delay no longer holds.
   • Evaluate whether graceful drain over some subset of the shutdown delay (much less than 8s) is needed for downstream clients. This probably depends on k8s networking delays - i.e., how long we expect to still receive new connection attempts after the pod starts termination - and how clients handle connection errors. Note that if we do this, we'll want to decouple graceful drain from the gradual drain-strategy (i.e., we would want graceful + immediate, meaning "all in-scope listeners are immediately eligible for graceful drain").
3. Roll out the change more widely, monitoring the same.
4. Once stabilized, update the mesh.admin values "API" to subsume what we're currently fiddling with via mesh.extra_env.

Change #1248889 merged by jenkins-bot:

[operations/deployment-charts@master] mw-debug: Pilot new drain configuration

https://gerrit.wikimedia.org/r/1248889

Change #1249373 had a related patch set uploaded (by Scott French; author: Scott French):

[operations/deployment-charts@master] Revert "mw-debug: Pilot new drain configuration"

https://gerrit.wikimedia.org/r/1249373

Change #1249373 merged by jenkins-bot:

[operations/deployment-charts@master] Revert "mw-debug: Pilot new drain configuration"

https://gerrit.wikimedia.org/r/1249373

Alright, progress (if incremental).

I was able to complete #1 from T364245#11683039 today.

Everything seems to work as expected from the envoy side of things. The new tool invokes /drain_listeners?inboundonly and then polls /stats with an appropriate query (both over the admin socket), and does not exit earlier than the 7s delay expires. Envoy in turn does exactly what we asked it to do.

Where this gets interesting how ATS responds. As alluded to in T364245#11683039, I was probing mw-debug (in this case, Special:BlankPage) externally while running rolling restarts. Sure enough, I received a handful of 502 errors that I can't reproduce in the prior configuration. ATS error logs: P89828.

So, what's going on there?

A clean envoy-initiated shutdown of an open-but-idle connection shouldn't cause any trouble (i.e., ATS should handle that fine). Indeed, these are clusters of repeated connect failures during the "short, but clearly not short enough" window where envoy has stopped accepting new connections in the inbound listeners, but k8s networking (kube-proxy) has not yet removed the terminating pod from the forwarding rules.

Contrast this with the current behavior, where envoy keeps accepting connections right up until it's terminated at the 7s mark. That's pretty effective in avoiding these kinds of downstream connect issues, at the expense of the problems described in this task.

In effect, this is pretty much exactly the second point from #2 in T364245#11683039. I'm just surprised we were able to see it at this tiny scale - i.e., I expected it to manifest only for large deployments, where there's significantly more networking churn.

In any case, the answer is likely the same: a graceful drain period covering the start of the drain window, where we accept connections for the benefit of clients still forwarded there, but discourage keeping them. I'll put something together for that today, though it will require additional changes to the drain-envoy.sh script to decouple graceful-drain from gradual-drain-strategy (i.e., we want graceful + immediate).

Aside: I'm a little surprised back the back-to-back 4x connection errors reported by ATS, as naively I would expect each retry to have some non-zero probability of forwarding to one of the non-terminating pods. I'm wondering if ATS is doing something cheeky and reusing the same source port, which combined with conntack on the k8s worker node would maybe keep new connects forwarding to the same pod.

Change #1249428 had a related patch set uploaded (by Scott French; author: Scott French):

[operations/docker-images/production-images@master] envoy: Decouple graceful drain from drain strategy

https://gerrit.wikimedia.org/r/1249428

Change #1249437 had a related patch set uploaded (by Scott French; author: Scott French):

[operations/deployment-charts@master] mw-debug: Pilot new drain configuration

https://gerrit.wikimedia.org/r/1249437

Change #1249428 merged by Scott French:

[operations/docker-images/production-images@master] envoy: Decouple graceful drain from drain strategy

https://gerrit.wikimedia.org/r/1249428

Change #1249437 merged by jenkins-bot:

[operations/deployment-charts@master] mw-debug: Pilot new drain configuration

https://gerrit.wikimedia.org/r/1249437

Change #1250019 had a related patch set uploaded (by Scott French; author: Scott French):

[operations/deployment-charts@master] Revert "mw-debug: Pilot new drain configuration"

https://gerrit.wikimedia.org/r/1250019

Change #1250019 merged by jenkins-bot:

[operations/deployment-charts@master] Revert "mw-debug: Pilot new drain configuration"

https://gerrit.wikimedia.org/r/1250019

More progress ...

Note: The changes in https://gerrit.wikimedia.org/r/1249437 work as expected, but I've reverted the patch just to leave things in a consistent state while we plan next steps.

So, today I was able to repeat my tests from yesterday, now with a 3s graceful drain covering the start of the now at-least-8s termination window (i.e., extended to match mediawiki's preStop hook).

Even with more aggressive external probing, I was able to observe only one 502 error across the 5 roll-restart runs. That's quite a significant improvement over yesterday (vs. multiple 502s per run), but ... why do we see any at all? Does --drain-time-s need to be longer?

That's when I realized (and confirmed by polling with kubectl get pods), that the degree to which our rolling-restart "rolls" is debatable. At least in our version of helmfile (v0.171.0), recreatePods is implemented in terms of helm's --recreate-pods, which in turn (helm v3.11.3) looks like this.

In short, I had no idea that the rate of termination is only limited by the latency of the (sequential) delete operations, rather than something that attempts to emulate the update strategy on the associated deployment. For a small deployment like mw-debug (2 pods) that basically means there will be a couple of seconds where the only pods that exist are terminating.

Anyway, what does this mean for us?

Well, for the purposes of this work, I definitely will not be using roll-restart on any large mediawiki deployments to verify the rollout. However, I think it is still appropriate for use when testing with canary deployments - i.e., it's functionally no different from what we already do by setting the update strategy to Recreate.

Whether we actually need graceful drain in practice, if a major contributor to the errors seen here in testing was the "delete all the things" implementation of roll-restart, is also less than clear. I think the answer is likely yes, in light of the timings observed in T364245#11634977 and the errors seen in yesterday's testing, which persisted for longer than I would expect if bounded only by pod startup time.

In any case, I think the next step is to continue with step #2 in T364245#11683039 - i.e., same change as today in the canary deployments of mw-api-int and mw-web.

Change #1250067 had a related patch set uploaded (by Scott French; author: Scott French):

[operations/deployment-charts@master] mw-(api-int|web): Pilot drain configuration in canary

https://gerrit.wikimedia.org/r/1250067

Change #1250090 had a related patch set uploaded (by Scott French; author: Scott French):

[operations/docker-images/production-images@master] envoy: Restore graceful default and support -max-wait-duration

https://gerrit.wikimedia.org/r/1250090

Change #1250090 merged by Scott French:

[operations/docker-images/production-images@master] envoy: Restore graceful default and support -max-wait-duration

https://gerrit.wikimedia.org/r/1250090

Change #1250067 merged by jenkins-bot:

[operations/deployment-charts@master] mw-(api-int|web): Pilot drain configuration in canary

https://gerrit.wikimedia.org/r/1250067

(Somewhat delayed update due to an incidental discovery that needed dealt with.)

I've left the changes from https://gerrit.wikimedia.org/r/1250067 in place in mw-web/canary and mw-api-int/canary, initially applied in eqiad and codfw around 17:10 and 17:30, respectively.

No issues encountered during initial testing (i.e., simulating deployments to canary), nor subsequently during the train deployment between 18:45 and 18:50. I'm specifically looking for deployment-correlated:

1. connection_failed errors (similar to what I saw in testing on Monday) and 5xx errors for mw-web reported by ATS
2. 5xx errors for mw-api-int reported by envoy
3. mediawiki errors in canary

It's a bit too early to say definitively, but it seems like we may be seeing fewer ATS-reported connection errors during the canary deployment stage than we typically do (note that connection-failed errors do seem to be a "normal" feature of the canary and prod stages of mediawiki deployments). If that remains true throughout the rest of today's deployments, that would be an interesting result.

In any case, I will check in periodically throughout the day today, and either revert before the end of my day, or (if no issues arise) potentially leave the changes intact until tomorrow's UTC-late infra window (24h total).

Around 8 hours on, the observations in T364245#11699657 continue to hold - I'm not seeing any deployment-correlated issues. I'm feeling pretty optimistic about leaving this as-is for the full 24h.

Revert: In the unlikely event that anything seems amiss while I'm not available, simply revert https://gerrit.wikimedia.org/r/1250067 and apply the changes to mw-api-int and mw-web.

Change #1251131 had a related patch set uploaded (by Scott French; author: Scott French):

[operations/deployment-charts@master] Revert "mw-(api-int|web): Pilot drain configuration in canary"

https://gerrit.wikimedia.org/r/1251131

Change #1251131 merged by jenkins-bot:

[operations/deployment-charts@master] Revert "mw-(api-int|web): Pilot drain configuration in canary"

https://gerrit.wikimedia.org/r/1251131

The experiment was fully reverted by 19:15 today.

Reviewing the same error-logs and metrics from T364245#11699657 and aligning with the scap logs, I'm again seeing no evidence of canary-deployment correlated errors [0].

Interestingly, the the connect_failed errors have regained their "double hump" shape (example) after the revert, which would be consistent with the earlier observation that the drain sequence may be helping there.

I believe this puts us in a good position to proceed with step #3 in T364245#11683039 at the start of next week, rolling this same configuration out to all production mediawiki deployments.

Monitoring would look similar, with at least one notable exception that comes to mind: changeprop-jobqueue <> mw-jobrunner. In that case, envoy is not the client - changeprop is a direct node http client (under numerous layers of abstraction), which we haven't explicitly tested here. There's no reason to believe it would behave oddly, but it's worth keeping in mind.

In any case, I'll give the specifics of the rollout some thought in the interim.

[0] There are some spikes in ATS connect_failed errors, but those correlate with rest-gateway deployments, rather than mediawiki (note: the trafficserver_transaction_errors_total metric doesn't implicate a specific backend).

Returning to this today, I'd like to pursue this as follows:

• Expand the pilot configuration (https://gerrit.wikimedia.org/r/1250067) to all releases of mw-api-int and mw-web. Soak for at least 24h to confirm the earlier observations hold.
• Expand the same configuration to all other large MediaWiki services, paying particularly close attention to the effect of the change in mw-jobrunner on changeprop-jobqueue. Again soak for 24h.

As long as there are no issues discovered up to that point, begin work to pull the ad-hoc configuration in mesh.extra_env into mesh.admin.

Change #1253664 had a related patch set uploaded (by Scott French; author: Scott French):

[operations/deployment-charts@master] mw-(api-int|web): Use envoy drain configuration

https://gerrit.wikimedia.org/r/1253664

Change #1253664 merged by jenkins-bot:

[operations/deployment-charts@master] mw-(api-int|web): Use envoy drain configuration

https://gerrit.wikimedia.org/r/1253664

The changes in https://gerrit.wikimedia.org/r/1253664 were rolled out to mw-api-int and mw-web between 17:00 and 18:00 UTC today. As a follow-on smoke-test during that window, I rolled out (and back) some noop changes to both services in eqiad (i.e., a noop configuration change that simply had the effect of inducing a rollout) to flush out any "obvious" surprises, and indeed none were observed.

Through the subsequent backport window, I'm pretty optimistic about what we've seen:

• Looking at mediawiki-error logs, I'm not seeing any deployment-correlated errors that suggest mesh issues on pod termination. Indeed, spot checking the instances of Could not enqueue jobs and one Shellbox server returned status code 503, these are actually all at steady-state or, in one case, shortly after pod start. Note: there is a brief spike in DBConnectionError a couple of minutes after the window, which appears to be a brief network disruption affecting a single pod (i.e., unrelated to the changes here).
• Looking at connect_failed errors, and ignoring the spike at ~ 20:21 which is not correlated with any deployment (and alas, cannot easily be attributed to a specific backend service [0]), this looks pretty good. Compare, e.g., with the window in which I rolled out the changes, where you'll see (still quite small) spikes in errors that are about an order of magnitude larger (these were the very last terminations without drain). While the improvement is clearly small in an absolute sense, the key point is that we're not seeing more errors when more eagerly shutting down the inbound listeners.
• Finally, looking at 5xx errors for mw-api-int reported by envoy I'm again not seeing anything that clearly correlates with deployments. Note you may want to filter out cirrus-streaming-updater to see the tail better (i.e., its steady-state error rate dominates).

In any case, I think we're on track to proceed as described in T364245#11716209 tomorrow, unless of course any issues are discovered in the interim.

Revert: If anything is discovered while I'm not available, simply revert https://gerrit.wikimedia.org/r/1253664 and helmfile-apply the changes to mw-api-int and mw-web.

[0] Edit: Spot-checking some ATS error logs, it was analytics-web.discovery.wmnet, which is backed by an-web1001 and was presumably rebooted around that time.

Change #1254962 had a related patch set uploaded (by Scott French; author: Scott French):

[operations/deployment-charts@master] mw-(api-ext|jobrunner): Use envoy drain configuration

https://gerrit.wikimedia.org/r/1254962

Change #1254962 merged by jenkins-bot:

[operations/deployment-charts@master] mw-(api-ext|jobrunner): Use envoy drain configuration

https://gerrit.wikimedia.org/r/1254962

The changes in https://gerrit.wikimedia.org/r/1254962 were deployed over the course of the 17:00 UTC hour today, using a similar procedure to that in T364245#11721272.

Before diving into that, one correction: I realized shortly before starting that migrating mw-jobrunner is not the first direct exposure of changeprop to the new drain behavior. That already happened for "normal" (non-jobqueue) changeprop when we migrated mw-api-int (I'd misremembered that the non-jobqueue instance uses Envoy; it does not).

In any case, no issues observed so far, and I'll continue to keep an eye on things through the backport window today.

One interesting observation: For changeprop-jobqueue specifically, long-running job executions hitting the (then) 7 second termination delay on envoy used to fail with errors like (example):

{"type":"internal_http_error","detail":"socket hang up","internalStack":"Error: socket hang up\n    at connResetException (node:internal/errors:720:14)\n    at TLSSocket.socketOnEnd (node:_http_client:519:23)\n    at TLSSocket.emit (node:events:526:35)\n    at endReadableNT (node:internal/streams/readable:1376:12)\n    at process.processTicksAndRejections (node:internal/process/task_queues:82:21)","internalURI":"https://mw-jobrunner.discovery.wmnet:4448/rpc/RunSingleJob.php","internalQuery":"{}","internalErr":"socket hang up","internalMethod":"post"}

That doesn't happen anymore following the change here. Instead, for jobs that run beyond the 8 second termination delay on MediaWiki those requests fail with a proper 5xx error emitted by Envoy on the mw-jobrunner side (example):

{"detail":"<!DOCTYPE html>\n<html lang=\"en\">[... snip ...]<p>Original error: upstream connect error or disconnect/reset before headers. reset reason: connection termination </p></div>\n</html>","internalURI":"https://mw-jobrunner.discovery.wmnet:4448/rpc/RunSingleJob.php","internalMethod":"post"}

That's our standard envoy error page, reporting that the upstream request to MediaWiki was terminated.

In any case, something to keep in mind if there are other contexts where client-detected network errors are now explicit error responses. Ultimately, for jobqueue, there seems to be no change in the volume of retry jobs produced, so it seems there's no net change in behavior.

Aside from that, no changes of note. I'll follow up later once we're through the backport window.

Revert: Simply revert https://gerrit.wikimedia.org/r/1254962 and helmfile-apply the changes to mw-api-ext and mw-jobrunner.

A couple of hours on, the observations in T364245#11724941 still hold.

It's too early to say definitively, but the deployment-correlated saw-tooth pattern of errors returned by rest-gateway (i.e., as a result of upstream errors toward mw-api-ext) may have been diminished a bit after the change applied in the 17:00 hour earlier today. You can sort of see that in the ATS backend errors attributed to that service, as well as the local (i.e., at rest-gateway) envoy-reported upstream errors toward mw-api-ext (example).

What's perhaps more interesting, though, is that with a bit longer baseline, we can now see some new behavior for mw-web: Since the change landed yesterday (the 17th) in the 17:00 hour, we now see small spikes of deployment-correlated 503 errors reported by ATS.

I was rather concerned when I noticed this, but then I realized that this is most likely the same behavior as described in T364245#11724941 - i.e., what were previously requests that failed by virtue of their network connections being terminated in-flight (upon envoy termination) are now explicit error responses from the backend (from envoy, upon MediaWiki termination), in turn making them visible in to the backend-requests metric, which (IIRC) only reflects explicit backend responses (and reflects all backend responses in a transaction, not just the "final" one - i.e., these may have been successfully retried, when permitted).

But where can we look to see the failing requests prior to this change?

So, we've looked previously at connect_failed transaction errors, but that's not really what we're looking for here - we want connections that were unceremoniously terminated, which I think would be surfaced as read errors by way of the trafficserver_backend_cache_result_code_client_ttfb_count metric, which also attributes to the specific backend service.

That looks like this, where you can clearly see errors throughout the day on the 17th correlated with deployments until 18:00 or so when the rollout completes, then nothing thereafter (e.g., no errors at all during the 20:00 UTC backport window). Of course, it's not exactly 1:1 in terms of amplitude (by a factor of >= 2), so I'm presumably not getting the full picture here.

All of that is to say, I think this all makes sense, and it has given us visibility into errors we would not have easily observed otherwise.

Some follow-ups from today:

@Joe pointed out that the behavior I'm describing now - i.e., small spikes in 503s during deployments - is actually similar to what we used to see prior to the k8s migration. In that scenario, envoy was running continuously through the upstream restart, and thus observed termination of in-flight requests (i.e., similar to what we have now, where envoy runs at least until all in-flight requests end).

There is of course always a trade-off between deployment speed and the grace period we allow for in-flight requests to complete (8s) and we could try extending that, at the expense of slower deployment.

Experiments

Just to double-check my understanding of how this is now working, I ran some experiments in mw-debug just now both with and without the drain behavior enabled.

Using fatal-error to simulate a long-running request (i.e., one that times out), I was able to observe the following:

• With drain (i.e., new behavior) it seems that ATS will retry an eligible (e.g., GET) request upon 503 response from envoy exactly once (and you can see both the 503 and the final response status in the trafficserver_backend_requests_seconds metric).
• Without drain (i.e., prior behavior) it seems that ATS will retry an eligible request upon connection termination (i.e., without headers sent) multiple times (hard to say exactly how many).

So, there is a slight behavior change w.r.t. how / whether (eligible) interrupted long-running requests are retried, in the event they are particularly unlucky and are interrupted multiple times. I think that's probably alright, but it's again something we'll want to keep in mind.

Change #1255882 had a related patch set uploaded (by Scott French; author: Scott French):

[operations/deployment-charts@master] mw-web: Revert envoy drain configuration

https://gerrit.wikimedia.org/r/1255882

Change #1255882 merged by jenkins-bot:

[operations/deployment-charts@master] mw-web: Revert envoy drain configuration

https://gerrit.wikimedia.org/r/1255882

While I believe we're on the right track in terms of understanding the effect of enabling the new drain behavior on mw-web, I still have some concerns about the details of interaction with ATS. I would like to resolve those with a bit more confidence before we leave this enabled in the long term.

Thus, I've reverted the change to mw-web, leaving it live on the other three large MediaWiki service (mw-api-ext, mw-api-int, and mw-jobrunner).

Once we're able to resolve the above (likely early next week, when I'll be able to consult with our resident ATS expert) we'll tweak things if needed, and proceed as planned with enabling across all MediaWiki services.

Note: This remains enabled on mw-api-ext, as it is no longer an ATS-facing backend service (i.e., requests are now proxied via rest-gateway).

Change #1259161 had a related patch set uploaded (by Scott French; author: Scott French):

[operations/deployment-charts@master] mw-web: Reenable envoy drain configuration

https://gerrit.wikimedia.org/r/1259161

Change #1259161 merged by jenkins-bot:

[operations/deployment-charts@master] mw-web: Reenable envoy drain configuration

https://gerrit.wikimedia.org/r/1259161

I was able to follow up with our resident ATS expert earlier today to double check some of the behaviors discussed previously.

Indeed it seems that, for safe methods ATS (1) will retry upon an explicit 503 response once and (2) may retry upon connection-closed-before-headers multiple times in certain scenarios (possibly up to 4 times). In cases where it cannot retry (e.g., non-safe methods), ATS will return the 503 in case #1 and synthesize one in case #2.

I was also able to confirm that case #2 is invisible to the trafficserver_backend_requests_seconds metric, which only reflects explicit origin responses, and indeed it reflects all responses - i.e., not just the final response returned to the user.

It was also pointed out that one additional area we should look at is the effect of connection churn during deployments, which will now behave differently due to the graceful drain (connection: close response headers). I'll keep any eye on whether there's any noticeable resource impact on ATS as a result.

With all of that, we decided to move ahead with reenabling drain-on-termination in mw-web. I've updated the revert-all-the-things patch in the task description to reflect that.

Some additional observations:

I noticed something curious today while following some envoy logs during MediaWiki deployments: in at least two cases, envoy receiving a SIGTERM while its preStop hook was still polling for in-flight requests to complete.

Importantly, this was happening ~ 10 seconds after termination had started (and drain triggered).

What's happening?

The key here is that we also have a terminationGracePeriodSeconds of 10 set on the Pod.

MediaWiki's preStop hook sleeps for 8 seconds, after which the kubelet sends a SIGTERM to PHP-FPM. I'd assumed that in-flight requests would terminate fairly promptly after that, though I was not sure how promptly.

In practice, it seems not-terribly-uncommon for requests to continue past that point for the full 2 seconds, right up to the terminationGracePeriodSeconds when PHP-FPM will receive a SIGKILL. My vague understanding of PHP-FPM termination is that, with process_control_timeout set to 60 as we currently have it, there's not really a meaningful bound on that side of things (vs. Pod lifecycle).

Now, on the envoy side, we hit a special case in kubelet: Since envoy's preStop hook may be running when terminationGracePeriodSeconds expires (this is racy; in some cases, it may very well have observed the upstream termination and exited), but envoy hasn't entered termination yet, there's a "bonus" 2 second grace period (second paragraph of 2.1 and here in killContainer) where envoy does not yet receive a SIGKILL and instead receives a SIGTERM.

Anyway, the significance of this is that, for at least some bound-to-fail requests (i.e., ones that would run beyond the terminationGracePeriodSeconds anyway), we may still encounter the previous connection-terminate-before-headers case (i.e., not everything is guaranteed to be an explicit 503).

Hopefully this is something we can make a bit easier to reason about once we switch to sidecar containers.

Yesterday evening, I realized that I'd really only looked closely the ATS error logs during initial testing (i.e., looking for evidence of increased connect failures), and hadn't revisited them last week in order to see if the previously "invisible" (to metrics) backend failures due to connection termination were visible there.

Sure enough, we used to see large waves of BAD_INCOMING_RESPONSE errors during deployments, which from a quick read of HttpTransact entirely makes sense given what we were doing (see, e.g., the scenarios that land us in that state in is_response_valid).

Here's a view of BAD_INCOMING_RESPONSE errors yesterday as errors-per-minute, collected from ATS error logs across the CDN:

The red vertical dashed lines are deployments, while the blue filled area is the time after drain had been reenabled.

Some additional points of note:

• Depending on deployment speed (see, e.g., how the first deployment picked up the weekly php8.3 image rebuild, which will be very slow due to the full MediaWiki image build) we can see peak errors per minute in the ~ 1500 - 2500 range. In comparison, we now only see per-minute 503 rates in the ~ 300 - 350 range. I'd take that as an indicator that the drain procedure is effective in reducing the number of in-flight requests at termination.
• The BAD_INCOMING_RESPONSE errors are not completely gone, but vastly diminished. This is consistent with the terminationGracePeriodSeconds behavior described yesterday.
• These error logs also include an attempt count, which we can use to estimate the fraction of requests that experience more than one error (recall, in this case, up to 4 attempts are permitted).
  • From this small sample, it seems to fall in the ~ 1% range over a given deployment. Even if pessimistically that's applicable to our current configuration (which seems more effective avoiding terminating Pods), that's quite a small number of requests that would fail (recall, only 2 attempts are allowed in the explicit error response case, though Varnish may also retry in some scenarios).
  • Of course, this is only relevant to requests that could be safely retried - i.e., for a non-retry-safe request, the reduced rate of errors overall should be helping.

Edit: Note that lower-amplitude patterns of BAD_INCOMING_RESPONSE errors not correlated with any deployment (e.g., stretching from a bit before 10:00 to a bit after 12:00 UTC) instead correlate with rolling k8s worker restarts (i.e., scheduling churn).

Change #1260096 had a related patch set uploaded (by Scott French; author: Scott French):

[operations/deployment-charts@master] mw-*: Use envoy drain configuration everywhere

https://gerrit.wikimedia.org/r/1260096

Change #1260096 merged by jenkins-bot:

[operations/deployment-charts@master] mw-*: Use envoy drain configuration everywhere

https://gerrit.wikimedia.org/r/1260096

Mentioned in SAL (#wikimedia-operations) [2026-03-26T17:52:40Z] <swfrench@deploy1003> Started scap sync-world: helmfile-only deployment to enable envoy drain on remaining services - T364245

Mentioned in SAL (#wikimedia-operations) [2026-03-26T17:55:13Z] <swfrench@deploy1003> Finished scap sync-world: helmfile-only deployment to enable envoy drain on remaining services - T364245 (duration: 05m 31s)

Since yesterday, all MediaWiki services (regardless of total request volume) now have drain-on-termination enabled. There are two high-level actions remaining here:

Verify impact - While we're confident that this functionality does what's intended in terms of termination behavior, we should still assess whether it has had an effect on the rate of data loss - e.g., using @tstarling's approach from T364245#11634849. I'll need to give a bit of thought as to what we're comparing to (i.e., how to measure a suitable baseline) and when to make the comparison (i.e., we probably want to wait until production is "back to normal" post-switchover).

Cleanup - This is currently configured in an ad-hoc way via environment variables in mesh.extra_env. As noted previously, we should lift this into mesh.admin now that we know which configuration knobs are relevant.

Now that we're back in a "normal" post-switchover state, we should be in good shape to start measuring the impact of this change.

Separately, I started looking at the cleanup aspect today. The good news is that consolidation into mesh.admin is pretty well isolated to the mesh.deployment module.

The tricky part comes from the way dependency versioning works among modules (i.e., hard <major>.<minor> constraints).

If we're strictly observing semver, these changes would be a minor version bump, however, introducing mesh.deployment 1.4.0 (latest is 1.3.2) comes at a cost.

We would also need to introduce:

• mesh.configuration 1.16.0 - a clone of latest 1.15.x with the mesh.deployment dependency bumped to 1.4 and mesh.certificate bumped to 1.2 (see below)
• mesh.name 1.2.0 - a clone of latest 1.1.x with the mesh.configuration dependency bumped to 1.16
• mesh.certificate 1.2.0 -> a clone of latest 1.1.x with the mesh.name dependency bumped to 1.2
• ingress.istio 1.3.0 - a clone of latest 1.2.x with mesh.name dependency bumped to 1.2

... in order to provide charts that touch any subset of these + mesh.deployment with a satisfiable upgrade path. While painful, it's less painful than retroactively bumping the mesh.deployment dependency of mesh.configuration (which invalidates the vendored dependencies of existing charts).

Anyway, this serves as another good example of why we need to implement proper dependency bounds instead.

(Note: I'm intentionally ignoring anything that still uses the cursed base.meta 1.0, of which there is only one chart, and it does not use the mesh).

On nl.wiktionary we noticed that some edits (new pages) are dropped from RecentChanges while they do show up in Logs.

Example:
The words (new pages) "troonwisselingetje" (https://nl.wiktionary.org/wiki/troonwisselingetje) en "data-uitwisselingen" ( https://nl.wiktionary.org/wiki/data-uitwisselingen ) show up in Logs ( https://nl.wiktionary.org/w/index.php?title=Speciaal:Logboeken&excludetempacct=1&page=&tagfilter=&type=create&user=&wpFormIdentifier=logeventslist&wpdate=2026-04-02&day=2&month=4&year=2026&offset=&limit=500 ) at 15:34 and 14:44 but are missing in Recent Changes ( https://nl.wiktionary.org/wiki/Speciaal:RecenteWijzigingen?userExpLevel=registered&hidebots=1&hidepageedits=1&hidecategorization=1&hideWikibase=1&hidelog=1&hideWikifunctions=1&hidenewuserlog=1&namespace=0&limit=4000&days=30&enhanced=1&urlversion=2 ).

The discussion in this thread is way above my pay grade, but I thought it wise to ask whether this is the same bug, before filing it as a new one.

This indeed looks like the same bug. But I am not able to verify if it shares the same cause.

Thanks for the report @MarcoSwart and for confirming that appears similar to how this issue manifests, @matej_suchanek.

I just checked our logs from 2026-04-02 to see whether either event overlaps with a MediaWiki deployment (or other disruption that could result in what @tstarling highlights in T364245#11634977). Although the second one does overlap with the very start of this deployment, that's well before any disruption would have happened (we're still building images at that point). Which is to say, I suspect a different underlying cause in this case.

@tstarling - Could I ask for your assistance in reproducing your analysis from T364245#11634977, ideally targeting days in the last week or so? Container termination should now follow a more sensible sequence and what we've seen in T364245#11744238 would suggest far fewer long-running requests are interrupted at the termination timeout (i.e., drain is effective).

In T364245#11816724, @Scott_French wrote:

@tstarling - Could I ask for your assistance in reproducing your analysis from T364245#11634977, ideally targeting days in the last week or so? Container termination should now follow a more sensible sequence and what we've seen in T364245#11744238 would suggest far fewer long-running requests are interrupted at the termination timeout (i.e., drain is effective).

There was a burst of lost RC entries on nlwiktionary on 2026-04-02.

wikiadmin2023@10.192.13.7(nlwiktionary)> SELECT left(rev_timestamp,8) as date,count(*) FROM revision LEFT JOIN recentchanges ON rev_id = rc_this_oldid AND (rc_source = 'mw.edit' OR rc_source = 'mw.new') LEFT JOIN page ON page_id = rev_page WHERE rc_id IS NULL AND rev_timestamp LIKE '202604%' group by date;
+----------+----------+
| date     | count(*) |
+----------+----------+
| 20260402 |       25 |
| 20260403 |        4 |
| 20260405 |        4 |
| 20260406 |        6 |
| 20260408 |        2 |
| 20260409 |        6 |
| 20260410 |        4 |
| 20260414 |        2 |
| 20260415 |        1 |
| 20260417 |        5 |
| 20260420 |        2 |
| 20260424 |        2 |
| 20260425 |        1 |
| 20260429 |        2 |
+----------+----------+
14 rows in set (0.130 sec)

In the case of troonwisselingetje with rev_id=5505290, the request ID was 97c4aba0-e73c-44a0-8c15-7e33c66070d9 and the pod name was mw-web.eqiad.main-6dbf997859-nlvdb. There were no relevant pod events at that time. In the MediaWiki DeferredUpdates channel we see the cause:

• mwversion: 1.46.0-wmf.22
• timestamp: 2026-04-02T13:34:34.806Z
• phpversion: 8.3.30
• reqId: 97c4aba0-e73c-44a0-8c15-7e33c66070d9
• Find reqId in Logstash
• normalized_message: Deferred update '{deferred_type}' failed to run.
• exception.class: Wikimedia\Rdbms\DBConnectionError
• exception.message: Cannot access the database: Database servers in cluster31 are overloaded. In order to protect application servers, the circuit breaking to databases of this section have been activated. Please try again a few seconds.

This is not the same root cause.

I don't know how I missed this the first time around, but most edits associated with log entries have a recentchanges row with rc_this_oldid=rev_id. The main problem with the queries by Ladsgroup and Krinkle was just their rc_source condition. If you drop that condition, then you get reasonable results.

wikiadmin2023@10.64.48.74(enwiki)> SELECT rev_id,rev_parent_id,rev_timestamp,page_namespace,page_title,comment_text FROM revision LEFT JOIN page ON rev_page=page_id LEFT JOIN recentchanges ON rev_id=rc_this_oldid LEFT JOIN comment ON comment_id=rev_comment_id WHERE rev_timestamp BETWEEN '20260422000000' AND '20260429000000' AND rc_id is null;
...
150 rows in set (12.419 sec)

wikiadmin2023@10.64.48.74(enwiki)> select count(*) from revision where rev_timestamp between '20260422000000' AND '20260429000000';
+----------+
| count(*) |
+----------+
|  1144809 |
+----------+
1 row in set (0.266 sec)

So that's 0.013% missing over the past week.

An example of a missing RC row is rev_id=1351500096, rev_timestamp=20260428102513, an API edit with request ID bf807b22-b237-4d23-9e07-61f5f7148736 on pod mw-api-ext.eqiad.main-5759c8cfbd-z7xlb. There was a syslog entry:

[28-Apr-2026 10:25:34] WARNING: [pool www] child 12 exited on signal 6 (SIGABRT) after 24869.082989 seconds from start

I don't know if something killed it or if it called abort() itself.

Thank you very much for the additional analysis, @tstarling - both the reanalysis of enwiki and digging into the nlwiktionary example.

Agreed that the external-store circuit breaking you observed in T364245#11873888 explains that specific failure, and also plausibly explains the burst seen on that day (there was a issue involving frequent circuit breaking from roughly 10:00 to 13:40 UTC).

Focusing on your results for enwiki, and assuming these are roughly comparable with what you measured previously (albeit with a different query), I'm cautiously optimistic about the fact the rate seems quite a bit lower. That would be consistent with having significantly reduced - but presumably not fully avoided, given the relevant time scales - the number of in-flight requests at pod termination.

If you happen to have the raw results available some where (i.e., specific rev_id / rev_timestamp pairs) I can try to do a bit more correlation to see if other patterns stand out.

As for the SIGABRT you found, that's an interesting observation. It is something I've seen before occasionally (i.e., seemingly raised by the worker itself), but not in any great number. I'll see if that correlates with anything else that might be on our radar.