agent/cache: refresh-enabled cached reads can drift per node after request context cancellation
- Dominant language
- Go
- Stars
- 30.1k
- Forks
- 4.6k
- Avg merge
- 1d 18h
- Merged PRs (30d)
- 39
Description
#### Overview of the Issue
After upgrading to `1.22.5`, we observed inconsistent results across Consul nodes when using `?stale&cached`. In a 5-server cluster, the same cached/stale read can return different values depending on which node handles the request, and that divergence can persist for many hours. The same reads with `consistent` are correct.
This does not appear to be limited to servers. The bug is in `agent/cache`, so any Consul node serving a refresh-enabled cached read from its local cache can potentially exhibit the same drift, including client agents.
This looks like a regression introduced by:
- PR [#23157](https://github.com/hashicorp/consul/pull/23157): `Addition of ctx context to cache fetch function and stop execution`
- Commit [`b7a1c5efd2256a2c68502bbe74ba2d961654fa0b`](https://github.com/hashicorp/consul/commit/b7a1c5efd2256a2c68502bbe74ba2d961654fa0b)
- Backport PR [#23159](https://github.com/hashicorp/consul/pull/23159): `Backport of Addition of ctx context to cache fetch function and stop execution into release/1.22.x`
- Backport commit [`0447f6d94effd9fc0b42d0b320324e2457acb1e1`](https://github.com/hashicorp/consul/commit/0447f6d94effd9fc0b42d0b320324e2457acb1e1)
There was a later partial fix:
- PR [#23266](https://github.com/hashicorp/consul/pull/23266): `Backport of Fix for cache context to save cache data in entries on context cancel into release/1.22.x`
- Commit [`f6d4f4d1859387dd1e9eb6166677a5e3ef31d12b`](https://github.com/hashicorp/consul/commit/f6d4f4d1859387dd1e9eb6166677a5e3ef31d12b)
That fix removes one cancellation-related failure mode, but it does not address the underlying refresh-lifecycle problem described below.
The suspected root cause is that the background refresh goroutine inherits the initiating request context and continues to reuse that same context for recursive refresh scheduling. Once the original request completes, that context is canceled and the node-local refresh loop exits, even though the cache entry is still being served to later callers.
Relevant code in `v1.22.5`:
- `getWithIndex` passes the caller context into `fetch`:
- [`agent/cache/cache.go#L406-L426`](https://github.com/hashicorp/consul/blob/v1.22.5/agent/cache/cache.go#L406-L426)
- [`agent/cache/cache.go#L513-L541`](https://github.com/hashicorp/consul/blob/v1.22.5/agent/cache/cache.go#L513-L541)
- [`agent/cache/cache.go#L526`](https://github.com/hashicorp/consul/blob/v1.22.5/agent/cache/cache.go#L526)
- the `Type` interface now takes a context:
- [`agent/cache/type.go#L14-L41`](https://github.com/hashicorp/consul/blob/v1.22.5/agent/cache/type.go#L14-L41)
- the background fetch goroutine uses the request context for the actual fetch:
- [`agent/cache/cache.go#L561-L620`](https://github.com/hashicorp/consul/blob/v1.22.5/agent/cache/cache.go#L561-L620)
- [`agent/cache/cache.go#L669`](https://github.com/hashicorp/consul/blob/v1.22.5/agent/cache/cache.go#L669)
- the recursive refresh loop also stops on that same request context:
- [`agent/cache/cache.go#L828-L853`](https://github.com/hashicorp/consul/blob/v1.22.5/agent/cache/cache.go#L828-L853)
- especially [`agent/cache/cache.go#L842`](https://github.com/hashicorp/consul/blob/v1.22.5/agent/cache/cache.go#L842) and [`agent/cache/cache.go#L853`](https://github.com/hashicorp/consul/blob/v1.22.5/agent/cache/cache.go#L853)
Why this can persist for a very long time:
- for refresh-enabled cache types, `MaxAge` is intentionally not used in the normal way:
- [`agent/cache/cache.go#L377-L385`](https://github.com/hashicorp/consul/blob/v1.22.5/agent/cache/cache.go#L377-L385)
- every read keeps the entry alive in the TTL heap:
- [`agent/cache/cache.go#L431-L449`](https://github.com/hashicorp/consul/blob/v1.22.5/agent/cache/cache.go#L431-L449)
So once refresh dies, a node can keep serving its last locally refreshed value for a very long time as long as requests keep touching that cache entry.
This also explains why the behavior is intermittent:
- it only affects cache types with `RegisterOptions.Refresh = true`
- it depends on which node initially populated the cache entry
- it depends on request timing
- it depends on later read traffic keeping the entry alive
This matches the field symptom of "sometimes wrong", "different across nodes", and "consistent is fine".
---
#### Reproduction Steps
1. Run a multi-node Consul deployment, for example a 5-server cluster. The same issue should also be possible on client agents when they serve from `agent/cache`.
2. Upgrade to a build containing `#23157` / `#23159`. We observed this on `1.22.5`.
3. Exercise an endpoint or code path that uses a refresh-enabled cache type and is served through the local cache path with `?stale&cached`.
4. Let a short-lived request populate the local cache entry on a given node.
5. Continue issuing the same `?stale&cached` request through different nodes.
6. Compare results across nodes. Some nodes can continue to serve older locally cached values for many hours, while `consistent` requests remain correct.
Minimal unit-test style reproduction:
1. Register a refresh-enabled blocking cache type.
2. Call `Get(ctx, ...)` once and return value/index `1`.
3. Cancel that original `ctx` immediately after the first result returns.
4. Expect the background refresh to continue and fetch value/index `2`.
5. On buggy code, the second fetch never starts because refresh exits on the canceled request context.
Expected behavior:
- request cancellation should stop the waiting `Get`
- request cancellation should not stop background refresh for an already-created refresh-enabled cache entry
Actual behavior:
- request cancellation stops the waiting `Get`
- the same request cancellation also stops background refresh for that node-local cache entry
- later `?stale&cached` reads keep serving the old local cached value
Outline of the fix:
- keep using the caller `ctx` in `getWithIndex` for waiting on behalf of the caller
- do not use the caller `ctx` as the lifecycle context for the background refresh goroutine
- once `fetch` launches background work, use a cache-owned context such as `c.rateLimitContext` for:
- the `Type.Fetch(...)` call inside the fetch goroutine
- the refresh timer/select loop
- the recursive `c.fetch(...)` call used for refresh continuation
- continue stopping refresh via cache-owned controls such as `handle.stopCh`, eviction/replacement, and cache shutdown
This preserves caller cancellation semantics while keeping background refresh aligned with cache lifecycle rather than request lifecycle.
### Operating system and Environment details
- Observed on `1.22.5`
- Reproduced in local code analysis and unit test against the `agent/cache` package
Contributor guide
Research direction
Start by reading agent/cache/cache.go sections around getWithIndex, fetch, the background fetch goroutine, and the recursive refresh loop, plus agent/cache/type.go. Reproduce the issue with a refresh-enabled blocking cache type: cancel the initial request after value/index 1 returns and verify whether refresh reaches value/index 2. Done means caller cancellation still stops waiting while cache-owned lifecycle controls continue and stop background refresh appropriately.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- go
- Domain
- backend, distributed-systems
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Quiet
- Clarity
- Clearly specified
- Newbie friendliness
- 55/100