xds: use logging components (#3718)

internal/grpclog/prefixLogger.go

@@ -18,10 +18,15 @@
 
 package grpclog
 
+import (
+	"fmt"
+)
+
 // PrefixLogger does logging with a prefix.
 //
 // Logging method on a nil logs without any prefix.
 type PrefixLogger struct {
+	logger DepthLoggerV2
 	prefix string
 }
 
@@ -30,34 +35,47 @@ func (pl *PrefixLogger) Infof(format string, args ...interface{}) {
 	if pl != nil {
 		// Handle nil, so the tests can pass in a nil logger.
 		format = pl.prefix + format
+		pl.logger.InfoDepth(1, fmt.Sprintf(format, args...))
+		return
 	}
-	Logger.Infof(format, args...)
+	InfoDepth(1, fmt.Sprintf(format, args...))
 }
 
 // Warningf does warning logging.
 func (pl *PrefixLogger) Warningf(format string, args ...interface{}) {
 	if pl != nil {
 		format = pl.prefix + format
+		pl.logger.WarningDepth(1, fmt.Sprintf(format, args...))
+		return
 	}
-	Logger.Warningf(format, args...)
+	WarningDepth(1, fmt.Sprintf(format, args...))
 }
 
 // Errorf does error logging.
 func (pl *PrefixLogger) Errorf(format string, args ...interface{}) {
 	if pl != nil {
 		format = pl.prefix + format
+		pl.logger.ErrorDepth(1, fmt.Sprintf(format, args...))
+		return
 	}
-	Logger.Errorf(format, args...)
+	ErrorDepth(1, fmt.Sprintf(format, args...))
 }
 
 // Debugf does info logging at verbose level 2.
 func (pl *PrefixLogger) Debugf(format string, args ...interface{}) {
-	if Logger.V(2) {
+	if !Logger.V(2) {
-		pl.Infof(format, args...)
+		return
 	}
+	if pl != nil {
+		// Handle nil, so the tests can pass in a nil logger.
+		format = pl.prefix + format
+		pl.logger.InfoDepth(1, fmt.Sprintf(format, args...))
+		return
+	}
+	InfoDepth(1, fmt.Sprintf(format, args...))
 }
 
 // NewPrefixLogger creates a prefix logger with the given prefix.
-func NewPrefixLogger(prefix string) *PrefixLogger {
+func NewPrefixLogger(logger DepthLoggerV2, prefix string) *PrefixLogger {
-	return &PrefixLogger{prefix: prefix}
+	return &PrefixLogger{logger: logger, prefix: prefix}
 }

xds/internal/balancer/cdsbalancer/cdsbalancer.go

@@ -76,7 +76,7 @@ func (cdsBB) Build(cc balancer.ClientConn, opts balancer.BuildOptions) balancer.
 		bOpts:    opts,
 		updateCh: buffer.NewUnbounded(),
 	}
-	b.logger = grpclog.NewPrefixLogger(loggingPrefix(b))
+	b.logger = prefixLogger((b))
 	b.logger.Infof("Created")
 	go b.run()
 	return b

xds/internal/balancer/cdsbalancer/logging.go

@@ -20,10 +20,15 @@ package cdsbalancer
 
 import (
 	"fmt"
+
+	"google.golang.org/grpc/grpclog"
+	internalgrpclog "google.golang.org/grpc/internal/grpclog"
 )
 
 const prefix = "[cds-lb %p] "
 
-func loggingPrefix(p *cdsBalancer) string {
+var logger = grpclog.Component("xds")
-	return fmt.Sprintf(prefix, p)
+
+func prefixLogger(p *cdsBalancer) *internalgrpclog.PrefixLogger {
+	return internalgrpclog.NewPrefixLogger(logger, fmt.Sprintf(prefix, p))
 }

xds/internal/balancer/edsbalancer/eds.go

@@ -64,7 +64,7 @@ func (b *edsBalancerBuilder) Build(cc balancer.ClientConn, opts balancer.BuildOp
 		childPolicyUpdate: buffer.NewUnbounded(),
 	}
 	loadStore := lrs.NewStore()
-	x.logger = grpclog.NewPrefixLogger(loggingPrefix(x))
+	x.logger = prefixLogger((x))
 	x.edsImpl = newEDSBalancer(x.cc, x.enqueueChildBalancerState, loadStore, x.logger)
 	x.client = newXDSClientWrapper(x.handleEDSUpdate, x.buildOpts, loadStore, x.logger)
 	x.logger.Infof("Created")

xds/internal/balancer/edsbalancer/eds_impl_priority.go

@@ -25,10 +25,8 @@ import (
 	"google.golang.org/grpc/balancer"
 	"google.golang.org/grpc/balancer/base"
 	"google.golang.org/grpc/connectivity"
-	"google.golang.org/grpc/grpclog"
 )
 
-var logger = grpclog.Component("xds")
 var errAllPrioritiesRemoved = errors.New("eds: no locality is provided, all priorities are removed")
 
 // handlePriorityChange handles priority after EDS adds/removes a
@@ -135,13 +133,13 @@ func (edsImpl *edsBalancerImpl) handlePriorityWithNewState(priority priorityType
 	defer edsImpl.priorityMu.Unlock()
 
 	if !edsImpl.priorityInUse.isSet() {
-		logger.Infof("eds: received picker update when no priority is in use (EDS returned an empty list)")
+		edsImpl.logger.Infof("eds: received picker update when no priority is in use (EDS returned an empty list)")
 		return false
 	}
 
 	if edsImpl.priorityInUse.higherThan(priority) {
 		// Lower priorities should all be closed, this is an unexpected update.
-		logger.Infof("eds: received picker update from priority lower then priorityInUse")
+		edsImpl.logger.Infof("eds: received picker update from priority lower then priorityInUse")
 		return false
 	}
 

xds/internal/balancer/edsbalancer/logging.go

@@ -20,10 +20,15 @@ package edsbalancer
 
 import (
 	"fmt"
+
+	"google.golang.org/grpc/grpclog"
+	internalgrpclog "google.golang.org/grpc/internal/grpclog"
 )
 
 const prefix = "[eds-lb %p] "
 
-func loggingPrefix(p *edsBalancer) string {
+var logger = grpclog.Component("xds")
-	return fmt.Sprintf(prefix, p)
+
+func prefixLogger(p *edsBalancer) *internalgrpclog.PrefixLogger {
+	return internalgrpclog.NewPrefixLogger(logger, fmt.Sprintf(prefix, p))
 }

xds/internal/balancer/weightedtarget/logging.go

@@ -20,10 +20,15 @@ package weightedtarget
 
 import (
 	"fmt"
+
+	"google.golang.org/grpc/grpclog"
+	internalgrpclog "google.golang.org/grpc/internal/grpclog"
 )
 
 const prefix = "[weighted-target-lb %p] "
 
-func loggingPrefix(p *weightedTargetBalancer) string {
+var logger = grpclog.Component("xds")
-	return fmt.Sprintf(prefix, p)
+
+func prefixLogger(p *weightedTargetBalancer) *internalgrpclog.PrefixLogger {
+	return internalgrpclog.NewPrefixLogger(logger, fmt.Sprintf(prefix, p))
 }

xds/internal/balancer/weightedtarget/weightedtarget.go

@@ -43,7 +43,7 @@ type weightedTargetBB struct{}
 
 func (wt *weightedTargetBB) Build(cc balancer.ClientConn, _ balancer.BuildOptions) balancer.Balancer {
 	b := &weightedTargetBalancer{}
-	b.logger = grpclog.NewPrefixLogger(loggingPrefix(b))
+	b.logger = prefixLogger((b))
 	b.bg = balancergroup.New(cc, nil, b.logger)
 	b.bg.Start()
 	b.logger.Infof("Created")

xds/internal/client/bootstrap/logging.go

@@ -18,8 +18,11 @@
 
 package bootstrap
 
-import "google.golang.org/grpc/internal/grpclog"
+import (
+	"google.golang.org/grpc/grpclog"
+	internalgrpclog "google.golang.org/grpc/internal/grpclog"
+)
 
 const prefix = "[xds-bootstrap] "
 
-var logger = grpclog.NewPrefixLogger(prefix)
+var logger = internalgrpclog.NewPrefixLogger(grpclog.Component("xds"), prefix)

xds/internal/client/client.go

@@ -128,7 +128,7 @@ func New(opts Options) (*Client, error) {
 		return nil, fmt.Errorf("xds: failed to dial balancer {%s}: %v", opts.Config.BalancerName, err)
 	}
 	c.cc = cc
-	c.logger = grpclog.NewPrefixLogger(loggingPrefix(c))
+	c.logger = prefixLogger((c))
 	c.logger.Infof("Created ClientConn to xDS server: %s", opts.Config.BalancerName)
 
 	c.v2c = newXDSV2Client(c, cc, opts.Config.NodeProto, backoff.DefaultExponential.Backoff, c.logger)

xds/internal/client/client_loadreport.go

@@ -24,14 +24,11 @@ import (
 	"github.com/golang/protobuf/proto"
 	structpb "github.com/golang/protobuf/ptypes/struct"
 	"google.golang.org/grpc"
-	"google.golang.org/grpc/grpclog"
 	"google.golang.org/grpc/xds/internal/balancer/lrs"
 )
 
 const nodeMetadataHostnameKey = "PROXYLESS_CLIENT_HOSTNAME"
 
-var logger = grpclog.Component("xds")
-
 // ReportLoad sends the load of the given clusterName from loadStore to the
 // given server. If the server is not an empty string, and is different from the
 // xds server, a new ClientConn will be created.
@@ -55,7 +52,7 @@ func (c *Client) ReportLoad(server string, clusterName string, loadStore lrs.Sto
 		ccNew, err := grpc.Dial(server, dopts...)
 		if err != nil {
 			// An error from a non-blocking dial indicates something serious.
-			logger.Infof("xds: failed to dial load report server {%s}: %v", server, err)
+			c.logger.Infof("xds: failed to dial load report server {%s}: %v", server, err)
 			return func() {}
 		}
 		cc = ccNew

xds/internal/client/client_logging.go

@@ -20,10 +20,15 @@ package client
 
 import (
 	"fmt"
+
+	"google.golang.org/grpc/grpclog"
+	internalgrpclog "google.golang.org/grpc/internal/grpclog"
 )
 
 const prefix = "[xds-client %p] "
 
-func loggingPrefix(p *Client) string {
+var logger = grpclog.Component("xds")
-	return fmt.Sprintf(prefix, p)
+
+func prefixLogger(p *Client) *internalgrpclog.PrefixLogger {
+	return internalgrpclog.NewPrefixLogger(logger, fmt.Sprintf(prefix, p))
 }

xds/internal/resolver/logging.go

@@ -20,10 +20,15 @@ package resolver
 
 import (
 	"fmt"
+
+	"google.golang.org/grpc/grpclog"
+	internalgrpclog "google.golang.org/grpc/internal/grpclog"
 )
 
 const prefix = "[xds-resolver %p] "
 
-func loggingPrefix(p *xdsResolver) string {
+var logger = grpclog.Component("xds")
-	return fmt.Sprintf(prefix, p)
+
+func prefixLogger(p *xdsResolver) *internalgrpclog.PrefixLogger {
+	return internalgrpclog.NewPrefixLogger(logger, fmt.Sprintf(prefix, p))
 }

xds/internal/resolver/xds_resolver.go

@@ -64,7 +64,7 @@ func (b *xdsResolverBuilder) Build(t resolver.Target, cc resolver.ClientConn, rb
 		cc:       cc,
 		updateCh: make(chan suWithError, 1),
 	}
-	r.logger = grpclog.NewPrefixLogger(loggingPrefix(r))
+	r.logger = prefixLogger((r))
 	r.logger.Infof("Creating resolver for target: %+v", t)
 
 	if config.Creds == nil {