bug: Prometheus shared-dict lock contention after upgrading from APISIX 3.16 to 3.18; possible expired-key resync amplification
Current Behavior
After upgrading our APISIX-based deployment from 3.16 to 3.18, one Pod started exhibiting recurring high CPU utilization across multiple workers. Other Pods in the deployment were less affected. The production traffic was reported as unchanged across the upgrade; this was not a controlled replay benchmark.
Two low-frequency profiles of the same worker identified the mutex of prometheus-metrics as a substantial CPU hotspot. We traced the mutex pointer to the actual shared-memory zone and verified its name from the zone's management metadata.
Comparing the Prometheus dependency versions revealed a possible regression mechanism: re-adding an expired indexed metric now increments delete_count, causing other workers to scan the entire historical index through sync_range(0, N). The affected Pod has an index high-water counter of approximately 192,000.
We can establish the lock identity, deployed dependency, configuration, index size, and source-level amplification mechanism. We have not captured a Lua stack proving that sync_range() was executing during these CPU spikes, and have not completed a controlled A/B test. We are reporting an observed performance problem with a specific, evidence-backed hypothesis, rather than claiming that a particular commit has been conclusively proven responsible.
Disclosure note: infrastructure identifiers, exact timestamps, runtime addresses, and application label values are omitted. Internal index counters are explicitly rounded. Public source revisions and sampling counts are retained.
CPU trend
The cropped dashboard below shows the affected Pod's elevated green CPU series alongside the other Pods. Identifying legends are omitted. This is a dashboard observation, separate from the single-worker perf sample percentages reported below.
Evidence 1: the dependency changed, and the new deployed files were verified
| Official APISIX release | Pinned nginx-lua-prometheus-api7 version |
|---|---|
| 3.16.0 rockspec | 0.20250302-1 |
| 3.18.0 rockspec | 1.0.0-1 |
The dependency repository is api7/nginx-lua-prometheus:
- Old version:
f86aa3ef2249e2dce4312e549ab45ad79203634f(0.20250302). - New version:
bc04f9daa8f8da0f8f8165687c9e53136f9c50f5(1.0.0).
SHA-256 hashes of the three deployed files match 1.0.0:
e8f909659a3a53bf11bdf908c7f68a709b74641102fb74b030c2d10a9fea58e1 prometheus.lua
91ae2b17b138602b7388f840177fbec9bf5516e2c3730b4c36224f1ba8bb3497 prometheus_keys.lua
749ecb10c6dd2060dbf081c93005a87f757679ff2eb81c99989a2553bd96bb01 prometheus_resty_counter.luaThe previous production image's files have not been independently verified; the old-side comparison uses the official 3.16.0 dependency pin. Between these two dependency tags, prometheus.lua and prometheus_resty_counter.lua are unchanged. The runtime code differences are in prometheus_keys.lua.
Evidence 2: repeated CPU samples identify the same metric-zone mutex
We sampled one serving worker from its host, using the same parameters twice: user-space cpu-clock:u, 19 Hz, 12 seconds, no inherited tasks, and the BX user register. A one-second CPU observation immediately before the second profile showed that worker at 99% CPU.
| Profile | Total decoded samples | Samples in the inspected spin loop | Sample share |
|---|---|---|---|
| First | 118 | 47 | 39.8% |
| Second | 105 | 54 | 51.4% |
All selected spin-loop samples in both profiles contained the same mutex pointer. Exact runtime addresses are omitted.
The attribution was verified as follows:
Disassembly of the actual worker executable showed that
ngx_shmtx_lock()saves its mutex argument fromRDIinRBXand retains it in the sampled spin loop. The sampled instructions were matched to that inspected spin loop./proc/<host-worker-pid>/mapsplaced that mutex inside a shared mapping of size 128 MiB.The actual binary's shared-dict initializer showed the
log_ctxfield offset. A bounded read of the zone header and its context string returned:zone_context = in lua_shared_dict zone "prometheus-metrics"
This identifies the dictionary by its actual name, not just by matching its configured size. The module's initialization code explains this name field.
Earlier native profiles also showed ngx_meta_lua_shdict_lookup and lj_str_new as hotspots. Those symbols are consistent with repeated dictionary lookup and string construction, but are not unique to KeyIndex:sync_range().
Interpretation limit: these percentages describe the selected worker's samples, not total Pod CPU, measured lock-hold duration, or a throughput regression percentage. We have no valid Lua call chain from these profiles. The sampled worker may be a lock waiter rather than the worker causing a long hold.
Profiling methodThe capture used the following command shape, with a verified host worker PID substituted for WORKER_PID:
timeout -s INT -k 2s 16s perf record -q -N -B -o - \
-p "$WORKER_PID" -e cpu-clock:u -F 19 -m 16 \
--no-inherit --user-regs=bx -- sleep 12 |
timeout -s INT -k 2s 22s perf script -i - -F time,ip,uregsThe decoded output was retained in shell memory for analysis. The spin-loop filter used instruction addresses verified against the actual executable. Exact addresses are omitted; instruction addresses and structure offsets are binary-specific and must not be reused blindly with other builds.
Metadata inspection used read-only /proc/<pid>/mem access without attaching a debugger, stopping a worker, injecting code, or calling the live shared-dict API. Profiling and inspection have some overhead; we did not establish zero request-latency impact. The collectors exited and all eight workers remained present afterward.
Evidence 3: expiry is configured and the historical index is large
Two bounded read-only lookups of the internal numeric keys produced the following state. Values are intentionally rounded for disclosure; these are summarized observations, not raw output:
| Relative time | __ngx_prom__key_count |
__ngx_prom__delete_count |
|---|---|---|
| T | approximately 192,000 | approximately 6,100 |
| T + 1 second | approximately 192,000 | approximately 6,100 |
These were non-atomic snapshots of the running process, with exact key-name/type checks. Less than 6 KiB of tree/entry metadata was read in total; no full key enumeration was performed.
Important distinctions:
key_countis an index-allocation counter/high-water value, not the current live series count. Normal deletion does not compact the scan range; counter eviction/recreation is a separate exceptional case.delete_countis a cumulative notification counter, not the number of full scans. Explicit deletions can also increase it.- The allocation counter increased slightly, while the deletion counter did not change between these two snapshots. Rounding masks the small allocation increase. These readings establish state and scale, not an expiry/re-add event during that particular second or during the earlier profiles.
Source-level hypothesis: expired re-adds amplify full historical resynchronization
The relevant change is api7/nginx-lua-prometheus#14, commit 845084f. Its purpose is to fix duplicate metric exposition following expired-key re-addition.
In the old version, failure to renew an expired index slot clears local state and registers a new slot. It does not increment delete_count on this branch.
In the new version, err == "not found" additionally executes:
self.deleted = self.deleted + 1
local _, incr_err, forcible = self.dict:incr(self.delete_count, 1, 0)Another worker's next KeyIndex:sync() then takes the existing full-sync branch:
local delete_count = self.dict:get(self.delete_count) or 0
local N = self.dict:get(self.key_count) or 0
if self.deleted ~= delete_count then
self:sync_range(0, N)
self.deleted = delete_count
endsync_range() iterates every index in that numeric range, constructs self.key_prefix .. i, calls dict:get() for each slot, and conditionally calls dict:ttl(). It includes historical empty slots and has no explicit yield in the loop.
This can execute on the request path: lookup_or_create() calls KeyIndex:add() even on a local lookup-cache hit when positive expiry is configured. add() calls sync() before updating the slot.
metric update with expiry configured
→ lookup_or_create / KeyIndex:add
→ expired indexed metric is re-added
→ shared delete_count increases [new behavior]
→ other workers observe the notification
→ sync_range(0, historical key_count)
→ many string constructions and shared-dict get/ttl operations
→ potential cross-worker mutex contention and request-path CPU amplificationAt the observed, rounded N≈192,000, one full sync executes approximately 192,000 index get() calls, plus conditional TTL reads. Across multiple workers, the operation count can reach the million range for an invalidation observed by all of them. Notifications can coalesce; we have not measured the actual scan frequency and do not multiply the cumulative deletion counter by N.
This provides a mechanism for increased CPU with unchanged traffic: the work performed for the same expired-metric reappearance changed, and its cost depends on accumulated index history. It does not yet explain why only one Pod is much more affected; per-Pod index history and expiry/re-add behavior have not been compared.
Secondary hypothesis: periodic full shared-dict reclamation
api7/nginx-lua-prometheus#18, commit 5f68f6c, adds an unconditional self.dict:flush_expired() after local expired-index cleanup.
For the initialization path observed in our deployment, Prometheus.init(dict, string_prefix) supplies the library's 3600-second cleanup interval. Therefore the or 600 fallback in KeyIndex.new() is not the effective interval here. This is separate from the 15-second exporter refresh and 300/600-second metric TTLs.
The apisix-nginx-module 1.19.9 implementation holds the zone mutex while traversing the LRU. With no argument, reclamation is not count-limited. This is a plausible source of periodic long holds, but we have not correlated its execution with the CPU spikes and do not attribute all recurring spikes to it.
Also, a finite flush_expired(n) bounds successfully freed entries, not necessarily nodes visited, so it would not by itself establish a strict traversal-time bound.
Questions for maintainers
- Is broadcasting a full historical resync on expired-key re-addition expected at this index scale, or could api7/nginx-lua-prometheus#14 introduce this performance regression under expiry/re-add churn?
- Could the consistency fix use bounded/incremental invalidation or index compaction while retaining duplicate-free exposition?
- Should the new reclamation path have single-worker ownership and a bounded amount of work, given that it shares the serving workers' metric-zone mutex?
We are not proposing simply removing either correctness fix: removing the broadcast can reintroduce duplicate metrics, and removing reclamation can reintroduce retained expired entries. We would appreciate guidance on a bounded implementation and the most useful additional evidence to distinguish these two paths.
Expected Behavior
Reintroducing an expired metric should preserve index consistency and avoid duplicate exposition without causing excessive request-path work across workers as the historical index grows. Background reclamation should also avoid excessive shared-dict lock hold times.
Error Logs
No error-log excerpt is attached. The evidence above consists of CPU samples, native symbol/disassembly analysis, and bounded read-only shared-memory metadata inspection. We did not change production log levels.
Steps to Reproduce
We do not yet have an executed minimal reproduction. We avoided changing production code/configuration or enabling in-worker instrumentation to obtain one. The production observation is recurring CPU spikes after upgrading our customized APISIX deployment from 3.16 to 3.18, with traffic reported as unchanged; this was not a controlled replay.
A focused isolated validation could compare the two dependency versions under the same conditions:
- Create two or more independent KeyIndex instances sharing one dictionary, representing workers with separate local index state.
- Build a large historical index, sync both instances, and let an indexed metric expire while retaining its local cached index entry.
- Re-add that metric through one instance.
- Update an existing metric through the other instance; count sync_range() calls and dictionary get/ttl operations.
- Compare incremental versus full historical scans, and verify duplicate-free exposition and expiry correctness. Then repeat with real workers to measure CPU, mutex contention, and request latency. Validate the periodic cleanup path separately.
This is a proposed validation procedure, not an experiment already performed.
Environment
- APISIX-based customized build, upgraded from 3.16 to 3.18.
- Eight NGINX workers; container CPU quota equivalent to eight cores.
- Linux 5.4-based kernel; x86-64, LuaJIT-enabled OpenResty. Vendor-specific build details are omitted.
lua_shared_dict prometheus-metrics 128m.- Exporter refresh interval: 15 seconds.
- Enabled bandwidth metrics expire after 300 seconds; several other configured metrics expire after 600 seconds.
- Additional application-specific labels are present.
- Our customized exporter disables the official HTTP status/latency updates and enables bandwidth/LLM updates. These switches are customization details, not stock APISIX configuration fields. The contribution of AI-specific metrics has not been measured.
- The underlying
prometheus.lua,prometheus_keys.lua, andprometheus_resty_counter.luafiles are byte-for-byte identical to the dependency's1.0.0release.
The customized exporter and the lack of a controlled traffic replay are relevant limitations when attributing the issue to an upstream change.
Source: apache/apisix