hahait opened a new issue, #14149:
URL: https://github.com/apache/apisix/issues/14149
### Current Behavior
Note on terminology: "APISIX pod" below means the pod running the APISIX
gateway itself (where the nginx worker processes live). "backend pod" /
"business pod" means a pod of the upstream service that APISIX is routing to,
discovered via K8s Endpoints.
With the kubernetes discovery module (single mode, classic Endpoints), one
nginx worker process inside an APISIX pod can get stuck serving a stale node
list for a service, while the other workers in that same APISIX pod serve the
correct list. This sends a steady fraction of requests (roughly 1/worker_count)
to Pod IPs that no longer exist, or to Pod IPs that have since been reassigned
by K8s to a different backend service — causing 499 (timeout, when the old IP
is simply unreachable) or 404 (when the old IP is now serving an unrelated
service).
We've hit this 4 times so far in production, on different services, each
time right after a backend rollout or scale-down. In the worst case it lasted
5.5+ hours on one worker, until someone manually deleted a backend (business)
pod, which happened to fix it.
Root cause (our theory, based on production debug evidence — not yet
confirmed by a forced reproduction)
To be clear upfront: what follows is our best explanation, built by reading
the source and cross-checking it against the per-worker debug evidence
described below. We have not forced the exact race in a controlled environment,
so we'd like maintainers to confirm or correct this.
In `init.lua`(3.10.0) / `core.lua` (3.18 / 3.19), writing a new Endpoints
snapshot into the shared dict is two separate `safe_set` calls, and the version
key is written first:
```lua
-- 3.10.0, apisix/discovery/kubernetes/init.lua (on_endpoint_modified)
local endpoint_content = core.json.encode(endpoint_buffer, true)
local endpoint_version = ngx.crc32_long(endpoint_content)
local _, err
_, err = handle.endpoint_dict:safe_set(endpoint_key .. "#version",
endpoint_version) -- version first
if err then
core.log.error(...)
return
end
_, err = handle.endpoint_dict:safe_set(endpoint_key, endpoint_content)
-- content second
if err then
handle.endpoint_dict:delete(endpoint_key .. "#version")
core.log.error(...)
end
```
3.18 / 3.19:
```lua
-- apisix/discovery/kubernetes/core.lua (_M.update_endpoint_dict)
function _M.update_endpoint_dict(handle, endpoints, endpoint_key)
local endpoint_content = core.json.encode(endpoints, true)
local endpoint_version = ngx.crc32_long(endpoint_content)
local _, err
_, err = handle.endpoint_dict:safe_set(endpoint_key .. "#version",
endpoint_version) -- same order
if err then
return false, "set endpoint version into discovery DICT failed, " ..
err
end
_, err = handle.endpoint_dict:safe_set(endpoint_key, endpoint_content)
-- same order
if err then
handle.endpoint_dict:delete(endpoint_key .. "#version")
return false, "set endpoint into discovery DICT failed, " .. err
end
return true
end
```
Same logic, just moved into a shared helper. We didn't see any change to the
write order or any added locking. Also checked the `3.18`and`3.19`branches
directly, so upgrading may not help — would appreciate maintainers confirming
this.
Between the two writes there's a small window where the version key already
points to the new version but the content key still holds the old content. A
worker that reads during this window, through `single_mode_nodes` /
`_M.resolve_nodes` → `fetch_valid_cache` in
`lrucache.lua`, ends up caching:
```lua
{ val = <old content>, ver = <new version> }
```
`fetch_valid_cache` only checks `ver == version`, it doesn't re-check the
content:
```lua
-- apisix/core/lrucache.lua
local function fetch_valid_cache(lru_obj, invalid_stale, item_ttl,
item_release, key, version)
local obj, stale_obj = lru_obj:get(key)
if obj and obj.ver == version then
return obj -- trusted once ver matches, content
not rechecked
end
if not invalid_stale and stale_obj and stale_obj.ver == version then
lru_obj:set(key, stale_obj, item_ttl) -- just refreshes TTL
return stale_obj
end
...
end
```
Once the endpoints stop changing, the version stays the same, so this cached
entry keeps passing the check forever — TTL expiry just refreshes it instead of
forcing a re-read. The worker is stuck until the content changes again (new
version → cache miss → re-fetch).
This would explain:
- only one worker inside a given APISIX pod being affected (each worker has
its own lrucache; the shared dict itself is fine and consistent, we checked
this directly below)
- the stuck state not clearing on its own
- deleting/restarting a backend (business) pod "fixing" it — it forces a
real content change and a new version, giving every APISIX worker a fresh
chance to re-cache correctly
What we observed (production, APISIX 3.10.0, 4 nginx workers per APISIX pod)
We used an isolated `serverless-pre-function` debug route (own uri, no
upstream nodes, no production traffic) to check per-worker state via
`ngx.worker.pid()` / `ngx.worker.id()`.
- Calling discovery["kubernetes"].nodes(service_name) 100 times on the
affected APISIX pod: workers 52/53/54 always returned 60 nodes (correct),
worker 55 always returned 72 nodes (12 of them stale backend pod IPs), 100/100
times.
- Same check on a healthy APISIX pod (not showing the issue): all 4 workers
returned 60 nodes every time.
- Reading the raw version key from shm
(ngx.shared["kubernetes"]:get_stale(key .. "#version")) alongside the same
call, 100 samples: every worker, including worker 55, read the exact same
version value. So this isn't a version mismatch or CRC32 collision between
workers — the stuck worker's cached version really does match current, it's the
content behind it that's wrong.
- Checked require("apisix.router").http_routes() on the live route too:
upstream.nodes count alternates 60/72 depending on which worker answers,
modifiedIndex stays constant — so it's not an etcd/route change, it's inside
discovery/upstream resolution.
- Rough math: 1 stuck worker out of 4, 12 stale nodes out of 72 on that
worker, ≈4.2% of requests — close to the 3.95%–4.4% bad-request ratio we saw in
ELK during the incident.
#8489 reports a similar symptom (backend pod IPs not updating, requests
going to already-closed backend pods, APISIX 2.13.3), but the maintainers'
theory there was a K8s-side timing issue between unregistering a backend pod
from Endpoints and that pod actually terminating, with a preStop sleep hook
suggested as a workaround. That issue went stale and was closed without a
confirmed root cause.
For context: the backend (business) services involved in our incidents
already have a preStop sleep hook configured, and we still hit this issue,
which is part of why we think the root cause is different — an APISIX-side
caching race rather than a K8s backend-pod-termination timing problem.
### Expected Behavior
The version and content should be updated atomically from a reader's point
of view — no worker should ever be able to observe a state where the version
already reflects a change but the content doesn't (or vice versa)
```lua
_, err = handle.endpoint_dict:safe_set(endpoint_key, endpoint_content)
-- content first
if err then ... return end
_, err = handle.endpoint_dict:safe_set(endpoint_key .. "#version",
endpoint_version) -- version second
if err then
handle.endpoint_dict:delete(endpoint_key) -- roll back content instead
...
end
```
It might also be worth having fetch_valid_cache not trust a version match
forever without any re-check, since this kind of thing could affect other
discovery backends too.
### Error Logs
For the 499 requests, error.log shows upstream timed out (110: Connection
timed out) while connecting to upstream — consistent with the IP being a
stale/recycled pod that's no longer reachable. For the 404 requests, there's no
error/warn log at all — those are just normal upstream responses from whatever
is currently listening on the stale IP, so nginx has nothing to complain about.
Either way, the worker itself never logs anything about serving a stale node
list, which made this hard to notice from logs/alerts alone
### Steps to Reproduce
We don't have a minimal repro — this is a low-probability race, but it's hit
us 4 times in production so far, each time right after a rollout or a
scale-down event on the affected backend (business) service. We haven't been
able to reproduce it in a test environment. The root cause above is our best
explanation based on the debug evidence from the live incidents (per-worker
behaviour, shm version reads, router state), not something we've confirmed by
forcing the race directly. Happy to share the debug route definitions if a
maintainer wants to try reproducing it under concurrent Endpoints updates.
### Environment
- APISIX version: 3.10.0 (same code pattern appears present in 3.18 / 3.19
based on source review)
- OS: Linux (APISIX pod running in Kubernetes)
- Deployment: APISIX server deployed directly in our own K8s cluster (not
via apisix-ingress-controller or similar)
- Discovery: kubernetes, single mode, classic Endpoints (not EndpointSlice)
- nginx worker_processes: 4 per APISIX pod
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
