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
This commit is contained in:
Menghan Li
2017-07-13 12:10:19 -07:00
committed by GitHub
parent 27b2052c95
commit d6723916d2
12 changed files with 156 additions and 78 deletions

View File

@ -157,7 +157,7 @@ type roundRobin struct {
func (rr *roundRobin) watchAddrUpdates() error { func (rr *roundRobin) watchAddrUpdates() error {
updates, err := rr.w.Next() updates, err := rr.w.Next()
if err != nil { 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 return err
} }
rr.mu.Lock() rr.mu.Lock()
@ -173,7 +173,7 @@ func (rr *roundRobin) watchAddrUpdates() error {
for _, v := range rr.addrs { for _, v := range rr.addrs {
if addr == v.addr { if addr == v.addr {
exist = true 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 break
} }
} }
@ -190,7 +190,7 @@ func (rr *roundRobin) watchAddrUpdates() error {
} }
} }
default: 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. // Make a copy of rr.addrs and write it onto rr.addrCh so that gRPC internals gets notified.

View File

@ -632,7 +632,7 @@ func (cc *ClientConn) resetAddrConn(addr Address, block bool, tearDownErr error)
// Start a goroutine connecting to the server asynchronously. // Start a goroutine connecting to the server asynchronously.
go func() { go func() {
if err := ac.resetTransport(false); err != nil { 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 { if err != errConnClosing {
// Keep this ac in cc.conns, to get the reason it's torn down. // Keep this ac in cc.conns, to get the reason it's torn down.
ac.tearDown(err) ac.tearDown(err)
@ -868,7 +868,7 @@ func (ac *addrConn) resetTransport(closeTransport bool) error {
if e, ok := err.(transport.ConnectionError); ok && !e.Temporary() { if e, ok := err.(transport.ConnectionError); ok && !e.Temporary() {
return err 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() ac.mu.Lock()
if ac.state == Shutdown { if ac.state == Shutdown {
// ac.tearDown(...) has been invoked. // ac.tearDown(...) has been invoked.
@ -973,7 +973,7 @@ func (ac *addrConn) transportMonitor() {
ac.mu.Lock() ac.mu.Lock()
ac.printf("transport exiting: %v", err) ac.printf("transport exiting: %v", err)
ac.mu.Unlock() 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 { if err != errConnClosing {
// Keep this ac in cc.conns, to get the reason it's torn down. // Keep this ac in cc.conns, to get the reason it's torn down.
ac.tearDown(err) ac.tearDown(err)

View File

@ -137,7 +137,7 @@ type balancer struct {
func (b *balancer) watchAddrUpdates(w naming.Watcher, ch chan []remoteBalancerInfo) error { func (b *balancer) watchAddrUpdates(w naming.Watcher, ch chan []remoteBalancerInfo) error {
updates, err := w.Next() updates, err := w.Next()
if err != nil { 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 return err
} }
b.mu.Lock() b.mu.Lock()
@ -162,13 +162,13 @@ func (b *balancer) watchAddrUpdates(w naming.Watcher, ch chan []remoteBalancerIn
md, ok := update.Metadata.(*AddrMetadataGRPCLB) md, ok := update.Metadata.(*AddrMetadataGRPCLB)
if !ok { if !ok {
// TODO: Revisit the handling here and may introduce some fallback mechanism. // 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 continue
} }
switch md.AddrType { switch md.AddrType {
case Backend: case Backend:
// TODO: Revisit the handling here and may introduce some fallback mechanism. // 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 continue
case GRPCLB: case GRPCLB:
b.rbs = append(b.rbs, remoteBalancerInfo{ b.rbs = append(b.rbs, remoteBalancerInfo{
@ -176,7 +176,7 @@ func (b *balancer) watchAddrUpdates(w naming.Watcher, ch chan []remoteBalancerIn
name: md.ServerName, name: md.ServerName,
}) })
default: default:
grpclog.Printf("Received unknow address type %d", md.AddrType) grpclog.Errorf("Received unknow address type %d", md.AddrType)
continue continue
} }
case naming.Delete: case naming.Delete:
@ -188,7 +188,7 @@ func (b *balancer) watchAddrUpdates(w naming.Watcher, ch chan []remoteBalancerIn
} }
} }
default: 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 // 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, ClientStats: &stats,
}, },
}); err != nil { }); err != nil {
grpclog.Printf("grpclb: failed to send load report: %v", err) grpclog.Errorf("grpclb: failed to send load report: %v", err)
return return
} }
} }
@ -310,7 +310,7 @@ func (b *balancer) callRemoteBalancer(lbc *loadBalancerClient, seq int) (retry b
defer cancel() defer cancel()
stream, err := lbc.BalanceLoad(ctx) stream, err := lbc.BalanceLoad(ctx)
if err != nil { 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 return
} }
b.mu.Lock() b.mu.Lock()
@ -327,25 +327,25 @@ func (b *balancer) callRemoteBalancer(lbc *loadBalancerClient, seq int) (retry b
}, },
} }
if err := stream.Send(initReq); err != nil { 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? // TODO: backoff on retry?
return true return true
} }
reply, err := stream.Recv() reply, err := stream.Recv()
if err != nil { 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? // TODO: backoff on retry?
return true return true
} }
initResp := reply.GetInitialResponse() initResp := reply.GetInitialResponse()
if initResp == nil { 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 return
} }
// TODO: Support delegation. // TODO: Support delegation.
if initResp.LoadBalancerDelegate != "" { if initResp.LoadBalancerDelegate != "" {
// delegation // delegation
grpclog.Println("TODO: Delegation is not supported yet.") grpclog.Errorf("TODO: Delegation is not supported yet.")
return return
} }
streamDone := make(chan struct{}) streamDone := make(chan struct{})
@ -360,7 +360,7 @@ func (b *balancer) callRemoteBalancer(lbc *loadBalancerClient, seq int) (retry b
for { for {
reply, err := stream.Recv() reply, err := stream.Recv()
if err != nil { if err != nil {
grpclog.Printf("grpclb: failed to recv server list: %v", err) grpclog.Errorf("grpclb: failed to recv server list: %v", err)
break break
} }
b.mu.Lock() b.mu.Lock()
@ -394,7 +394,7 @@ func (b *balancer) Start(target string, config BalancerConfig) error {
w, err := b.r.Resolve(target) w, err := b.r.Resolve(target)
if err != nil { if err != nil {
b.mu.Unlock() 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 return err
} }
b.w = w b.w = w
@ -404,7 +404,7 @@ func (b *balancer) Start(target string, config BalancerConfig) error {
go func() { go func() {
for { for {
if err := b.watchAddrUpdates(w, balancerAddrsCh); err != nil { 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) close(balancerAddrsCh)
return return
} }
@ -495,7 +495,7 @@ func (b *balancer) Start(target string, config BalancerConfig) error {
if creds := config.DialCreds; creds != nil { if creds := config.DialCreds; creds != nil {
if rb.name != "" { if rb.name != "" {
if err := creds.OverrideServerName(rb.name); err != nil { 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 continue
} }
} }
@ -510,7 +510,7 @@ func (b *balancer) Start(target string, config BalancerConfig) error {
ccError = make(chan struct{}) ccError = make(chan struct{})
cc, err = Dial(rb.addr, dopts...) cc, err = Dial(rb.addr, dopts...)
if err != nil { 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) close(ccError)
continue continue
} }

View File

@ -21,6 +21,8 @@
package glogger package glogger
import ( import (
"fmt"
"github.com/golang/glog" "github.com/golang/glog"
"google.golang.org/grpc/grpclog" "google.golang.org/grpc/grpclog"
) )
@ -32,51 +34,51 @@ func init() {
type glogger struct{} type glogger struct{}
func (g *glogger) Info(args ...interface{}) { func (g *glogger) Info(args ...interface{}) {
glog.Info(args...) glog.InfoDepth(2, args...)
} }
func (g *glogger) Infoln(args ...interface{}) { func (g *glogger) Infoln(args ...interface{}) {
glog.Infoln(args...) glog.InfoDepth(2, fmt.Sprintln(args...))
} }
func (g *glogger) Infof(format string, args ...interface{}) { 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{}) { func (g *glogger) Warning(args ...interface{}) {
glog.Warning(args...) glog.WarningDepth(2, args...)
} }
func (g *glogger) Warningln(args ...interface{}) { func (g *glogger) Warningln(args ...interface{}) {
glog.Warningln(args...) glog.WarningDepth(2, fmt.Sprintln(args...))
} }
func (g *glogger) Warningf(format string, args ...interface{}) { 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{}) { func (g *glogger) Error(args ...interface{}) {
glog.Error(args...) glog.ErrorDepth(2, args...)
} }
func (g *glogger) Errorln(args ...interface{}) { func (g *glogger) Errorln(args ...interface{}) {
glog.Errorln(args...) glog.ErrorDepth(2, fmt.Sprintln(args...))
} }
func (g *glogger) Errorf(format string, args ...interface{}) { 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{}) { func (g *glogger) Fatal(args ...interface{}) {
glog.Fatal(args...) glog.FatalDepth(2, args...)
} }
func (g *glogger) Fatalln(args ...interface{}) { func (g *glogger) Fatalln(args ...interface{}) {
glog.Fatalln(args...) glog.FatalDepth(2, fmt.Sprintln(args...))
} }
func (g *glogger) Fatalf(format string, args ...interface{}) { 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 { func (g *glogger) V(l int) bool {

View File

@ -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" import "os"

View File

@ -16,8 +16,7 @@
* *
*/ */
// Package grpclog defines logging for grpc. package grpclog
package grpclog // import "google.golang.org/grpc/grpclog"
// Logger mimics golang's standard Logger as an interface. // Logger mimics golang's standard Logger as an interface.
// Deprecated: use LoggerV2. // Deprecated: use LoggerV2.

View File

@ -31,16 +31,14 @@
* *
*/ */
/* package grpclog
Package grpclog defines logging for grpc.
*/
package grpclog // import "google.golang.org/grpc/grpclog"
import ( import (
"io" "io"
"io/ioutil" "io/ioutil"
"log" "log"
"os" "os"
"strconv"
) )
// LoggerV2 does underlying logging work for grpclog. // LoggerV2 does underlying logging work for grpclog.
@ -104,6 +102,7 @@ var severityName = []string{
// loggerT is the default logger used by grpclog. // loggerT is the default logger used by grpclog.
type loggerT struct { type loggerT struct {
m []*log.Logger m []*log.Logger
v int
} }
// NewLoggerV2 creates a loggerV2 with the provided writers. // NewLoggerV2 creates a loggerV2 with the provided writers.
@ -112,19 +111,44 @@ type loggerT struct {
// Warning logs will be written to warningW and infoW. // Warning logs will be written to warningW and infoW.
// Info logs will be written to infoW. // Info logs will be written to infoW.
func NewLoggerV2(infoW, warningW, errorW io.Writer) LoggerV2 { 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 var m []*log.Logger
m = append(m, log.New(infoW, severityName[infoLog]+": ", log.LstdFlags)) m = append(m, log.New(infoW, severityName[infoLog]+": ", log.LstdFlags))
m = append(m, log.New(io.MultiWriter(infoW, warningW), severityName[warningLog]+": ", 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. 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[errorLog]+": ", log.LstdFlags))
m = append(m, log.New(ew, severityName[fatalLog]+": ", 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. // newLoggerV2 creates a loggerV2 to be used as default logger.
// All logs are written to stderr. // All logs are written to stderr.
func newLoggerV2() LoggerV2 { 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{}) { 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 { func (g *loggerT) V(l int) bool {
// Returns true for all verbose level. return l <= g.v
// TODO support verbose level in the default logger.
return true
} }

View File

@ -485,7 +485,7 @@ func (s *Server) handleRawConn(rawConn net.Conn) {
s.mu.Lock() s.mu.Lock()
s.errorf("ServerHandshake(%q) failed: %v", rawConn.RemoteAddr(), err) s.errorf("ServerHandshake(%q) failed: %v", rawConn.RemoteAddr(), err)
s.mu.Unlock() 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 serverHandShake returns ErrConnDispatched, keep rawConn open.
if err != credentials.ErrConnDispatched { if err != credentials.ErrConnDispatched {
rawConn.Close() 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.errorf("NewServerTransport(%q) failed: %v", c.RemoteAddr(), err)
s.mu.Unlock() s.mu.Unlock()
c.Close() c.Close()
grpclog.Println("grpc: Server.Serve failed to create ServerTransport: ", err) grpclog.Warningln("grpc: Server.Serve failed to create ServerTransport: ", err)
return return
} }
if !s.addConn(st) { 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) p, err := encode(s.opts.codec, msg, cp, cbuf, outPayload)
if err != nil { if err != nil {
grpclog.Println("grpc: server failed to encode response: ", err) grpclog.Errorln("grpc: server failed to encode response: ", err)
return err return err
} }
if len(p) > s.opts.maxSendMessageSize { if len(p) > s.opts.maxSendMessageSize {
@ -712,7 +712,7 @@ func (s *Server) processUnaryRPC(t transport.ServerTransport, stream *transport.
if err != nil { if err != nil {
if st, ok := status.FromError(err); ok { if st, ok := status.FromError(err); ok {
if e := t.WriteStatus(stream, st); e != nil { 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 { } else {
switch st := err.(type) { switch st := err.(type) {
@ -720,7 +720,7 @@ func (s *Server) processUnaryRPC(t transport.ServerTransport, stream *transport.
// Nothing to do here. // Nothing to do here.
case transport.StreamError: case transport.StreamError:
if e := t.WriteStatus(stream, status.New(st.Code, st.Desc)); e != nil { 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: default:
panic(fmt.Sprintf("grpc: Unexpected error (%T) from recvMsg: %v", st, st)) 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 err := checkRecvPayload(pf, stream.RecvCompress(), s.opts.dc); err != nil {
if st, ok := status.FromError(err); ok { if st, ok := status.FromError(err); ok {
if e := t.WriteStatus(stream, st); e != nil { 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 return err
} }
if e := t.WriteStatus(stream, status.New(codes.Internal, err.Error())); e != nil { 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. // 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() trInfo.tr.SetError()
} }
if e := t.WriteStatus(stream, appStatus); e != nil { 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 return appErr
} }
@ -809,7 +809,7 @@ func (s *Server) processUnaryRPC(t transport.ServerTransport, stream *transport.
} }
if s, ok := status.FromError(err); ok { if s, ok := status.FromError(err); ok {
if e := t.WriteStatus(stream, s); e != nil { 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 { } else {
switch st := err.(type) { switch st := err.(type) {
@ -817,7 +817,7 @@ func (s *Server) processUnaryRPC(t transport.ServerTransport, stream *transport.
// Nothing to do here. // Nothing to do here.
case transport.StreamError: case transport.StreamError:
if e := t.WriteStatus(stream, status.New(st.Code, st.Desc)); e != nil { 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: default:
panic(fmt.Sprintf("grpc: Unexpected error (%T) from sendResponse: %v", st, st)) 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.LazyLog(&fmtStringer{"%v", []interface{}{err}}, true)
trInfo.tr.SetError() 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 { if trInfo != nil {
trInfo.tr.Finish() 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.LazyLog(&fmtStringer{"%v", []interface{}{err}}, true)
trInfo.tr.SetError() 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 { if trInfo != nil {
trInfo.tr.Finish() 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.LazyLog(&fmtStringer{"%v", []interface{}{err}}, true)
trInfo.tr.SetError() 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 { if trInfo != nil {
trInfo.tr.Finish() trInfo.tr.Finish()

View File

@ -33,7 +33,6 @@ import (
"golang.org/x/net/http2/hpack" "golang.org/x/net/http2/hpack"
"google.golang.org/grpc/codes" "google.golang.org/grpc/codes"
"google.golang.org/grpc/credentials" "google.golang.org/grpc/credentials"
"google.golang.org/grpc/grpclog"
"google.golang.org/grpc/keepalive" "google.golang.org/grpc/keepalive"
"google.golang.org/grpc/metadata" "google.golang.org/grpc/metadata"
"google.golang.org/grpc/peer" "google.golang.org/grpc/peer"
@ -953,7 +952,7 @@ func (t *http2Client) handleRSTStream(f *http2.RSTStreamFrame) {
} }
statusCode, ok := http2ErrConvTab[http2.ErrCode(f.ErrCode)] statusCode, ok := http2ErrConvTab[http2.ErrCode(f.ErrCode)]
if !ok { 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 statusCode = codes.Unknown
} }
s.finish(status.Newf(statusCode, "stream terminated by RST_STREAM with error code: %d", f.ErrCode)) 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) { func (t *http2Client) handleGoAway(f *http2.GoAwayFrame) {
if f.ErrCode == http2.ErrCodeEnhanceYourCalm { if f.ErrCode == http2.ErrCodeEnhanceYourCalm {
grpclog.Printf("Client received GoAway with http2.ErrCodeEnhanceYourCalm.") infof("Client received GoAway with http2.ErrCodeEnhanceYourCalm.")
} }
t.mu.Lock() t.mu.Lock()
if t.state == reachable || t.state == draining { if t.state == reachable || t.state == draining {
@ -1189,7 +1188,7 @@ func (t *http2Client) reader() {
case *http2.WindowUpdateFrame: case *http2.WindowUpdateFrame:
t.handleWindowUpdate(frame) t.handleWindowUpdate(frame)
default: 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) t.framer.writePing(true, i.ack, i.data)
default: 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 t.writableChan <- 0
continue continue
@ -1343,7 +1342,7 @@ func (t *http2Client) notifyError(err error) {
if t.state == reachable { if t.state == reachable {
t.state = unreachable t.state = unreachable
close(t.errorChan) 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() t.mu.Unlock()
} }

View File

@ -36,7 +36,6 @@ import (
"golang.org/x/net/http2/hpack" "golang.org/x/net/http2/hpack"
"google.golang.org/grpc/codes" "google.golang.org/grpc/codes"
"google.golang.org/grpc/credentials" "google.golang.org/grpc/credentials"
"google.golang.org/grpc/grpclog"
"google.golang.org/grpc/keepalive" "google.golang.org/grpc/keepalive"
"google.golang.org/grpc/metadata" "google.golang.org/grpc/metadata"
"google.golang.org/grpc/peer" "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) s.ctx, err = t.inTapHandle(s.ctx, info)
if err != nil { 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}) t.controlBuf.put(&resetStream{s.id, http2.ErrCodeRefusedStream})
return return
} }
@ -306,7 +305,7 @@ func (t *http2Server) operateHeaders(frame *http2.MetaHeadersFrame, handle func(
if s.id%2 != 1 || s.id <= t.maxStreamID { if s.id%2 != 1 || s.id <= t.maxStreamID {
t.mu.Unlock() t.mu.Unlock()
// illegal gRPC stream id. // 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 return true
} }
t.maxStreamID = s.id 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 { 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) // Only log if it isn't a simple tcp accept check (ie: tcp balancer doing open/close socket)
if err != io.EOF { 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() t.Close()
return return
} }
if !bytes.Equal(preface, clientPreface) { 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() t.Close()
return return
} }
@ -361,14 +360,14 @@ func (t *http2Server) HandleStreams(handle func(*Stream), traceCtx func(context.
return return
} }
if err != nil { 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() t.Close()
return return
} }
atomic.StoreUint32(&t.activity, 1) atomic.StoreUint32(&t.activity, 1)
sf, ok := frame.(*http2.SettingsFrame) sf, ok := frame.(*http2.SettingsFrame)
if !ok { 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() t.Close()
return return
} }
@ -392,7 +391,7 @@ func (t *http2Server) HandleStreams(handle func(*Stream), traceCtx func(context.
t.Close() t.Close()
return return
} }
grpclog.Printf("transport: http2Server.HandleStreams failed to read frame: %v", err) warningf("transport: http2Server.HandleStreams failed to read frame: %v", err)
t.Close() t.Close()
return return
} }
@ -415,7 +414,7 @@ func (t *http2Server) HandleStreams(handle func(*Stream), traceCtx func(context.
case *http2.GoAwayFrame: case *http2.GoAwayFrame:
// TODO: Handle GoAway from the client appropriately. // TODO: Handle GoAway from the client appropriately.
default: 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) t.controlBuf.put(bdpPing)
} else { } else {
if err := t.fc.onData(uint32(size)); err != nil { if err := t.fc.onData(uint32(size)); err != nil {
grpclog.Printf("transport: http2Server %v", err) errorf("transport: http2Server %v", err)
t.Close() t.Close()
return return
} }
@ -1048,7 +1047,7 @@ func (t *http2Server) controller() {
} }
t.framer.writePing(true, i.ack, i.data) t.framer.writePing(true, i.ack, i.data)
default: 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 t.writableChan <- 0
continue continue

View File

@ -36,7 +36,6 @@ import (
"golang.org/x/net/http2/hpack" "golang.org/x/net/http2/hpack"
spb "google.golang.org/genproto/googleapis/rpc/status" spb "google.golang.org/genproto/googleapis/rpc/status"
"google.golang.org/grpc/codes" "google.golang.org/grpc/codes"
"google.golang.org/grpc/grpclog"
"google.golang.org/grpc/status" "google.golang.org/grpc/status"
) )
@ -283,7 +282,7 @@ func (d *decodeState) processHeaderField(f hpack.HeaderField) error {
} }
v, err := decodeMetadataHeader(f.Name, f.Value) v, err := decodeMetadataHeader(f.Name, f.Value)
if err != nil { 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 return nil
} }
d.mdata[f.Name] = append(d.mdata[f.Name], v) d.mdata[f.Name] = append(d.mdata[f.Name], v)

50
transport/log.go Normal file
View File

@ -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...)
}
}