fixup name

logging/logrus/DOC.md

@@ -36,7 +36,7 @@ var (
 func DefaultClientCodeToLevel(code codes.Code) logrus.Level
 ```
 DefaultClientCodeToLevel is the default implementation of gRPC return codes to
-log levels for server side.
+log levels for client side.
 
 #### func  DefaultCodeToLevel
 

logging/logrus/options.go

@@ -107,7 +107,7 @@ func DefaultCodeToLevel(code codes.Code) logrus.Level {
 	}
 }
 
-// DefaultClientCodeToLevel is the default implementation of gRPC return codes to log levels for server side.
+// DefaultClientCodeToLevel is the default implementation of gRPC return codes to log levels for client side.
 func DefaultClientCodeToLevel(code codes.Code) logrus.Level {
 	switch code {
 	case codes.OK:

logging/logrus/server_interceptors_test.go

@@ -95,7 +95,7 @@ func (s *logrusServerSuite) TestPingError_WithCustomLevels() {
 		{
 			code:  codes.Unauthenticated,
 			level: logrus.ErrorLevel,
-			msg:   "Unauthenticated is overwritten to ErrorLevel with customClientCodeToLevel override, which probably didn't work",
+			msg:   "Unauthenticated is overwritten to ErrorLevel with customCodeToLevel override, which probably didn't work",
 		},
 	} {
 		s.buffer.Reset()

logging/zap/DOC.md

@@ -24,16 +24,34 @@ Please see examples and tests for examples of use.
 var (
 	// SystemField is used in every log statement made through grpc_zap. Can be overwritten before any initialization code.
 	SystemField = zap.String("system", "grpc")
+
+	// ServerField is used in every server-side log statment made through grpc_zap.Can be overwritten before initialization.
+	ServerField = zap.String("span.kind", "server")
+)
+```
+
+```go
+var (
+	// ClientField is used in every client-side log statement made through grpc_zap. Can be overwritten before initialization.
+	ClientField = zap.String("span.kind", "client")
 )
 ```
 
+#### func  DefaultClientCodeToLevel
+
+```go
+func DefaultClientCodeToLevel(code codes.Code) zapcore.Level
+```
+DefaultClientCodeToLevel is the default implementation of gRPC return codes to
+log levels for client side.
+
 #### func  DefaultCodeToLevel
 
 ```go
 func DefaultCodeToLevel(code codes.Code) zapcore.Level
 ```
 DefaultCodeToLevel is the default implementation of gRPC return codes and
-interceptor log level.
+interceptor log level for server side.
 
 #### func  Extract
 
@@ -52,6 +70,14 @@ func ReplaceGrpcLogger(logger *zap.Logger)
 ReplaceGrpcLogger sets the given zap.Logger as a gRPC-level logger. This should
 be called *before* any other initialization, preferably from init() functions.
 
+#### func  StreamClientInterceptor
+
+```go
+func StreamClientInterceptor(logger *zap.Logger, opts ...Option) grpc.StreamClientInterceptor
+```
+StreamServerInterceptor returns a new streaming client interceptor that
+optionally logs the execution of external gRPC calls.
+
 #### func  StreamServerInterceptor
 
 ```go
@@ -60,6 +86,14 @@ func StreamServerInterceptor(logger *zap.Logger, opts ...Option) grpc.StreamServ
 StreamServerInterceptor returns a new streaming server interceptor that adds
 zap.Logger to the context.
 
+#### func  UnaryClientInterceptor
+
+```go
+func UnaryClientInterceptor(logger *zap.Logger, opts ...Option) grpc.UnaryClientInterceptor
+```
+UnaryClientInterceptor returns a new unary client interceptor that optionally
+logs the execution of external gRPC calls.
+
 #### func  UnaryServerInterceptor
 
 ```go

logging/zap/client_interceptors.go

@@ -0,0 +1,64 @@
+// Copyright 2017 Michal Witkowski. All Rights Reserved.
+// See LICENSE for licensing terms.
+
+package grpc_zap
+
+import (
+	"path"
+	"time"
+
+	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
+	"golang.org/x/net/context"
+	"google.golang.org/grpc"
+)
+
+var (
+	// ClientField is used in every client-side log statement made through grpc_zap. Can be overwritten before initialization.
+	ClientField = zap.String("span.kind", "client")
+)
+
+// UnaryClientInterceptor returns a new unary client interceptor that optionally logs the execution of external gRPC calls.
+func UnaryClientInterceptor(logger *zap.Logger, opts ...Option) grpc.UnaryClientInterceptor {
+	o := evaluateClientOpt(opts)
+	return func(ctx context.Context, method string, req, reply interface{}, cc *grpc.ClientConn, invoker grpc.UnaryInvoker, opts ...grpc.CallOption) error {
+		fields := newClientLoggerFields(ctx, method)
+		startTime := time.Now()
+		err := invoker(ctx, method, req, reply, cc, opts...)
+		logFinalClientLine(o, logger.With(fields...), startTime, err, "finished client unary call")
+		return err
+	}
+}
+
+// StreamServerInterceptor returns a new streaming client interceptor that optionally logs the execution of external gRPC calls.
+func StreamClientInterceptor(logger *zap.Logger, opts ...Option) grpc.StreamClientInterceptor {
+	o := evaluateClientOpt(opts)
+	return func(ctx context.Context, desc *grpc.StreamDesc, cc *grpc.ClientConn, method string, streamer grpc.Streamer, opts ...grpc.CallOption) (grpc.ClientStream, error) {
+		fields := newClientLoggerFields(ctx, method)
+		startTime := time.Now()
+		clientStream, err := streamer(ctx, desc, cc, method, opts...)
+		logFinalClientLine(o, logger.With(fields...), startTime, err, "finished client streaming call")
+		return clientStream, err
+	}
+}
+
+func logFinalClientLine(o *options, logger *zap.Logger, startTime time.Time, err error, msg string) {
+	code := o.codeFunc(err)
+	level := o.levelFunc(code)
+	logger.Check(level, msg).Write(
+		zap.Error(err),
+		zap.String("grpc.code", code.String()),
+		zap.Float32("grpc.time_ms", timeDiffToMilliseconds(startTime)),
+	)
+}
+
+func newClientLoggerFields(ctx context.Context, fullMethodString string) []zapcore.Field {
+	service := path.Dir(fullMethodString)[1:]
+	method := path.Base(fullMethodString)
+	return []zapcore.Field{
+		SystemField,
+		ClientField,
+		zap.String("grpc.service", service),
+		zap.String("grpc.method", method),
+	}
+}

logging/zap/client_interceptors_test.go

@@ -0,0 +1,128 @@
+// Copyright 2017 Michal Witkowski. All Rights Reserved.
+// See LICENSE for licensing terms.
+
+package grpc_zap_test
+
+import (
+	"fmt"
+	"io"
+	"runtime"
+	"strings"
+	"testing"
+
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+	"github.com/stretchr/testify/suite"
+	"google.golang.org/grpc"
+	"google.golang.org/grpc/codes"
+
+	"github.com/grpc-ecosystem/go-grpc-middleware/logging/zap"
+	pb_testproto "github.com/grpc-ecosystem/go-grpc-middleware/testing/testproto"
+	"go.uber.org/zap/zapcore"
+)
+
+func customClientCodeToLevel(c codes.Code) zapcore.Level {
+	if c == codes.Unauthenticated {
+		// Make this a special case for tests, and an error.
+		return zapcore.ErrorLevel
+	}
+	level := grpc_zap.DefaultClientCodeToLevel(c)
+	return level
+}
+
+func TestZapClientSuite(t *testing.T) {
+	if strings.HasPrefix(runtime.Version(), "go1.7") {
+		t.Skipf("Skipping due to json.RawMessage incompatibility with go1.7")
+		return
+	}
+	opts := []grpc_zap.Option{
+		grpc_zap.WithLevels(customClientCodeToLevel),
+	}
+	b := newBaseZapSuite(t)
+	b.InterceptorTestSuite.ClientOpts = []grpc.DialOption{
+		grpc.WithUnaryInterceptor(grpc_zap.UnaryClientInterceptor(b.log, opts...)),
+		grpc.WithStreamInterceptor(grpc_zap.StreamClientInterceptor(b.log, opts...)),
+	}
+	suite.Run(t, &zapClientSuite{b})
+}
+
+type zapClientSuite struct {
+	*zapBaseSuite
+}
+
+func (s *zapClientSuite) TestPing() {
+	_, err := s.Client.Ping(s.SimpleCtx(), goodPing)
+	assert.NoError(s.T(), err, "there must be not be an on a successful call")
+	msgs := s.getOutputJSONs()
+	require.Len(s.T(), msgs, 1, "one log statement should be logged")
+	m := msgs[0]
+	assert.Contains(s.T(), m, `"grpc.service": "mwitkow.testproto.TestService"`, "all lines must contain service name")
+	assert.Contains(s.T(), m, `"grpc.method": "Ping"`, "all lines must contain method name")
+	assert.Contains(s.T(), m, `"span.kind": "client"`, "all lines must contain the kind of call (client)")
+	assert.Contains(s.T(), m, `"msg": "finished client unary call"`, "interceptor message must contain string")
+	assert.Contains(s.T(), m, `"level": "debug"`, "OK error codes must be logged on debug level.")
+	assert.Contains(s.T(), m, `"grpc.time_ms":`, "interceptor log statement should contain execution time")
+}
+
+func (s *zapClientSuite) TestPingList() {
+	stream, err := s.Client.PingList(s.SimpleCtx(), goodPing)
+	require.NoError(s.T(), err, "should not fail on establishing the stream")
+	for {
+		_, err := stream.Recv()
+		if err == io.EOF {
+			break
+		}
+		require.NoError(s.T(), err, "reading stream should not fail")
+	}
+	msgs := s.getOutputJSONs()
+	require.Len(s.T(), msgs, 1, "one log statement should be logged")
+	m := msgs[0]
+	assert.Contains(s.T(), m, `"grpc.service": "mwitkow.testproto.TestService"`, "all lines must contain service name")
+	assert.Contains(s.T(), m, `"grpc.method": "PingList"`, "all lines must contain method name")
+	assert.Contains(s.T(), m, `"span.kind": "client"`, "all lines must contain the kind of call (client)")
+	assert.Contains(s.T(), m, `"msg": "finished client streaming call"`, "interceptor message must contain string")
+	assert.Contains(s.T(), m, `"level": "debug"`, "OK error codes must be logged on debug level.")
+	assert.Contains(s.T(), m, `"grpc.time_ms":`, "interceptor log statement should contain execution time")
+}
+
+func (s *zapClientSuite) TestPingError_WithCustomLevels() {
+	for _, tcase := range []struct {
+		code  codes.Code
+		level zapcore.Level
+		msg   string
+	}{
+		{
+			code:  codes.Internal,
+			level: zapcore.WarnLevel,
+			msg:   "Internal must remap to ErrorLevel in DefaultClientCodeToLevel",
+		},
+		{
+			code:  codes.NotFound,
+			level: zapcore.DebugLevel,
+			msg:   "NotFound must remap to InfoLevel in DefaultClientCodeToLevel",
+		},
+		{
+			code:  codes.FailedPrecondition,
+			level: zapcore.DebugLevel,
+			msg:   "FailedPrecondition must remap to WarnLevel in DefaultClientCodeToLevel",
+		},
+		{
+			code:  codes.Unauthenticated,
+			level: zapcore.ErrorLevel,
+			msg:   "Unauthenticated is overwritten to ErrorLevel with customClientCodeToLevel override, which probably didn't work",
+		},
+	} {
+		s.SetupTest()
+		_, err := s.Client.PingError(
+			s.SimpleCtx(),
+			&pb_testproto.PingRequest{Value: "something", ErrorCodeReturned: uint32(tcase.code)})
+		assert.Error(s.T(), err, "each call here must return an error")
+		msgs := s.getOutputJSONs()
+		require.Len(s.T(), msgs, 1, "only the interceptor log message is printed in PingErr")
+		m := msgs[0]
+		assert.Contains(s.T(), m, `"grpc.service": "mwitkow.testproto.TestService"`, "all lines must contain service name")
+		assert.Contains(s.T(), m, `"grpc.method": "PingError"`, "all lines must contain method name")
+		assert.Contains(s.T(), m, fmt.Sprintf(`"grpc.code": "%s"`, tcase.code.String()), "all lines must contain method name")
+		assert.Contains(s.T(), m, fmt.Sprintf(`"level": "%s"`, tcase.level.String()), tcase.msg)
+	}
+}

logging/zap/options.go

@@ -31,6 +31,22 @@ func evaluateOptions(opts []Option) *options {
 	return optCopy
 }
 
+func evaluateServerOpt(opts []Option) *options {
+	o := evaluateOptions(opts)
+	if o.codeFunc == nil {
+		o.levelFunc = DefaultCodeToLevel
+	}
+	return o
+}
+
+func evaluateClientOpt(opts []Option) *options {
+	o := evaluateOptions(opts)
+	if o.codeFunc == nil {
+		o.levelFunc = DefaultCodeToLevel
+	}
+	return o
+}
+
 type Option func(*options)
 
 // CodeToLevel function defines the mapping between gRPC return codes and interceptor log level.
@@ -50,7 +66,7 @@ func WithCodes(f grpc_logging.ErrorToCode) Option {
 	}
 }
 
-// DefaultCodeToLevel is the default implementation of gRPC return codes and interceptor log level.
+// DefaultCodeToLevel is the default implementation of gRPC return codes and interceptor log level for server side.
 func DefaultCodeToLevel(code codes.Code) zapcore.Level {
 	switch code {
 	case codes.OK:
@@ -91,3 +107,45 @@ func DefaultCodeToLevel(code codes.Code) zapcore.Level {
 		return zap.ErrorLevel
 	}
 }
+
+// DefaultClientCodeToLevel is the default implementation of gRPC return codes to log levels for client side.
+func DefaultClientCodeToLevel(code codes.Code) zapcore.Level {
+	switch code {
+	case codes.OK:
+		return zap.DebugLevel
+	case codes.Canceled:
+		return zap.DebugLevel
+	case codes.Unknown:
+		return zap.InfoLevel
+	case codes.InvalidArgument:
+		return zap.DebugLevel
+	case codes.DeadlineExceeded:
+		return zap.InfoLevel
+	case codes.NotFound:
+		return zap.DebugLevel
+	case codes.AlreadyExists:
+		return zap.DebugLevel
+	case codes.PermissionDenied:
+		return zap.InfoLevel
+	case codes.Unauthenticated:
+		return zap.InfoLevel // unauthenticated requests can happen
+	case codes.ResourceExhausted:
+		return zap.DebugLevel
+	case codes.FailedPrecondition:
+		return zap.DebugLevel
+	case codes.Aborted:
+		return zap.DebugLevel
+	case codes.OutOfRange:
+		return zap.DebugLevel
+	case codes.Unimplemented:
+		return zap.WarnLevel
+	case codes.Internal:
+		return zap.WarnLevel
+	case codes.Unavailable:
+		return zap.WarnLevel
+	case codes.DataLoss:
+		return zap.WarnLevel
+	default:
+		return zap.InfoLevel
+	}
+}