bound memory growth from high-cardinality tags with idle pruning - #189
Open
sokada1221 wants to merge 16 commits into
Open
bound memory growth from high-cardinality tags with idle pruning#189sokada1221 wants to merge 16 commits into
sokada1221 wants to merge 16 commits into
Conversation
Adds the config knob for idle-based counter/timer pruning. Defaults to 0 (disabled) so existing behavior is unchanged until a service opts in.
Counters track consecutive zero-delta flushes; timers track whether AddValue was called since the last flush. Either crossing pruneAfterFlushes removes the entry from its map. Zero (the default) disables pruning, so existing behavior is unchanged until a store opts in. This does not yet handle a held reference that gets pruned and then written to again - that's the next commit.
A held Counter reference must not go silent just because it sat idle long enough to be pruned - the pervasive Lyft pattern is to resolve a Counter once and hold it in a struct field for the process lifetime, so eviction has to be transparent to callers. Add/Set now check a detached flag and rejoin the store if set. rejoin re-inserts the counter under its original name, or - if a fresh lookup already created a new counter there while this one was detached - forwards its pending delta into that one and stays detached so later writes keep forwarding. Ordering in Flush matters: delete from the map before marking detached, not after. Otherwise a concurrent rejoin can observe itself still present, conclude it's already attached, and then get deleted anyway - orphaned, with no write ever able to bring it back. Deleting first guarantees any write that can observe detached=1 does so only after the delete has already happened. Timers need none of this: AddValue writes straight to the sink regardless of map membership, so a held Timer reference is unaffected by pruning either way. Verified with a concurrent stress test under -race: 8 goroutines each issuing 2000 increments against a store configured to prune after a single idle flush (the most aggressive setting, to maximize exposure to the delete/detach race window) reports the full total with none lost.
NewStore now reads Settings and converts PruneIdleSeconds into a flush count, rounding up so an idle entry always survives at least the requested number of seconds. Assumes the store flushes at FlushIntervalS; documented that a caller driving Start with its own ticker gets flushes-of-that-period pruning instead of wall-clock seconds.
gostats.tracked (gauge, tagged type=counter|gauge|timer) reports live map sizes; gostats.pruned (counter, tagged type=counter|timer) reports eviction counts. Both piggyback on the Range calls Flush already does, so there's no added iteration. Both are gated behind pruneAfterFlushes > 0. Emitting them unconditionally was tried first and reverted: it added three gauge series to the wire output of every store in the fleet, including the majority that never opt into pruning, and broke existing tests that assert exact sink output (TestZeroCounters, TestPerInstanceStats, the FastExit integration tests). The ticket's ask - eviction should be observable - is conditioned on eviction happening at all, so gating on the same flag that enables pruning matches the ask without the blast radius.
TestCounterTimerStructSizes pins counter (16->48 bytes) and timer (40->48 bytes, absorbed by Go's existing size class) with a loose upper-bound regression guard. BenchmarkStoreBytesPerStat gives the total per-counter heap cost (~184 bytes: sync.Map entry + key string + struct) so the 32-byte struct delta can be read against the total it's small next to. BenchmarkCardinalityFlood is the number for the ticket: a flood of one-shot tag combinations, each written once and never again, interspersed with flushes. Without pruning, live count equals flood size (unbounded). With pruning, it settles at 0. BenchmarkCounterAdd/Inc rebut PR #158's measured +3443% regression directly: pruning disabled vs enabled cost the same ~7ns, since the disabled path is a single non-atomic pointer comparison, not a lock. BenchmarkStoreNewCounterParallel and BenchmarkStoreFlush are ported from PR #158/#160 for contention and flush-cost coverage. BenchmarkStoreFlush went through one real bug before landing: writing to each entry only once during setup instead of on every iteration meant pruning deleted the entire map within the first ~5 iterations, so the "enabled" variant spent the rest of the run measuring Flush() on an empty store - reporting ~65ns against disabled's ~68000ns, a fake 1000x speedup. Fixed by writing to every entry each iteration (with the timer stopped, so only Flush's cost is measured) - both variants now report ~78000ns, as expected when nothing needs pruning.
Covers what unbounded growth looks like, the env var, what pruning guarantees for a held reference (reattaches on next write, nothing lost), the gauge exclusion, how to pick a value, the seconds-to-flush conversion caveat for a custom ticker, and alert guidance for gostats.tracked/gostats.pruned.
An independent review of the pruning feature (commits 9b6fdcf..536f29e) found one Critical and one Important concurrency bug, plus several smaller issues. Both were independently re-derived and empirically reproduced before fixing, not accepted on the reviewer's word alone - see the specific tests below for how each was confirmed. Critical: rejoin() could permanently orphan a held counter. rejoin() cleared c.detached unconditionally after its LoadOrStore reinserted c into the map. If Flush deleted and re-detached c again in the gap between that LoadOrStore and the clear, the clear then landed after the second prune, leaving c outside the map with detached == 0. maybeRejoin never calls rejoin() when detached reads 0, so every future write on that held reference was silently dropped forever. Reproduced deterministically by replaying the exact interleaving by hand, and empirically (independent of the reviewer's own repro) via TestPrunedCounterIntermittentWriteNeverOrphans: a single counter written with a brief real gap between writes, against a store pruning as aggressively as possible, loses a substantial fraction of increments in roughly 1 run in 15 against the pre-fix code. Continuous multi-writer hammering (TestPrunedCounterRaceWithFlush) essentially never reaches the prune branch for a contended key, which is why that test only ever caught this 1-in-20 rather than reliably. Fixed by never clearing detached from rejoin() - only Flush's active branch does, and only at a point where it has just confirmed, via that same Range callback, that the counter is currently in the map. This is simpler than a sequence-number/CAS scheme the reviewer sketched for the same bug; that sketch has its own gap (an ignored CAS failure leaves the same clobber possible, just moved), which is why it wasn't used as-is. Both tests pass 40-50/50 under -race after the fix; the new test fails reliably enough against the pre-fix code to serve as a real regression guard, though - like the bug itself - it's probabilistic rather than deterministic. Important: counter.latch() was not safe for concurrent callers. latch() was only ever called from the single Flush goroutine before rejoin's forwarding path existed. That path calls c.latch() from whatever goroutine is writing to a permanently-detached, forwarding counter (rejoin's "other != c" branch), so latch needed to tolerate concurrent callers on the same object - the old Load-then-Swap implementation did not: two callers' reads and swaps could interleave so a later caller's stale swap regresses lastSentValue backwards, both underflowing its own delta (to a huge uint64) and corrupting the next caller's. TestLatchDoesNotCommitStaleSwap deterministically pins the property the fix relies on (a stale commit attempt must fail, not overwrite). TestLatchConcurrentCallersSumCorrect stress-tests the real method concurrently. Natural scheduling did not reproduce the underflow in this environment even at high iteration counts - the window is two instructions wide - so the arithmetic hazard was confirmed by forcing the exact adversarial ordering directly against the atomic primitives, not by relying on a naturally-occurring failure. Fixed with a CAS retry loop: a caller only commits a read that is still current at the moment it commits, and retries against fresh values otherwise. Minor fixes, also from the same review: - NewStore called GetSettings(), which panics on a malformed value for ANY gostats env var, including ones it has nothing to do with. A caller passing its own sink specifically to bypass env-driven config could be broken by an unrelated typo (e.g. STATSD_PORT). Now reads only the two env vars it needs directly, tolerating a parse failure by falling back to disabled/default rather than panicking. - The seconds-to-flushes conversion now clamps to math.MaxUint32 instead of silently wrapping - an unclamped uint32(n) could turn "practically never prune" into "prune every flush" for a large enough PruneIdleSeconds value, the worst possible misreading of the operator's intent. Also dropped a dead "if n < 1" branch: both operands are already >= 1 by construction, so ceil(a/b) >= 1 always. - TestCounterTimerStructSizes now asserts the exact size (48 bytes) on 64-bit platforms instead of an <= 64 bound loose enough to miss a 16-byte regression. - Two comments described the originally-unconditional gostats.tracked behavior that commit f134d5b already reverted; a third (found during self-review, not by the external pass) claimed a rejoin self-observation mechanism that no longer exists now that rejoin never touches detached. All three corrected. - idleFlushes wasn't reset when a counter reattached via Flush's own race-catch path, so it could be immediately re-pruned next flush despite having nothing pending. Harmless (no data loss) but wasteful; now reset alongside the same-path rejoin() call. - Documented, rather than runtime-checked, that pruneAfterFlushes must not be mutated after construction: the scenario where that matters requires reaching into the unexported statStore directly, which is unreachable through the public API - adding a runtime guard for it would be validating a case that can't happen.
Two corrections from the same review pass as 05b87e5: - "without being written to" was imprecise for counters: Add(0) or a Set to the value already held counts as idle too, since idleness is judged by reported delta, not by whether a method was called. - gostats.tracked being gated behind pruning means it can't be used to discover a cardinality problem before opting in - only a service that already suspects one and has enabled pruning gets to watch it.
Independent re-review of commit 05b87e5 found that the orphan fix there did not hold under two concurrent Flush() calls - a case Store's own doc comment explicitly permits ("the store will flush either at the regular interval, or whenever Flush() is called"). Chased a lock-free fix first: a generation counter (odd=detached, even=attached, transitioned only via CAS) so a Flush call could tell whether a counter had been re-pruned since it last looked, closing the specific race the reviewer found. Verified empirically (not just reasoned through) that the fix worked for that specific case - then, under sustained stress via TestConcurrentFlushesDoNotOrphanCounter, found it had only narrowed the window, not closed it. Two more rounds of the same pattern followed: fix a race, verify empirically, find a narrower one underneath. All three shared the same root cause - winning a CAS, or re-verifying a value immediately before a map delete, still leaves a gap between "check" and "act" that Go's scheduler can land a full, legitimate reattachment cycle inside, because sync.Map has no primitive for "delete this key, but only if some unrelated field on the value still holds a specific number." Diagnosing this needed real tooling, not just re-reading the code: a mutex-protected logger was tried first and its own overhead masked the race entirely (2000/2000 clean, including at counts that reliably failed without it) - a classic observer effect. Replaced with a lock-free ring buffer (plain atomics, no locks, no formatting at trace time) plus a per-callback-invocation ID threaded through the relevant calls, which is what actually made the interleavings legible enough to find each successive bug. Reverted the generation-counter design entirely rather than patch a fourth time. Flush() is periodic (typically every 5-10s), not the hot Add()/Inc()/Set() path this feature is designed to leave lock-free - so a mutex around Flush() (statStore.flushMu), serializing it against itself, is a large, provable simplification for a cost that does not exist in the common case (a single ticker-driven Start goroutine never contends this lock at all). It also lets counter.detached go back to the plain boolean it was in 05b87e5's first fix, since "Flush never races itself" restores the precondition that fix already relied on. TestConcurrentFlushesDoNotOrphanCounter, which failed reliably before this fix, now passes 2000/2000 under -race; the rest of the pruning and rejoin suite passes 30/30 at the same settings. Benchmarks are unchanged within noise (an uncontended mutex is negligible next to the O(n) work Flush already does per call).
A second scoped re-review of 116ae5f confirmed flushMu closes the race, then found three minor, documentation-only gaps in what it doesn't say: - Concurrent Flush() calls are now serialized rather than free to run independently, and that's now user-visible behavior worth stating on the exported interface, not just the unexported field. - Calling Flush from a StatGenerator or a Sink's own Flush method now deadlocks instead of recursing indefinitely. Both are misuse, but worth naming since a deadlock has no stack trace pointing at the cause the way a stack-overflow panic would. - Serialization spans the Sink's own flush call, which can block on I/O (confirmed: netSink.Flush blocks on a channel round-trip with its run loop). A manual Flush() can now queue behind a slow or stuck one rather than running concurrently with it. No code change: narrowing flushMu's scope to exclude the Sink call reopens exactly the kind of "shrink the critical section a little" question that cost three rounds of subtle bugs in 116ae5f, and the re-review's own recommendation was to leave it as plain Lock.
Three fixes from PR review: - "A service that tags a Counter or Timer with a user ID..." read as a neutral use case rather than a warning. Leads with "don't" now. - The GOSTATS_PRUNE_IDLE_SECONDS=60 example appeared before the "how to pick a value" guidance, so a reader hit the number before anything said it was illustrative. Moved the guidance first and framed the example as "prune anything idle for more than a minute." (The default flush interval is 5s, not 60s - the 60 was never chosen to match it, but the reordering was worth doing regardless.) - The full explanation belonged in docs/, not the top-level README, which had no docs/ convention to fit into before this. Moved the detail to docs/idle-pruning.md; the README section is now a short pointer to it.
Two more fixes from PR review: - Dropped "a user ID, a request ID" as concrete anti-pattern examples per feedback; "a high-cardinality value" says the same thing without naming specific patterns. - The example idle value assumed the wrong mental model: matching it to how long a leak takes to become noticeable (the ticket's week-long creep) doesn't track - a shorter value bounds cardinality more tightly regardless of the leak's own timescale, since it just reclaims each stale entry sooner. The actual tradeoff is against churn on legitimately-infrequent stats. Documented that, and moved the example to 10 minutes as a safer default for a reader who hasn't audited their own firing patterns yet, not because it matches the ticket.
sokada1221
changed the title
Checked whether this library's one existing internal metric (reserved_tag) has any real consumer in the dashboards repo - it doesn't. With no track record of anyone using a gostats-emitted internal metric, adding two more wasn't worth it: dropped both rather than resolve the earlier open question about their naming shape. Removed the emission, the per-flush live/pruned counting that only existed to feed it, the tests for it, and the corresponding documentation section. The pruning mechanism itself (idle detection, delete, detach, rejoin) is unchanged - this only removes the observability layer on top of it. docs/idle-pruning.md now ends by pointing at your own service's memory metrics as the way to confirm pruning is working, since gostats itself no longer reports anything about it.
"the way you noticed the growth in the first place" assumes the reader is specifically the team that filed OBSX-1114. This is general library documentation any gostats consumer reads, most of whom haven't noticed anything.
"bounds the damage if that happens anyway" read informally. "limits the growth" says the same thing.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
statStorekeeps every uniquecounter/timer/gauge name it has ever seen for the life of the process, with no eviction. A service
that tags a Counter or Timer with a per-request value (user ID, request ID, region+use-case
combinations, etc.) grows memory without limit. This adds opt-in idle-based pruning:
GOSTATS_PRUNE_IDLE_SECONDS(default: unset, disabled) prunes counters and timers that have gonethat many seconds without reporting a changed value.
Counter/Timerreference reattaches to the store onits next write, so the pervasive pattern of resolving a stat once and holding it in a struct field
keeps working correctly across a prune/reattach cycle.
is cheaper (no clock reads, no lock, no sort) and better matches the failure mode encountered by
the reported service. See the
stats.gocomments and commit messages for the full reasoning.Disabled by default, so no existing behavior changes unless a service opts in. When disabled, the
hot
Add/Inc/Setpath is unchanged (a single non-atomic pointer check).Notable fixes found during review
Two independent review rounds surfaced real concurrency bugs, both fixed and covered by regression
tests (see
05b87e5and116ae5ffor full detail):pruned while a write was in flight. Fixed by making rejoin write-driven rather than lookup-driven.
counter.latch()wasn't safe for the concurrent callers the fix introduced, which could underflowa delta and corrupt subsequent reporting. Fixed with a CAS retry loop.
Flush()calls, whichStore's own doc comment explicitly permits. Three rounds of lock-free fixes each verifiedempirically against a stress test and each found to only narrow the race window, not close it -
resolved by serializing
Flush()with a mutex instead, which is cheap sinceFlush()is periodic(every 5-10s), not the hot path this feature keeps lock-free.
Benchmarks
All run with
go test -bench . -benchtime=5000x, Apple M1 Pro. Full commands and rationale for eachin the
BenchmarkXxxdoc comments instats_test.go.vs. master - does this PR regress existing callers who never touch the new env var:
BenchmarkCounterAddBenchmarkCounterIncBenchmarkStoreNewCounterParallelPruning off vs. on, this PR only - cost and effect of opting in:
BenchmarkStoreFlush(2048 counters + 2048 timers)BenchmarkCardinalityFloodBenchmarkCardinalityFloodis the number for the ticket: a flood of one-shot tag combinations staysunbounded without pruning, settles to 0 with it.
Memory footprint:
countergrew from 16 to 48 bytes (TestCounterTimerStructSizes) - the newidle-tracking fields. That's ~18% of the ~183 bytes/counter total heap cost per stat
(
BenchmarkStoreBytesPerStat); the rest is thesync.Mapentry and the key string, both unaffectedby this PR.
Test plan
go test -vet all -race ./...(the repo's CI command) - cleangolangci-lint run ./...- cleanTestConcurrentFlushesDoNotOrphanCounter- 2000/2000 under-race(failed reliably before theflushMufix)-race🤖 Generated with Claude Code