ctxlogger split out from grpc_logging (grpc-ecosystem#107)

* moving this out will make ctxlogger independent and mean you do not
always have to use it withg grpc_logging loggers.

It is then consumed by the grpc_logging loggers and we will depricate
methods on there in future.

* moving this out will make ctxlogger independent and mean you do not
always have to use it withg grpc_logging loggers.

It is then consumed by the grpc_logging loggers and we will depricate
methods on there in future.

* changes from commit

* fixing

* removing comment

* removing interceptor for the context loggers

* ctxlogger_zap > ctx_zap ... removing redundant logger from package name

Author: domgreen

logging/DOC.md

@@ -6,12 +6,14 @@
 * [Index](#pkg-index)
 
 ## <a name="pkg-overview">Overview</a>
-grpc_logging is a "parent" package for gRPC logging middlewares
+grpc_logging is a "parent" package for gRPC logging middlewares.
 
 ### General functionality of all middleware
-All logging middleware have an `Extract(ctx)` function that provides a request-scoped logger with gRPC-related fields
-(service and method names). Moreover, that logger will have fields populated from the `grpc_ctxtags.Tags` of the
-context.
+The gRPC logging middleware populates request-scoped data to `grpc_ctxtags.Tags` that relate to the current gRPC call
+(e.g. service and method names).
+
+Once the gRPC logging middleware has added the gRPC specific Tags to the ctx they will then be written with the logs
+that are made using the `ctx_logrus` or `ctx_zap` loggers.
 
 All logging middleware will emit a final log statement. It is based on the error returned by the handler function,
 the gRPC status code, an error (if any) and it will emit at a level controlled via `WithLevels`.

logging/doc.go

@@ -3,13 +3,15 @@
 
 //
 /*
-grpc_logging is a "parent" package for gRPC logging middlewares
+grpc_logging is a "parent" package for gRPC logging middlewares.
 
 General functionality of all middleware
 
-All logging middleware have an `Extract(ctx)` function that provides a request-scoped logger with gRPC-related fields
-(service and method names). Moreover, that logger will have fields populated from the `grpc_ctxtags.Tags` of the
-context.
+The gRPC logging middleware populates request-scoped data to `grpc_ctxtags.Tags` that relate to the current gRPC call
+(e.g. service and method names).
+
+Once the gRPC logging middleware has added the gRPC specific Tags to the ctx they will then be written with the logs
+that are made using the `ctx_logrus` or `ctx_zap` loggers.
 
 All logging middleware will emit a final log statement. It is based on the error returned by the handler function,
 the gRPC status code, an error (if any) and it will emit at a level controlled via `WithLevels`.

logging/logrus/DOC.md

@@ -11,11 +11,8 @@
 It accepts a user-configured `logrus.Entry` that will be used for logging completed gRPC calls. The same
 `logrus.Entry` will be used for logging completed gRPC calls, and be populated into the `context.Context` passed into gRPC handler code.
 
-You can use `Extract` to log into a request-scoped `logrus.Entry` instance in your handler code. The fields set on the
-logger correspond to the grpc_ctxtags.Tags attached to the context.
-
-As `Extract` will iterate all tags on from `grpc_ctxtags` it is therefore expensive so it is advised that you
-extract once at the start of the function from the context and reuse it for the remainder of the function (see examples).
+On calling `StreamServerInterceptor` or `UnaryServerInterceptor` this logging middleware will add gRPC call information
+to the ctx so that it will be present on subsequent use of the `ctx_zap` logger.
 
 This package also implements request and response *payload* logging, both for server-side and client-side. These will be
 logged as structured `jsonbp` fields for every message received/sent (both unary and streaming). For that please use
@@ -32,7 +29,7 @@ Please see examples and tests for examples of use.
 - [github.com/golang/protobuf/proto](https://godoc.org/github.com/golang/protobuf/proto)
 - [github.com/grpc-ecosystem/go-grpc-middleware](./../..)
 - [github.com/grpc-ecosystem/go-grpc-middleware/logging](./..)
-- [github.com/grpc-ecosystem/go-grpc-middleware/tags](./../../tags)
+- [github.com/grpc-ecosystem/go-grpc-middleware/tags/logrus](./../../tags/logrus)
 - [github.com/sirupsen/logrus](https://godoc.org/github.com/sirupsen/logrus)
 - [golang.org/x/net/context](https://godoc.org/golang.org/x/net/context)
 - [google.golang.org/grpc](https://godoc.org/google.golang.org/grpc)
@@ -64,7 +61,7 @@ Please see examples and tests for examples of use.
   * [func WithLevels(f CodeToLevel) Option](#WithLevels)
 
 #### <a name="pkg-files">Package files</a>
-[client_interceptors.go](./client_interceptors.go) [context.go](./context.go) [doc.go](./doc.go) [grpclogger.go](./grpclogger.go) [noop.go](./noop.go) [options.go](./options.go) [payload_interceptors.go](./payload_interceptors.go) [server_interceptors.go](./server_interceptors.go) 
+[client_interceptors.go](./client_interceptors.go) [context.go](./context.go) [doc.go](./doc.go) [grpclogger.go](./grpclogger.go) [options.go](./options.go) [payload_interceptors.go](./payload_interceptors.go) [server_interceptors.go](./server_interceptors.go) 
 
 ## <a name="pkg-variables">Variables</a>
 ``` go
@@ -88,11 +85,12 @@ var (
 )
 ```
 
-## <a name="AddFields">func</a> [AddFields](./context.go#L24)
+## <a name="AddFields">func</a> [AddFields](./context.go#L11)
 ``` go
 func AddFields(ctx context.Context, fields logrus.Fields)
 ```
 AddFields adds logrus fields to the logger.
+Deprecated: should use the ctx_logrus.Extract instead
 
 ## <a name="DefaultClientCodeToLevel">func</a> [DefaultClientCodeToLevel](./options.go#L120)
 ``` go
@@ -118,22 +116,20 @@ func DurationToTimeMillisField(duration time.Duration) (key string, value interf
 ```
 DurationToTimeMillisField converts the duration to milliseconds and uses the key `grpc.time_ms`.
 
-## <a name="Extract">func</a> [Extract](./context.go#L38)
+## <a name="Extract">func</a> [Extract](./context.go#L17)
 ``` go
 func Extract(ctx context.Context) *logrus.Entry
 ```
 Extract takes the call-scoped logrus.Entry from grpc_logrus middleware.
+Deprecated: should use the ctx_logrus.Extract instead
 
-If the grpc_logrus middleware wasn't used, a no-op `logrus.Entry` is returned. This makes it safe to
-use regardless.
-
-## <a name="PayloadStreamClientInterceptor">func</a> [PayloadStreamClientInterceptor](./payload_interceptors.go#L77)
+## <a name="PayloadStreamClientInterceptor">func</a> [PayloadStreamClientInterceptor](./payload_interceptors.go#L74)
 ``` go
 func PayloadStreamClientInterceptor(entry *logrus.Entry, decider grpc_logging.ClientPayloadLoggingDecider) grpc.StreamClientInterceptor
 ```
 PayloadStreamServerInterceptor returns a new streaming client interceptor that logs the paylods of requests and responses.
 
-## <a name="PayloadStreamServerInterceptor">func</a> [PayloadStreamServerInterceptor](./payload_interceptors.go#L48)
+## <a name="PayloadStreamServerInterceptor">func</a> [PayloadStreamServerInterceptor](./payload_interceptors.go#L45)
 ``` go
 func PayloadStreamServerInterceptor(entry *logrus.Entry, decider grpc_logging.ServerPayloadLoggingDecider) grpc.StreamServerInterceptor
 ```
@@ -142,13 +138,13 @@ PayloadUnaryServerInterceptor returns a new server server interceptors that logs
 This *only* works when placed *after* the `grpc_logrus.StreamServerInterceptor`. However, the logging can be done to a
 separate instance of the logger.
 
-## <a name="PayloadUnaryClientInterceptor">func</a> [PayloadUnaryClientInterceptor](./payload_interceptors.go#L61)
+## <a name="PayloadUnaryClientInterceptor">func</a> [PayloadUnaryClientInterceptor](./payload_interceptors.go#L58)
 ``` go
 func PayloadUnaryClientInterceptor(entry *logrus.Entry, decider grpc_logging.ClientPayloadLoggingDecider) grpc.UnaryClientInterceptor
 ```
 PayloadUnaryClientInterceptor returns a new unary client interceptor that logs the paylods of requests and responses.
 
-## <a name="PayloadUnaryServerInterceptor">func</a> [PayloadUnaryServerInterceptor](./payload_interceptors.go#L28)
+## <a name="PayloadUnaryServerInterceptor">func</a> [PayloadUnaryServerInterceptor](./payload_interceptors.go#L25)
 ``` go
 func PayloadUnaryServerInterceptor(entry *logrus.Entry, decider grpc_logging.ServerPayloadLoggingDecider) grpc.UnaryServerInterceptor
 ```
@@ -170,7 +166,7 @@ func StreamClientInterceptor(entry *logrus.Entry, opts ...Option) grpc.StreamCli
 ```
 StreamServerInterceptor returns a new streaming client interceptor that optionally logs the execution of external gRPC calls.
 
-## <a name="StreamServerInterceptor">func</a> [StreamServerInterceptor](./server_interceptors.go#L50)
+## <a name="StreamServerInterceptor">func</a> [StreamServerInterceptor](./server_interceptors.go#L48)
 ``` go
 func StreamServerInterceptor(entry *logrus.Entry, opts ...Option) grpc.StreamServerInterceptor
 ```
@@ -182,7 +178,7 @@ func UnaryClientInterceptor(entry *logrus.Entry, opts ...Option) grpc.UnaryClien
 ```
 UnaryClientInterceptor returns a new unary client interceptor that optionally logs the execution of external gRPC calls.
 
-## <a name="UnaryServerInterceptor">func</a> [UnaryServerInterceptor](./server_interceptors.go#L25)
+## <a name="UnaryServerInterceptor">func</a> [UnaryServerInterceptor](./server_interceptors.go#L23)
 ``` go
 func UnaryServerInterceptor(entry *logrus.Entry, opts ...Option) grpc.UnaryServerInterceptor
 ```

logging/logrus/context.go

@@ -1,66 +1,19 @@
-// Copyright 2016 Michal Witkowski. All Rights Reserved.
-// See LICENSE for licensing terms.
-
 package grpc_logrus
 
 import (
-	"github.com/grpc-ecosystem/go-grpc-middleware/tags"
+	"github.com/grpc-ecosystem/go-grpc-middleware/tags/logrus"
 	"github.com/sirupsen/logrus"
 	"golang.org/x/net/context"
 )
 
-type ctxMarker struct{}
-
-type ctxLogger struct {
-	logger *logrus.Entry
-	fields logrus.Fields
-}
-
-var (
-	ctxMarkerKey = &ctxMarker{}
-)
-
 // AddFields adds logrus fields to the logger.
+// Deprecated: should use the ctx_logrus.Extract instead
 func AddFields(ctx context.Context, fields logrus.Fields) {
-	l, ok := ctx.Value(ctxMarkerKey).(*ctxLogger)
-	if !ok || l == nil {
-		return
-	}
-	for k, v := range fields {
-		l.fields[k] = v
-	}
+	ctx_logrus.AddFields(ctx, fields)
 }
 
 // Extract takes the call-scoped logrus.Entry from grpc_logrus middleware.
-//
-// If the grpc_logrus middleware wasn't used, a no-op `logrus.Entry` is returned. This makes it safe to
-// use regardless.
+// Deprecated: should use the ctx_logrus.Extract instead
 func Extract(ctx context.Context) *logrus.Entry {
-	l, ok := ctx.Value(ctxMarkerKey).(*ctxLogger)
-	if !ok || l == nil {
-		return logrus.NewEntry(nullLogger)
-	}
-
-	fields := logrus.Fields{}
-
-	// Add grpc_ctxtags tags metadata until now.
-	tags := grpc_ctxtags.Extract(ctx)
-	for k, v := range tags.Values() {
-		fields[k] = v
-	}
-
-	// Add logrus fields added until now.
-	for k, v := range l.fields {
-		fields[k] = v
-	}
-
-	return l.logger.WithFields(fields)
-}
-
-func toContext(ctx context.Context, entry *logrus.Entry) context.Context {
-	l := &ctxLogger{
-		logger: entry,
-		fields: logrus.Fields{},
-	}
-	return context.WithValue(ctx, ctxMarkerKey, l)
+	return ctx_logrus.Extract(ctx)
 }

logging/logrus/doc.go

@@ -1,17 +1,11 @@
-// Copyright 2017 Michal Witkowski. All Rights Reserved.
-// See LICENSE for licensing terms.
-
 /*
 `grpc_logrus` is a gRPC logging middleware backed by Logrus loggers
 
 It accepts a user-configured `logrus.Entry` that will be used for logging completed gRPC calls. The same
 `logrus.Entry` will be used for logging completed gRPC calls, and be populated into the `context.Context` passed into gRPC handler code.
 
-You can use `Extract` to log into a request-scoped `logrus.Entry` instance in your handler code. The fields set on the
-logger correspond to the grpc_ctxtags.Tags attached to the context.
-
-As `Extract` will iterate all tags on from `grpc_ctxtags` it is therefore expensive so it is advised that you
-extract once at the start of the function from the context and reuse it for the remainder of the function (see examples).
+On calling `StreamServerInterceptor` or `UnaryServerInterceptor` this logging middleware will add gRPC call information
+to the ctx so that it will be present on subsequent use of the `ctx_zap` logger.
 
 This package also implements request and response *payload* logging, both for server-side and client-side. These will be
 logged as structured `jsonbp` fields for every message received/sent (both unary and streaming). For that please use

logging/logrus/examples_test.go

@@ -8,6 +8,7 @@ import (
 
 	"github.com/grpc-ecosystem/go-grpc-middleware"
 	"github.com/grpc-ecosystem/go-grpc-middleware/tags"
+	"github.com/grpc-ecosystem/go-grpc-middleware/tags/logrus"
 	pb_testproto "github.com/grpc-ecosystem/go-grpc-middleware/testing/testproto"
 	"golang.org/x/net/context"
 	"google.golang.org/grpc"
@@ -68,7 +69,7 @@ func Example_HandlerUsageUnaryPing() {
 		// Add fields the ctxtags of the request which will be added to all extracted loggers.
 		grpc_ctxtags.Extract(ctx).Set("custom_tags.string", "something").Set("custom_tags.int", 1337)
 		// Extract a single request-scoped logrus.Logger and log messages.
-		l := grpc_logrus.Extract(ctx)
+		l := ctx_logrus.Extract(ctx)
 		l.Info("some ping")
 		l.Info("another ping")
 		return &pb_testproto.PingResponse{Value: ping.Value}, nil

logging/logrus/payload_interceptors.go

@@ -1,16 +1,13 @@
-// Copyright 2017 Michal Witkowski. All Rights Reserved.
-// See LICENSE for licensing terms.
-
 package grpc_logrus
 
 import (
 	"bytes"
-
 	"fmt"
 
 	"github.com/golang/protobuf/jsonpb"
 	"github.com/golang/protobuf/proto"
 	"github.com/grpc-ecosystem/go-grpc-middleware/logging"
+	"github.com/grpc-ecosystem/go-grpc-middleware/tags/logrus"
 	"github.com/sirupsen/logrus"
 	"golang.org/x/net/context"
 	"google.golang.org/grpc"
@@ -31,7 +28,7 @@ func PayloadUnaryServerInterceptor(entry *logrus.Entry, decider grpc_logging.Ser
 			return handler(ctx, req)
 		}
 		// Use the provided logrus.Entry for logging but use the fields from context.
-		logEntry := entry.WithFields(Extract(ctx).Data)
+		logEntry := entry.WithFields(ctx_logrus.Extract(ctx).Data)
 		logProtoMessageAsJson(logEntry, req, "grpc.request.content", "server request payload logged as grpc.request.content field")
 		resp, err := handler(ctx, req)
 		if err == nil {

logging/logrus/payload_interceptors_test.go

@@ -1,20 +1,12 @@
-// Copyright 2017 Michal Witkowski. All Rights Reserved.
-// See LICENSE for licensing terms.
-
 package grpc_logrus_test
 
 import (
 	"fmt"
-	"runtime"
-	"testing"
-
+	"io"
 	"io/ioutil"
+	"runtime"
 	"strings"
-
-	"github.com/stretchr/testify/suite"
-	"google.golang.org/grpc"
-
-	"io"
+	"testing"
 
 	"github.com/grpc-ecosystem/go-grpc-middleware"
 	"github.com/grpc-ecosystem/go-grpc-middleware/logging/logrus"
@@ -23,7 +15,9 @@ import (
 	"github.com/sirupsen/logrus"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
+	"github.com/stretchr/testify/suite"
 	"golang.org/x/net/context"
+	"google.golang.org/grpc"
 )
 
 var (

logging/logrus/server_interceptors.go

@@ -1,13 +1,11 @@
-// Copyright 2017 Michal Witkowski. All Rights Reserved.
-// See LICENSE for licensing terms.
-
 package grpc_logrus
 
 import (
 	"path"
 	"time"
 
 	"github.com/grpc-ecosystem/go-grpc-middleware"
+	"github.com/grpc-ecosystem/go-grpc-middleware/tags/logrus"
 	"github.com/sirupsen/logrus"
 	"golang.org/x/net/context"
 	"google.golang.org/grpc"
@@ -39,7 +37,7 @@ func UnaryServerInterceptor(entry *logrus.Entry, opts ...Option) grpc.UnaryServe
 			fields[logrus.ErrorKey] = err
 		}
 		levelLogf(
-			Extract(newCtx).WithFields(fields), // re-extract logger from newCtx, as it may have extra fields that changed in the holder.
+			ctx_logrus.Extract(newCtx).WithFields(fields), // re-extract logger from newCtx, as it may have extra fields that changed in the holder.
 			level,
 			"finished unary call")
 		return resp, err
@@ -67,7 +65,7 @@ func StreamServerInterceptor(entry *logrus.Entry, opts ...Option) grpc.StreamSer
 			fields[logrus.ErrorKey] = err
 		}
 		levelLogf(
-			Extract(newCtx).WithFields(fields), // re-extract logger from newCtx, as it may have extra fields that changed in the holder.
+			ctx_logrus.Extract(newCtx).WithFields(fields), // re-extract logger from newCtx, as it may have extra fields that changed in the holder.
 			level,
 			"finished streaming call")
 		return err
@@ -101,5 +99,7 @@ func newLoggerForCall(ctx context.Context, entry *logrus.Entry, fullMethodString
 			"grpc.service": service,
 			"grpc.method":  method,
 		})
-	return toContext(ctx, callLog)
+
+	callLog = callLog.WithFields(ctx_logrus.Extract(ctx).Data)
+	return ctx_logrus.ToContext(ctx, callLog)
 }

logging/logrus/server_interceptors_test.go

@@ -1,20 +1,11 @@
-// Copyright 2017 Michal Witkowski. All Rights Reserved.
-// See LICENSE for licensing terms.
-
 package grpc_logrus_test
 
 import (
-	"runtime"
-	"testing"
-
-	"github.com/stretchr/testify/suite"
-	"google.golang.org/grpc"
-
-	"io"
-
 	"fmt"
-
+	"io"
+	"runtime"
 	"strings"
+	"testing"
 
 	"github.com/grpc-ecosystem/go-grpc-middleware"
 	"github.com/grpc-ecosystem/go-grpc-middleware/logging/logrus"
@@ -23,6 +14,8 @@ import (
 	"github.com/sirupsen/logrus"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
+	"github.com/stretchr/testify/suite"
+	"google.golang.org/grpc"
 	"google.golang.org/grpc/codes"
 )