Merge pull request #9080 from gyuho/log-debug

etcdserver: log stream error with debug level, silence gRPC server info level logs

embed/etcd.go

@@ -179,6 +179,7 @@ func StartEtcd(inCfg *Config) (e *Etcd, err error) {
 		AuthToken:               cfg.AuthToken,
 		InitialCorruptCheck:     cfg.ExperimentalInitialCorruptCheck,
 		CorruptCheckTime:        cfg.ExperimentalCorruptCheckTime,
+		Debug:                   cfg.Debug,
 	}
 
 	if e.Server, err = etcdserver.NewServer(srvcfg); err != nil {

etcdserver/api/v3rpc/grpc.go

@@ -16,8 +16,10 @@ package v3rpc
 
 import (
 	"crypto/tls"
+	"io/ioutil"
 	"math"
 	"os"
+	"sync"
 
 	"github.com/coreos/etcd/etcdserver"
 	pb "github.com/coreos/etcd/etcdserver/etcdserverpb"
@@ -36,9 +38,8 @@ const (
 	maxSendBytes      = math.MaxInt32
 )
 
-func init() {
-	grpclog.SetLoggerV2(grpclog.NewLoggerV2(os.Stderr, os.Stderr, os.Stderr))
-}
+// integration tests call this multiple times, which is racey in gRPC side
+var grpclogOnce sync.Once
 
 func Server(s *etcdserver.EtcdServer, tls *tls.Config, gopts ...grpc.ServerOption) *grpc.Server {
 	var opts []grpc.ServerOption
@@ -70,5 +71,16 @@ func Server(s *etcdserver.EtcdServer, tls *tls.Config, gopts ...grpc.ServerOptio
 	// set zero values for metrics registered for this grpc server
 	grpc_prometheus.Register(grpcServer)
 
+	grpclogOnce.Do(func() {
+		if s.Cfg.Debug {
+			grpc.EnableTracing = true
+			// enable info, warning, error
+			grpclog.SetLoggerV2(grpclog.NewLoggerV2(os.Stderr, os.Stderr, os.Stderr))
+		} else {
+			// only discard info
+			grpclog.SetLoggerV2(grpclog.NewLoggerV2(ioutil.Discard, os.Stderr, os.Stderr))
+		}
+	})
+
 	return grpcServer
 }

etcdserver/api/v3rpc/lease.go

@@ -107,7 +107,7 @@ func (ls *LeaseServer) leaseKeepAlive(stream pb.Lease_LeaseKeepAliveServer) erro
 			return nil
 		}
 		if err != nil {
-			plog.Warningf("failed to receive lease keepalive request from gRPC stream (%q)", err.Error())
+			plog.Debugf("failed to receive lease keepalive request from gRPC stream (%q)", err.Error())
 			return err
 		}
 
@@ -133,7 +133,7 @@ func (ls *LeaseServer) leaseKeepAlive(stream pb.Lease_LeaseKeepAliveServer) erro
 		resp.TTL = ttl
 		err = stream.Send(resp)
 		if err != nil {
-			plog.Warningf("failed to send lease keepalive response to gRPC stream (%q)", err.Error())
+			plog.Debugf("failed to send lease keepalive response to gRPC stream (%q)", err.Error())
 			return err
 		}
 	}

etcdserver/api/v3rpc/watch.go

@@ -140,7 +140,7 @@ func (ws *watchServer) Watch(stream pb.Watch_WatchServer) (err error) {
 	// deadlock when calling sws.close().
 	go func() {
 		if rerr := sws.recvLoop(); rerr != nil {
-			plog.Warningf("failed to receive watch request from gRPC stream (%q)", rerr.Error())
+			plog.Debugf("failed to receive watch request from gRPC stream (%q)", rerr.Error())
 			errc <- rerr
 		}
 	}()
@@ -339,7 +339,7 @@ func (sws *serverWatchStream) sendLoop() {
 
 			mvcc.ReportEventReceived(len(evs))
 			if err := sws.gRPCStream.Send(wr); err != nil {
-				plog.Warningf("failed to send watch response to gRPC stream (%q)", err.Error())
+				plog.Debugf("failed to send watch response to gRPC stream (%q)", err.Error())
 				return
 			}
 
@@ -356,7 +356,7 @@ func (sws *serverWatchStream) sendLoop() {
 			}
 
 			if err := sws.gRPCStream.Send(c); err != nil {
-				plog.Warningf("failed to send watch control response to gRPC stream (%q)", err.Error())
+				plog.Debugf("failed to send watch control response to gRPC stream (%q)", err.Error())
 				return
 			}
 
@@ -372,7 +372,7 @@ func (sws *serverWatchStream) sendLoop() {
 				for _, v := range pending[wid] {
 					mvcc.ReportEventReceived(len(v.Events))
 					if err := sws.gRPCStream.Send(v); err != nil {
-						plog.Warningf("failed to send pending watch response to gRPC stream (%q)", err.Error())
+						plog.Debugf("failed to send pending watch response to gRPC stream (%q)", err.Error())
 						return
 					}
 				}

etcdserver/config.go

@@ -70,6 +70,8 @@ type ServerConfig struct {
 	// before serving any peer/client traffic.
 	InitialCorruptCheck bool
 	CorruptCheckTime    time.Duration
+
+	Debug bool
 }
 
 // VerifyBootstrap sanity-checks the initial config for bootstrap case

tools/functional-tester/etcd-tester/stresser.go

@@ -16,17 +16,13 @@ package main
 
 import (
 	"fmt"
-	"os"
 	"strings"
 	"sync"
 	"time"
 
 	"golang.org/x/time/rate"
-	"google.golang.org/grpc/grpclog"
 )
 
-func init() { grpclog.SetLoggerV2(grpclog.NewLoggerV2(os.Stderr, os.Stderr, os.Stderr)) }
-
 type Stresser interface {
 	// Stress starts to stress the etcd cluster
 	Stress() error