xds/internal/balancer/outlierdetection: Add Channelz Logger to Outlie…

…r Detection LB (#6145)
grpc · Apr 25, 2023 · 8628e07 · 8628e07
1 parent 83c460b
commit 8628e07
Show file tree

Hide file tree

Showing 3 changed files with 41 additions and 13 deletions.
diff --git a/xds/internal/balancer/outlierdetection/balancer.go b/xds/internal/balancer/outlierdetection/balancer.go
@@ -26,6 +26,7 @@ import (
 	"errors"
 	"fmt"
 	"math"
+	"strings"
 	"sync"
 	"sync/atomic"
 	"time"
@@ -35,6 +36,7 @@ import (
 	"google.golang.org/grpc/connectivity"
 	"google.golang.org/grpc/internal/balancer/gracefulswitch"
 	"google.golang.org/grpc/internal/buffer"
+	"google.golang.org/grpc/internal/channelz"
 	"google.golang.org/grpc/internal/envconfig"
 	"google.golang.org/grpc/internal/grpclog"
 	"google.golang.org/grpc/internal/grpcrand"
@@ -62,13 +64,14 @@ type bb struct{}
 
 func (bb) Build(cc balancer.ClientConn, bOpts balancer.BuildOptions) balancer.Balancer {
 	b := &outlierDetectionBalancer{
-		cc:             cc,
-		closed:         grpcsync.NewEvent(),
-		done:           grpcsync.NewEvent(),
-		addrs:          make(map[string]*addressInfo),
-		scWrappers:     make(map[balancer.SubConn]*subConnWrapper),
-		scUpdateCh:     buffer.NewUnbounded(),
-		pickerUpdateCh: buffer.NewUnbounded(),
+		cc:               cc,
+		closed:           grpcsync.NewEvent(),
+		done:             grpcsync.NewEvent(),
+		addrs:            make(map[string]*addressInfo),
+		scWrappers:       make(map[balancer.SubConn]*subConnWrapper),
+		scUpdateCh:       buffer.NewUnbounded(),
+		pickerUpdateCh:   buffer.NewUnbounded(),
+		channelzParentID: bOpts.ChannelzParentID,
 	}
 	b.logger = prefixLogger(b)
 	b.logger.Infof("Created")
@@ -159,10 +162,11 @@ type outlierDetectionBalancer struct {
 	// to suppress redundant picker updates.
 	recentPickerNoop bool
 
-	closed *grpcsync.Event
-	done   *grpcsync.Event
-	cc     balancer.ClientConn
-	logger *grpclog.PrefixLogger
+	closed           *grpcsync.Event
+	done             *grpcsync.Event
+	cc               balancer.ClientConn
+	logger           *grpclog.PrefixLogger
+	channelzParentID *channelz.Identifier
 
 	// childMu guards calls into child (to uphold the balancer.Balancer API
 	// guarantee of synchronous calls).
@@ -822,7 +826,10 @@ func (b *outlierDetectionBalancer) successRateAlgorithm() {
 			return
 		}
 		successRate := float64(bucket.numSuccesses) / float64(bucket.numSuccesses+bucket.numFailures)
-		if successRate < (mean - stddev*(float64(ejectionCfg.StdevFactor)/1000)) {
+		requiredSuccessRate := mean - stddev*(float64(ejectionCfg.StdevFactor)/1000)
+		if successRate < requiredSuccessRate {
+			channelz.Infof(logger, b.channelzParentID, "SuccessRate algorithm detected outlier: %s. Parameters: successRate=%f, mean=%f, stddev=%f, requiredSuccessRate=%f",
+				addrInfo.string(), successRate, mean, stddev, requiredSuccessRate)
 			if uint32(grpcrand.Int31n(100)) < ejectionCfg.EnforcementPercentage {
 				b.ejectAddress(addrInfo)
 			}
@@ -849,6 +856,8 @@ func (b *outlierDetectionBalancer) failurePercentageAlgorithm() {
 		}
 		failurePercentage := (float64(bucket.numFailures) / float64(bucket.numSuccesses+bucket.numFailures)) * 100
 		if failurePercentage > float64(b.cfg.FailurePercentageEjection.Threshold) {
+			channelz.Infof(logger, b.channelzParentID, "FailurePercentage algorithm detected outlier: %s, failurePercentage=%f",
+				addrInfo.string(), failurePercentage)
 			if uint32(grpcrand.Int31n(100)) < ejectionCfg.EnforcementPercentage {
 				b.ejectAddress(addrInfo)
 			}
@@ -863,7 +872,9 @@ func (b *outlierDetectionBalancer) ejectAddress(addrInfo *addressInfo) {
 	addrInfo.ejectionTimeMultiplier++
 	for _, sbw := range addrInfo.sws {
 		sbw.eject()
+		channelz.Infof(logger, b.channelzParentID, "Subchannel ejected: %s", sbw.string())
 	}
+
 }
 
 // Caller must hold b.mu.
@@ -872,6 +883,7 @@ func (b *outlierDetectionBalancer) unejectAddress(addrInfo *addressInfo) {
 	addrInfo.latestEjectionTimestamp = time.Time{}
 	for _, sbw := range addrInfo.sws {
 		sbw.uneject()
+		channelz.Infof(logger, b.channelzParentID, "Subchannel unejected: %s", sbw.string())
 	}
 }
 
@@ -896,6 +908,16 @@ type addressInfo struct {
 	sws []*subConnWrapper
 }
 
+func (a *addressInfo) string() string {
+	var res strings.Builder
+	res.WriteString("[")
+	for _, sw := range a.sws {
+		res.WriteString(sw.string())
+	}
+	res.WriteString("]")
+	return res.String()
+}
+
 func newAddressInfo() *addressInfo {
 	return &addressInfo{
 		callCounter: newCallCounter(),

diff --git a/xds/internal/balancer/outlierdetection/balancer_test.go b/xds/internal/balancer/outlierdetection/balancer_test.go
@@ -34,6 +34,7 @@ import (
 	"google.golang.org/grpc/balancer"
 	"google.golang.org/grpc/connectivity"
 	"google.golang.org/grpc/internal/balancer/stub"
+	"google.golang.org/grpc/internal/channelz"
 	"google.golang.org/grpc/internal/grpcsync"
 	"google.golang.org/grpc/internal/grpctest"
 	internalserviceconfig "google.golang.org/grpc/internal/serviceconfig"
@@ -304,7 +305,7 @@ func setup(t *testing.T) (*outlierDetectionBalancer, *testutils.TestClientConn,
 		t.Fatalf("balancer.Get(%q) returned nil", Name)
 	}
 	tcc := testutils.NewTestClientConn(t)
-	odB := builder.Build(tcc, balancer.BuildOptions{})
+	odB := builder.Build(tcc, balancer.BuildOptions{ChannelzParentID: channelz.NewIdentifierForTesting(channelz.RefChannel, time.Now().Unix(), nil)})
 	return odB.(*outlierDetectionBalancer), tcc, odB.Close
 }
 

diff --git a/xds/internal/balancer/outlierdetection/subconn_wrapper.go b/xds/internal/balancer/outlierdetection/subconn_wrapper.go
@@ -18,6 +18,7 @@
 package outlierdetection
 
 import (
+	"fmt"
 	"unsafe"
 
 	"google.golang.org/grpc/balancer"
@@ -66,3 +67,7 @@ func (scw *subConnWrapper) uneject() {
 		isEjected: false,
 	})
 }
+
+func (scw *subConnWrapper) string() string {
+	return fmt.Sprintf("%+v", scw.addresses)
+}