Goroutine leak from controller.(*groupCostController).handleTokenBucketUpdateEvent

[yzhan1]

Bug Report

We noticed an issue where RG goroutines don't get cleaned up properly when the traffic ramp down:

goroutine 5042535512 [select, 1540 minutes]:

github.com/tikv/pd/client/resource_group/controller.(*groupCostController).handleTokenBucketUpdateEvent(0xc023ad4000?, {0x679abb0, 0xc002803040}, {0xc1d66f62a0?, 0xc0e3235560?, 0x9662f80?})
      .../resource_group/controller/controller.go:720 +0x1ea
created by github.com/tikv/pd/client/resource_group/controller.(*ResourceGroupsController).Start.func1 in goroutine 1064
      .../resource_group/controller/controller.go:720 +0x1ea
created by github.com/tikv/pd/client/resource_group/controller.(*ResourceGroupsController).Start.func1 in goroutine 1064
      .../resource_group/controller/controller.go:251 +0x906

We saw thousands of tikv:8252 errors during that window and every time this happens, the TiDB server's goroutine goes up by 100K, and all goroutines are blocked on the above code. This leads to high CPU usage on the TiDB node.

What did you do?

1. Create a RG group with minimal quota RU_PER_SEC=1
2. Send 10K QPS using this RG group

What did you expect to see?

TiDB server's goroutine should be stable. When the traffic ramp down it should recover to lower level.

What did you see instead?

A lot of goroutines from RG package sticked around and didn't get cleaned up.

What version of PD are you using (pd-server -V)?

trace is provided for v7.1.0 but the same can be reproduced on our v8.5.2 cluster.

[yzhan1]

The issue seems to be that:

1. Whenever a new response comes in for RU request,

   pd/client/resource_group/controller/controller.go

   Line 1190 in 53b1fbf

   gc.modifyTokenCounter(counter, grantedTB.GetGrantedTokens(), grantedTB.GetTrickleTimeMs())

   is executed and inits/resets the timer and channel for that request and its subsequent gc goroutine in

   pd/client/resource_group/controller/controller.go

   Line 1240 in 53b1fbf

   initCounterNotify(counter)

   and

   pd/client/resource_group/controller/controller.go

   Line 1270 in 53b1fbf

   counter.notify.setupNotificationTimer = time.NewTimer(timerDuration)

2. Later the groupController itself gets pushed into a channel to create gc goroutines:

   pd/client/resource_group/controller/controller.go

   Line 1277 in 53b1fbf

   case gc.tokenBucketUpdateChan <- gc:

3. Because the RG is short of quota, TiDB kept asking for RUs from PD, and sends many more RU requests. Subsequent RU responses come in, and goes to modifyTokenCounter and initCounterNotify again, where initCounterNotify stops the timer held by the gc goroutines created in step 2:

   pd/client/resource_group/controller/controller.go

   Line 1289 in 53b1fbf

   counter.notify.setupNotificationTimer.Stop()

4. Timer.Stop does not close/end the channel: https://pkg.go.dev/time#Timer.Stop
5. As a result, the gc goroutines are blocked on

   pd/client/resource_group/controller/controller.go

   Line 1070 in 53b1fbf

   case <-ch:

   which will never be signaled

[yzhan1]

Given timer's channel is receiving only, we could add a separate channel to signal the GC goroutines when things are getting closed/stopped.

@nolouch @rleungx WDYT? Feel free to forward to other reviewers/owners of the module. Thanks!

[rleungx]

/cc @JmPotato

[yzhan1]

@JmPotato PTAL #9749 Thanks!