From 07b4ff52301a993a7cfc2d2f0c6d8a75153cad7a Mon Sep 17 00:00:00 2001 From: Bartlomiej Plotka Date: Fri, 29 Jan 2021 21:56:41 +0000 Subject: [PATCH] Removed tags; Simplified interceptor code; Added logging fields editability. Fixes https://github.com/grpc-ecosystem/go-grpc-middleware/issues/382 Signed-off-by: Bartlomiej Plotka --- .gitignore | 2 +- CHANGELOG.md | 6 + go.sum | 1 + interceptors/auth/examples_test.go | 11 +- interceptors/client.go | 4 +- interceptors/client_test.go | 49 ++--- interceptors/logging/doc.go | 13 +- interceptors/logging/interceptors.go | 101 +++++---- interceptors/logging/interceptors_test.go | 200 ++++++++++-------- interceptors/logging/logging.go | 154 ++++++++------ interceptors/logging/options.go | 71 ++++++- interceptors/logging/payload.go | 75 ++++--- interceptors/logging/payload_test.go | 59 +++--- interceptors/reporter.go | 26 ++- interceptors/server.go | 4 +- interceptors/server_test.go | 20 +- interceptors/tags/context.go | 82 ------- interceptors/tags/doc.go | 22 -- interceptors/tags/examples_test.go | 18 -- interceptors/tags/fieldextractor.go | 80 ------- interceptors/tags/fieldextractor_test.go | 21 -- interceptors/tags/interceptors.go | 70 ------ interceptors/tags/interceptors_test.go | 194 ----------------- interceptors/tags/options.go | 33 --- interceptors/tracing/client.go | 29 +-- interceptors/tracing/id_extract.go | 56 +++-- interceptors/tracing/id_extract_test.go | 21 +- interceptors/tracing/interceptors_test.go | 45 ++-- interceptors/tracing/metadata.go | 2 +- interceptors/tracing/server.go | 54 +++-- providers/tokenbucket/examples_test.go | 3 +- testing/testpb/pingservice.go | 3 +- .../testpb/test.manual_extractfields.pb.go | 25 --- util/metautils/nicemd.go | 4 +- 34 files changed, 556 insertions(+), 1002 deletions(-) delete mode 100644 interceptors/tags/context.go delete mode 100644 interceptors/tags/doc.go delete mode 100644 interceptors/tags/examples_test.go delete mode 100644 interceptors/tags/fieldextractor.go delete mode 100644 interceptors/tags/fieldextractor_test.go delete mode 100644 interceptors/tags/interceptors.go delete mode 100644 interceptors/tags/interceptors_test.go delete mode 100644 interceptors/tags/options.go delete mode 100644 testing/testpb/test.manual_extractfields.pb.go diff --git a/.gitignore b/.gitignore index b818e03db..159a5219b 100644 --- a/.gitignore +++ b/.gitignore @@ -202,4 +202,4 @@ coverage.txt vendor/ .envrc -.bin +.bin \ No newline at end of file diff --git a/CHANGELOG.md b/CHANGELOG.md index 4d7840480..3d72ead0d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -12,6 +12,12 @@ Types of changes: - `Fixed` for any bug fixes. - `Security` in case of vulnerabilities. +## v2 + +### Changed + +* `tags` removed. Use `logging.ExtractFields` to read logging fields from logging interceptor for your local request logger. Use `logging.InjectFields` to inject custom fields to logging interceptor to client context or interceptor before logging interceptor. + ## [Unreleased] ### Added diff --git a/go.sum b/go.sum index 42190ddfa..e1d0ddb5a 100644 --- a/go.sum +++ b/go.sum @@ -30,6 +30,7 @@ github.com/google/go-cmp v0.3.1/go.mod h1:8QqcDgzrUqlUb/G2PQTWiueGozuR1884gddMyw github.com/google/go-cmp v0.4.0/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= github.com/google/go-cmp v0.5.0 h1:/QaMHBdZ26BB3SSst0Iwl10Epc+xhTquomWX0oZEB6w= github.com/google/go-cmp v0.5.0/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= +github.com/grpc-ecosystem/go-grpc-middleware v1.2.2 h1:FlFbCRLd5Jr4iYXZufAvgWN6Ao0JrI5chLINnUXDDr0= github.com/opentracing/opentracing-go v1.1.0 h1:pWlfV3Bxv7k65HYwkikxat0+s3pV4bsqf19k25Ur8rU= github.com/opentracing/opentracing-go v1.1.0/go.mod h1:UkNAQd3GIcIGf0SeVgPpRdFStlNbqXla1AfSYxPUl2o= github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4= diff --git a/interceptors/auth/examples_test.go b/interceptors/auth/examples_test.go index 4614f7f3e..de0871741 100644 --- a/interceptors/auth/examples_test.go +++ b/interceptors/auth/examples_test.go @@ -9,8 +9,9 @@ import ( pb "google.golang.org/grpc/examples/helloworld/helloworld" "google.golang.org/grpc/status" + "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/logging" + "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/auth" - "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/tags" ) var tokenInfoKey struct{} @@ -35,12 +36,10 @@ func exampleAuthFunc(ctx context.Context) (context.Context, error) { return nil, status.Errorf(codes.Unauthenticated, "invalid auth token: %v", err) } - tags.Extract(ctx).Set("auth.sub", userClaimFromToken(tokenInfo)) - - // WARNING: in production define your own type to avoid context collisions - newCtx := context.WithValue(ctx, tokenInfoKey, tokenInfo) + ctx = logging.InjectFields(ctx, logging.Fields{"auth.sub", userClaimFromToken(tokenInfo)}) - return newCtx, nil + // WARNING: In production define your own type to avoid context collisions. + return context.WithValue(ctx, tokenInfoKey, tokenInfo), nil } // Simple example of server initialization code diff --git a/interceptors/client.go b/interceptors/client.go index 051c92c7f..f9878158e 100644 --- a/interceptors/client.go +++ b/interceptors/client.go @@ -16,7 +16,7 @@ import ( func UnaryClientInterceptor(reportable ClientReportable) grpc.UnaryClientInterceptor { return func(ctx context.Context, method string, req, reply interface{}, cc *grpc.ClientConn, invoker grpc.UnaryInvoker, opts ...grpc.CallOption) error { r := newReport(Unary, method) - reporter, newCtx := reportable.ClientReporter(ctx, req, r.rpcType, r.service, r.method) + reporter, newCtx := reportable.ClientReporter(ctx, CallMeta{ReqProtoOrNil: req, Typ: r.rpcType, Service: r.service, Method: r.method}) reporter.PostMsgSend(req, nil, time.Since(r.startTime)) err := invoker(newCtx, method, req, reply, cc, opts...) @@ -31,7 +31,7 @@ func UnaryClientInterceptor(reportable ClientReportable) grpc.UnaryClientInterce func StreamClientInterceptor(reportable ClientReportable) grpc.StreamClientInterceptor { return func(ctx context.Context, desc *grpc.StreamDesc, cc *grpc.ClientConn, method string, streamer grpc.Streamer, opts ...grpc.CallOption) (grpc.ClientStream, error) { r := newReport(clientStreamType(desc), method) - reporter, newCtx := reportable.ClientReporter(ctx, nil, r.rpcType, r.service, r.method) + reporter, newCtx := reportable.ClientReporter(ctx, CallMeta{ReqProtoOrNil: nil, Typ: r.rpcType, Service: r.service, Method: r.method}) clientStream, err := streamer(newCtx, desc, cc, method, opts...) if err != nil { diff --git a/interceptors/client_test.go b/interceptors/client_test.go index 84a48830c..adb953bbb 100644 --- a/interceptors/client_test.go +++ b/interceptors/client_test.go @@ -21,8 +21,7 @@ import ( ) type mockReport struct { - typ GRPCType - svcName, methodName string + CallMeta postCalls []error postMsgSends []error @@ -40,9 +39,9 @@ type mockReportable struct { func (m *mockReportable) Equal(t *testing.T, expected []*mockReport) { require.Len(t, expected, len(m.reports)) for i, e := range m.reports { - require.Equal(t, expected[i].typ, e.typ, "%v", i) - require.Equal(t, expected[i].svcName, e.svcName, "%v", i) - require.Equal(t, expected[i].methodName, e.methodName, "%v", i) + require.Equal(t, expected[i].Typ, e.Typ, "%v", i) + require.Equal(t, expected[i].Service, e.Service, "%v", i) + require.Equal(t, expected[i].Method, e.Method, "%v", i) require.Len(t, expected[i].postCalls, len(e.postCalls), "%v", i) for k, err := range e.postCalls { @@ -111,14 +110,14 @@ func (m *mockReportable) PostMsgReceive(_ interface{}, err error, _ time.Duratio m.curr.postMsgReceives = append(m.curr.postMsgReceives, err) } -func (m *mockReportable) ClientReporter(ctx context.Context, _ interface{}, typ GRPCType, serviceName string, methodName string) (Reporter, context.Context) { - m.curr = &mockReport{typ: typ, svcName: serviceName, methodName: methodName} +func (m *mockReportable) ClientReporter(ctx context.Context, c CallMeta) (Reporter, context.Context) { + m.curr = &mockReport{CallMeta: c} m.reports = append(m.reports, m.curr) return m, ctx } -func (m *mockReportable) ServerReporter(ctx context.Context, _ interface{}, typ GRPCType, serviceName string, methodName string) (Reporter, context.Context) { - m.curr = &mockReport{typ: typ, svcName: serviceName, methodName: methodName} +func (m *mockReportable) ServerReporter(ctx context.Context, c CallMeta) (Reporter, context.Context) { + m.curr = &mockReport{CallMeta: c} m.reports = append(m.reports, m.curr) return m, ctx } @@ -206,9 +205,7 @@ func (s *ClientInterceptorTestSuite) TestUnaryReporting() { _, err := s.testClient.PingEmpty(s.ctx, &testpb.PingEmptyRequest{}) // should return with code=OK require.NoError(s.T(), err) s.mock.Equal(s.T(), []*mockReport{{ - typ: Unary, - svcName: testpb.TestServiceFullName, - methodName: "PingEmpty", + CallMeta: CallMeta{Typ: Unary, Service: testpb.TestServiceFullName, Method: "PingEmpty"}, postCalls: []error{nil}, postMsgReceives: []error{nil}, postMsgSends: []error{nil}, @@ -218,9 +215,7 @@ func (s *ClientInterceptorTestSuite) TestUnaryReporting() { _, err = s.testClient.PingError(s.ctx, &testpb.PingErrorRequest{ErrorCodeReturned: uint32(codes.FailedPrecondition)}) // should return with code=FailedPrecondition require.Error(s.T(), err) s.mock.Equal(s.T(), []*mockReport{{ - typ: Unary, - svcName: testpb.TestServiceFullName, - methodName: "PingError", + CallMeta: CallMeta{Typ: Unary, Service: testpb.TestServiceFullName, Method: "PingError"}, postCalls: []error{status.Errorf(codes.FailedPrecondition, "Userspace error.")}, postMsgReceives: []error{status.Errorf(codes.FailedPrecondition, "Userspace error.")}, postMsgSends: []error{nil}, @@ -233,9 +228,7 @@ func (s *ClientInterceptorTestSuite) TestStartedListReporting() { // Even without reading, we should get initial mockReport. s.mock.Equal(s.T(), []*mockReport{{ - typ: ServerStream, - svcName: testpb.TestServiceFullName, - methodName: "PingList", + CallMeta: CallMeta{Typ: ServerStream, Service: testpb.TestServiceFullName, Method: "PingList"}, postMsgSends: []error{nil}, }}) @@ -244,14 +237,10 @@ func (s *ClientInterceptorTestSuite) TestStartedListReporting() { // Even without reading, we should get initial mockReport. s.mock.Equal(s.T(), []*mockReport{{ - typ: ServerStream, - svcName: testpb.TestServiceFullName, - methodName: "PingList", + CallMeta: CallMeta{Typ: ServerStream, Service: testpb.TestServiceFullName, Method: "PingList"}, postMsgSends: []error{nil}, }, { - typ: ServerStream, - svcName: testpb.TestServiceFullName, - methodName: "PingList", + CallMeta: CallMeta{Typ: ServerStream, Service: testpb.TestServiceFullName, Method: "PingList"}, postMsgSends: []error{nil}, }}) } @@ -273,9 +262,7 @@ func (s *ClientInterceptorTestSuite) TestListReporting() { require.EqualValues(s.T(), testpb.ListResponseCount, count, "Number of received msg on the wire must match") s.mock.Equal(s.T(), []*mockReport{{ - typ: ServerStream, - svcName: testpb.TestServiceFullName, - methodName: "PingList", + CallMeta: CallMeta{Typ: ServerStream, Service: testpb.TestServiceFullName, Method: "PingList"}, postCalls: []error{io.EOF}, postMsgReceives: append(make([]error, testpb.ListResponseCount), io.EOF), postMsgSends: []error{nil}, @@ -298,9 +285,7 @@ func (s *ClientInterceptorTestSuite) TestListReporting() { require.Equal(s.T(), codes.FailedPrecondition, st.Code(), "Recv must return FailedPrecondition, otherwise the test is wrong") s.mock.Equal(s.T(), []*mockReport{{ - typ: ServerStream, - svcName: testpb.TestServiceFullName, - methodName: "PingList", + CallMeta: CallMeta{Typ: ServerStream, Service: testpb.TestServiceFullName, Method: "PingList"}, postCalls: []error{status.Errorf(codes.FailedPrecondition, "foobar"), status.Errorf(codes.FailedPrecondition, "foobar")}, postMsgReceives: []error{status.Errorf(codes.FailedPrecondition, "foobar"), status.Errorf(codes.FailedPrecondition, "foobar")}, postMsgSends: []error{nil}, @@ -342,9 +327,7 @@ func (s *ClientInterceptorTestSuite) TestBiStreamingReporting() { require.EqualValues(s.T(), count, 100, "Number of received msg on the wire must match") s.mock.Equal(s.T(), []*mockReport{{ - typ: BidiStream, - svcName: testpb.TestServiceFullName, - methodName: "PingStream", + CallMeta: CallMeta{Typ: BidiStream, Service: testpb.TestServiceFullName, Method: "PingStream"}, postCalls: []error{io.EOF}, postMsgReceives: append(make([]error, 100), io.EOF), postMsgSends: make([]error, 100), diff --git a/interceptors/logging/doc.go b/interceptors/logging/doc.go index 378baed77..b108d37e1 100644 --- a/interceptors/logging/doc.go +++ b/interceptors/logging/doc.go @@ -5,19 +5,19 @@ /* logging is a "parent" package for gRPC logging middlewares. -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). +The gRPC logging middleware populates request-scoped data to `logging.Fields` that relate to the current gRPC call +(e.g. service and method names). You can laverage that data using `logging.ExtractFields` and `logging.InjectFields`. -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. +Once the gRPC logging middleware has added the gRPC specific Fields to the ctx they will then be written with the log lines. 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 emit at a level controlled via `WithLevels`. +the gRPC status code, an error (if any) and it emit at a level controlled via `WithLevels`. You can control this behavior +using `WithDecider`. This parent package This particular package is intended for use by other middleware, logging or otherwise. It contains interfaces that other -logging middlewares *could* share . This allows code to be shared between different implementations. +logging middlewares *could* share. This allows code to be shared between different implementations. Field names @@ -31,6 +31,5 @@ Implementations: * providers/kit * providers/zerolog -See relevant packages below. */ package logging diff --git a/interceptors/logging/interceptors.go b/interceptors/logging/interceptors.go index 654223f2a..e711d1c1c 100644 --- a/interceptors/logging/interceptors.go +++ b/interceptors/logging/interceptors.go @@ -7,28 +7,20 @@ import ( "time" "google.golang.org/grpc" + "google.golang.org/grpc/peer" "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors" - "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/tags" ) -// extractFields returns all fields from tags. -func extractFields(tags tags.Tags) Fields { - var fields Fields - for k, v := range tags.Values() { - fields = append(fields, k, v) - } - return fields -} - type reporter struct { + interceptors.CallMeta + ctx context.Context - typ interceptors.GRPCType - service, method string - startCallLogged bool - opts *options - logger Logger kind string + startCallLogged bool + + opts *options + logger Logger } func (c *reporter) logMessage(logger Logger, err error, msg string, duration time.Duration) { @@ -37,12 +29,11 @@ func (c *reporter) logMessage(logger Logger, err error, msg string, duration tim if err != nil { logger = logger.With("grpc.error", fmt.Sprintf("%v", err)) } - logger = logger.With(extractFields(tags.Extract(c.ctx))...) logger.With(c.opts.durationFieldFunc(duration)...).Log(c.opts.levelFunc(code), msg) } func (c *reporter) PostCall(err error, duration time.Duration) { - switch c.opts.shouldLog(interceptors.FullMethod(c.service, c.method), err) { + switch c.opts.shouldLog(c.FullMethod(), err) { case LogFinishCall, LogStartAndFinishCall: if err == io.EOF { err = nil @@ -57,7 +48,7 @@ func (c *reporter) PostMsgSend(_ interface{}, err error, duration time.Duration) if c.startCallLogged { return } - switch c.opts.shouldLog(interceptors.FullMethod(c.service, c.method), err) { + switch c.opts.shouldLog(c.FullMethod(), err) { case LogStartAndFinishCall: c.startCallLogged = true c.logMessage(c.logger, err, "started call", duration) @@ -68,68 +59,72 @@ func (c *reporter) PostMsgReceive(_ interface{}, err error, duration time.Durati if c.startCallLogged { return } - switch c.opts.shouldLog(interceptors.FullMethod(c.service, c.method), err) { + switch c.opts.shouldLog(c.FullMethod(), err) { case LogStartAndFinishCall: c.startCallLogged = true c.logMessage(c.logger, err, "started call", duration) } } -type reportable struct { - opts *options - logger Logger -} - -func (r *reportable) ServerReporter(ctx context.Context, _ interface{}, typ interceptors.GRPCType, service string, method string) (interceptors.Reporter, context.Context) { - return r.reporter(ctx, typ, service, method, KindServerFieldValue) -} +func reportable(logger Logger, opts *options) interceptors.CommonReportableFunc { + return func(ctx context.Context, c interceptors.CallMeta, isClient bool) (interceptors.Reporter, context.Context) { + kind := KindServerFieldValue + if isClient { + kind = KindClientFieldValue + } -func (r *reportable) ClientReporter(ctx context.Context, _ interface{}, typ interceptors.GRPCType, service string, method string) (interceptors.Reporter, context.Context) { - return r.reporter(ctx, typ, service, method, KindClientFieldValue) -} + fields := newCommonFields(kind, c) + if !isClient { + if peer, ok := peer.FromContext(ctx); ok { + fields = append(fields, "peer.address", peer.Addr.String()) + } + } + fields = fields.AppendUnique(ExtractFields(ctx)) -func (r *reportable) reporter(ctx context.Context, typ interceptors.GRPCType, service string, method string, kind string) (interceptors.Reporter, context.Context) { - fields := commonFields(kind, typ, service, method) - fields = append(fields, "grpc.start_time", time.Now().Format(time.RFC3339)) - if d, ok := ctx.Deadline(); ok { - fields = append(fields, "grpc.request.deadline", d.Format(time.RFC3339)) + // Start/end specific fields. We don't want to pollute potential request fields downstream might use. + singleUseFields := []string{"grpc.start_time", time.Now().Format(time.RFC3339)} + if d, ok := ctx.Deadline(); ok { + singleUseFields = append(singleUseFields, "grpc.request.deadline", d.Format(time.RFC3339)) + } + return &reporter{ + CallMeta: c, + ctx: ctx, + startCallLogged: false, + opts: opts, + logger: logger.With(fields...).With(singleUseFields...), + kind: kind, + }, InjectFields(ctx, fields) } - return &reporter{ - ctx: ctx, - typ: typ, - service: service, - method: method, - startCallLogged: false, - opts: r.opts, - logger: r.logger.With(fields...), - kind: kind, - }, ctx } // UnaryClientInterceptor returns a new unary client interceptor that optionally logs the execution of external gRPC calls. -// Logger will use all tags (from tags package) available in current context as fields. +// Logger will read existing and write new logging.Fields available in current context. +// See `ExtractFields` and `InjectFields` for details. func UnaryClientInterceptor(logger Logger, opts ...Option) grpc.UnaryClientInterceptor { o := evaluateClientOpt(opts) - return interceptors.UnaryClientInterceptor(&reportable{logger: logger, opts: o}) + return interceptors.UnaryClientInterceptor(reportable(logger, o)) } // StreamClientInterceptor returns a new streaming client interceptor that optionally logs the execution of external gRPC calls. -// Logger will use all tags (from tags package) available in current context as fields. +// Logger will read existing and write new logging.Fields available in current context. +// See `ExtractFields` and `InjectFields` for details. func StreamClientInterceptor(logger Logger, opts ...Option) grpc.StreamClientInterceptor { o := evaluateClientOpt(opts) - return interceptors.StreamClientInterceptor(&reportable{logger: logger, opts: o}) + return interceptors.StreamClientInterceptor(reportable(logger, o)) } // UnaryServerInterceptor returns a new unary server interceptors that optionally logs endpoint handling. -// Logger will use all tags (from tags package) available in current context as fields. +// Logger will read existing and write new logging.Fields available in current context. +// See `ExtractFields` and `InjectFields` for details. func UnaryServerInterceptor(logger Logger, opts ...Option) grpc.UnaryServerInterceptor { o := evaluateServerOpt(opts) - return interceptors.UnaryServerInterceptor(&reportable{logger: logger, opts: o}) + return interceptors.UnaryServerInterceptor(reportable(logger, o)) } // StreamServerInterceptor returns a new stream server interceptors that optionally logs endpoint handling. -// Logger will use all tags (from tags package) available in current context as fields. +// Logger will read existing and write new logging.Fields available in current context. +// See `ExtractFields` and `InjectFields` for details.. func StreamServerInterceptor(logger Logger, opts ...Option) grpc.StreamServerInterceptor { o := evaluateServerOpt(opts) - return interceptors.StreamServerInterceptor(&reportable{logger: logger, opts: o}) + return interceptors.StreamServerInterceptor(reportable(logger, o)) } diff --git a/interceptors/logging/interceptors_test.go b/interceptors/logging/interceptors_test.go index 5208ce98e..5b182f735 100644 --- a/interceptors/logging/interceptors_test.go +++ b/interceptors/logging/interceptors_test.go @@ -1,6 +1,7 @@ package logging_test import ( + "context" "encoding/json" "fmt" "io" @@ -19,20 +20,19 @@ import ( "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors" "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/logging" - "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/tags" "github.com/grpc-ecosystem/go-grpc-middleware/v2/testing/testpb" ) type testDisposableFields map[string]string -func (f testDisposableFields) AssertNextField(t *testing.T, key, value string) testDisposableFields { +func (f testDisposableFields) AssertField(t *testing.T, key, value string) testDisposableFields { require.Truef(t, len(f) > 0, "expected field %s = %v, but fields ended", key, value) assert.Equalf(t, value, f[key], "expected %s for %s", value, key) delete(f, key) return f } -func (f testDisposableFields) AssertNextFieldNotEmpty(t *testing.T, key string) testDisposableFields { +func (f testDisposableFields) AssertFieldNotEmpty(t *testing.T, key string) testDisposableFields { require.Truef(t, len(f) > 0, "expected field %s and some non-empty value, but fields ended", key) assert.Truef(t, f[key] != "", "%s is empty", key) delete(f, key) @@ -173,30 +173,58 @@ func TestSuite(t *testing.T) { }, } s.InterceptorTestSuite.ClientOpts = []grpc.DialOption{ - grpc.WithUnaryInterceptor(logging.UnaryClientInterceptor(s.logger, logging.WithLevels(customClientCodeToLevel))), - grpc.WithStreamInterceptor(logging.StreamClientInterceptor(s.logger, logging.WithLevels(customClientCodeToLevel))), + grpc.WithChainUnaryInterceptor( + addCustomFieldsUnaryClientInterceptor(), + logging.UnaryClientInterceptor(s.logger, logging.WithLevels(customClientCodeToLevel)), + ), + grpc.WithChainStreamInterceptor( + addCustomFieldsStreamClientInterceptor(), + logging.StreamClientInterceptor(s.logger, logging.WithLevels(customClientCodeToLevel)), + ), } s.InterceptorTestSuite.ServerOpts = []grpc.ServerOption{ grpc.ChainStreamInterceptor( - tags.StreamServerInterceptor(tags.WithFieldExtractor(tags.CodeGenRequestFieldExtractor)), + addCustomFieldsStreamServerInterceptor(), logging.StreamServerInterceptor(s.logger, logging.WithLevels(customClientCodeToLevel))), grpc.ChainUnaryInterceptor( - tags.UnaryServerInterceptor(tags.WithFieldExtractor(tags.CodeGenRequestFieldExtractor)), + addCustomFieldsUnaryServerInterceptor(), logging.UnaryServerInterceptor(s.logger, logging.WithLevels(customClientCodeToLevel))), } suite.Run(t, s) } +var addCustomFields = interceptors.CommonReportableFunc(func(ctx context.Context, _ interceptors.CallMeta, _ bool) (interceptors.Reporter, context.Context) { + // Add custom fields, one new and one that should be ignored as it duplicates the standard field. + return interceptors.NoopReporter{}, logging.InjectFields(ctx, logging.Fields{"custom-field", "yolo", logging.ServiceFieldKey, "something different"}) +}) + +func addCustomFieldsUnaryClientInterceptor() grpc.UnaryClientInterceptor { + return interceptors.UnaryClientInterceptor(addCustomFields) +} + +func addCustomFieldsStreamClientInterceptor() grpc.StreamClientInterceptor { + return interceptors.StreamClientInterceptor(addCustomFields) +} + +func addCustomFieldsUnaryServerInterceptor() grpc.UnaryServerInterceptor { + return interceptors.UnaryServerInterceptor(addCustomFields) +} + +func addCustomFieldsStreamServerInterceptor() grpc.StreamServerInterceptor { + return interceptors.StreamServerInterceptor(addCustomFields) +} + func assertStandardFields(t *testing.T, kind string, f testDisposableFields, method string, typ interceptors.GRPCType) testDisposableFields { - return f.AssertNextField(t, logging.SystemTag[0], logging.SystemTag[1]). - AssertNextField(t, logging.ComponentFieldKey, kind). - AssertNextField(t, logging.ServiceFieldKey, testpb.TestServiceFullName). - AssertNextField(t, logging.MethodFieldKey, method). - AssertNextField(t, logging.MethodTypeFieldKey, string(typ)) + return f.AssertField(t, logging.SystemTag[0], logging.SystemTag[1]). + AssertField(t, logging.ComponentFieldKey, kind). + AssertField(t, logging.ServiceFieldKey, testpb.TestServiceFullName). + AssertField(t, logging.MethodFieldKey, method). + AssertField(t, logging.MethodTypeFieldKey, string(typ)) } func (s *loggingClientServerSuite) TestPing() { - _, err := s.Client.Ping(s.SimpleCtx(), testpb.GoodPing) + ctx := logging.InjectFields(s.SimpleCtx(), logging.Fields{"grpc.request.value", testpb.GoodPing.Value}) + _, err := s.Client.Ping(ctx, testpb.GoodPing) assert.NoError(s.T(), err, "there must be not be an on a successful call") lines := s.logger.o.Lines() @@ -217,21 +245,23 @@ func (s *loggingClientServerSuite) TestPing() { assert.Equal(s.T(), logging.DEBUG, serverFinishCallLogLine.lvl) assert.Equal(s.T(), "finished call", serverFinishCallLogLine.msg) serverFinishCallFields := assertStandardFields(s.T(), logging.KindServerFieldValue, serverFinishCallLogLine.fields, "Ping", interceptors.Unary) - serverFinishCallFields.AssertNextField(s.T(), "grpc.request.value", "something"). - AssertNextFieldNotEmpty(s.T(), "peer.address"). - AssertNextFieldNotEmpty(s.T(), "grpc.start_time"). - AssertNextFieldNotEmpty(s.T(), "grpc.request.deadline"). - AssertNextField(s.T(), "grpc.code", "OK"). - AssertNextFieldNotEmpty(s.T(), "grpc.time_ms").AssertNoMoreTags(s.T()) + serverFinishCallFields.AssertFieldNotEmpty(s.T(), "peer.address"). + AssertField(s.T(), "custom-field", "yolo"). + AssertFieldNotEmpty(s.T(), "grpc.start_time"). + AssertFieldNotEmpty(s.T(), "grpc.request.deadline"). + AssertField(s.T(), "grpc.code", "OK"). + AssertFieldNotEmpty(s.T(), "grpc.time_ms").AssertNoMoreTags(s.T()) clientFinishCallLogLine := lines[0] assert.Equal(s.T(), logging.DEBUG, clientFinishCallLogLine.lvl) assert.Equal(s.T(), "finished call", clientFinishCallLogLine.msg) clientFinishCallFields := assertStandardFields(s.T(), logging.KindClientFieldValue, clientFinishCallLogLine.fields, "Ping", interceptors.Unary) - clientFinishCallFields.AssertNextFieldNotEmpty(s.T(), "grpc.start_time"). - AssertNextFieldNotEmpty(s.T(), "grpc.request.deadline"). - AssertNextField(s.T(), "grpc.code", "OK"). - AssertNextFieldNotEmpty(s.T(), "grpc.time_ms").AssertNoMoreTags(s.T()) + clientFinishCallFields.AssertField(s.T(), "custom-field", "yolo"). + AssertField(s.T(), "grpc.request.value", "something"). + AssertFieldNotEmpty(s.T(), "grpc.start_time"). + AssertFieldNotEmpty(s.T(), "grpc.request.deadline"). + AssertField(s.T(), "grpc.code", "OK"). + AssertFieldNotEmpty(s.T(), "grpc.time_ms").AssertNoMoreTags(s.T()) } func (s *loggingClientServerSuite) TestPingList() { @@ -262,21 +292,22 @@ func (s *loggingClientServerSuite) TestPingList() { assert.Equal(s.T(), logging.DEBUG, serverFinishCallLogLine.lvl) assert.Equal(s.T(), "finished call", serverFinishCallLogLine.msg) serverFinishCallFields := assertStandardFields(s.T(), logging.KindServerFieldValue, serverFinishCallLogLine.fields, "PingList", interceptors.ServerStream) - serverFinishCallFields.AssertNextField(s.T(), "grpc.request.value", "something"). - AssertNextFieldNotEmpty(s.T(), "peer.address"). - AssertNextFieldNotEmpty(s.T(), "grpc.start_time"). - AssertNextFieldNotEmpty(s.T(), "grpc.request.deadline"). - AssertNextField(s.T(), "grpc.code", "OK"). - AssertNextFieldNotEmpty(s.T(), "grpc.time_ms").AssertNoMoreTags(s.T()) + serverFinishCallFields.AssertField(s.T(), "custom-field", "yolo"). + AssertFieldNotEmpty(s.T(), "peer.address"). + AssertFieldNotEmpty(s.T(), "grpc.start_time"). + AssertFieldNotEmpty(s.T(), "grpc.request.deadline"). + AssertField(s.T(), "grpc.code", "OK"). + AssertFieldNotEmpty(s.T(), "grpc.time_ms").AssertNoMoreTags(s.T()) clientFinishCallLogLine := lines[0] assert.Equal(s.T(), logging.DEBUG, clientFinishCallLogLine.lvl) assert.Equal(s.T(), "finished call", clientFinishCallLogLine.msg) clientFinishCallFields := assertStandardFields(s.T(), logging.KindClientFieldValue, clientFinishCallLogLine.fields, "PingList", interceptors.ServerStream) - clientFinishCallFields.AssertNextFieldNotEmpty(s.T(), "grpc.start_time"). - AssertNextFieldNotEmpty(s.T(), "grpc.request.deadline"). - AssertNextField(s.T(), "grpc.code", "OK"). - AssertNextFieldNotEmpty(s.T(), "grpc.time_ms").AssertNoMoreTags(s.T()) + clientFinishCallFields.AssertFieldNotEmpty(s.T(), "grpc.start_time"). + AssertField(s.T(), "custom-field", "yolo"). + AssertFieldNotEmpty(s.T(), "grpc.request.deadline"). + AssertField(s.T(), "grpc.code", "OK"). + AssertFieldNotEmpty(s.T(), "grpc.time_ms").AssertNoMoreTags(s.T()) } func (s *loggingClientServerSuite) TestPingError_WithCustomLevels() { @@ -320,23 +351,24 @@ func (s *loggingClientServerSuite) TestPingError_WithCustomLevels() { assert.Equal(t, tcase.level, serverFinishCallLogLine.lvl) assert.Equal(t, "finished call", serverFinishCallLogLine.msg) serverFinishCallFields := assertStandardFields(t, logging.KindServerFieldValue, serverFinishCallLogLine.fields, "PingError", interceptors.Unary) - serverFinishCallFields.AssertNextField(t, "grpc.request.value", "something"). - AssertNextFieldNotEmpty(t, "peer.address"). - AssertNextFieldNotEmpty(t, "grpc.start_time"). - AssertNextFieldNotEmpty(t, "grpc.request.deadline"). - AssertNextField(t, "grpc.code", tcase.code.String()). - AssertNextField(t, "grpc.error", fmt.Sprintf("rpc error: code = %s desc = Userspace error.", tcase.code.String())). - AssertNextFieldNotEmpty(t, "grpc.time_ms").AssertNoMoreTags(t) + serverFinishCallFields.AssertField(s.T(), "custom-field", "yolo"). + AssertFieldNotEmpty(t, "peer.address"). + AssertFieldNotEmpty(t, "grpc.start_time"). + AssertFieldNotEmpty(t, "grpc.request.deadline"). + AssertField(t, "grpc.code", tcase.code.String()). + AssertField(t, "grpc.error", fmt.Sprintf("rpc error: code = %s desc = Userspace error.", tcase.code.String())). + AssertFieldNotEmpty(t, "grpc.time_ms").AssertNoMoreTags(t) clientFinishCallLogLine := lines[0] assert.Equal(t, tcase.level, clientFinishCallLogLine.lvl) assert.Equal(t, "finished call", clientFinishCallLogLine.msg) clientFinishCallFields := assertStandardFields(t, logging.KindClientFieldValue, clientFinishCallLogLine.fields, "PingError", interceptors.Unary) - clientFinishCallFields.AssertNextFieldNotEmpty(t, "grpc.start_time"). - AssertNextFieldNotEmpty(t, "grpc.request.deadline"). - AssertNextField(t, "grpc.code", tcase.code.String()). - AssertNextField(t, "grpc.error", fmt.Sprintf("rpc error: code = %s desc = Userspace error.", tcase.code.String())). - AssertNextFieldNotEmpty(t, "grpc.time_ms").AssertNoMoreTags(t) + clientFinishCallFields.AssertField(s.T(), "custom-field", "yolo"). + AssertFieldNotEmpty(t, "grpc.start_time"). + AssertFieldNotEmpty(t, "grpc.request.deadline"). + AssertField(t, "grpc.code", tcase.code.String()). + AssertField(t, "grpc.error", fmt.Sprintf("rpc error: code = %s desc = Userspace error.", tcase.code.String())). + AssertFieldNotEmpty(t, "grpc.time_ms").AssertNoMoreTags(t) }) } } @@ -364,12 +396,8 @@ func TestCustomDurationSuite(t *testing.T) { grpc.WithStreamInterceptor(logging.StreamClientInterceptor(s.logger, logging.WithDurationField(logging.DurationToDurationField))), } s.InterceptorTestSuite.ServerOpts = []grpc.ServerOption{ - grpc.ChainStreamInterceptor( - tags.StreamServerInterceptor(tags.WithFieldExtractor(tags.CodeGenRequestFieldExtractor)), - logging.StreamServerInterceptor(s.logger, logging.WithDurationField(logging.DurationToDurationField))), - grpc.ChainUnaryInterceptor( - tags.UnaryServerInterceptor(tags.WithFieldExtractor(tags.CodeGenRequestFieldExtractor)), - logging.UnaryServerInterceptor(s.logger, logging.WithDurationField(logging.DurationToDurationField))), + grpc.StreamInterceptor(logging.StreamServerInterceptor(s.logger, logging.WithDurationField(logging.DurationToDurationField))), + grpc.UnaryInterceptor(logging.UnaryServerInterceptor(s.logger, logging.WithDurationField(logging.DurationToDurationField))), } suite.Run(t, s) } @@ -396,21 +424,20 @@ func (s *loggingCustomDurationSuite) TestPing_HasOverriddenDuration() { assert.Equal(s.T(), logging.INFO, serverFinishCallLogLine.lvl) assert.Equal(s.T(), "finished call", serverFinishCallLogLine.msg) serverFinishCallFields := assertStandardFields(s.T(), logging.KindServerFieldValue, serverFinishCallLogLine.fields, "Ping", interceptors.Unary) - serverFinishCallFields.AssertNextField(s.T(), "grpc.request.value", "something"). - AssertNextFieldNotEmpty(s.T(), "peer.address"). - AssertNextFieldNotEmpty(s.T(), "grpc.start_time"). - AssertNextFieldNotEmpty(s.T(), "grpc.request.deadline"). - AssertNextField(s.T(), "grpc.code", "OK"). - AssertNextFieldNotEmpty(s.T(), "grpc.duration").AssertNoMoreTags(s.T()) + serverFinishCallFields.AssertFieldNotEmpty(s.T(), "peer.address"). + AssertFieldNotEmpty(s.T(), "grpc.start_time"). + AssertFieldNotEmpty(s.T(), "grpc.request.deadline"). + AssertField(s.T(), "grpc.code", "OK"). + AssertFieldNotEmpty(s.T(), "grpc.duration").AssertNoMoreTags(s.T()) clientFinishCallLogLine := lines[0] assert.Equal(s.T(), logging.DEBUG, clientFinishCallLogLine.lvl) assert.Equal(s.T(), "finished call", clientFinishCallLogLine.msg) clientFinishCallFields := assertStandardFields(s.T(), logging.KindClientFieldValue, clientFinishCallLogLine.fields, "Ping", interceptors.Unary) - clientFinishCallFields.AssertNextFieldNotEmpty(s.T(), "grpc.start_time"). - AssertNextFieldNotEmpty(s.T(), "grpc.request.deadline"). - AssertNextField(s.T(), "grpc.code", "OK"). - AssertNextFieldNotEmpty(s.T(), "grpc.duration").AssertNoMoreTags(s.T()) + clientFinishCallFields.AssertFieldNotEmpty(s.T(), "grpc.start_time"). + AssertFieldNotEmpty(s.T(), "grpc.request.deadline"). + AssertField(s.T(), "grpc.code", "OK"). + AssertFieldNotEmpty(s.T(), "grpc.duration").AssertNoMoreTags(s.T()) } func (s *loggingCustomDurationSuite) TestPingList_HasOverriddenDuration() { @@ -442,21 +469,20 @@ func (s *loggingCustomDurationSuite) TestPingList_HasOverriddenDuration() { assert.Equal(s.T(), logging.INFO, serverFinishCallLogLine.lvl) assert.Equal(s.T(), "finished call", serverFinishCallLogLine.msg) serverFinishCallFields := assertStandardFields(s.T(), logging.KindServerFieldValue, serverFinishCallLogLine.fields, "PingList", interceptors.ServerStream) - serverFinishCallFields.AssertNextField(s.T(), "grpc.request.value", "something"). - AssertNextFieldNotEmpty(s.T(), "peer.address"). - AssertNextFieldNotEmpty(s.T(), "grpc.start_time"). - AssertNextFieldNotEmpty(s.T(), "grpc.request.deadline"). - AssertNextField(s.T(), "grpc.code", "OK"). - AssertNextFieldNotEmpty(s.T(), "grpc.duration").AssertNoMoreTags(s.T()) + serverFinishCallFields.AssertFieldNotEmpty(s.T(), "peer.address"). + AssertFieldNotEmpty(s.T(), "grpc.start_time"). + AssertFieldNotEmpty(s.T(), "grpc.request.deadline"). + AssertField(s.T(), "grpc.code", "OK"). + AssertFieldNotEmpty(s.T(), "grpc.duration").AssertNoMoreTags(s.T()) clientFinishCallLogLine := lines[0] assert.Equal(s.T(), logging.DEBUG, clientFinishCallLogLine.lvl) assert.Equal(s.T(), "finished call", clientFinishCallLogLine.msg) clientFinishCallFields := assertStandardFields(s.T(), logging.KindClientFieldValue, clientFinishCallLogLine.fields, "PingList", interceptors.ServerStream) - clientFinishCallFields.AssertNextFieldNotEmpty(s.T(), "grpc.start_time"). - AssertNextFieldNotEmpty(s.T(), "grpc.request.deadline"). - AssertNextField(s.T(), "grpc.code", "OK"). - AssertNextFieldNotEmpty(s.T(), "grpc.duration").AssertNoMoreTags(s.T()) + clientFinishCallFields.AssertFieldNotEmpty(s.T(), "grpc.start_time"). + AssertFieldNotEmpty(s.T(), "grpc.request.deadline"). + AssertField(s.T(), "grpc.code", "OK"). + AssertFieldNotEmpty(s.T(), "grpc.duration").AssertNoMoreTags(s.T()) } type loggingCustomDeciderSuite struct { @@ -488,12 +514,8 @@ func TestCustomDeciderSuite(t *testing.T) { grpc.WithStreamInterceptor(logging.StreamClientInterceptor(s.logger, opts)), } s.InterceptorTestSuite.ServerOpts = []grpc.ServerOption{ - grpc.ChainStreamInterceptor( - tags.StreamServerInterceptor(tags.WithFieldExtractor(tags.CodeGenRequestFieldExtractor)), - logging.StreamServerInterceptor(s.logger, opts)), - grpc.ChainUnaryInterceptor( - tags.UnaryServerInterceptor(tags.WithFieldExtractor(tags.CodeGenRequestFieldExtractor)), - logging.UnaryServerInterceptor(s.logger, opts)), + grpc.StreamInterceptor(logging.StreamServerInterceptor(s.logger, opts)), + grpc.UnaryInterceptor(logging.UnaryServerInterceptor(s.logger, opts)), } suite.Run(t, s) } @@ -531,23 +553,22 @@ func (s *loggingCustomDeciderSuite) TestPingError_HasCustomDecider() { assert.Equal(s.T(), logging.INFO, serverFinishCallLogLine.lvl) assert.Equal(s.T(), "finished call", serverFinishCallLogLine.msg) serverFinishCallFields := assertStandardFields(s.T(), logging.KindServerFieldValue, serverFinishCallLogLine.fields, "PingError", interceptors.Unary) - serverFinishCallFields.AssertNextField(s.T(), "grpc.request.value", "something"). - AssertNextFieldNotEmpty(s.T(), "peer.address"). - AssertNextFieldNotEmpty(s.T(), "grpc.start_time"). - AssertNextFieldNotEmpty(s.T(), "grpc.request.deadline"). - AssertNextField(s.T(), "grpc.code", "NotFound"). - AssertNextField(s.T(), "grpc.error", "rpc error: code = NotFound desc = Userspace error."). - AssertNextFieldNotEmpty(s.T(), "grpc.time_ms").AssertNoMoreTags(s.T()) + serverFinishCallFields.AssertFieldNotEmpty(s.T(), "peer.address"). + AssertFieldNotEmpty(s.T(), "grpc.start_time"). + AssertFieldNotEmpty(s.T(), "grpc.request.deadline"). + AssertField(s.T(), "grpc.code", "NotFound"). + AssertField(s.T(), "grpc.error", "rpc error: code = NotFound desc = Userspace error."). + AssertFieldNotEmpty(s.T(), "grpc.time_ms").AssertNoMoreTags(s.T()) clientFinishCallLogLine := lines[0] assert.Equal(s.T(), logging.DEBUG, clientFinishCallLogLine.lvl) assert.Equal(s.T(), "finished call", clientFinishCallLogLine.msg) clientFinishCallFields := assertStandardFields(s.T(), logging.KindClientFieldValue, clientFinishCallLogLine.fields, "PingError", interceptors.Unary) - clientFinishCallFields.AssertNextFieldNotEmpty(s.T(), "grpc.start_time"). - AssertNextFieldNotEmpty(s.T(), "grpc.request.deadline"). - AssertNextField(s.T(), "grpc.code", "NotFound"). - AssertNextField(s.T(), "grpc.error", "rpc error: code = NotFound desc = Userspace error."). - AssertNextFieldNotEmpty(s.T(), "grpc.time_ms").AssertNoMoreTags(s.T()) + clientFinishCallFields.AssertFieldNotEmpty(s.T(), "grpc.start_time"). + AssertFieldNotEmpty(s.T(), "grpc.request.deadline"). + AssertField(s.T(), "grpc.code", "NotFound"). + AssertField(s.T(), "grpc.error", "rpc error: code = NotFound desc = Userspace error."). + AssertFieldNotEmpty(s.T(), "grpc.time_ms").AssertNoMoreTags(s.T()) } func (s *loggingCustomDeciderSuite) TestPingList_HasCustomDecider() { @@ -560,6 +581,5 @@ func (s *loggingCustomDeciderSuite) TestPingList_HasCustomDecider() { } require.NoError(s.T(), err, "reading stream should not fail") } - require.Len(s.T(), s.logger.o.Lines(), 0) // Decider should suppress. } diff --git a/interceptors/logging/logging.go b/interceptors/logging/logging.go index 8ab7c8b54..43e9cc45f 100644 --- a/interceptors/logging/logging.go +++ b/interceptors/logging/logging.go @@ -6,8 +6,6 @@ package logging import ( "context" - "google.golang.org/grpc/codes" - "google.golang.org/grpc/status" "google.golang.org/protobuf/proto" "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors" @@ -37,46 +35,110 @@ var ( MethodTypeFieldKey = "grpc.method_type" ) -func commonFields(kind string, typ interceptors.GRPCType, service string, method string) Fields { +type fieldsCtxMarker struct{} + +var ( + // fieldsCtxMarkerKey is the Context value marker that is used by logging middleware to read and write logging fields into context. + fieldsCtxMarkerKey = &fieldsCtxMarker{} +) + +// Fields represents logging fields. It has to have even number of elements (pairs). +type Fields []string + +func newCommonFields(kind string, c interceptors.CallMeta) Fields { return Fields{ SystemTag[0], SystemTag[1], ComponentFieldKey, kind, - ServiceFieldKey, service, - MethodFieldKey, method, - MethodTypeFieldKey, string(typ), + ServiceFieldKey, c.Service, + MethodFieldKey, c.Method, + MethodTypeFieldKey, string(c.Typ), } } -// Fields represents logging fields. It has to have even number of elements (pairs). -type Fields []string +func (f Fields) Iter() FieldsIter { + return iter{i: -2, f: f} +} -// ErrorToCode function determines the error code of an error -// This makes using custom errors with grpc middleware easier -type ErrorToCode func(err error) codes.Code +type FieldsIter interface { + Next() bool + At() (k, v string) +} + +type iter struct { + f Fields + i int +} + +func (i iter) Next() bool { + if i.i >= len(i.f) { + return false + } + + i.i += 2 + return i.i < len(i.f) +} + +func (i iter) At() (k, v string) { + if i.i < 0 || i.i >= len(i.f) { + return "", "" + } -func DefaultErrorToCode(err error) codes.Code { - return status.Code(err) + if i.i+1 == len(i.f) { + // Non even number of elements, add empty string. + return i.f[i.i], "" + } + return i.f[i.i], i.f[i.i+1] } -// Decider function defines rules for suppressing any interceptor logs -type Decider func(fullMethodName string, err error) Decision +// AppendUnique returns fields which is the union of all keys with the added values having lower priority. +func (f Fields) AppendUnique(add Fields) Fields { + if len(add) == 0 { + return f + } + + existing := map[string]struct{}{} + i := f.Iter() + for i.Next() { + k, _ := i.At() + existing[k] = struct{}{} + } + + n := make(Fields, len(f), len(f)+len(add)) + copy(n, f) -// DefaultDeciderMethod is the default implementation of decider to see if you should log the call -// by default this if always true so all calls are logged -func DefaultDeciderMethod(_ string, _ error) Decision { - return LogStartAndFinishCall + a := add.Iter() + for a.Next() { + k, v := a.At() + if _, ok := existing[k]; ok { + continue + } + n = append(n, k, v) + } + return n } -// ServerPayloadLoggingDecider is a user-provided function for deciding whether to log the server-side -// request/response payloads -type ServerPayloadLoggingDecider func(ctx context.Context, fullMethodName string, servingObject interface{}) bool +// ExtractFields returns logging.Fields object from the Context. +// Logging interceptor adds fields into context when used. +// If no one injected fields before ExtractFields returns empty Fields. +// +// It's useful for server implementations to use this method to instantiate request logger for consistent fields (e.g request-id/tracing-id). +func ExtractFields(ctx context.Context) Fields { + t, ok := ctx.Value(fieldsCtxMarkerKey).(Fields) + if !ok { + return Fields{} + } + n := make(Fields, len(t)) + copy(n, t) + return n +} -// ClientPayloadLoggingDecider is a user-provided function for deciding whether to log the client-side -// request/response payloads -type ClientPayloadLoggingDecider func(ctx context.Context, fullMethodName string) bool +// InjectFields allows to add logging.Fields that will be used logging interceptor in the path of given context (if any). +func InjectFields(ctx context.Context, f Fields) context.Context { + return context.WithValue(ctx, fieldsCtxMarkerKey, ExtractFields(ctx).AppendUnique(f)) +} -// JsonPbMarshaller is a marshaller that serializes protobuf messages. -type JsonPbMarshaler interface { +// JsonPBMarshaller is a marshaller that serializes protobuf messages. +type JsonPBMarshaller interface { Marshal(pb proto.Message) ([]byte, error) } @@ -86,7 +148,7 @@ type Logger interface { // Log logs the fields for given log level. We can assume users (middleware library) will put fields in pairs and // those will be unique. Log(Level, string) - // With returns mockLogger with given fields appended. We can assume users (middleware library) will put fields in pairs + // With returns Logger with given fields appended. We can assume users (middleware library) will put fields in pairs // and those will be unique. With(fields ...string) Logger } @@ -100,39 +162,3 @@ const ( WARNING = Level("warning") ERROR = Level("error") ) - -// CodeToLevel function defines the mapping between gRPC return codes and interceptor log level. -type CodeToLevel func(code codes.Code) Level - -// DefaultServerCodeToLevel is the helper mapper that maps gRPC return codes to log levels for server side. -func DefaultServerCodeToLevel(code codes.Code) Level { - switch code { - case codes.OK, codes.NotFound, codes.Canceled, codes.AlreadyExists, codes.InvalidArgument, codes.Unauthenticated: - return INFO - - case codes.DeadlineExceeded, codes.PermissionDenied, codes.ResourceExhausted, codes.FailedPrecondition, codes.Aborted, - codes.OutOfRange, codes.Unavailable: - return WARNING - - case codes.Unknown, codes.Unimplemented, codes.Internal, codes.DataLoss: - return ERROR - - default: - return ERROR - } -} - -// DefaultClientCodeToLevel is the helper mapper that maps gRPC return codes to log levels for client side. -func DefaultClientCodeToLevel(code codes.Code) Level { - switch code { - case codes.OK, codes.Canceled, codes.InvalidArgument, codes.NotFound, codes.AlreadyExists, codes.ResourceExhausted, - codes.FailedPrecondition, codes.Aborted, codes.OutOfRange: - return DEBUG - case codes.Unknown, codes.DeadlineExceeded, codes.PermissionDenied, codes.Unauthenticated: - return INFO - case codes.Unimplemented, codes.Internal, codes.Unavailable, codes.DataLoss: - return WARNING - default: - return INFO - } -} diff --git a/interceptors/logging/options.go b/interceptors/logging/options.go index b1aa328cf..6581ecb54 100644 --- a/interceptors/logging/options.go +++ b/interceptors/logging/options.go @@ -1,8 +1,12 @@ package logging import ( + "context" "fmt" "time" + + "google.golang.org/grpc/codes" + "google.golang.org/grpc/status" ) var ( @@ -24,9 +28,6 @@ type options struct { type Option func(*options) -// DurationToFields function defines how to produce duration fields for logging. -type DurationToFields func(duration time.Duration) Fields - func evaluateServerOpt(opts []Option) *options { optCopy := &options{} *optCopy = *defaultOptions @@ -47,6 +48,70 @@ func evaluateClientOpt(opts []Option) *options { return optCopy } +// DurationToFields function defines how to produce duration fields for logging. +type DurationToFields func(duration time.Duration) Fields + +// ErrorToCode function determines the error code of an error. +// This makes using custom errors with grpc middleware easier. +type ErrorToCode func(err error) codes.Code + +func DefaultErrorToCode(err error) codes.Code { + return status.Code(err) +} + +// Decider function defines rules for suppressing any interceptor logs. +type Decider func(fullMethodName string, err error) Decision + +// DefaultDeciderMethod is the default implementation of decider to see if you should log the call +// by default this if always true so all calls are logged. +func DefaultDeciderMethod(_ string, _ error) Decision { + return LogStartAndFinishCall +} + +// ServerPayloadLoggingDecider is a user-provided function for deciding whether to log the server-side +// request/response payloads. +type ServerPayloadLoggingDecider func(ctx context.Context, fullMethodName string, servingObject interface{}) bool + +// ClientPayloadLoggingDecider is a user-provided function for deciding whether to log the client-side +// request/response payloads. +type ClientPayloadLoggingDecider func(ctx context.Context, fullMethodName string) bool + +// CodeToLevel function defines the mapping between gRPC return codes and interceptor log level. +type CodeToLevel func(code codes.Code) Level + +// DefaultServerCodeToLevel is the helper mapper that maps gRPC return codes to log levels for server side. +func DefaultServerCodeToLevel(code codes.Code) Level { + switch code { + case codes.OK, codes.NotFound, codes.Canceled, codes.AlreadyExists, codes.InvalidArgument, codes.Unauthenticated: + return INFO + + case codes.DeadlineExceeded, codes.PermissionDenied, codes.ResourceExhausted, codes.FailedPrecondition, codes.Aborted, + codes.OutOfRange, codes.Unavailable: + return WARNING + + case codes.Unknown, codes.Unimplemented, codes.Internal, codes.DataLoss: + return ERROR + + default: + return ERROR + } +} + +// DefaultClientCodeToLevel is the helper mapper that maps gRPC return codes to log levels for client side. +func DefaultClientCodeToLevel(code codes.Code) Level { + switch code { + case codes.OK, codes.Canceled, codes.InvalidArgument, codes.NotFound, codes.AlreadyExists, codes.ResourceExhausted, + codes.FailedPrecondition, codes.Aborted, codes.OutOfRange: + return DEBUG + case codes.Unknown, codes.DeadlineExceeded, codes.PermissionDenied, codes.Unauthenticated: + return INFO + case codes.Unimplemented, codes.Internal, codes.Unavailable, codes.DataLoss: + return WARNING + default: + return INFO + } +} + // WithDecider customizes the function for deciding if the gRPC interceptor logs should log. func WithDecider(f Decider) Option { return func(o *options) { diff --git a/interceptors/logging/payload.go b/interceptors/logging/payload.go index 936ea4a45..94e249dd3 100644 --- a/interceptors/logging/payload.go +++ b/interceptors/logging/payload.go @@ -7,11 +7,11 @@ import ( "time" "google.golang.org/grpc" + "google.golang.org/grpc/peer" "google.golang.org/protobuf/encoding/protojson" "google.golang.org/protobuf/proto" "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors" - "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/tags" ) type serverPayloadReporter struct { @@ -26,15 +26,19 @@ func (c *serverPayloadReporter) PostMsgSend(req interface{}, err error, duration return } - logger := c.logger.With(extractFields(tags.Extract(c.ctx))...) + logger := c.logger.With(ExtractFields(c.ctx)...) p, ok := req.(proto.Message) if !ok { logger.With("req.type", fmt.Sprintf("%T", req)).Log(ERROR, "req is not a google.golang.org/protobuf/proto.Message; programmatic error?") - return } // For server send message is the response. - logProtoMessageAsJson(logger.With("grpc.send.duration", duration.String()), p, "grpc.response.content", "response payload logged as grpc.response.content field") + logProtoMessageAsJson( + logger.With("grpc.send.duration", duration.String()), + p, + "grpc.response.content", + "response payload logged as grpc.response.content field", + ) } func (c *serverPayloadReporter) PostMsgReceive(reply interface{}, err error, duration time.Duration) { @@ -42,7 +46,7 @@ func (c *serverPayloadReporter) PostMsgReceive(reply interface{}, err error, dur return } - logger := c.logger.With(extractFields(tags.Extract(c.ctx))...) + logger := c.logger.With(ExtractFields(c.ctx)...) p, ok := reply.(proto.Message) if !ok { @@ -50,7 +54,12 @@ func (c *serverPayloadReporter) PostMsgReceive(reply interface{}, err error, dur return } // For server recv message is the request. - logProtoMessageAsJson(logger.With("grpc.recv.duration", duration.String()), p, "grpc.request.content", "request payload logged as grpc.request.content field") + logProtoMessageAsJson( + logger.With("grpc.recv.duration", duration.String()), + p, + "grpc.request.content", + "request payload logged as grpc.request.content field", + ) } type clientPayloadReporter struct { @@ -65,13 +74,18 @@ func (c *clientPayloadReporter) PostMsgSend(req interface{}, err error, duration return } - logger := c.logger.With(extractFields(tags.Extract(c.ctx))...) + logger := c.logger.With(ExtractFields(c.ctx)...) p, ok := req.(proto.Message) if !ok { logger.With("req.type", fmt.Sprintf("%T", req)).Log(ERROR, "req is not a google.golang.org/protobuf/proto.Message; programmatic error?") return } - logProtoMessageAsJson(logger.With("grpc.send.duration", duration.String()), p, "grpc.request.content", "request payload logged as grpc.request.content field") + logProtoMessageAsJson( + logger.With("grpc.send.duration", duration.String()), + p, + "grpc.request.content", + "request payload logged as grpc.request.content field", + ) } func (c *clientPayloadReporter) PostMsgReceive(reply interface{}, err error, duration time.Duration) { @@ -79,13 +93,18 @@ func (c *clientPayloadReporter) PostMsgReceive(reply interface{}, err error, dur return } - logger := c.logger.With(extractFields(tags.Extract(c.ctx))...) + logger := c.logger.With(ExtractFields(c.ctx)...) p, ok := reply.(proto.Message) if !ok { logger.With("reply.type", fmt.Sprintf("%T", reply)).Log(ERROR, "reply is not a google.golang.org/protobuf/proto.Message; programmatic error?") return } - logProtoMessageAsJson(logger.With("grpc.recv.duration", duration.String()), p, "grpc.response.content", "response payload logged as grpc.response.content field") + logProtoMessageAsJson( + logger.With("grpc.recv.duration", duration.String()), + p, + "grpc.response.content", + "response payload logged as grpc.response.content field", + ) } type payloadReportable struct { @@ -94,33 +113,33 @@ type payloadReportable struct { logger Logger } -func (r *payloadReportable) ServerReporter(ctx context.Context, req interface{}, typ interceptors.GRPCType, service string, method string) (interceptors.Reporter, context.Context) { - if !r.serverDecider(ctx, interceptors.FullMethod(service, method), req) { +func (r *payloadReportable) ServerReporter(ctx context.Context, c interceptors.CallMeta) (interceptors.Reporter, context.Context) { + if !r.serverDecider(ctx, c.Method, c.ReqProtoOrNil) { return interceptors.NoopReporter{}, ctx } - fields := commonFields(KindServerFieldValue, typ, service, method) - fields = append(fields, "grpc.start_time", time.Now().Format(time.RFC3339)) + fields := newCommonFields(KindServerFieldValue, c) + fields = fields.AppendUnique(ExtractFields(ctx)) + singleUseFields := []string{"grpc.start_time", time.Now().Format(time.RFC3339)} if d, ok := ctx.Deadline(); ok { - fields = append(fields, "grpc.request.deadline", d.Format(time.RFC3339)) + singleUseFields = append(singleUseFields, "grpc.request.deadline", d.Format(time.RFC3339)) } - return &serverPayloadReporter{ - ctx: ctx, - logger: r.logger.With(fields...), - }, ctx + return &serverPayloadReporter{ctx: ctx, logger: r.logger.With(fields...).With(singleUseFields...)}, InjectFields(ctx, fields) } -func (r *payloadReportable) ClientReporter(ctx context.Context, _ interface{}, typ interceptors.GRPCType, service string, method string) (interceptors.Reporter, context.Context) { - if !r.clientDecider(ctx, interceptors.FullMethod(service, method)) { + +func (r *payloadReportable) ClientReporter(ctx context.Context, c interceptors.CallMeta) (interceptors.Reporter, context.Context) { + if !r.clientDecider(ctx, c.FullMethod()) { return interceptors.NoopReporter{}, ctx } - fields := commonFields(KindClientFieldValue, typ, service, method) - fields = append(fields, "grpc.start_time", time.Now().Format(time.RFC3339)) + fields := newCommonFields(KindClientFieldValue, c) + if peer, ok := peer.FromContext(ctx); ok { + fields = append(fields, "peer.address", peer.Addr.String()) + } + fields = fields.AppendUnique(ExtractFields(ctx)) + singleUseFields := []string{"grpc.start_time", time.Now().Format(time.RFC3339)} if d, ok := ctx.Deadline(); ok { - fields = append(fields, "grpc.request.deadline", d.Format(time.RFC3339)) + singleUseFields = append(singleUseFields, "grpc.request.deadline", d.Format(time.RFC3339)) } - return &clientPayloadReporter{ - ctx: ctx, - logger: r.logger.With(fields...), - }, ctx + return &clientPayloadReporter{ctx: ctx, logger: r.logger.With(fields...)}, InjectFields(ctx, fields) } // PayloadUnaryServerInterceptor returns a new unary server interceptors that logs the payloads of requests on INFO level. diff --git a/interceptors/logging/payload_test.go b/interceptors/logging/payload_test.go index de95bccc1..18c7df146 100644 --- a/interceptors/logging/payload_test.go +++ b/interceptors/logging/payload_test.go @@ -15,7 +15,6 @@ import ( "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors" "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/logging" - "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/tags" "github.com/grpc-ecosystem/go-grpc-middleware/v2/testing/testpb" ) @@ -40,12 +39,8 @@ func TestPayloadSuite(t *testing.T) { grpc.WithStreamInterceptor(logging.PayloadStreamClientInterceptor(s.logger, alwaysLoggingDeciderClient)), } s.InterceptorTestSuite.ServerOpts = []grpc.ServerOption{ - grpc.ChainStreamInterceptor( - tags.StreamServerInterceptor(tags.WithFieldExtractor(tags.CodeGenRequestFieldExtractor)), - logging.PayloadStreamServerInterceptor(s.logger, alwaysLoggingDeciderServer)), - grpc.ChainUnaryInterceptor( - tags.UnaryServerInterceptor(tags.WithFieldExtractor(tags.CodeGenRequestFieldExtractor)), - logging.PayloadUnaryServerInterceptor(s.logger, alwaysLoggingDeciderServer)), + grpc.StreamInterceptor(logging.PayloadStreamServerInterceptor(s.logger, alwaysLoggingDeciderServer)), + grpc.UnaryInterceptor(logging.PayloadUnaryServerInterceptor(s.logger, alwaysLoggingDeciderServer)), } suite.Run(t, s) } @@ -70,10 +65,10 @@ func (s *loggingPayloadSuite) assertPayloadLogLinesForMessage(lines LogLines, me assert.Equal(s.T(), logging.INFO, clientRequestLogLine.lvl) assert.Equal(s.T(), "request payload logged as grpc.request.content field", clientRequestLogLine.msg) clientRequestFields := assertStandardFields(s.T(), logging.KindClientFieldValue, clientRequestLogLine.fields, method, typ) - clientRequestFields.AssertNextFieldNotEmpty(s.T(), "grpc.start_time"). - AssertNextFieldNotEmpty(s.T(), "grpc.send.duration"). - AssertNextField(s.T(), "grpc.request.content", `{"value":"something","sleepTimeMs":9999}`). - AssertNextFieldNotEmpty(s.T(), "grpc.request.deadline").AssertNoMoreTags(s.T()) + clientRequestFields.AssertFieldNotEmpty(s.T(), "grpc.start_time"). + AssertFieldNotEmpty(s.T(), "grpc.send.duration"). + AssertField(s.T(), "grpc.request.content", `{"value":"something","sleepTimeMs":9999}`). + AssertFieldNotEmpty(s.T(), "grpc.request.deadline").AssertNoMoreTags(s.T()) } curr += repetitions for i := curr; i < curr+repetitions; i++ { @@ -81,13 +76,13 @@ func (s *loggingPayloadSuite) assertPayloadLogLinesForMessage(lines LogLines, me assert.Equal(s.T(), logging.INFO, clientResponseLogLine.lvl) assert.Equal(s.T(), "response payload logged as grpc.response.content field", clientResponseLogLine.msg) clientResponseFields := assertStandardFields(s.T(), logging.KindClientFieldValue, clientResponseLogLine.fields, method, typ) - clientResponseFields = clientResponseFields.AssertNextFieldNotEmpty(s.T(), "grpc.start_time"). - AssertNextFieldNotEmpty(s.T(), "grpc.recv.duration"). - AssertNextFieldNotEmpty(s.T(), "grpc.request.deadline") + clientResponseFields = clientResponseFields.AssertFieldNotEmpty(s.T(), "grpc.start_time"). + AssertFieldNotEmpty(s.T(), "grpc.recv.duration"). + AssertFieldNotEmpty(s.T(), "grpc.request.deadline") if i-curr == 0 { - clientResponseFields = clientResponseFields.AssertNextField(s.T(), "grpc.response.content", `{"value":"something"}`) + clientResponseFields = clientResponseFields.AssertField(s.T(), "grpc.response.content", `{"value":"something"}`) } else { - clientResponseFields = clientResponseFields.AssertNextField(s.T(), "grpc.response.content", fmt.Sprintf(`{"value":"something","counter":%v}`, i-curr)) + clientResponseFields = clientResponseFields.AssertField(s.T(), "grpc.response.content", fmt.Sprintf(`{"value":"something","counter":%v}`, i-curr)) } clientResponseFields.AssertNoMoreTags(s.T()) } @@ -97,12 +92,11 @@ func (s *loggingPayloadSuite) assertPayloadLogLinesForMessage(lines LogLines, me assert.Equal(s.T(), logging.INFO, serverRequestLogLine.lvl) assert.Equal(s.T(), "request payload logged as grpc.request.content field", serverRequestLogLine.msg) serverRequestFields := assertStandardFields(s.T(), logging.KindServerFieldValue, serverRequestLogLine.fields, method, typ) - serverRequestFields.AssertNextField(s.T(), "grpc.request.value", "something"). - AssertNextFieldNotEmpty(s.T(), "peer.address"). - AssertNextFieldNotEmpty(s.T(), "grpc.start_time"). - AssertNextFieldNotEmpty(s.T(), "grpc.recv.duration"). - AssertNextFieldNotEmpty(s.T(), "grpc.request.deadline"). - AssertNextField(s.T(), "grpc.request.content", `{"value":"something","sleepTimeMs":9999}`).AssertNoMoreTags(s.T()) + serverRequestFields.AssertFieldNotEmpty(s.T(), "peer.address"). + AssertFieldNotEmpty(s.T(), "grpc.start_time"). + AssertFieldNotEmpty(s.T(), "grpc.recv.duration"). + AssertFieldNotEmpty(s.T(), "grpc.request.deadline"). + AssertField(s.T(), "grpc.request.content", `{"value":"something","sleepTimeMs":9999}`).AssertNoMoreTags(s.T()) } curr += repetitions for i := curr; i < curr+repetitions; i++ { @@ -110,15 +104,14 @@ func (s *loggingPayloadSuite) assertPayloadLogLinesForMessage(lines LogLines, me assert.Equal(s.T(), logging.INFO, serverResponseLogLine.lvl) assert.Equal(s.T(), "response payload logged as grpc.response.content field", serverResponseLogLine.msg) serverResponseFields := assertStandardFields(s.T(), logging.KindServerFieldValue, serverResponseLogLine.fields, method, typ) - serverResponseFields = serverResponseFields.AssertNextField(s.T(), "grpc.request.value", "something"). - AssertNextFieldNotEmpty(s.T(), "peer.address"). - AssertNextFieldNotEmpty(s.T(), "grpc.start_time"). - AssertNextFieldNotEmpty(s.T(), "grpc.send.duration"). - AssertNextFieldNotEmpty(s.T(), "grpc.request.deadline") + serverResponseFields = serverResponseFields.AssertFieldNotEmpty(s.T(), "peer.address"). + AssertFieldNotEmpty(s.T(), "grpc.start_time"). + AssertFieldNotEmpty(s.T(), "grpc.send.duration"). + AssertFieldNotEmpty(s.T(), "grpc.request.deadline") if i-curr == 0 { - serverResponseFields = serverResponseFields.AssertNextField(s.T(), "grpc.response.content", `{"value":"something"}`) + serverResponseFields = serverResponseFields.AssertField(s.T(), "grpc.response.content", `{"value":"something"}`) } else { - serverResponseFields = serverResponseFields.AssertNextField(s.T(), "grpc.response.content", fmt.Sprintf(`{"value":"something","counter":%v}`, i-curr)) + serverResponseFields = serverResponseFields.AssertField(s.T(), "grpc.response.content", fmt.Sprintf(`{"value":"something","counter":%v}`, i-curr)) } serverResponseFields.AssertNoMoreTags(s.T()) } @@ -136,10 +129,10 @@ func (s *loggingPayloadSuite) TestPingError_LogsOnlyRequestsOnError() { assert.Equal(s.T(), "request payload logged as grpc.request.content field", clientRequestLogLine.msg) clientRequestFields := assertStandardFields(s.T(), logging.KindClientFieldValue, clientRequestLogLine.fields, "PingError", interceptors.Unary) - clientRequestFields.AssertNextFieldNotEmpty(s.T(), "grpc.start_time"). - AssertNextFieldNotEmpty(s.T(), "grpc.send.duration"). - AssertNextField(s.T(), "grpc.request.content", `{"value":"something","errorCodeReturned":4}`). - AssertNextFieldNotEmpty(s.T(), "grpc.request.deadline").AssertNoMoreTags(s.T()) + clientRequestFields.AssertFieldNotEmpty(s.T(), "grpc.start_time"). + AssertFieldNotEmpty(s.T(), "grpc.send.duration"). + AssertField(s.T(), "grpc.request.content", `{"value":"something","errorCodeReturned":4}`). + AssertFieldNotEmpty(s.T(), "grpc.request.deadline").AssertNoMoreTags(s.T()) } func (s *loggingPayloadSuite) TestPingStream_LogsAllRequestsAndResponses() { diff --git a/interceptors/reporter.go b/interceptors/reporter.go index 1f5391de2..dfe01deff 100644 --- a/interceptors/reporter.go +++ b/interceptors/reporter.go @@ -55,16 +55,34 @@ func SplitMethodName(fullMethod string) (string, string) { return "unknown", "unknown" } -func FullMethod(service, method string) string { - return fmt.Sprintf("/%s/%s", service, method) +type CallMeta struct { + ReqProtoOrNil interface{} + Typ GRPCType + Service string + Method string +} + +func (c CallMeta) FullMethod() string { + return fmt.Sprintf("/%s/%s", c.Service, c.Method) } type ClientReportable interface { - ClientReporter(ctx context.Context, reqProtoOrNil interface{}, typ GRPCType, service string, method string) (Reporter, context.Context) + ClientReporter(context.Context, CallMeta) (Reporter, context.Context) } type ServerReportable interface { - ServerReporter(ctx context.Context, reqProtoOrNil interface{}, typ GRPCType, service string, method string) (Reporter, context.Context) + ServerReporter(context.Context, CallMeta) (Reporter, context.Context) +} + +// CommonReportableFunc helper allows an easy way to implement reporter with common client and server logic. +type CommonReportableFunc func(ctx context.Context, c CallMeta, isClient bool) (Reporter, context.Context) + +func (f CommonReportableFunc) ClientReporter(ctx context.Context, c CallMeta) (Reporter, context.Context) { + return f(ctx, c, true) +} + +func (f CommonReportableFunc) ServerReporter(ctx context.Context, c CallMeta) (Reporter, context.Context) { + return f(ctx, c, false) } type Reporter interface { diff --git a/interceptors/server.go b/interceptors/server.go index 61afbc06e..14095f679 100644 --- a/interceptors/server.go +++ b/interceptors/server.go @@ -16,7 +16,7 @@ import ( func UnaryServerInterceptor(reportable ServerReportable) grpc.UnaryServerInterceptor { return func(ctx context.Context, req interface{}, info *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (interface{}, error) { r := newReport(Unary, info.FullMethod) - reporter, newCtx := reportable.ServerReporter(ctx, req, r.rpcType, r.service, r.method) + reporter, newCtx := reportable.ServerReporter(ctx, CallMeta{ReqProtoOrNil: req, Typ: r.rpcType, Service: r.service, Method: r.method}) reporter.PostMsgReceive(req, nil, time.Since(r.startTime)) resp, err := handler(newCtx, req) @@ -31,7 +31,7 @@ func UnaryServerInterceptor(reportable ServerReportable) grpc.UnaryServerInterce func StreamServerInterceptor(reportable ServerReportable) grpc.StreamServerInterceptor { return func(srv interface{}, ss grpc.ServerStream, info *grpc.StreamServerInfo, handler grpc.StreamHandler) error { r := newReport(ServerStream, info.FullMethod) - reporter, newCtx := reportable.ServerReporter(ss.Context(), nil, StreamRPCType(info), r.service, r.method) + reporter, newCtx := reportable.ServerReporter(ss.Context(), CallMeta{ReqProtoOrNil: nil, Typ: StreamRPCType(info), Service: r.service, Method: r.method}) err := handler(srv, &monitoredServerStream{ServerStream: ss, newCtx: newCtx, reporter: reporter}) reporter.PostCall(err, time.Since(r.startTime)) return err diff --git a/interceptors/server_test.go b/interceptors/server_test.go index 9b9f9570a..1456e8639 100644 --- a/interceptors/server_test.go +++ b/interceptors/server_test.go @@ -91,9 +91,7 @@ func (s *ServerInterceptorTestSuite) TestUnaryReporting() { _, err := s.testClient.PingEmpty(s.ctx, &testpb.PingEmptyRequest{}) // should return with code=OK require.NoError(s.T(), err) s.mock.Equal(s.T(), []*mockReport{{ - typ: Unary, - svcName: testpb.TestServiceFullName, - methodName: "PingEmpty", + CallMeta: CallMeta{Typ: Unary, Service: testpb.TestServiceFullName, Method: "PingEmpty"}, postCalls: []error{nil}, postMsgReceives: []error{nil}, postMsgSends: []error{nil}, @@ -103,9 +101,7 @@ func (s *ServerInterceptorTestSuite) TestUnaryReporting() { _, err = s.testClient.PingError(s.ctx, &testpb.PingErrorRequest{ErrorCodeReturned: uint32(codes.FailedPrecondition)}) // should return with code=FailedPrecondition require.Error(s.T(), err) s.mock.Equal(s.T(), []*mockReport{{ - typ: Unary, - svcName: testpb.TestServiceFullName, - methodName: "PingError", + CallMeta: CallMeta{Typ: Unary, Service: testpb.TestServiceFullName, Method: "PingError"}, postCalls: []error{status.Errorf(codes.FailedPrecondition, "Userspace error.")}, postMsgReceives: []error{nil}, postMsgSends: []error{status.Errorf(codes.FailedPrecondition, "Userspace error.")}, @@ -126,9 +122,7 @@ func (s *ServerInterceptorTestSuite) TestStreamingReports() { } require.EqualValues(s.T(), testpb.ListResponseCount, count, "Number of received msg on the wire must match") s.mock.Equal(s.T(), []*mockReport{{ - typ: ServerStream, - svcName: testpb.TestServiceFullName, - methodName: "PingList", + CallMeta: CallMeta{Typ: ServerStream, Service: testpb.TestServiceFullName, Method: "PingList"}, postCalls: []error{nil}, postMsgReceives: []error{nil}, postMsgSends: make([]error, testpb.ListResponseCount), @@ -139,9 +133,7 @@ func (s *ServerInterceptorTestSuite) TestStreamingReports() { require.NoError(s.T(), err, "PingList must not fail immediately") s.mock.requireOneReportWithRetry(s.ctx, s.T(), &mockReport{ - typ: ServerStream, - svcName: testpb.TestServiceFullName, - methodName: "PingList", + CallMeta: CallMeta{Typ: ServerStream, Service: testpb.TestServiceFullName, Method: "PingList"}, postCalls: []error{status.Errorf(codes.FailedPrecondition, "foobar")}, postMsgReceives: []error{nil}, }) @@ -183,9 +175,7 @@ func (s *ServerInterceptorTestSuite) TestBiStreamingReporting() { require.EqualValues(s.T(), count, 100, "Number of received msg on the wire must match") s.mock.Equal(s.T(), []*mockReport{{ - typ: BidiStream, - svcName: testpb.TestServiceFullName, - methodName: "PingStream", + CallMeta: CallMeta{Typ: BidiStream, Service: testpb.TestServiceFullName, Method: "PingStream"}, postCalls: []error{nil}, postMsgReceives: append(make([]error, 100), io.EOF), postMsgSends: make([]error, 100), diff --git a/interceptors/tags/context.go b/interceptors/tags/context.go deleted file mode 100644 index 90f9e8c36..000000000 --- a/interceptors/tags/context.go +++ /dev/null @@ -1,82 +0,0 @@ -package tags - -import ( - "context" -) - -type ctxMarker struct{} - -var ( - // ctxMarkerKey is the Context value marker used by *all* middlewares that supports unique fields e.g tracing and logging. - ctxMarkerKey = &ctxMarker{} - // NoopTags is a trivial, minimum overhead implementation of Tags for which all operations are no-ops. - NoopTags = &noopTags{} -) - -// Tags is the interface used for storing request tags between Context calls. -// The default implementation is *not* thread safe, and should be handled only in the context of the request. -type Tags interface { - // Set sets the given key in the metadata tags. - Set(key string, value string) Tags - // Has checks if the given key exists. - Has(key string) bool - // Values returns a map of key to values. - // Do not modify the underlying map, use Set instead. - Values() map[string]string -} - -type mapTags struct { - values map[string]string -} - -func (t *mapTags) Set(key string, value string) Tags { - t.values[key] = value - return t -} - -func (t *mapTags) Has(key string) bool { - _, ok := t.values[key] - return ok -} - -func (t *mapTags) Values() map[string]string { - return t.values -} - -type noopTags struct{} - -func (t *noopTags) Set(key string, value string) Tags { return t } - -func (t *noopTags) Has(key string) bool { return false } - -func (t *noopTags) Values() map[string]string { return nil } - -// Extracts returns a pre-existing Tags object in the Context. -// If the context wasn't set in a tag interceptor, a no-op Tag storage is returned that will *not* be propagated in context. -func Extract(ctx context.Context) Tags { - t, ok := ctx.Value(ctxMarkerKey).(Tags) - if !ok { - return NoopTags - } - - return t -} - -// extractOrCreate returns a pre-existing Tags object in the Context. -// If the context wasn't set in a tag interceptor, a new Tag (map) storage is returned that will be propagated in context. -func extractOrCreate(ctx context.Context) Tags { - t, ok := ctx.Value(ctxMarkerKey).(Tags) - if !ok { - return NewTags() - } - - return t -} - -func SetInContext(ctx context.Context, tags Tags) context.Context { - return context.WithValue(ctx, ctxMarkerKey, tags) -} - -func NewTags() Tags { - return &mapTags{values: make(map[string]string)} -} diff --git a/interceptors/tags/doc.go b/interceptors/tags/doc.go deleted file mode 100644 index a22045414..000000000 --- a/interceptors/tags/doc.go +++ /dev/null @@ -1,22 +0,0 @@ -/* -`tags` adds a Tag object to the context that can be used by other middleware to add context about a request. - -Request Context Tags - -Tags describe information about the request, and can be set and used by other middleware, or handlers. Tags are used -for logging and tracing of requests. Tags are populated both upwards, *and* downwards in the interceptor-handler stack. - -You can automatically extract tags (in `grpc.request.`) from request payloads. - -For unary and server-streaming methods, pass in the `WithFieldExtractor` option. For client-streams and bidirectional-streams, you can -use `WithFieldExtractorForInitialReq` which will extract the tags from the first message passed from client to server. -Note the tags will not be modified for subsequent requests, so this option only makes sense when the initial message -establishes the meta-data for the stream. - -If a user doesn't use the interceptors that initialize the `Tags` object, all operations following from an `Extract(ctx)` -will be no-ops. This is to ensure that code doesn't panic if the interceptors weren't used. - -Tags fields are typed, and shallow and should follow the OpenTracing semantics convention: -https://github.com/opentracing/specification/blob/master/semantic_conventions.md -*/ -package tags diff --git a/interceptors/tags/examples_test.go b/interceptors/tags/examples_test.go deleted file mode 100644 index d1d6787fe..000000000 --- a/interceptors/tags/examples_test.go +++ /dev/null @@ -1,18 +0,0 @@ -package tags_test - -import ( - "google.golang.org/grpc" - - "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/tags" -) - -// Simple example of server initialization code, with data automatically populated from `log_fields` Golang tags. -func Example_initialization() { - opts := []tags.Option{ - tags.WithFieldExtractor(tags.TagBasedRequestFieldExtractor("log_fields")), - } - _ = grpc.NewServer( - grpc.StreamInterceptor(tags.StreamServerInterceptor(opts...)), - grpc.UnaryInterceptor(tags.UnaryServerInterceptor(opts...)), - ) -} diff --git a/interceptors/tags/fieldextractor.go b/interceptors/tags/fieldextractor.go deleted file mode 100644 index 1d0f2172b..000000000 --- a/interceptors/tags/fieldextractor.go +++ /dev/null @@ -1,80 +0,0 @@ -// Copyright 2017 Michal Witkowski. All Rights Reserved. -// See LICENSE for licensing terms. - -package tags - -import ( - "fmt" - "reflect" -) - -// RequestFieldExtractorFunc is a user-provided function that extracts field information from a gRPC request. -// It is called from tags middleware on arrival of unary request or a server-stream request. -// Keys and values will be added to the context tags of the request. If there are no fields, you should return a nil. -type RequestFieldExtractorFunc func(fullMethod string, req interface{}) map[string]string - -type requestFieldsExtractor interface { - // ExtractRequestFields is a method declared on a Protobuf message that extracts fields from the interface. - // The values from the extracted fields should be set in the appendToMap, in order to avoid allocations. - ExtractRequestFields(appendToMap map[string]string) -} - -// CodeGenRequestFieldExtractor is a function that relies on code-generated functions that export log fields from requests. -// These are usually coming from a protoc-plugin that generates additional information based on custom field options. -func CodeGenRequestFieldExtractor(_ string, req interface{}) map[string]string { - if ext, ok := req.(requestFieldsExtractor); ok { - retMap := make(map[string]string) - ext.ExtractRequestFields(retMap) - if len(retMap) == 0 { - return nil - } - return retMap - } - return nil -} - -// TagBasedRequestFieldExtractor is a function that relies on Go struct tags to export log fields from requests. -// TODO(bwplotka): Add tests/examples https://github.com/grpc-ecosystem/go-grpc-middleware/issues/382 -// The tagName is configurable using the tagName variable. Here it would be "log_field". -func TagBasedRequestFieldExtractor(tagName string) RequestFieldExtractorFunc { - return func(fullMethod string, req interface{}) map[string]string { - retMap := make(map[string]string) - reflectMessageTags(req, retMap, tagName) - if len(retMap) == 0 { - return nil - } - return retMap - } -} - -func reflectMessageTags(msg interface{}, existingMap map[string]string, tagName string) { - v := reflect.ValueOf(msg) - // Only deal with pointers to structs. - if v.Kind() != reflect.Ptr || v.Elem().Kind() != reflect.Struct { - return - } - // Deref the pointer get to the struct. - v = v.Elem() - t := v.Type() - for i := 0; i < v.NumField(); i++ { - field := v.Field(i) - kind := field.Kind() - // Only recurse down direct pointers or interfaces, which should only be to nested structs. - if (kind == reflect.Ptr || kind == reflect.Interface) && field.CanInterface() { - reflectMessageTags(field.Interface(), existingMap, tagName) - } - // In case of arrays/slices (repeated fields) go down to the concrete type. - if kind == reflect.Array || kind == reflect.Slice { - if field.Len() == 0 { - continue - } - kind = field.Index(0).Kind() - } - // Only be interested in those fields. - if (kind >= reflect.Bool && kind <= reflect.Float64) || kind == reflect.String { - if tag := t.Field(i).Tag.Get(tagName); tag != "" { - existingMap[tag] = fmt.Sprintf("%v", field.Interface()) - } - } - } -} diff --git a/interceptors/tags/fieldextractor_test.go b/interceptors/tags/fieldextractor_test.go deleted file mode 100644 index f367ce276..000000000 --- a/interceptors/tags/fieldextractor_test.go +++ /dev/null @@ -1,21 +0,0 @@ -// Copyright 2017 Michal Witkowski. All Rights Reserved. -// See LICENSE for licensing terms. - -package tags_test - -import ( - "testing" - - "github.com/stretchr/testify/require" - - "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/tags" - "github.com/grpc-ecosystem/go-grpc-middleware/v2/testing/testpb" -) - -// TODO(bwplotka): Add tests/examples https://github.com/grpc-ecosystem/go-grpc-middleware/issues/382 -func TestCodeGenRequestLogFieldExtractor_ManualIsDeclared(t *testing.T) { - req := &testpb.PingRequest{Value: "my_value"} - valMap := tags.CodeGenRequestFieldExtractor("", req) - require.Len(t, valMap, 1, "PingRequest should have a ExtractLogFields method declared in test.manual_extractfields.pb") - require.EqualValues(t, valMap, map[string]string{"value": "my_value"}) -} diff --git a/interceptors/tags/interceptors.go b/interceptors/tags/interceptors.go deleted file mode 100644 index 1ac21f624..000000000 --- a/interceptors/tags/interceptors.go +++ /dev/null @@ -1,70 +0,0 @@ -// Copyright 2017 Michal Witkowski. All Rights Reserved. -// See LICENSE for licensing terms. - -package tags - -import ( - "context" - "time" - - "google.golang.org/grpc" - "google.golang.org/grpc/peer" - - "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors" -) - -type reporter struct { - service, method string - - ctx context.Context - opts *options - initial bool -} - -func (c *reporter) PostCall(error, time.Duration) {} - -func (c *reporter) PostMsgSend(interface{}, error, time.Duration) {} - -func (c *reporter) PostMsgReceive(m interface{}, _ error, _ time.Duration) { - if c.initial { - c.initial = false - if valMap := c.opts.requestFieldsFunc(interceptors.FullMethod(c.service, c.method), m); valMap != nil { - t := Extract(c.ctx) - for k, v := range valMap { - // This assumes we can modify in place (it depends on tags implementation). - t.Set("grpc.request."+k, v) - } - } - } -} - -type reportable struct { - opts *options -} - -func (r *reportable) ServerReporter(ctx context.Context, _ interface{}, typ interceptors.GRPCType, service string, method string) (interceptors.Reporter, context.Context) { - tags := extractOrCreate(ctx) - if peer, ok := peer.FromContext(ctx); ok { - tags.Set("peer.address", peer.Addr.String()) - } - newCtx := SetInContext(ctx, tags) - if r.opts.requestFieldsFunc != nil { - return &reporter{ctx: newCtx, service: service, method: method, opts: r.opts, initial: true}, newCtx - } - - return interceptors.NoopReporter{}, newCtx -} - -// TODO(bwplotka): Add client, Add request ID / trace ID generation. - -// UnaryServerInterceptor returns a new unary server interceptors that sets the values for request tags. -func UnaryServerInterceptor(opts ...Option) grpc.UnaryServerInterceptor { - o := evaluateOptions(opts) - return interceptors.UnaryServerInterceptor(&reportable{opts: o}) -} - -// StreamServerInterceptor returns a new streaming server interceptor that sets the values for request tags. -func StreamServerInterceptor(opts ...Option) grpc.StreamServerInterceptor { - o := evaluateOptions(opts) - return interceptors.StreamServerInterceptor(&reportable{opts: o}) -} diff --git a/interceptors/tags/interceptors_test.go b/interceptors/tags/interceptors_test.go deleted file mode 100644 index e684b1cd1..000000000 --- a/interceptors/tags/interceptors_test.go +++ /dev/null @@ -1,194 +0,0 @@ -package tags_test - -import ( - "context" - "encoding/json" - "io" - "testing" - "time" - - "github.com/stretchr/testify/assert" - "github.com/stretchr/testify/require" - "github.com/stretchr/testify/suite" - "google.golang.org/grpc" - - "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/tags" - "github.com/grpc-ecosystem/go-grpc-middleware/v2/testing/testpb" -) - -func tagsToJson(value map[string]string) string { - str, _ := json.Marshal(value) - return string(str) -} - -func tagsFromJson(t *testing.T, jstring string) map[string]string { - var msgMapTemplate map[string]string - err := json.Unmarshal([]byte(jstring), &msgMapTemplate) - if err != nil { - t.Fatalf("failed unmarshaling tags from response %v", err) - } - return msgMapTemplate -} - -type tagPingBack struct { - testpb.TestServiceServer -} - -func (s *tagPingBack) Ping(ctx context.Context, _ *testpb.PingRequest) (*testpb.PingResponse, error) { - return &testpb.PingResponse{Value: tagsToJson(tags.Extract(ctx).Values())}, nil -} - -func (s *tagPingBack) PingError(ctx context.Context, ping *testpb.PingErrorRequest) (*testpb.PingErrorResponse, error) { - return s.TestServiceServer.PingError(ctx, ping) -} - -func (s *tagPingBack) PingList(_ *testpb.PingListRequest, stream testpb.TestService_PingListServer) error { - return stream.Send(&testpb.PingListResponse{Value: tagsToJson(tags.Extract(stream.Context()).Values())}) -} - -func (s *tagPingBack) PingEmpty(ctx context.Context, empty *testpb.PingEmptyRequest) (*testpb.PingEmptyResponse, error) { - return s.TestServiceServer.PingEmpty(ctx, empty) -} - -func (s *tagPingBack) PingStream(stream testpb.TestService_PingStreamServer) error { - for { - _, err := stream.Recv() - if err == io.EOF { - return nil - } - if err != nil { - return err - } - err = stream.Send(&testpb.PingStreamResponse{Value: tagsToJson(tags.Extract(stream.Context()).Values())}) - if err != nil { - return err - } - } -} -func TestTaggingSuite(t *testing.T) { - opts := []tags.Option{ - tags.WithFieldExtractor(tags.CodeGenRequestFieldExtractor), - } - s := &TaggingSuite{ - InterceptorTestSuite: &testpb.InterceptorTestSuite{ - TestService: &tagPingBack{&testpb.TestPingService{T: t}}, - ServerOpts: []grpc.ServerOption{ - grpc.StreamInterceptor(tags.StreamServerInterceptor(opts...)), - grpc.UnaryInterceptor(tags.UnaryServerInterceptor(opts...)), - }, - }, - } - suite.Run(t, s) -} - -type TaggingSuite struct { - *testpb.InterceptorTestSuite -} - -func (s *TaggingSuite) SetupTest() { -} - -func (s *TaggingSuite) TestPing_WithCustomTags() { - resp, err := s.Client.Ping(s.SimpleCtx(), testpb.GoodPing) - require.NoError(s.T(), err, "must not be an error on a successful call") - - tags := tagsFromJson(s.T(), resp.Value) - assert.Equal(s.T(), "something", tags["grpc.request.value"], "the tags should contain the correct request value") - assert.Contains(s.T(), tags, "peer.address", "the tags should contain a peer address") - require.Len(s.T(), tags, 2) -} - -func (s *TaggingSuite) TestPing_WithDeadline() { - ctx, cancel := context.WithDeadline(context.TODO(), time.Now().AddDate(0, 0, 5)) - defer cancel() - resp, err := s.Client.Ping(ctx, testpb.GoodPing) - require.NoError(s.T(), err, "must not be an error on a successful call") - - tags := tagsFromJson(s.T(), resp.Value) - assert.Equal(s.T(), "something", tags["grpc.request.value"], "the tags should contain the correct request value") - assert.Contains(s.T(), tags, "peer.address", "the tags should contain a peer address") - require.Len(s.T(), tags, 2) -} - -func (s *TaggingSuite) TestPing_WithNoDeadline() { - ctx := context.TODO() - resp, err := s.Client.Ping(ctx, testpb.GoodPing) - require.NoError(s.T(), err, "must not be an error on a successful call") - - tags := tagsFromJson(s.T(), resp.Value) - assert.Equal(s.T(), "something", tags["grpc.request.value"], "the tags should contain the correct request value") - assert.Contains(s.T(), tags, "peer.address", "the tags should contain a peer address") - require.Len(s.T(), tags, 2) -} - -func (s *TaggingSuite) TestPingList_WithCustomTags() { - stream, err := s.Client.PingList(s.SimpleCtx(), testpb.GoodPingList) - require.NoError(s.T(), err, "should not fail on establishing the stream") - for { - resp, err := stream.Recv() - if err == io.EOF { - break - } - require.NoError(s.T(), err, "reading stream should not fail") - - tags := tagsFromJson(s.T(), resp.Value) - assert.Equal(s.T(), "something", tags["grpc.request.value"], "the tags should contain the correct request value") - assert.Contains(s.T(), tags, "peer.address", "the tags should contain a peer address") - } -} - -func TestTaggingOnInitialRequestSuite(t *testing.T) { - opts := []tags.Option{ - tags.WithFieldExtractor(tags.CodeGenRequestFieldExtractor), - } - // Embeds TaggingSuite as the behaviour should be identical in - // the case of unary and server-streamed calls - s := &ClientStreamedTaggingSuite{ - TaggingSuite: &TaggingSuite{ - InterceptorTestSuite: &testpb.InterceptorTestSuite{ - TestService: &tagPingBack{&testpb.TestPingService{T: t}}, - ServerOpts: []grpc.ServerOption{ - grpc.StreamInterceptor(tags.StreamServerInterceptor(opts...)), - grpc.UnaryInterceptor(tags.UnaryServerInterceptor(opts...)), - }, - }, - }, - } - suite.Run(t, s) -} - -type ClientStreamedTaggingSuite struct { - *TaggingSuite -} - -func (s *ClientStreamedTaggingSuite) TestPingStream_WithCustomTagsFirstRequest() { - stream, err := s.Client.PingStream(s.SimpleCtx()) - require.NoError(s.T(), err, "should not fail on establishing the stream") - - count := 0 - for { - switch { - case count == 0: - err = stream.Send(testpb.GoodPingStream) - case count < 3: - err = stream.Send(&testpb.PingStreamRequest{Value: "another", SleepTimeMs: 9999}) - default: - err = stream.CloseSend() - } - require.NoError(s.T(), err, "sending stream should not fail") - - resp, err := stream.Recv() - if err == io.EOF { - break - } - require.NoError(s.T(), err, "reading stream should not fail") - - tags := tagsFromJson(s.T(), resp.Value) - assert.Equal(s.T(), "something", tags["grpc.request.value"], "the tags should contain the correct request value") - assert.Contains(s.T(), tags, "peer.address", "the tags should contain a peer address") - require.Len(s.T(), tags, 2) - count++ - } - - assert.Equal(s.T(), count, 3) -} diff --git a/interceptors/tags/options.go b/interceptors/tags/options.go deleted file mode 100644 index c3997c2fc..000000000 --- a/interceptors/tags/options.go +++ /dev/null @@ -1,33 +0,0 @@ -// Copyright 2017 Michal Witkowski. All Rights Reserved. -// See LICENSE for licensing terms. - -package tags - -var ( - defaultOptions = &options{ - requestFieldsFunc: nil, - } -) - -type options struct { - requestFieldsFunc RequestFieldExtractorFunc -} - -func evaluateOptions(opts []Option) *options { - optCopy := &options{} - *optCopy = *defaultOptions - for _, o := range opts { - o(optCopy) - } - return optCopy -} - -type Option func(*options) - -// WithFieldExtractor customizes the function for extracting log fields from protobuf messages, for -// unary and server-streamed methods only. -func WithFieldExtractor(f RequestFieldExtractorFunc) Option { - return func(o *options) { - o.requestFieldsFunc = f - } -} diff --git a/interceptors/tracing/client.go b/interceptors/tracing/client.go index ead4931af..0f17aa645 100644 --- a/interceptors/tracing/client.go +++ b/interceptors/tracing/client.go @@ -18,14 +18,13 @@ import ( "github.com/grpc-ecosystem/go-grpc-middleware/v2/util/metautils" ) -type opentracingClientReporter struct { - typ interceptors.GRPCType - svcName, methodName string +type clientReporter struct { + interceptors.CallMeta clientSpan opentracing.Span } -func (o *opentracingClientReporter) PostCall(err error, _ time.Duration) { +func (o *clientReporter) PostCall(err error, _ time.Duration) { // Finish span. if err != nil && err != io.EOF { ext.Error.Set(o.clientSpan, true) @@ -34,35 +33,37 @@ func (o *opentracingClientReporter) PostCall(err error, _ time.Duration) { o.clientSpan.Finish() } -func (o *opentracingClientReporter) PostMsgSend(interface{}, error, time.Duration) {} +func (o *clientReporter) PostMsgSend(interface{}, error, time.Duration) {} -func (o *opentracingClientReporter) PostMsgReceive(interface{}, error, time.Duration) {} +func (o *clientReporter) PostMsgReceive(interface{}, error, time.Duration) {} -type opentracingClientReportable struct { +type clientReportable struct { tracer opentracing.Tracer filterOutFunc FilterFunc } -func (o *opentracingClientReportable) ClientReporter(ctx context.Context, _ interface{}, typ interceptors.GRPCType, service string, method string) (interceptors.Reporter, context.Context) { - if o.filterOutFunc != nil && !o.filterOutFunc(ctx, method) { +func (o *clientReportable) ClientReporter(ctx context.Context, c interceptors.CallMeta) (interceptors.Reporter, context.Context) { + if o.filterOutFunc != nil && !o.filterOutFunc(ctx, c.FullMethod()) { return interceptors.NoopReporter{}, ctx } - - newCtx, clientSpan := newClientSpanFromContext(ctx, o.tracer, interceptors.FullMethod(service, method)) - mock := &opentracingClientReporter{typ: typ, svcName: service, methodName: method, clientSpan: clientSpan} + newCtx, clientSpan := newClientSpanFromContext(ctx, o.tracer, c.FullMethod()) + mock := &clientReporter{ + CallMeta: c, + clientSpan: clientSpan, + } return mock, newCtx } // UnaryClientInterceptor returns a new unary client interceptor for OpenTracing. func UnaryClientInterceptor(opts ...Option) grpc.UnaryClientInterceptor { o := evaluateOptions(opts) - return interceptors.UnaryClientInterceptor(&opentracingClientReportable{tracer: o.tracer, filterOutFunc: o.filterOutFunc}) + return interceptors.UnaryClientInterceptor(&clientReportable{tracer: o.tracer, filterOutFunc: o.filterOutFunc}) } // StreamClientInterceptor returns a new streaming client interceptor for OpenTracing. func StreamClientInterceptor(opts ...Option) grpc.StreamClientInterceptor { o := evaluateOptions(opts) - return interceptors.StreamClientInterceptor(&opentracingClientReportable{tracer: o.tracer, filterOutFunc: o.filterOutFunc}) + return interceptors.StreamClientInterceptor(&clientReportable{tracer: o.tracer, filterOutFunc: o.filterOutFunc}) } // ClientAddContextTags returns a context with specified opentracing tags, which diff --git a/interceptors/tracing/id_extract.go b/interceptors/tracing/id_extract.go index a0e482cb0..5802edd31 100644 --- a/interceptors/tracing/id_extract.go +++ b/interceptors/tracing/id_extract.go @@ -5,18 +5,16 @@ import ( "github.com/opentracing/opentracing-go" "google.golang.org/grpc/grpclog" - - "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/tags" ) const ( - TagTraceId = "trace.traceid" - TagSpanId = "trace.spanid" - TagSampled = "trace.sampled" + FieldTraceID = "trace.traceid" + FieldSpanID = "trace.spanid" + FieldSampled = "trace.sampled" jaegerNotSampledFlag = "0" ) -// injectOpentracingIdsToTags writes trace data to tags. +// getTraceMeta returns trace hidden data from tracer. // This is done in an incredibly hacky way, because the public-facing interface of opentracing doesn't give access to // the TraceId and SpanId of the SpanContext. Only the Tracer's Inject/Extract methods know what these are. // Most tracers have them encoded as keys with 'traceid' and 'spanid': @@ -26,58 +24,56 @@ const ( // https://www.jaegertracing.io/docs/client-libraries/#trace-span-identity // Datadog uses keys ending with 'trace-id' and 'parent-id' (for span) by default: // https://github.com/DataDog/dd-trace-go/blob/v1/ddtrace/tracer/textmap.go#L77 -func injectOpentracingIdsToTags(traceHeaderName string, span opentracing.Span, tags tags.Tags) { - if err := span.Tracer().Inject(span.Context(), opentracing.HTTPHeaders, - &tagsCarrier{Tags: tags, traceHeaderName: traceHeaderName}); err != nil { +func getTraceMeta(traceHeaderName string, span opentracing.Span) TraceMeta { + c := &mockedCarrier{traceHeaderName: traceHeaderName} + if err := span.Tracer().Inject(span.Context(), opentracing.HTTPHeaders, c); err != nil { grpclog.Infof("grpc_opentracing: failed extracting trace info into ctx %v", err) } + return c.m +} + +type TraceMeta struct { + TraceID string + SpanID string + Sampled bool } -// tagsCarrier is a really hacky way of -type tagsCarrier struct { - tags.Tags +type mockedCarrier struct { + m TraceMeta traceHeaderName string } -func (t *tagsCarrier) Set(key, val string) { +func (c *mockedCarrier) Set(key, val string) { key = strings.ToLower(key) - if key == t.traceHeaderName { + if key == c.traceHeaderName { parts := strings.Split(val, ":") if len(parts) == 4 { - t.Tags.Set(TagTraceId, parts[0]) - t.Tags.Set(TagSpanId, parts[1]) - - if parts[3] != jaegerNotSampledFlag { - t.Tags.Set(TagSampled, "true") - } else { - t.Tags.Set(TagSampled, "false") - } + c.m.TraceID = parts[0] + c.m.SpanID = parts[1] + c.m.Sampled = parts[3] != jaegerNotSampledFlag return } } if strings.Contains(key, "traceid") { - t.Tags.Set(TagTraceId, val) // this will most likely be base-16 (hex) encoded + c.m.TraceID = val // This will most likely be base-16 (hex) encoded. } if strings.Contains(key, "spanid") && !strings.Contains(strings.ToLower(key), "parent") { - t.Tags.Set(TagSpanId, val) // this will most likely be base-16 (hex) encoded + c.m.SpanID = val // This will most likely be base-16 (hex) encoded. } if strings.Contains(key, "sampled") { - switch val { - case "true", "false": - t.Tags.Set(TagSampled, val) - } + c.m.Sampled = val == "true" } if strings.HasSuffix(key, "trace-id") { - t.Tags.Set(TagTraceId, val) + c.m.TraceID = val } if strings.HasSuffix(key, "parent-id") { - t.Tags.Set(TagSpanId, val) + c.m.SpanID = val } } diff --git a/interceptors/tracing/id_extract_test.go b/interceptors/tracing/id_extract_test.go index ce93b6e91..adc753357 100644 --- a/interceptors/tracing/id_extract_test.go +++ b/interceptors/tracing/id_extract_test.go @@ -5,11 +5,9 @@ import ( "testing" "github.com/stretchr/testify/assert" - - "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/tags" ) -func TestTagsCarrier_Set_JaegerTraceFormat(t *testing.T) { +func TestMockedCarrier_Set_JaegerTraceFormat(t *testing.T) { var ( fakeTraceSampled = 1 fakeInboundTraceId = "deadbeef" @@ -19,16 +17,11 @@ func TestTagsCarrier_Set_JaegerTraceFormat(t *testing.T) { traceHeaderValue := fmt.Sprintf("%s:%s:%s:%d", fakeInboundTraceId, fakeInboundSpanId, fakeInboundSpanId, fakeTraceSampled) - c := &tagsCarrier{ - Tags: tags.NewTags(), - traceHeaderName: traceHeaderName, - } - + c := &mockedCarrier{traceHeaderName: traceHeaderName} c.Set(traceHeaderName, traceHeaderValue) - - assert.EqualValues(t, map[string]string{ - TagTraceId: fakeInboundTraceId, - TagSpanId: fakeInboundSpanId, - TagSampled: "true", - }, c.Tags.Values()) + assert.Equal(t, TraceMeta{ + TraceID: fakeInboundTraceId, + SpanID: fakeInboundSpanId, + Sampled: true, + }, c.m) } diff --git a/interceptors/tracing/interceptors_test.go b/interceptors/tracing/interceptors_test.go index 71d9bdda8..00d52dd04 100644 --- a/interceptors/tracing/interceptors_test.go +++ b/interceptors/tracing/interceptors_test.go @@ -21,14 +21,15 @@ import ( "google.golang.org/grpc" "google.golang.org/grpc/codes" - "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/tags" + "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/logging" + "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/tracing" "github.com/grpc-ecosystem/go-grpc-middleware/v2/testing/testpb" ) var ( - fakeInboundTraceId = 1337 - fakeInboundSpanId = 999 + fakeInboundTraceId = "1337" + fakeInboundSpanId = "999" traceHeaderName = "uber-trace-id" ) @@ -39,11 +40,7 @@ type tracingAssertService struct { func (s *tracingAssertService) Ping(ctx context.Context, ping *testpb.PingRequest) (*testpb.PingResponse, error) { assert.NotNil(s.T, opentracing.SpanFromContext(ctx), "handlers must have the spancontext in their context, otherwise propagation will fail") - tags := tags.Extract(ctx) - assert.True(s.T, tags.Has(tracing.TagTraceId), "tags must contain traceid") - assert.True(s.T, tags.Has(tracing.TagSpanId), "tags must contain spanid") - assert.True(s.T, tags.Has(tracing.TagSampled), "tags must contain sampled") - assert.Equal(s.T, tags.Values()[tracing.TagSampled], "true", "sampled must be set to true") + assert.Equal(s.T, []string{tracing.FieldTraceID, fakeInboundTraceId, tracing.FieldSpanID, fakeInboundSpanId, tracing.FieldSampled, "true"}, logging.ExtractFields(ctx)) return s.TestServiceServer.Ping(ctx, ping) } @@ -54,25 +51,17 @@ func (s *tracingAssertService) PingError(ctx context.Context, ping *testpb.PingE func (s *tracingAssertService) PingList(ping *testpb.PingListRequest, stream testpb.TestService_PingListServer) error { assert.NotNil(s.T, opentracing.SpanFromContext(stream.Context()), "handlers must have the spancontext in their context, otherwise propagation will fail") - tags := tags.Extract(stream.Context()) - assert.True(s.T, tags.Has(tracing.TagTraceId), "tags must contain traceid") - assert.True(s.T, tags.Has(tracing.TagSpanId), "tags must contain spanid") - assert.True(s.T, tags.Has(tracing.TagSampled), "tags must contain sampled") - assert.Equal(s.T, tags.Values()[tracing.TagSampled], "true", "sampled must be set to true") + assert.Equal(s.T, []string{tracing.FieldTraceID, fakeInboundTraceId, tracing.FieldSpanID, fakeInboundSpanId, tracing.FieldSampled, "true"}, logging.ExtractFields(stream.Context())) return s.TestServiceServer.PingList(ping, stream) } func (s *tracingAssertService) PingEmpty(ctx context.Context, empty *testpb.PingEmptyRequest) (*testpb.PingEmptyResponse, error) { assert.NotNil(s.T, opentracing.SpanFromContext(ctx), "handlers must have the spancontext in their context, otherwise propagation will fail") - tags := tags.Extract(ctx) - assert.True(s.T, tags.Has(tracing.TagTraceId), "tags must contain traceid") - assert.True(s.T, tags.Has(tracing.TagSpanId), "tags must contain spanid") - assert.True(s.T, tags.Has(tracing.TagSampled), "tags must contain sampled") - assert.Equal(s.T, tags.Values()[tracing.TagSampled], "false", "sampled must be set to false") + assert.Equal(s.T, []string{tracing.FieldTraceID, fakeInboundTraceId, tracing.FieldSpanID, fakeInboundSpanId, tracing.FieldSampled, "true"}, logging.ExtractFields(ctx)) return s.TestServiceServer.PingEmpty(ctx, empty) } -func TestTaggingSuite(t *testing.T) { +func TestTracingSuite(t *testing.T) { mockTracer := mocktracer.New() opts := []tracing.Option{ tracing.WithTracer(mockTracer), @@ -85,7 +74,7 @@ func TestTaggingSuite(t *testing.T) { suite.Run(t, s) } -func TestTaggingSuiteJaeger(t *testing.T) { +func TestTracingSuiteJaeger(t *testing.T) { mockTracer := mocktracer.New() mockTracer.RegisterInjector(opentracing.HTTPHeaders, jaegerFormatInjector{}) mockTracer.RegisterExtractor(opentracing.HTTPHeaders, jaegerFormatExtractor{}) @@ -107,12 +96,8 @@ func makeInterceptorTestSuite(t *testing.T, opts []tracing.Option) *testpb.Inter grpc.WithStreamInterceptor(tracing.StreamClientInterceptor(opts...)), }, ServerOpts: []grpc.ServerOption{ - grpc.ChainStreamInterceptor( - tags.StreamServerInterceptor(tags.WithFieldExtractor(tags.CodeGenRequestFieldExtractor)), - tracing.StreamServerInterceptor(opts...)), - grpc.ChainUnaryInterceptor( - tags.UnaryServerInterceptor(tags.WithFieldExtractor(tags.CodeGenRequestFieldExtractor)), - tracing.UnaryServerInterceptor(opts...)), + grpc.StreamInterceptor(tracing.StreamServerInterceptor(opts...)), + grpc.UnaryInterceptor(tracing.UnaryServerInterceptor(opts...)), }, } } @@ -133,9 +118,9 @@ func (s *OpentracingSuite) createContextFromFakeHttpRequestParent(ctx context.Co } hdr := http.Header{} - hdr.Set(traceHeaderName, fmt.Sprintf("%d:%d:%d:%d", fakeInboundTraceId, fakeInboundSpanId, fakeInboundSpanId, jFlag)) - hdr.Set("mockpfx-ids-traceid", fmt.Sprint(fakeInboundTraceId)) - hdr.Set("mockpfx-ids-spanid", fmt.Sprint(fakeInboundSpanId)) + hdr.Set(traceHeaderName, fmt.Sprintf("%s:%s:%s:%d", fakeInboundTraceId, fakeInboundSpanId, fakeInboundSpanId, jFlag)) + hdr.Set("mockpfx-ids-traceid", fakeInboundTraceId) + hdr.Set("mockpfx-ids-spanid", fakeInboundSpanId) hdr.Set("mockpfx-ids-sampled", fmt.Sprint(sampled)) parentSpanContext, err := s.mockTracer.Extract(opentracing.HTTPHeaders, opentracing.HTTPHeadersCarrier(hdr)) @@ -155,7 +140,7 @@ func (s *OpentracingSuite) assertTracesCreated(methodName string) (clientSpan *m s.T().Logf("span: %v, tags: %v", span, span.Tags()) } require.Len(s.T(), spans, 3, "should record 3 spans: one fake inbound, one client, one server") - traceIdAssert := fmt.Sprintf("traceId=%d", fakeInboundTraceId) + traceIdAssert := fmt.Sprintf("traceId=%s", fakeInboundTraceId) for _, span := range spans { assert.Contains(s.T(), span.String(), traceIdAssert, "not part of the fake parent trace: %v", span) if span.OperationName == methodName { diff --git a/interceptors/tracing/metadata.go b/interceptors/tracing/metadata.go index 83a16a7c9..0486a4f78 100644 --- a/interceptors/tracing/metadata.go +++ b/interceptors/tracing/metadata.go @@ -14,7 +14,7 @@ const ( binHdrSuffix = "-bin" ) -// metadataTextMap extends a metadata.MD to be an opentracing textmap +// metadataTextMap extends a metadata.MD to be an opentracing textmap. type metadataTextMap metadata.MD // Set is a opentracing.TextMapReader interface that extracts values. diff --git a/interceptors/tracing/server.go b/interceptors/tracing/server.go index ba05f90b4..9180f0fa0 100644 --- a/interceptors/tracing/server.go +++ b/interceptors/tracing/server.go @@ -5,6 +5,7 @@ package tracing import ( "context" + "fmt" "time" "github.com/opentracing/opentracing-go" @@ -13,8 +14,9 @@ import ( "google.golang.org/grpc" "google.golang.org/grpc/grpclog" + "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/logging" + "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors" - "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/tags" "github.com/grpc-ecosystem/go-grpc-middleware/v2/util/metautils" ) @@ -22,19 +24,18 @@ var ( grpcTag = opentracing.Tag{Key: string(ext.Component), Value: "gRPC"} ) -type opentracingServerReporter struct { - ctx context.Context - typ interceptors.GRPCType - service, method string +type serverReporter struct { + ctx context.Context + interceptors.CallMeta serverSpan opentracing.Span } -func (o *opentracingServerReporter) PostCall(err error, _ time.Duration) { - // Finish span and log context information. - tags := tags.Extract(o.ctx) - for k, v := range tags.Values() { - o.serverSpan.SetTag(k, v) +func (o *serverReporter) PostCall(err error, _ time.Duration) { + // Finish span and extract logging context information for richer spans. + fieldIter := logging.ExtractFields(o.ctx).Iter() + for fieldIter.Next() { + o.serverSpan.SetTag(fieldIter.At()) } if err != nil { ext.Error.Set(o.serverSpan, true) @@ -43,37 +44,40 @@ func (o *opentracingServerReporter) PostCall(err error, _ time.Duration) { o.serverSpan.Finish() } -func (o *opentracingServerReporter) PostMsgSend(interface{}, error, time.Duration) {} +func (o *serverReporter) PostMsgSend(interface{}, error, time.Duration) {} -func (o *opentracingServerReporter) PostMsgReceive(interface{}, error, time.Duration) {} +func (o *serverReporter) PostMsgReceive(interface{}, error, time.Duration) {} -type opentracingServerReportable struct { - tracer opentracing.Tracer - // This is only used for server. TODO: Investigate if needed in client. +type serverReportable struct { + tracer opentracing.Tracer traceHeaderName string filterOutFunc FilterFunc } -func (o *opentracingServerReportable) ServerReporter(ctx context.Context, _ interface{}, typ interceptors.GRPCType, service string, method string) (interceptors.Reporter, context.Context) { - if o.filterOutFunc != nil && !o.filterOutFunc(ctx, interceptors.FullMethod(service, method)) { +func (o *serverReportable) ServerReporter(ctx context.Context, c interceptors.CallMeta) (interceptors.Reporter, context.Context) { + if o.filterOutFunc != nil && !o.filterOutFunc(ctx, c.FullMethod()) { return interceptors.NoopReporter{}, ctx } - newCtx, serverSpan := newServerSpanFromInbound(ctx, o.tracer, o.traceHeaderName, interceptors.FullMethod(service, method)) - mock := &opentracingServerReporter{ctx: newCtx, typ: typ, service: service, method: method, serverSpan: serverSpan} + newCtx, serverSpan := newServerSpanFromInbound(ctx, o.tracer, o.traceHeaderName, c.FullMethod()) + mock := &serverReporter{ + ctx: newCtx, + CallMeta: c, + serverSpan: serverSpan, + } return mock, newCtx } // UnaryServerInterceptor returns a new unary server interceptor for OpenTracing. func UnaryServerInterceptor(opts ...Option) grpc.UnaryServerInterceptor { o := evaluateOptions(opts) - return interceptors.UnaryServerInterceptor(&opentracingServerReportable{tracer: o.tracer, traceHeaderName: o.traceHeaderName, filterOutFunc: o.filterOutFunc}) + return interceptors.UnaryServerInterceptor(&serverReportable{tracer: o.tracer, traceHeaderName: o.traceHeaderName, filterOutFunc: o.filterOutFunc}) } // StreamServerInterceptor returns a new streaming server interceptor for OpenTracing. func StreamServerInterceptor(opts ...Option) grpc.StreamServerInterceptor { o := evaluateOptions(opts) - return interceptors.StreamServerInterceptor(&opentracingServerReportable{tracer: o.tracer, traceHeaderName: o.traceHeaderName, filterOutFunc: o.filterOutFunc}) + return interceptors.StreamServerInterceptor(&serverReportable{tracer: o.tracer, traceHeaderName: o.traceHeaderName, filterOutFunc: o.filterOutFunc}) } func newServerSpanFromInbound(ctx context.Context, tracer opentracing.Tracer, traceHeaderName, fullMethodName string) (context.Context, opentracing.Span) { @@ -85,11 +89,15 @@ func newServerSpanFromInbound(ctx context.Context, tracer opentracing.Tracer, tr serverSpan := tracer.StartSpan( fullMethodName, - // this is magical, it attaches the new span to the parent parentSpanContext, and creates an unparented one if empty. + // This is magical, it attaches the new span to the parent parentSpanContext, and creates an unparented one if empty. ext.RPCServerOption(parentSpanContext), grpcTag, ) - injectOpentracingIdsToTags(traceHeaderName, serverSpan, tags.Extract(ctx)) + meta := getTraceMeta(traceHeaderName, serverSpan) + + // Logging fields are used as input for span finish tags. We also want request/trace ID to be part of logging. + // Use logging fields to preserve this information. + ctx = logging.InjectFields(ctx, logging.Fields{FieldTraceID, meta.TraceID, FieldSpanID, meta.SpanID, FieldSampled, fmt.Sprintf("%v", meta.Sampled)}) return opentracing.ContextWithSpan(ctx, serverSpan), serverSpan } diff --git a/providers/tokenbucket/examples_test.go b/providers/tokenbucket/examples_test.go index eb5e4ffeb..1635546cf 100644 --- a/providers/tokenbucket/examples_test.go +++ b/providers/tokenbucket/examples_test.go @@ -1,9 +1,10 @@ package tokenbucket import ( - grpc_ratelimit "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/ratelimit" "github.com/juju/ratelimit" "google.golang.org/grpc" + + grpc_ratelimit "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/ratelimit" ) // Hard-coded for simplicity sake, but make this configurable in your application. diff --git a/testing/testpb/pingservice.go b/testing/testpb/pingservice.go index 4107a4c91..a346bb614 100644 --- a/testing/testpb/pingservice.go +++ b/testing/testpb/pingservice.go @@ -18,7 +18,8 @@ import ( const ( // ListResponseCount is the expected number of responses to PingList - ListResponseCount = 100 + ListResponseCount = 100 + TestServiceFullName = "testing.testpb.v1.TestService" ) // Interface implementation assert. diff --git a/testing/testpb/test.manual_extractfields.pb.go b/testing/testpb/test.manual_extractfields.pb.go deleted file mode 100644 index 7006fa466..000000000 --- a/testing/testpb/test.manual_extractfields.pb.go +++ /dev/null @@ -1,25 +0,0 @@ -// Manual code for logging field extraction tests. - -package testpb - -const TestServiceFullName = "testing.testpb.v1.TestService" - -// This is implementing tags.requestFieldsExtractor -func (x *PingRequest) ExtractRequestFields(appendToMap map[string]string) { - appendToMap["value"] = x.Value -} - -// This is implementing tags.requestFieldsExtractor -func (x *PingErrorRequest) ExtractRequestFields(appendToMap map[string]string) { - appendToMap["value"] = x.Value -} - -// This is implementing tags.requestFieldsExtractor -func (x *PingListRequest) ExtractRequestFields(appendToMap map[string]string) { - appendToMap["value"] = x.Value -} - -// This is implementing tags.requestFieldsExtractor -func (x *PingStreamRequest) ExtractRequestFields(appendToMap map[string]string) { - appendToMap["value"] = x.Value -} diff --git a/util/metautils/nicemd.go b/util/metautils/nicemd.go index 5ea519ccd..3b7c1d40e 100644 --- a/util/metautils/nicemd.go +++ b/util/metautils/nicemd.go @@ -61,7 +61,7 @@ func (m NiceMD) Clone(copiedKeys ...string) NiceMD { newMd[k] = make([]string, len(vv)) copy(newMd[k], vv) } - return NiceMD(newMd) + return newMd } // ToOutgoing sets the given NiceMD as a client-side context for dispatching. @@ -71,7 +71,7 @@ func (m NiceMD) ToOutgoing(ctx context.Context) context.Context { // ToIncoming sets the given NiceMD as a server-side context for dispatching. // -// This is mostly useful in ServerInterceptors.. +// This is mostly useful in ServerInterceptors. func (m NiceMD) ToIncoming(ctx context.Context) context.Context { return metadata.NewIncomingContext(ctx, metadata.MD(m)) }