From 9a50255515b5e381fff7f3a7448e37a2c567ee90 Mon Sep 17 00:00:00 2001 From: Gyuho Lee Date: Tue, 2 Jan 2018 07:39:04 -0800 Subject: [PATCH 1/4] etcdserver/api/v3rpc: log stream error with debug level Signed-off-by: Gyuho Lee --- etcdserver/api/v3rpc/lease.go | 4 ++-- etcdserver/api/v3rpc/watch.go | 8 ++++---- 2 files changed, 6 insertions(+), 6 deletions(-) diff --git a/etcdserver/api/v3rpc/lease.go b/etcdserver/api/v3rpc/lease.go index b9c6b268645..13602b4e652 100644 --- a/etcdserver/api/v3rpc/lease.go +++ b/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 } } diff --git a/etcdserver/api/v3rpc/watch.go b/etcdserver/api/v3rpc/watch.go index e29c4210b62..b2f8169ded9 100644 --- a/etcdserver/api/v3rpc/watch.go +++ b/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 } } From 9e11ef3ad53993eec55a25efc417269a7812ca70 Mon Sep 17 00:00:00 2001 From: Gyuho Lee Date: Tue, 2 Jan 2018 07:40:50 -0800 Subject: [PATCH 2/4] etcdserver,embed: discard gRPC info logs when debug is off Signed-off-by: Gyuho Lee --- embed/etcd.go | 1 + etcdserver/api/v3rpc/grpc.go | 13 +++++++++---- etcdserver/config.go | 2 ++ 3 files changed, 12 insertions(+), 4 deletions(-) diff --git a/embed/etcd.go b/embed/etcd.go index e5da45ad80f..d36d732a62c 100644 --- a/embed/etcd.go +++ b/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 { diff --git a/etcdserver/api/v3rpc/grpc.go b/etcdserver/api/v3rpc/grpc.go index 3fd8e864a0f..5adb3e6efa8 100644 --- a/etcdserver/api/v3rpc/grpc.go +++ b/etcdserver/api/v3rpc/grpc.go @@ -16,6 +16,7 @@ package v3rpc import ( "crypto/tls" + "io/ioutil" "math" "os" @@ -36,10 +37,6 @@ const ( maxSendBytes = math.MaxInt32 ) -func init() { - grpclog.SetLoggerV2(grpclog.NewLoggerV2(os.Stderr, os.Stderr, os.Stderr)) -} - func Server(s *etcdserver.EtcdServer, tls *tls.Config, gopts ...grpc.ServerOption) *grpc.Server { var opts []grpc.ServerOption opts = append(opts, grpc.CustomCodec(&codec{})) @@ -70,5 +67,13 @@ 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) + 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 } diff --git a/etcdserver/config.go b/etcdserver/config.go index 80d8219436e..249e8d5fc13 100644 --- a/etcdserver/config.go +++ b/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 From 5b2f5150d9c15315c590e8dc12ff24d9f507ddf4 Mon Sep 17 00:00:00 2001 From: Gyuho Lee Date: Tue, 2 Jan 2018 10:00:29 -0800 Subject: [PATCH 3/4] etcdserver/api/v3rpc: set grpclog once Signed-off-by: Gyuho Lee --- etcdserver/api/v3rpc/grpc.go | 23 +++++++++++++++-------- 1 file changed, 15 insertions(+), 8 deletions(-) diff --git a/etcdserver/api/v3rpc/grpc.go b/etcdserver/api/v3rpc/grpc.go index 5adb3e6efa8..39776b444d1 100644 --- a/etcdserver/api/v3rpc/grpc.go +++ b/etcdserver/api/v3rpc/grpc.go @@ -19,6 +19,7 @@ import ( "io/ioutil" "math" "os" + "sync" "github.com/coreos/etcd/etcdserver" pb "github.com/coreos/etcd/etcdserver/etcdserverpb" @@ -37,6 +38,9 @@ const ( maxSendBytes = math.MaxInt32 ) +// 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 opts = append(opts, grpc.CustomCodec(&codec{})) @@ -67,13 +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) - 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)) - } + 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 } From e567d94fc23892e066cc53c3173f95048ef48cc0 Mon Sep 17 00:00:00 2001 From: Gyuho Lee Date: Tue, 2 Jan 2018 11:00:42 -0800 Subject: [PATCH 4/4] tools/functional-tester: remove duplicate grpclog set Signed-off-by: Gyuho Lee --- tools/functional-tester/etcd-tester/stresser.go | 4 ---- 1 file changed, 4 deletions(-) diff --git a/tools/functional-tester/etcd-tester/stresser.go b/tools/functional-tester/etcd-tester/stresser.go index 4c5cdcef63c..f9ab3f9fbc6 100644 --- a/tools/functional-tester/etcd-tester/stresser.go +++ b/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