diff --git a/internal/balancergroup/balancergroup.go b/internal/balancergroup/balancergroup.go index 8177fb58da9a..4cee66aeb6e6 100644 --- a/internal/balancergroup/balancergroup.go +++ b/internal/balancergroup/balancergroup.go @@ -328,6 +328,11 @@ func (bg *BalancerGroup) AddWithClientConn(id, balancerName string, cc balancer. // caching is disabled. if bg.outgoingStarted && bg.deletedBalancerCache != nil { if old, ok := bg.deletedBalancerCache.Remove(id); ok { + if bg.logger.V(2) { + bg.logger.Infof("Removing and reusing child policy of type %q for locality %q from the balancer cache", balancerName, id) + bg.logger.Infof("Number of items remaining in the balancer cache: %d", bg.deletedBalancerCache.Len()) + } + sbc, _ = old.(*subBalancerWrapper) if sbc != nil && sbc.builder != builder { // If the sub-balancer in cache was built with a different @@ -403,7 +408,7 @@ func (bg *BalancerGroup) Remove(id string) { sbToRemove, ok := bg.idToBalancerConfig[id] if !ok { - bg.logger.Infof("balancer group: trying to remove a non-existing locality from balancer group: %v", id) + bg.logger.Errorf("Child policy for locality %q does not exist in the balancer group", id) bg.outgoingMu.Unlock() return } @@ -418,7 +423,17 @@ func (bg *BalancerGroup) Remove(id string) { } if bg.deletedBalancerCache != nil { + if bg.logger.V(2) { + bg.logger.Infof("Adding child policy for locality %q to the balancer cache", id) + bg.logger.Infof("Number of items remaining in the balancer cache: %d", bg.deletedBalancerCache.Len()) + } + bg.deletedBalancerCache.Add(id, sbToRemove, func() { + if bg.logger.V(2) { + bg.logger.Infof("Removing child policy for locality %q from the balancer cache after timeout", id) + bg.logger.Infof("Number of items remaining in the balancer cache: %d", bg.deletedBalancerCache.Len()) + } + // A sub-balancer evicted from the timeout cache needs to closed // and its subConns need to removed, unconditionally. There is a // possibility that a sub-balancer might be removed (thereby diff --git a/internal/cache/timeoutCache.go b/internal/cache/timeoutCache.go index 3f2d47302c4e..2fa48701023d 100644 --- a/internal/cache/timeoutCache.go +++ b/internal/cache/timeoutCache.go @@ -142,3 +142,10 @@ func (c *TimeoutCache) Clear(runCallback bool) { entry.callback() } } + +// Len returns the number of entries in the cache. +func (c *TimeoutCache) Len() int { + c.mu.Lock() + defer c.mu.Unlock() + return len(c.cache) +} diff --git a/internal/cache/timeoutCache_test.go b/internal/cache/timeoutCache_test.go index 106ea7c911d7..0a6ab39ef431 100644 --- a/internal/cache/timeoutCache_test.go +++ b/internal/cache/timeoutCache_test.go @@ -58,6 +58,9 @@ func (s) TestCacheExpire(t *testing.T) { if gotV, ok := c.getForTesting(k); !ok || gotV.item != v { t.Fatalf("After Add(), before timeout, from cache got: %v, %v, want %v, %v", gotV.item, ok, v, true) } + if l := c.Len(); l != 1 { + t.Fatalf("%d number of items in the cache, want 1", l) + } select { case <-callbackChan: @@ -68,6 +71,9 @@ func (s) TestCacheExpire(t *testing.T) { if _, ok := c.getForTesting(k); ok { t.Fatalf("After Add(), after timeout, from cache got: _, %v, want _, %v", ok, false) } + if l := c.Len(); l != 0 { + t.Fatalf("%d number of items in the cache, want 0", l) + } } // TestCacheRemove attempts to remove an existing entry from the cache and @@ -83,6 +89,9 @@ func (s) TestCacheRemove(t *testing.T) { if got, ok := c.getForTesting(k); !ok || got.item != v { t.Fatalf("After Add(), before timeout, from cache got: %v, %v, want %v, %v", got.item, ok, v, true) } + if l := c.Len(); l != 1 { + t.Fatalf("%d number of items in the cache, want 1", l) + } time.Sleep(testCacheTimeout / 2) @@ -94,6 +103,9 @@ func (s) TestCacheRemove(t *testing.T) { if _, ok := c.getForTesting(k); ok { t.Fatalf("After Add(), before timeout, after Remove(), from cache got: _, %v, want _, %v", ok, false) } + if l := c.Len(); l != 0 { + t.Fatalf("%d number of items in the cache, want 0", l) + } select { case <-callbackChan: @@ -133,6 +145,9 @@ func (s) TestCacheClearWithoutCallback(t *testing.T) { t.Fatalf("After Add(), before timeout, from cache got: %v, %v, want %v, %v", got.item, ok, v, true) } } + if l := c.Len(); l != itemCount { + t.Fatalf("%d number of items in the cache, want %d", l, itemCount) + } time.Sleep(testCacheTimeout / 2) c.Clear(false) @@ -142,6 +157,9 @@ func (s) TestCacheClearWithoutCallback(t *testing.T) { t.Fatalf("After Add(), before timeout, after Remove(), from cache got: _, %v, want _, %v", ok, false) } } + if l := c.Len(); l != 0 { + t.Fatalf("%d number of items in the cache, want 0", l) + } select { case <-callbackChan: @@ -188,6 +206,9 @@ func (s) TestCacheClearWithCallback(t *testing.T) { t.Fatalf("After Add(), before timeout, from cache got: %v, %v, want %v, %v", got.item, ok, v, true) } } + if l := c.Len(); l != itemCount { + t.Fatalf("%d number of items in the cache, want %d", l, itemCount) + } time.Sleep(testCacheTimeout / 2) c.Clear(true) @@ -197,6 +218,9 @@ func (s) TestCacheClearWithCallback(t *testing.T) { t.Fatalf("After Add(), before timeout, after Remove(), from cache got: _, %v, want _, %v", ok, false) } } + if l := c.Len(); l != 0 { + t.Fatalf("%d number of items in the cache, want 0", l) + } select { case <-allGoroutineDone: