resource_control: creation race lets calcAvg compute 0/0, permanently poisoning avgRUPerSec with NaN (likely root cause of #9455) #11022

Bug Report

What did you do?

Ran periodic batch jobs on a v8.5.4-based production cluster (the PD server includes #9751, i.e. the release-8.5 cherry-pick of #9597) against a resource group configured as fill_rate=2147483647, burst_limit=-1 (unlimited). Since the group is only touched by periodic batches, the TiDB-embedded resource group controllers (pd/client/resource_group/controller) for it are repeatedly deleted by the 5-minute idle cleanup and recreated when the next batch window starts, on ~20 TiDB nodes.

What did you see instead?

The PD leader occasionally emits a burst of the following ERROR (twice within one week, lasting ~9 min and ~6 min respectively), i.e. the guard added by #9597 keeps firing:

[ERROR] [token_buckets.go:372] ["assigned token is invalid"] [client-unique-id=<tidb-server-id>] [target-period-ms=5000] [required-token=NaN] [assigned-tokens=NaN] [slot-fill-rate=2147483647] [slot-burst-limit=-1] [slot-require-tokens-sum=0] [slot-token-capacity=0] [slot-last-token-capacity=0] [resource-group-name=<group>] [settings="fill_rate:2147483647 burst_limit:-1 "] [tokens=0] [client-consumption-tokens-sum=0] [slot-len=1]

The guard works as designed (log + resetLoan() + empty grant), but the client keeps sending required-token=NaN on every report cycle until its controller is garbage-collected.

Root cause analysis

Key observation: in BOTH occurrences, the first NaN request hit PD exactly 1 ms after one single TiDB node logged create resource group cost controller for that group:

Other TiDB nodes that created their controller for the same group within the same seconds (creation storm at the batch-window start) were all fine. So the NaN is already present in the very first token-bucket request of a freshly created groupCostController; long-running moving-average drift cannot explain this timing.

Mechanism (line numbers from release-8.5 / v8.5.4; the same code exists on current master in global_controller.go / group_controller.go):

1. The main loop's stateUpdateTicker branch runs three separate sync.Map.Range passes: executeOnAllGroups(updateRunState) → executeOnAllGroups(updateAvgRequestResourcePerSec) → collectTokenBucketRequests (another Range internally).

2. A SQL goroutine can concurrently create and publish a new groupCostController (tryGetResourceGroupController → newGroupCostController → loadOrStoreGroupController). initRunState sets gc.run.now and counter.avgLastTime to the same time.Now() value.

3. If the store lands between pass 1 and pass 2, the new controller misses updateRunState for this tick but participates in updateAvgRequestResourcePerSec. calcAvg then computes:

   deltaDuration := gc.run.now.Sub(counter.avgLastTime) // exactly 0: identical monotonic reading
   delta := (new - counter.avgRUPerSecLastRU) / deltaDuration.Seconds() // (0-0)/0 = NaN
   counter.avgRUPerSec = movingAvgFactor*counter.avgRUPerSec + (1-movingAvgFactor)*delta // NaN, forever

   (the deltaDuration = 100 * time.Millisecond line above it is failpoint-only, so production has no zero guard)

4. Pass 3 sends the request in the same tick: calcRequest = NaN*targetPeriod*amplification - AvailableTokens = NaN, and the if value < 0 clamp does not catch NaN → required-token=NaN reaches PD ~1 ms after creation.

5. For a burst_limit=-1 group, PD's assignSlotTokens echoes res.Tokens = requiredToken, so before fix(resourcemanager): add validation for token assignment anomaly #9597 the NaN was granted back to the client — which is presumably how TiFlash ended up hanging in Global Admission Controller return Nan tokens #9455. With fix(resourcemanager): add validation for token assignment anomaly #9597 the request is rejected and the slot reset, so the only remaining symptom is the ERROR burst.

6. movingAvgFactor = 0.5 keeps avgRUPerSec NaN on every subsequent cycle. The tracked consumption itself stays finite, so equalRU still works and the idle cleanup (5 min, two sweeps) eventually deletes the poisoned controller — the burst self-heals and the next creation is clean.

All secondary observations match this mechanism:

• Report cadence during the bursts: every ~5 s while the group is active (defaultTargetPeriod), every ~20-21 s while idle (extendedReportingPeriodFactor = 4).
• slot-len=1 on PD: the other nodes' required-token=0 requests do not create/keep slots in balanceSlotTokens; only the NaN sender holds a slot (NaN != 0).
• The bursts end exactly when the idle cleanup would delete the controller, and the node recreates a clean controller minutes later.
• No client impact for the unlimited group: burstable=true skips the limiter in OnRequestWait, resource_manager_client_request_fail{types others/throttled} and retry counters stayed 0, token RPCs all succeeded (empty grant, not an RPC error), no degraded mode (DegradedModeWaitDuration defaults to 0).

The race window is microseconds wide (between two Range passes inside one tick), which matches the observed frequency: ~2 occurrences per week with ~20 nodes recreating controllers every 5-15 minutes.

What did you expect to see?

calcAvg should never produce NaN; a freshly created controller should send required-token=0 on its first report.

Suggested fix

• Minimal: skip the sample (or clamp to a minimum duration) in calcAvg when deltaDuration <= 0.
• More structural: fuse updateRunState and updateAvgRequestResourcePerSec into a single Range pass so a controller can never execute the latter without the former, and/or initialize avgLastTime slightly in the past.
• Add a regression test that publishes a new groupCostController between the two passes.

What version of PD are you using?

• PD server: v8.5.4 (includes the fix(resourcemanager): add validation for token assignment anomaly (#9597) #9751 guard, which is why the NaN was intercepted and logged instead of granted).
• Client: tikv/pd/client at release-8.5 (2025-09) embedded in a v8.5.4-based TiDB build. The same unguarded calcAvg and the split Range passes are present on current master (client/resource_group/controller/group_controller.go / global_controller.go).

Ref #9455 — this appears to be the client-side root cause that was still marked as unidentified there.