From d6723916d2e73e8824d22a1ba5c52f8e6255e6f8 Mon Sep 17 00:00:00 2001 From: Menghan Li Date: Thu, 13 Jul 2017 12:10:19 -0700 Subject: [PATCH] Use log severity and verbosity level (#1340) - All logs use 1 severity level instead of printf - All transport logs only go to verbose level 2+ - The default logger only log errors and verbosity level 1 - Add environment variable GRPC_GO_LOG_SEVERITY_LEVEL and GRPC_GO_LOG_VERBOSITY_LEVEL to set severity or verbosity levels for the default logger --- balancer.go | 6 ++--- clientconn.go | 6 ++--- grpclb.go | 32 ++++++++++++------------ grpclog/glogger/glogger.go | 26 +++++++++++--------- grpclog/grpclog.go | 10 +++++++- grpclog/logger.go | 3 +-- grpclog/loggerv2.go | 40 +++++++++++++++++++++++------- server.go | 26 ++++++++++---------- transport/http2_client.go | 11 ++++----- transport/http2_server.go | 21 ++++++++-------- transport/http_util.go | 3 +-- transport/log.go | 50 ++++++++++++++++++++++++++++++++++++++ 12 files changed, 156 insertions(+), 78 deletions(-) create mode 100644 transport/log.go diff --git a/balancer.go b/balancer.go index 57c20c6c5180..cde472c8120a 100644 --- a/balancer.go +++ b/balancer.go @@ -157,7 +157,7 @@ type roundRobin struct { func (rr *roundRobin) watchAddrUpdates() error { updates, err := rr.w.Next() if err != nil { - grpclog.Printf("grpc: the naming watcher stops working due to %v.\n", err) + grpclog.Warningf("grpc: the naming watcher stops working due to %v.", err) return err } rr.mu.Lock() @@ -173,7 +173,7 @@ func (rr *roundRobin) watchAddrUpdates() error { for _, v := range rr.addrs { if addr == v.addr { exist = true - grpclog.Println("grpc: The name resolver wanted to add an existing address: ", addr) + grpclog.Infoln("grpc: The name resolver wanted to add an existing address: ", addr) break } } @@ -190,7 +190,7 @@ func (rr *roundRobin) watchAddrUpdates() error { } } default: - grpclog.Println("Unknown update.Op ", update.Op) + grpclog.Errorln("Unknown update.Op ", update.Op) } } // Make a copy of rr.addrs and write it onto rr.addrCh so that gRPC internals gets notified. diff --git a/clientconn.go b/clientconn.go index c09df18ed5e9..fd5c1cf817c5 100644 --- a/clientconn.go +++ b/clientconn.go @@ -632,7 +632,7 @@ func (cc *ClientConn) resetAddrConn(addr Address, block bool, tearDownErr error) // Start a goroutine connecting to the server asynchronously. go func() { if err := ac.resetTransport(false); err != nil { - grpclog.Printf("Failed to dial %s: %v; please retry.", ac.addr.Addr, err) + grpclog.Warningln("Failed to dial %s: %v; please retry.", ac.addr.Addr, err) if err != errConnClosing { // Keep this ac in cc.conns, to get the reason it's torn down. ac.tearDown(err) @@ -868,7 +868,7 @@ func (ac *addrConn) resetTransport(closeTransport bool) error { if e, ok := err.(transport.ConnectionError); ok && !e.Temporary() { return err } - grpclog.Printf("grpc: addrConn.resetTransport failed to create client transport: %v; Reconnecting to %v", err, ac.addr) + grpclog.Warningf("grpc: addrConn.resetTransport failed to create client transport: %v; Reconnecting to %v", err, ac.addr) ac.mu.Lock() if ac.state == Shutdown { // ac.tearDown(...) has been invoked. @@ -973,7 +973,7 @@ func (ac *addrConn) transportMonitor() { ac.mu.Lock() ac.printf("transport exiting: %v", err) ac.mu.Unlock() - grpclog.Printf("grpc: addrConn.transportMonitor exits due to: %v", err) + grpclog.Warningf("grpc: addrConn.transportMonitor exits due to: %v", err) if err != errConnClosing { // Keep this ac in cc.conns, to get the reason it's torn down. ac.tearDown(err) diff --git a/grpclb.go b/grpclb.go index c5bd65225c3b..619985e60824 100644 --- a/grpclb.go +++ b/grpclb.go @@ -137,7 +137,7 @@ type balancer struct { func (b *balancer) watchAddrUpdates(w naming.Watcher, ch chan []remoteBalancerInfo) error { updates, err := w.Next() if err != nil { - grpclog.Printf("grpclb: failed to get next addr update from watcher: %v", err) + grpclog.Warningf("grpclb: failed to get next addr update from watcher: %v", err) return err } b.mu.Lock() @@ -162,13 +162,13 @@ func (b *balancer) watchAddrUpdates(w naming.Watcher, ch chan []remoteBalancerIn md, ok := update.Metadata.(*AddrMetadataGRPCLB) if !ok { // TODO: Revisit the handling here and may introduce some fallback mechanism. - grpclog.Printf("The name resolution contains unexpected metadata %v", update.Metadata) + grpclog.Errorf("The name resolution contains unexpected metadata %v", update.Metadata) continue } switch md.AddrType { case Backend: // TODO: Revisit the handling here and may introduce some fallback mechanism. - grpclog.Printf("The name resolution does not give grpclb addresses") + grpclog.Errorf("The name resolution does not give grpclb addresses") continue case GRPCLB: b.rbs = append(b.rbs, remoteBalancerInfo{ @@ -176,7 +176,7 @@ func (b *balancer) watchAddrUpdates(w naming.Watcher, ch chan []remoteBalancerIn name: md.ServerName, }) default: - grpclog.Printf("Received unknow address type %d", md.AddrType) + grpclog.Errorf("Received unknow address type %d", md.AddrType) continue } case naming.Delete: @@ -188,7 +188,7 @@ func (b *balancer) watchAddrUpdates(w naming.Watcher, ch chan []remoteBalancerIn } } default: - grpclog.Println("Unknown update.Op ", update.Op) + grpclog.Errorf("Unknown update.Op %v", update.Op) } } // TODO: Fall back to the basic round-robin load balancing if the resulting address is @@ -299,7 +299,7 @@ func (b *balancer) sendLoadReport(s *balanceLoadClientStream, interval time.Dura ClientStats: &stats, }, }); err != nil { - grpclog.Printf("grpclb: failed to send load report: %v", err) + grpclog.Errorf("grpclb: failed to send load report: %v", err) return } } @@ -310,7 +310,7 @@ func (b *balancer) callRemoteBalancer(lbc *loadBalancerClient, seq int) (retry b defer cancel() stream, err := lbc.BalanceLoad(ctx) if err != nil { - grpclog.Printf("grpclb: failed to perform RPC to the remote balancer %v", err) + grpclog.Errorf("grpclb: failed to perform RPC to the remote balancer %v", err) return } b.mu.Lock() @@ -327,25 +327,25 @@ func (b *balancer) callRemoteBalancer(lbc *loadBalancerClient, seq int) (retry b }, } if err := stream.Send(initReq); err != nil { - grpclog.Printf("grpclb: failed to send init request: %v", err) + grpclog.Errorf("grpclb: failed to send init request: %v", err) // TODO: backoff on retry? return true } reply, err := stream.Recv() if err != nil { - grpclog.Printf("grpclb: failed to recv init response: %v", err) + grpclog.Errorf("grpclb: failed to recv init response: %v", err) // TODO: backoff on retry? return true } initResp := reply.GetInitialResponse() if initResp == nil { - grpclog.Println("grpclb: reply from remote balancer did not include initial response.") + grpclog.Errorf("grpclb: reply from remote balancer did not include initial response.") return } // TODO: Support delegation. if initResp.LoadBalancerDelegate != "" { // delegation - grpclog.Println("TODO: Delegation is not supported yet.") + grpclog.Errorf("TODO: Delegation is not supported yet.") return } streamDone := make(chan struct{}) @@ -360,7 +360,7 @@ func (b *balancer) callRemoteBalancer(lbc *loadBalancerClient, seq int) (retry b for { reply, err := stream.Recv() if err != nil { - grpclog.Printf("grpclb: failed to recv server list: %v", err) + grpclog.Errorf("grpclb: failed to recv server list: %v", err) break } b.mu.Lock() @@ -394,7 +394,7 @@ func (b *balancer) Start(target string, config BalancerConfig) error { w, err := b.r.Resolve(target) if err != nil { b.mu.Unlock() - grpclog.Printf("grpclb: failed to resolve address: %v, err: %v", target, err) + grpclog.Errorf("grpclb: failed to resolve address: %v, err: %v", target, err) return err } b.w = w @@ -404,7 +404,7 @@ func (b *balancer) Start(target string, config BalancerConfig) error { go func() { for { if err := b.watchAddrUpdates(w, balancerAddrsCh); err != nil { - grpclog.Printf("grpclb: the naming watcher stops working due to %v.\n", err) + grpclog.Warningf("grpclb: the naming watcher stops working due to %v.\n", err) close(balancerAddrsCh) return } @@ -495,7 +495,7 @@ func (b *balancer) Start(target string, config BalancerConfig) error { if creds := config.DialCreds; creds != nil { if rb.name != "" { if err := creds.OverrideServerName(rb.name); err != nil { - grpclog.Printf("grpclb: failed to override the server name in the credentials: %v", err) + grpclog.Warningf("grpclb: failed to override the server name in the credentials: %v", err) continue } } @@ -510,7 +510,7 @@ func (b *balancer) Start(target string, config BalancerConfig) error { ccError = make(chan struct{}) cc, err = Dial(rb.addr, dopts...) if err != nil { - grpclog.Printf("grpclb: failed to setup a connection to the remote balancer %v: %v", rb.addr, err) + grpclog.Warningf("grpclb: failed to setup a connection to the remote balancer %v: %v", rb.addr, err) close(ccError) continue } diff --git a/grpclog/glogger/glogger.go b/grpclog/glogger/glogger.go index 9fdce27d9728..e5498f823a12 100644 --- a/grpclog/glogger/glogger.go +++ b/grpclog/glogger/glogger.go @@ -21,6 +21,8 @@ package glogger import ( + "fmt" + "github.com/golang/glog" "google.golang.org/grpc/grpclog" ) @@ -32,51 +34,51 @@ func init() { type glogger struct{} func (g *glogger) Info(args ...interface{}) { - glog.Info(args...) + glog.InfoDepth(2, args...) } func (g *glogger) Infoln(args ...interface{}) { - glog.Infoln(args...) + glog.InfoDepth(2, fmt.Sprintln(args...)) } func (g *glogger) Infof(format string, args ...interface{}) { - glog.Infof(format, args...) + glog.InfoDepth(2, fmt.Sprintf(format, args...)) } func (g *glogger) Warning(args ...interface{}) { - glog.Warning(args...) + glog.WarningDepth(2, args...) } func (g *glogger) Warningln(args ...interface{}) { - glog.Warningln(args...) + glog.WarningDepth(2, fmt.Sprintln(args...)) } func (g *glogger) Warningf(format string, args ...interface{}) { - glog.Warningf(format, args...) + glog.WarningDepth(2, fmt.Sprintf(format, args...)) } func (g *glogger) Error(args ...interface{}) { - glog.Error(args...) + glog.ErrorDepth(2, args...) } func (g *glogger) Errorln(args ...interface{}) { - glog.Errorln(args...) + glog.ErrorDepth(2, fmt.Sprintln(args...)) } func (g *glogger) Errorf(format string, args ...interface{}) { - glog.Errorf(format, args...) + glog.ErrorDepth(2, fmt.Sprintf(format, args...)) } func (g *glogger) Fatal(args ...interface{}) { - glog.Fatal(args...) + glog.FatalDepth(2, args...) } func (g *glogger) Fatalln(args ...interface{}) { - glog.Fatalln(args...) + glog.FatalDepth(2, fmt.Sprintln(args...)) } func (g *glogger) Fatalf(format string, args ...interface{}) { - glog.Fatalf(format, args...) + glog.FatalDepth(2, fmt.Sprintf(format, args...)) } func (g *glogger) V(l int) bool { diff --git a/grpclog/grpclog.go b/grpclog/grpclog.go index 23f28ec5c664..73d1170975c7 100644 --- a/grpclog/grpclog.go +++ b/grpclog/grpclog.go @@ -31,7 +31,15 @@ * */ -package grpclog +// Package grpclog defines logging for grpc. +// +// All logs in transport package only go to verbose level 2. +// All logs in other packages in grpc are logged in spite of the verbosity level. +// +// In the default logger, +// severity level can be set by environment variable GRPC_GO_LOG_SEVERITY_LEVEL, +// verbosity level can be set by GRPC_GO_LOG_VERBOSITY_LEVEL. +package grpclog // import "google.golang.org/grpc/grpclog" import "os" diff --git a/grpclog/logger.go b/grpclog/logger.go index a87bb05ce825..d03b2397bfab 100644 --- a/grpclog/logger.go +++ b/grpclog/logger.go @@ -16,8 +16,7 @@ * */ -// Package grpclog defines logging for grpc. -package grpclog // import "google.golang.org/grpc/grpclog" +package grpclog // Logger mimics golang's standard Logger as an interface. // Deprecated: use LoggerV2. diff --git a/grpclog/loggerv2.go b/grpclog/loggerv2.go index f0cbfec9a22c..f5193be922fe 100644 --- a/grpclog/loggerv2.go +++ b/grpclog/loggerv2.go @@ -31,16 +31,14 @@ * */ -/* -Package grpclog defines logging for grpc. -*/ -package grpclog // import "google.golang.org/grpc/grpclog" +package grpclog import ( "io" "io/ioutil" "log" "os" + "strconv" ) // LoggerV2 does underlying logging work for grpclog. @@ -104,6 +102,7 @@ var severityName = []string{ // loggerT is the default logger used by grpclog. type loggerT struct { m []*log.Logger + v int } // NewLoggerV2 creates a loggerV2 with the provided writers. @@ -112,19 +111,44 @@ type loggerT struct { // Warning logs will be written to warningW and infoW. // Info logs will be written to infoW. func NewLoggerV2(infoW, warningW, errorW io.Writer) LoggerV2 { + return NewLoggerV2WithVerbosity(infoW, warningW, errorW, 0) +} + +// NewLoggerV2WithVerbosity creates a loggerV2 with the provided writers and +// verbosity level. +func NewLoggerV2WithVerbosity(infoW, warningW, errorW io.Writer, v int) LoggerV2 { var m []*log.Logger m = append(m, log.New(infoW, severityName[infoLog]+": ", log.LstdFlags)) m = append(m, log.New(io.MultiWriter(infoW, warningW), severityName[warningLog]+": ", log.LstdFlags)) ew := io.MultiWriter(infoW, warningW, errorW) // ew will be used for error and fatal. m = append(m, log.New(ew, severityName[errorLog]+": ", log.LstdFlags)) m = append(m, log.New(ew, severityName[fatalLog]+": ", log.LstdFlags)) - return &loggerT{m: m} + return &loggerT{m: m, v: v} } // newLoggerV2 creates a loggerV2 to be used as default logger. // All logs are written to stderr. func newLoggerV2() LoggerV2 { - return NewLoggerV2(os.Stderr, ioutil.Discard, ioutil.Discard) + errorW := ioutil.Discard + warningW := ioutil.Discard + infoW := ioutil.Discard + + logLevel := os.Getenv("GRPC_GO_LOG_SEVERITY_LEVEL") + switch logLevel { + case "", "ERROR", "error": // If env is unset, set level to ERROR. + errorW = os.Stderr + case "WARNING", "warning": + warningW = os.Stderr + case "INFO", "info": + infoW = os.Stderr + } + + var v int + vLevel := os.Getenv("GRPC_GO_LOG_VERBOSITY_LEVEL") + if vl, err := strconv.Atoi(vLevel); err == nil { + v = vl + } + return NewLoggerV2WithVerbosity(infoW, warningW, errorW, v) } func (g *loggerT) Info(args ...interface{}) { @@ -176,7 +200,5 @@ func (g *loggerT) Fatalf(format string, args ...interface{}) { } func (g *loggerT) V(l int) bool { - // Returns true for all verbose level. - // TODO support verbose level in the default logger. - return true + return l <= g.v } diff --git a/server.go b/server.go index 183cd6dca3d2..5e9da3d952c0 100644 --- a/server.go +++ b/server.go @@ -485,7 +485,7 @@ func (s *Server) handleRawConn(rawConn net.Conn) { s.mu.Lock() s.errorf("ServerHandshake(%q) failed: %v", rawConn.RemoteAddr(), err) s.mu.Unlock() - grpclog.Printf("grpc: Server.Serve failed to complete security handshake from %q: %v", rawConn.RemoteAddr(), err) + grpclog.Warningf("grpc: Server.Serve failed to complete security handshake from %q: %v", rawConn.RemoteAddr(), err) // If serverHandShake returns ErrConnDispatched, keep rawConn open. if err != credentials.ErrConnDispatched { rawConn.Close() @@ -530,7 +530,7 @@ func (s *Server) serveHTTP2Transport(c net.Conn, authInfo credentials.AuthInfo) s.errorf("NewServerTransport(%q) failed: %v", c.RemoteAddr(), err) s.mu.Unlock() c.Close() - grpclog.Println("grpc: Server.Serve failed to create ServerTransport: ", err) + grpclog.Warningln("grpc: Server.Serve failed to create ServerTransport: ", err) return } if !s.addConn(st) { @@ -654,7 +654,7 @@ func (s *Server) sendResponse(t transport.ServerTransport, stream *transport.Str } p, err := encode(s.opts.codec, msg, cp, cbuf, outPayload) if err != nil { - grpclog.Println("grpc: server failed to encode response: ", err) + grpclog.Errorln("grpc: server failed to encode response: ", err) return err } if len(p) > s.opts.maxSendMessageSize { @@ -712,7 +712,7 @@ func (s *Server) processUnaryRPC(t transport.ServerTransport, stream *transport. if err != nil { if st, ok := status.FromError(err); ok { if e := t.WriteStatus(stream, st); e != nil { - grpclog.Printf("grpc: Server.processUnaryRPC failed to write status %v", e) + grpclog.Warningf("grpc: Server.processUnaryRPC failed to write status %v", e) } } else { switch st := err.(type) { @@ -720,7 +720,7 @@ func (s *Server) processUnaryRPC(t transport.ServerTransport, stream *transport. // Nothing to do here. case transport.StreamError: if e := t.WriteStatus(stream, status.New(st.Code, st.Desc)); e != nil { - grpclog.Printf("grpc: Server.processUnaryRPC failed to write status %v", e) + grpclog.Warningf("grpc: Server.processUnaryRPC failed to write status %v", e) } default: panic(fmt.Sprintf("grpc: Unexpected error (%T) from recvMsg: %v", st, st)) @@ -732,12 +732,12 @@ func (s *Server) processUnaryRPC(t transport.ServerTransport, stream *transport. if err := checkRecvPayload(pf, stream.RecvCompress(), s.opts.dc); err != nil { if st, ok := status.FromError(err); ok { if e := t.WriteStatus(stream, st); e != nil { - grpclog.Printf("grpc: Server.processUnaryRPC failed to write status %v", e) + grpclog.Warningf("grpc: Server.processUnaryRPC failed to write status %v", e) } return err } if e := t.WriteStatus(stream, status.New(codes.Internal, err.Error())); e != nil { - grpclog.Printf("grpc: Server.processUnaryRPC failed to write status %v", e) + grpclog.Warningf("grpc: Server.processUnaryRPC failed to write status %v", e) } // TODO checkRecvPayload always return RPC error. Add a return here if necessary. @@ -791,7 +791,7 @@ func (s *Server) processUnaryRPC(t transport.ServerTransport, stream *transport. trInfo.tr.SetError() } if e := t.WriteStatus(stream, appStatus); e != nil { - grpclog.Printf("grpc: Server.processUnaryRPC failed to write status: %v", e) + grpclog.Warningf("grpc: Server.processUnaryRPC failed to write status: %v", e) } return appErr } @@ -809,7 +809,7 @@ func (s *Server) processUnaryRPC(t transport.ServerTransport, stream *transport. } if s, ok := status.FromError(err); ok { if e := t.WriteStatus(stream, s); e != nil { - grpclog.Printf("grpc: Server.processUnaryRPC failed to write status: %v", e) + grpclog.Warningf("grpc: Server.processUnaryRPC failed to write status: %v", e) } } else { switch st := err.(type) { @@ -817,7 +817,7 @@ func (s *Server) processUnaryRPC(t transport.ServerTransport, stream *transport. // Nothing to do here. case transport.StreamError: if e := t.WriteStatus(stream, status.New(st.Code, st.Desc)); e != nil { - grpclog.Printf("grpc: Server.processUnaryRPC failed to write status %v", e) + grpclog.Warningf("grpc: Server.processUnaryRPC failed to write status %v", e) } default: panic(fmt.Sprintf("grpc: Unexpected error (%T) from sendResponse: %v", st, st)) @@ -944,7 +944,7 @@ func (s *Server) handleStream(t transport.ServerTransport, stream *transport.Str trInfo.tr.LazyLog(&fmtStringer{"%v", []interface{}{err}}, true) trInfo.tr.SetError() } - grpclog.Printf("grpc: Server.handleStream failed to write status: %v", err) + grpclog.Warningf("grpc: Server.handleStream failed to write status: %v", err) } if trInfo != nil { trInfo.tr.Finish() @@ -969,7 +969,7 @@ func (s *Server) handleStream(t transport.ServerTransport, stream *transport.Str trInfo.tr.LazyLog(&fmtStringer{"%v", []interface{}{err}}, true) trInfo.tr.SetError() } - grpclog.Printf("grpc: Server.handleStream failed to write status: %v", err) + grpclog.Warningf("grpc: Server.handleStream failed to write status: %v", err) } if trInfo != nil { trInfo.tr.Finish() @@ -999,7 +999,7 @@ func (s *Server) handleStream(t transport.ServerTransport, stream *transport.Str trInfo.tr.LazyLog(&fmtStringer{"%v", []interface{}{err}}, true) trInfo.tr.SetError() } - grpclog.Printf("grpc: Server.handleStream failed to write status: %v", err) + grpclog.Warningf("grpc: Server.handleStream failed to write status: %v", err) } if trInfo != nil { trInfo.tr.Finish() diff --git a/transport/http2_client.go b/transport/http2_client.go index 094bb5c038fa..a62f4e31a323 100644 --- a/transport/http2_client.go +++ b/transport/http2_client.go @@ -33,7 +33,6 @@ import ( "golang.org/x/net/http2/hpack" "google.golang.org/grpc/codes" "google.golang.org/grpc/credentials" - "google.golang.org/grpc/grpclog" "google.golang.org/grpc/keepalive" "google.golang.org/grpc/metadata" "google.golang.org/grpc/peer" @@ -953,7 +952,7 @@ func (t *http2Client) handleRSTStream(f *http2.RSTStreamFrame) { } statusCode, ok := http2ErrConvTab[http2.ErrCode(f.ErrCode)] if !ok { - grpclog.Println("transport: http2Client.handleRSTStream found no mapped gRPC status for the received http2 error ", f.ErrCode) + warningf("transport: http2Client.handleRSTStream found no mapped gRPC status for the received http2 error %v", f.ErrCode) statusCode = codes.Unknown } s.finish(status.Newf(statusCode, "stream terminated by RST_STREAM with error code: %d", f.ErrCode)) @@ -989,7 +988,7 @@ func (t *http2Client) handlePing(f *http2.PingFrame) { func (t *http2Client) handleGoAway(f *http2.GoAwayFrame) { if f.ErrCode == http2.ErrCodeEnhanceYourCalm { - grpclog.Printf("Client received GoAway with http2.ErrCodeEnhanceYourCalm.") + infof("Client received GoAway with http2.ErrCodeEnhanceYourCalm.") } t.mu.Lock() if t.state == reachable || t.state == draining { @@ -1189,7 +1188,7 @@ func (t *http2Client) reader() { case *http2.WindowUpdateFrame: t.handleWindowUpdate(frame) default: - grpclog.Printf("transport: http2Client.reader got unhandled frame type %v.", frame) + errorf("transport: http2Client.reader got unhandled frame type %v.", frame) } } } @@ -1256,7 +1255,7 @@ func (t *http2Client) controller() { } t.framer.writePing(true, i.ack, i.data) default: - grpclog.Printf("transport: http2Client.controller got unexpected item type %v\n", i) + errorf("transport: http2Client.controller got unexpected item type %v\n", i) } t.writableChan <- 0 continue @@ -1343,7 +1342,7 @@ func (t *http2Client) notifyError(err error) { if t.state == reachable { t.state = unreachable close(t.errorChan) - grpclog.Printf("transport: http2Client.notifyError got notified that the client transport was broken %v.", err) + infof("transport: http2Client.notifyError got notified that the client transport was broken %v.", err) } t.mu.Unlock() } diff --git a/transport/http2_server.go b/transport/http2_server.go index d188bd88c9fa..5bb283ffca49 100644 --- a/transport/http2_server.go +++ b/transport/http2_server.go @@ -36,7 +36,6 @@ import ( "golang.org/x/net/http2/hpack" "google.golang.org/grpc/codes" "google.golang.org/grpc/credentials" - "google.golang.org/grpc/grpclog" "google.golang.org/grpc/keepalive" "google.golang.org/grpc/metadata" "google.golang.org/grpc/peer" @@ -288,7 +287,7 @@ func (t *http2Server) operateHeaders(frame *http2.MetaHeadersFrame, handle func( } s.ctx, err = t.inTapHandle(s.ctx, info) if err != nil { - grpclog.Printf("transport: http2Server.operateHeaders got an error from InTapHandle: %v", err) + warningf("transport: http2Server.operateHeaders got an error from InTapHandle: %v", err) t.controlBuf.put(&resetStream{s.id, http2.ErrCodeRefusedStream}) return } @@ -306,7 +305,7 @@ func (t *http2Server) operateHeaders(frame *http2.MetaHeadersFrame, handle func( if s.id%2 != 1 || s.id <= t.maxStreamID { t.mu.Unlock() // illegal gRPC stream id. - grpclog.Println("transport: http2Server.HandleStreams received an illegal stream id: ", s.id) + errorf("transport: http2Server.HandleStreams received an illegal stream id: %v", s.id) return true } t.maxStreamID = s.id @@ -344,13 +343,13 @@ func (t *http2Server) HandleStreams(handle func(*Stream), traceCtx func(context. if _, err := io.ReadFull(t.conn, preface); err != nil { // Only log if it isn't a simple tcp accept check (ie: tcp balancer doing open/close socket) if err != io.EOF { - grpclog.Printf("transport: http2Server.HandleStreams failed to receive the preface from client: %v", err) + errorf("transport: http2Server.HandleStreams failed to receive the preface from client: %v", err) } t.Close() return } if !bytes.Equal(preface, clientPreface) { - grpclog.Printf("transport: http2Server.HandleStreams received bogus greeting from client: %q", preface) + errorf("transport: http2Server.HandleStreams received bogus greeting from client: %q", preface) t.Close() return } @@ -361,14 +360,14 @@ func (t *http2Server) HandleStreams(handle func(*Stream), traceCtx func(context. return } if err != nil { - grpclog.Printf("transport: http2Server.HandleStreams failed to read initial settings frame: %v", err) + errorf("transport: http2Server.HandleStreams failed to read initial settings frame: %v", err) t.Close() return } atomic.StoreUint32(&t.activity, 1) sf, ok := frame.(*http2.SettingsFrame) if !ok { - grpclog.Printf("transport: http2Server.HandleStreams saw invalid preface type %T from client", frame) + errorf("transport: http2Server.HandleStreams saw invalid preface type %T from client", frame) t.Close() return } @@ -392,7 +391,7 @@ func (t *http2Server) HandleStreams(handle func(*Stream), traceCtx func(context. t.Close() return } - grpclog.Printf("transport: http2Server.HandleStreams failed to read frame: %v", err) + warningf("transport: http2Server.HandleStreams failed to read frame: %v", err) t.Close() return } @@ -415,7 +414,7 @@ func (t *http2Server) HandleStreams(handle func(*Stream), traceCtx func(context. case *http2.GoAwayFrame: // TODO: Handle GoAway from the client appropriately. default: - grpclog.Printf("transport: http2Server.HandleStreams found unhandled frame type %v.", frame) + errorf("transport: http2Server.HandleStreams found unhandled frame type %v.", frame) } } } @@ -514,7 +513,7 @@ func (t *http2Server) handleData(f *http2.DataFrame) { t.controlBuf.put(bdpPing) } else { if err := t.fc.onData(uint32(size)); err != nil { - grpclog.Printf("transport: http2Server %v", err) + errorf("transport: http2Server %v", err) t.Close() return } @@ -1048,7 +1047,7 @@ func (t *http2Server) controller() { } t.framer.writePing(true, i.ack, i.data) default: - grpclog.Printf("transport: http2Server.controller got unexpected item type %v\n", i) + errorf("transport: http2Server.controller got unexpected item type %v\n", i) } t.writableChan <- 0 continue diff --git a/transport/http_util.go b/transport/http_util.go index 8ecea9291ea5..685c6fbf9678 100644 --- a/transport/http_util.go +++ b/transport/http_util.go @@ -36,7 +36,6 @@ import ( "golang.org/x/net/http2/hpack" spb "google.golang.org/genproto/googleapis/rpc/status" "google.golang.org/grpc/codes" - "google.golang.org/grpc/grpclog" "google.golang.org/grpc/status" ) @@ -283,7 +282,7 @@ func (d *decodeState) processHeaderField(f hpack.HeaderField) error { } v, err := decodeMetadataHeader(f.Name, f.Value) if err != nil { - grpclog.Printf("Failed to decode (%q, %q): %v", f.Name, f.Value, err) + errorf("Failed to decode metadata header (%q, %q): %v", f.Name, f.Value, err) return nil } d.mdata[f.Name] = append(d.mdata[f.Name], v) diff --git a/transport/log.go b/transport/log.go new file mode 100644 index 000000000000..ac8e358c5c8c --- /dev/null +++ b/transport/log.go @@ -0,0 +1,50 @@ +/* + * + * Copyright 2017 gRPC authors. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + */ + +// This file contains wrappers for grpclog functions. +// The transport package only logs to verbose level 2 by default. + +package transport + +import "google.golang.org/grpc/grpclog" + +const logLevel = 2 + +func infof(format string, args ...interface{}) { + if grpclog.V(logLevel) { + grpclog.Infof(format, args...) + } +} + +func warningf(format string, args ...interface{}) { + if grpclog.V(logLevel) { + grpclog.Warningf(format, args...) + } +} + +func errorf(format string, args ...interface{}) { + if grpclog.V(logLevel) { + grpclog.Errorf(format, args...) + } +} + +func fatalf(format string, args ...interface{}) { + if grpclog.V(logLevel) { + grpclog.Fatalf(format, args...) + } +}