proxy: report optimistic cache refreshes - #520
Conversation
An optimistic cache hit is answered from the cache right away while the expired entry is refreshed in a separate goroutine, which calls replyFromUpstream on a clone of the context. That clone, and with it the QueryStatistics of every exchange the refresh performed, is then dropped. The refresh never reaches Config.RequestHandler either, so a caller has no way to observe those exchanges at all. Collecting response times from DNSContext.QueryStatistics therefore only ever samples cache misses, and with the optimistic cache enabled the popular names, which are the ones kept warm, are never sampled. The resulting average is biased towards the rare names that upstreams resolve slower. Add an optional Config.OnOptimisticRefresh, called once a background refresh finishes, with the context that carries its statistics. It is reported whether or not the refresh succeeded, since the statistics describe the attempt either way. Wrapping the upstreams instead does not work: Upstream.Exchange takes no context, and ExchangeParallel and ExchangeAll copy the request per upstream, so nothing identifies the request an exchange belongs to. See AdguardTeam/AdGuardHome#8435.
Sil3ntVip3r
left a comment
There was a problem hiding this comment.
Reviewed exact head 858999ba4ce11ea3a96ab4633e2b59448f4f5f8d as the dependency path for AdGuard Home #8522.
The callback is placed after replyFromUpstream, so the refresh context already contains the final QueryStatistics; it remains optional, reports both successful and failed attempts as documented, and leaves existing behavior unchanged when nil. The context ownership and nonblocking contract are explicit, and the single-flight deletion and cache update paths remain intact.
Validation performed:
go test -race -count=20 -run "^TestOptimisticResolver_ResolveOnce_reportRefresh$" ./proxy
PASS
go test -race -count=1 ./proxy
PASS
disposable real-Proxy Config.OnOptimisticRefresh integration test, -race -count=20
PASS; callback received the same context with populated successful upstream statistics
git diff --check origin/master...858999ba
PASS
gofmt inspection of all four changed files
clean
make go-check completed linting and the internal/proxy package suites, including zero reachable vulnerabilities. Its full test phase then failed only in the repository existing live-network probes: UDP 94.140.14.14:5353 timed out and TLS 9.9.9.9:853 reset the connection. Those failures are unrelated to this four-file callback change; the complete proxy package passed independently under -race.
I found no correctness or compatibility blocker. This is the right explicit seam for attributing optimistic background refresh statistics without the request-identity problem in AdGuard Home #8522.
Replace the upstream wrapper with the callback added in AdguardTeam/dnsproxy#520. The wrapper could not work. An exchange has to be attributed to the request it belongs to, both so that the statistics ignore lists apply and so that a background refresh can be told from a foreground query, and an upstream.Upstream is given no way to do it: Exchange takes only a *dns.Msg and no context, and ExchangeParallel and ExchangeAll copy the request once per upstream before calling it, so no identity of the original survives. The request-pointer key therefore missed in parallel and fastest-address mode with more than one upstream, and queries from clients with ignored statistics were counted after all. Only the single-upstream path skips the copy, which is why the first regression passed. Foreground exchanges go back to being collected from proxy.DNSContext.QueryStatistics, which is client-attributed and already gated by ShouldCount, so the ignore lists behave exactly as they did before this branch. Background refreshes arrive through proxy.Config.OnOptimisticRefresh, which fires once the optimistic cache has refreshed an expired entry; they belong to no client by construction, so there is nothing to attribute and nothing to double count. A retried exchange is still left out, but the check moved to where the statistics entry is built, and compares against the timeout the upstreams of that request were constructed with: defaultLocalTimeout for private rDNS, the configured one otherwise. Both are covered end to end, and both regressions fail against the unfixed implementation: the retry filter in load-balance, parallel, and fastest-address mode, and the refresh collection against an entry that expires while the test runs.
The previous commit needs proxy.Config.OnOptimisticRefresh, which is added by AdguardTeam/dnsproxy#520 and is not in any released dnsproxy, so this branch does not compile without it. Point the module at the branch of the fork that carries the change, purely so that the tree builds and CI has something to run. This commit is not part of the fix and must be dropped once dnsproxy#520 is merged and a release is tagged; the change then needs nothing but the ordinary version bump. Revert this one commit to see exactly what merging looks like.
|
Combined dependency integration check on exact heads: I applied these four PR diffs together on current
The diffs applied together without conflicts. Fresh validation of the combined GitHub currently shows no check runs for these heads, so this is local |
Replace the upstream wrapper with the callback added in AdguardTeam/dnsproxy#520. The wrapper could not work. An exchange has to be attributed to the request it belongs to, both so that the statistics ignore lists apply and so that a background refresh can be told from a foreground query, and an upstream.Upstream is given no way to do it: Exchange takes only a *dns.Msg and no context, and ExchangeParallel and ExchangeAll copy the request once per upstream before calling it, so no identity of the original survives. The request-pointer key therefore missed in parallel and fastest-address mode with more than one upstream, and queries from clients with ignored statistics were counted after all. Only the single-upstream path skips the copy, which is why the first regression passed. Foreground exchanges go back to being collected from proxy.DNSContext.QueryStatistics, which is client-attributed and already gated by ShouldCount, so the ignore lists behave exactly as they did before this branch. Background refreshes arrive through proxy.Config.OnOptimisticRefresh, which fires once the optimistic cache has refreshed an expired entry; they belong to no client by construction, so there is nothing to attribute and nothing to double count. A retried exchange is still left out, but the check moved to where the statistics entry is built, and compares against the timeout the upstreams of that request were constructed with: defaultLocalTimeout for private rDNS, the configured one otherwise. Both are covered end to end, and both regressions fail against the unfixed implementation: the retry filter in load-balance, parallel, and fastest-address mode, and the refresh collection against an entry that expires while the test runs.
Replace the upstream wrapper with the callback added in AdguardTeam/dnsproxy#520. The wrapper could not work. An exchange has to be attributed to the request it belongs to, both so that the statistics ignore lists apply and so that a background refresh can be told from a foreground query, and an upstream.Upstream is given no way to do it: Exchange takes only a *dns.Msg and no context, and ExchangeParallel and ExchangeAll copy the request once per upstream before calling it, so no identity of the original survives. The request-pointer key therefore missed in parallel and fastest-address mode with more than one upstream, and queries from clients with ignored statistics were counted after all. Only the single-upstream path skips the copy, which is why the first regression passed. Foreground exchanges go back to being collected from proxy.DNSContext.QueryStatistics, which is client-attributed and already gated by ShouldCount, so the ignore lists behave exactly as they did before this branch. Background refreshes arrive through proxy.Config.OnOptimisticRefresh, which fires once the optimistic cache has refreshed an expired entry; they belong to no client by construction, so there is nothing to attribute and nothing to double count. A retried exchange is still left out, but the check moved to where the statistics entry is built, and compares against the timeout the upstreams of that request were constructed with: defaultLocalTimeout for private rDNS, the configured one otherwise. Both are covered end to end, and both regressions fail against the unfixed implementation: the retry filter in load-balance, parallel, and fastest-address mode, and the refresh collection against an entry that expires while the test runs.
See AdguardTeam/AdGuardHome#8435.
Problem
An optimistic cache hit is answered from the cache immediately while the expired entry is refreshed in a separate goroutine.
Proxy.replyFromCachebuilds a reduced clone of the context for that refresh:resolveOncecallsreplyFromUpstreamon the clone, which fills in itsqueryStatistics, and then drops it. The refresh also never reachesConfig.RequestHandler, since it bypasseshandleDNSRequestentirely.So a caller has no way to observe those exchanges. Anything collecting response times from
DNSContext.QueryStatisticsonly ever samples cache misses — and with the optimistic cache enabled, the popular names are exactly the ones kept warm and therefore never sampled. The average ends up biased towards the rare names that upstreams resolve slower, which is what the AdGuard Home issue above reports as a 2-4x inflation.Change
An optional
Config.OnOptimisticRefresh, called once a background refresh finishes, with the context carrying its statistics:It is routed through the existing
cachingResolverseam thatoptimisticResolveralready depends on, soresolveOncegains one call and no new dependency. The refresh is reported whether or not it succeeded, since its statistics describe the attempt either way.Nothing changes when the field is nil, which is every current caller.
Why not wrap the upstreams
Wrapping
upstream.Upstreamand timingExchangelooks like it would avoid an API change, but it cannot attribute an exchange to the request it belongs to:Exchange(req *dns.Msg)takes no context and carries no per-request metadata.ExchangeParallelandExchangeAllboth doreq.Copy()per upstream before calling it, so the identity of the original request does not survive — only the single-upstream path skips the copy.A wrapper therefore cannot tell a background refresh from a client's query, nor apply per-client policy to what it records. That is what motivated adding the hook here rather than working around it downstream.
Testing
TestOptimisticResolver_ResolveOnce_reportRefreshcovers both the successful and the failed refresh, asserting the callback receives the same context and that caching still only happens on success.go build ./...,go vet ./...andgofmtare clean, andgo test ./proxy/passes exceptTestExchangeWithReservedDomains, which resolveswww.google.ruagainst real upstreams and fails identically on a clean checkout here.