From 02bbafe1f55c49b86c781b4861de775f76f858ea Mon Sep 17 00:00:00 2001 From: Bakhtiyor Ruziev Date: Mon, 8 May 2023 16:22:50 +0600 Subject: [PATCH] add tests for examples interceptors --- interceptors/logging/examples/go.mod | 6 +- interceptors/logging/examples/go.sum | 7 +- .../logging/examples/kit/example_test.go | 54 ++++++++++++ .../logging/examples/log/example_test.go | 53 ++++++++++++ .../logging/examples/logr/example_test.go | 55 +++++++++++- .../logging/examples/logrus/example_test.go | 64 +++++++++++++- .../logging/examples/slog/example_test.go | 50 +++++++++++ .../logging/examples/zap/example_test.go | 85 ++++++++++++++----- .../logging/examples/zerolog/example_test.go | 55 ++++++++++++ 9 files changed, 402 insertions(+), 27 deletions(-) diff --git a/interceptors/logging/examples/go.mod b/interceptors/logging/examples/go.mod index 49d4a3e2c..0080ffc82 100644 --- a/interceptors/logging/examples/go.mod +++ b/interceptors/logging/examples/go.mod @@ -6,9 +6,9 @@ require ( github.com/go-kit/log v0.2.1 github.com/go-logr/logr v1.2.4 github.com/grpc-ecosystem/go-grpc-middleware/v2 v2.0.0 - github.com/phuslu/log v1.0.83 github.com/rs/zerolog v1.29.0 github.com/sirupsen/logrus v1.9.0 + github.com/stretchr/testify v1.8.0 go.uber.org/zap v1.24.0 golang.org/x/exp v0.0.0-20230321023759-10a507213a29 google.golang.org/grpc v1.53.0 @@ -16,10 +16,13 @@ require ( ) require ( + github.com/davecgh/go-spew v1.1.1 // indirect github.com/go-logfmt/logfmt v0.5.1 // indirect github.com/golang/protobuf v1.5.2 // indirect github.com/mattn/go-colorable v0.1.12 // indirect github.com/mattn/go-isatty v0.0.14 // indirect + github.com/pkg/errors v0.9.1 // indirect + github.com/pmezard/go-difflib v1.0.0 // indirect go.uber.org/atomic v1.7.0 // indirect go.uber.org/multierr v1.6.0 // indirect golang.org/x/net v0.8.0 // indirect @@ -27,6 +30,7 @@ require ( golang.org/x/text v0.8.0 // indirect google.golang.org/genproto v0.0.0-20230110181048-76db0878b65f // indirect google.golang.org/protobuf v1.30.0 // indirect + gopkg.in/yaml.v3 v3.0.1 // indirect ) replace github.com/grpc-ecosystem/go-grpc-middleware/v2 => ../../../ diff --git a/interceptors/logging/examples/go.sum b/interceptors/logging/examples/go.sum index 04c905451..f4fe39e02 100644 --- a/interceptors/logging/examples/go.sum +++ b/interceptors/logging/examples/go.sum @@ -20,8 +20,6 @@ github.com/mattn/go-colorable v0.1.12 h1:jF+Du6AlPIjs2BiUiQlKOX0rt3SujHxPnksPKZb github.com/mattn/go-colorable v0.1.12/go.mod h1:u5H1YNBxpqRaxsYJYSkiCWKzEfiAb1Gb520KVy5xxl4= github.com/mattn/go-isatty v0.0.14 h1:yVuAays6BHfxijgZPzw+3Zlu5yQgKGP2/hcQbHb7S9Y= github.com/mattn/go-isatty v0.0.14/go.mod h1:7GGIvUiUoEMVVmxf/4nioHXj79iQHKdU27kJ6hsGG94= -github.com/phuslu/log v1.0.83 h1:zfqz5tfFPLF8w0jEscpDxE2aFg1Y1kcbORDPliKdIbU= -github.com/phuslu/log v1.0.83/go.mod h1:yAZh4pv6KxAsJDmJIcVSMxkMiUF7mJbpFN3vROkf0dc= github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4= github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= @@ -32,9 +30,12 @@ github.com/rs/zerolog v1.29.0/go.mod h1:NILgTygv/Uej1ra5XxGf82ZFSLk58MFGAUS2o6us github.com/sirupsen/logrus v1.9.0 h1:trlNQbNUG3OdDrDil03MCb1H2o9nJ1x4/5LYw7byDE0= github.com/sirupsen/logrus v1.9.0/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= +github.com/stretchr/objx v0.4.0/go.mod h1:YvHI0jy2hoMjB+UWwv71VJQ9isScKT/TqJzVSSt89Yw= github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI= github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= +github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= github.com/stretchr/testify v1.8.0 h1:pSgiaMZlXftHpm5L7V1+rVB+AZJydKsMxsQBIJw4PKk= +github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU= go.uber.org/atomic v1.7.0 h1:ADUqmZGgLDDfbSL9ZmPxKTybcoEYHgpYfELNoN+7hsw= go.uber.org/atomic v1.7.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc= go.uber.org/goleak v1.1.11 h1:wy28qYRKZgnJTxGxvye5/wgWr1EKjmUDGYox5mGlRlI= @@ -62,8 +63,10 @@ google.golang.org/protobuf v1.26.0-rc.1/go.mod h1:jlhhOSvTdKEhbULTjvd4ARK9grFBp0 google.golang.org/protobuf v1.26.0/go.mod h1:9q0QmTI4eRPtz6boOQmLYwt+qCgq0jsYwAQnmE0givc= google.golang.org/protobuf v1.30.0 h1:kPPoIgf3TsEvrm0PFe15JQ+570QVxYzEvvHqChK+cng= google.golang.org/protobuf v1.30.0/go.mod h1:HV8QOd/L58Z+nl8r43ehVNZIU/HEI6OcFqwMG9pJV4I= +gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA= +gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= k8s.io/klog/v2 v2.90.1 h1:m4bYOKall2MmOiRaR1J+We67Do7vm9KiQVlT96lnHUw= k8s.io/klog/v2 v2.90.1/go.mod h1:y1WjHnz7Dj687irZUWR/WLkLc5N1YHtjLdmgWjndZn0= diff --git a/interceptors/logging/examples/kit/example_test.go b/interceptors/logging/examples/kit/example_test.go index e41bada31..5c2cfae69 100644 --- a/interceptors/logging/examples/kit/example_test.go +++ b/interceptors/logging/examples/kit/example_test.go @@ -4,12 +4,20 @@ package kit_test import ( + "bytes" "context" "fmt" + "runtime" + "strings" + "testing" "github.com/go-kit/log" "github.com/go-kit/log/level" "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/logging" + "github.com/grpc-ecosystem/go-grpc-middleware/v2/testing/testpb" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + "github.com/stretchr/testify/suite" "google.golang.org/grpc" ) @@ -68,3 +76,49 @@ func ExampleInterceptorLogger() { ) // Output: } + +type kitExampleTestSuite struct { + *testpb.InterceptorTestSuite + logBuffer *bytes.Buffer +} + +func TestSuite(t *testing.T) { + if strings.HasPrefix(runtime.Version(), "go1.7") { + t.Skipf("Skipping due to json.RawMessage incompatibility with go1.7") + return + } + + buffer := &bytes.Buffer{} + logger := InterceptorLogger(log.NewLogfmtLogger(buffer)) + + s := &kitExampleTestSuite{ + InterceptorTestSuite: &testpb.InterceptorTestSuite{ + TestService: &testpb.TestPingService{}, + }, + logBuffer: buffer, + } + + s.InterceptorTestSuite.ServerOpts = []grpc.ServerOption{ + grpc.StreamInterceptor(logging.StreamServerInterceptor(logger)), + grpc.UnaryInterceptor(logging.UnaryServerInterceptor(logger)), + } + + suite.Run(t, s) +} + +func (s *kitExampleTestSuite) TestPing() { + ctx := context.Background() + _, err := s.Client.Ping(ctx, testpb.GoodPing) + assert.NoError(s.T(), err, "there must be not be an on a successful call") + logStr := s.logBuffer.String() + require.Contains(s.T(), logStr, "level=info") + require.Contains(s.T(), logStr, "msg=\"started call\"") + require.Contains(s.T(), logStr, "protocol=grpc") + require.Contains(s.T(), logStr, "grpc.component=server") + require.Contains(s.T(), logStr, "grpc.service=testing.testpb.v1.TestService") + require.Contains(s.T(), logStr, "grpc.method=Ping") + require.Contains(s.T(), logStr, "grpc.method_type=unary") + require.Contains(s.T(), logStr, "start_time=") + require.Contains(s.T(), logStr, "grpc.time_ms=") + +} diff --git a/interceptors/logging/examples/log/example_test.go b/interceptors/logging/examples/log/example_test.go index 44dacc56e..73b6db78e 100644 --- a/interceptors/logging/examples/log/example_test.go +++ b/interceptors/logging/examples/log/example_test.go @@ -4,12 +4,20 @@ package log_test import ( + "bytes" "context" "fmt" "log" "os" + "runtime" + "strings" + "testing" "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/logging" + "github.com/grpc-ecosystem/go-grpc-middleware/v2/testing/testpb" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + "github.com/stretchr/testify/suite" "google.golang.org/grpc" ) @@ -68,3 +76,48 @@ func ExampleInterceptorLogger() { ) // Output: } + +type logExampleTestSuite struct { + *testpb.InterceptorTestSuite + logBuffer *bytes.Buffer +} + +func TestSuite(t *testing.T) { + if strings.HasPrefix(runtime.Version(), "go1.7") { + t.Skipf("Skipping due to json.RawMessage incompatibility with go1.7") + return + } + buffer := &bytes.Buffer{} + logger := InterceptorLogger(log.New(buffer, "", 0)) + + s := &logExampleTestSuite{ + InterceptorTestSuite: &testpb.InterceptorTestSuite{ + TestService: &testpb.TestPingService{}, + }, + logBuffer: buffer, + } + + s.InterceptorTestSuite.ServerOpts = []grpc.ServerOption{ + grpc.StreamInterceptor(logging.StreamServerInterceptor(logger)), + grpc.UnaryInterceptor(logging.UnaryServerInterceptor(logger)), + } + + suite.Run(t, s) +} + +func (s *logExampleTestSuite) TestPing() { + ctx := context.Background() + _, err := s.Client.Ping(ctx, testpb.GoodPing) + assert.NoError(s.T(), err, "there must be not be an on a successful call") + logStr := s.logBuffer.String() + require.Contains(s.T(), logStr, "msg INFO") + require.Contains(s.T(), logStr, ":started call") + require.Contains(s.T(), logStr, "protocol grpc") + require.Contains(s.T(), logStr, "grpc.component server") + require.Contains(s.T(), logStr, "grpc.service testing.testpb.v1.TestService") + require.Contains(s.T(), logStr, "grpc.method Ping") + require.Contains(s.T(), logStr, "grpc.method_type unary") + require.Contains(s.T(), logStr, "start_time ") + require.Contains(s.T(), logStr, "grpc.time_ms") + +} diff --git a/interceptors/logging/examples/logr/example_test.go b/interceptors/logging/examples/logr/example_test.go index 8f1bf89d3..44846a67f 100644 --- a/interceptors/logging/examples/logr/example_test.go +++ b/interceptors/logging/examples/logr/example_test.go @@ -6,11 +6,19 @@ package logr_test import ( "context" "fmt" + "runtime" + "strings" + "testing" "github.com/go-logr/logr" "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/logging" + "github.com/grpc-ecosystem/go-grpc-middleware/v2/testing/testpb" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + "github.com/stretchr/testify/suite" "google.golang.org/grpc" "k8s.io/klog/v2" + "k8s.io/klog/v2/ktesting" ) // verbosity https://github.com/kubernetes/community/blob/master/contributors/devel/sig-instrumentation/logging.md#what-method-to-use @@ -25,7 +33,7 @@ const ( // This code is simple enough to be copied and not imported. func InterceptorLogger(l logr.Logger) logging.Logger { return logging.LoggerFunc(func(_ context.Context, lvl logging.Level, msg string, fields ...any) { - l := l.WithValues(fields...) + l = l.WithValues(fields...) switch lvl { case logging.LevelDebug: l.V(debugVerbosity).Info(msg) @@ -76,3 +84,48 @@ func ExampleInterceptorLogger() { ) // Output: } + +type logrExampleTestSuite struct { + *testpb.InterceptorTestSuite + logBuffer *ktesting.BufferTL +} + +func TestSuite(t *testing.T) { + if strings.HasPrefix(runtime.Version(), "go1.7") { + t.Skipf("Skipping due to json.RawMessage incompatibility with go1.7") + return + } + + buffer := &ktesting.BufferTL{} + cfg := ktesting.NewConfig() + logger := InterceptorLogger(ktesting.NewLogger(buffer, cfg)) + + s := &logrExampleTestSuite{ + InterceptorTestSuite: &testpb.InterceptorTestSuite{ + TestService: &testpb.TestPingService{}, + }, + logBuffer: buffer, + } + + s.InterceptorTestSuite.ServerOpts = []grpc.ServerOption{ + grpc.StreamInterceptor(logging.StreamServerInterceptor(logger)), + grpc.UnaryInterceptor(logging.UnaryServerInterceptor(logger)), + } + + suite.Run(t, s) +} + +func (s *logrExampleTestSuite) TestPing() { + ctx := context.Background() + _, err := s.Client.Ping(ctx, testpb.GoodPing) + assert.NoError(s.T(), err, "there must be not be an on a successful call") + logStr := s.logBuffer.String() + require.Contains(s.T(), logStr, "started call") + require.Contains(s.T(), logStr, "protocol=\"grpc\"") + require.Contains(s.T(), logStr, "grpc.component=\"server\"") + require.Contains(s.T(), logStr, "grpc.service=\"testing.testpb.v1.TestService\"") + require.Contains(s.T(), logStr, "grpc.method=\"Ping\"") + require.Contains(s.T(), logStr, "grpc.method_type=\"unary\"") + require.Contains(s.T(), logStr, "start_time=") + require.Contains(s.T(), logStr, "grpc.time_ms=") +} diff --git a/interceptors/logging/examples/logrus/example_test.go b/interceptors/logging/examples/logrus/example_test.go index d0f232f8a..22fd63f6f 100644 --- a/interceptors/logging/examples/logrus/example_test.go +++ b/interceptors/logging/examples/logrus/example_test.go @@ -4,11 +4,20 @@ package logrus_test import ( + "bytes" "context" + "encoding/json" "fmt" + "runtime" + "strings" + "testing" "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/logging" + "github.com/grpc-ecosystem/go-grpc-middleware/v2/testing/testpb" "github.com/sirupsen/logrus" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + "github.com/stretchr/testify/suite" "google.golang.org/grpc" ) @@ -18,11 +27,11 @@ func InterceptorLogger(l logrus.FieldLogger) logging.Logger { return logging.LoggerFunc(func(_ context.Context, lvl logging.Level, msg string, fields ...any) { f := make(map[string]any, len(fields)/2) i := logging.Fields(fields).Iterator() - if i.Next() { + for i.Next() { k, v := i.At() f[k] = v } - l := l.WithFields(f) + l = l.WithFields(f) switch lvl { case logging.LevelDebug: @@ -74,3 +83,54 @@ func ExampleInterceptorLogger() { ) // Output: } + +type logrusExampleTestSuite struct { + *testpb.InterceptorTestSuite + logBuffer *bytes.Buffer +} + +func TestSuite(t *testing.T) { + if strings.HasPrefix(runtime.Version(), "go1.7") { + t.Skipf("Skipping due to json.RawMessage incompatibility with go1.7") + return + } + + buffer := &bytes.Buffer{} + testLogger := logrus.New() + testLogger.Out = buffer + testLogger.SetFormatter(&logrus.JSONFormatter{}) + logger := InterceptorLogger(testLogger) + + s := &logrusExampleTestSuite{ + InterceptorTestSuite: &testpb.InterceptorTestSuite{ + TestService: &testpb.TestPingService{}, + }, + logBuffer: buffer, + } + + s.InterceptorTestSuite.ServerOpts = []grpc.ServerOption{ + grpc.StreamInterceptor(logging.StreamServerInterceptor(logger, logging.WithLogOnEvents(logging.StartCall))), + grpc.UnaryInterceptor(logging.UnaryServerInterceptor(logger, logging.WithLogOnEvents(logging.StartCall))), + } + + suite.Run(t, s) +} + +func (s *logrusExampleTestSuite) TestPing() { + ctx := context.Background() + _, err := s.Client.Ping(ctx, testpb.GoodPing) + assert.NoError(s.T(), err, "there must be not be an on a successful call") + var logMap map[string]interface{} + err = json.Unmarshal(s.logBuffer.Bytes(), &logMap) + require.NoError(s.T(), err) + + require.Equal(s.T(), "started call", logMap["msg"]) + require.Equal(s.T(), "grpc", logMap["protocol"]) + require.Equal(s.T(), "server", logMap["grpc.component"]) + require.Equal(s.T(), "testing.testpb.v1.TestService", logMap["grpc.service"]) + require.Equal(s.T(), "Ping", logMap["grpc.method"]) + require.Equal(s.T(), "unary", logMap["grpc.method_type"]) + require.Contains(s.T(), logMap["peer.address"], "127.0.0.1") + require.NotEmpty(s.T(), logMap["grpc.start_time"]) + require.NotEmpty(s.T(), logMap["grpc.time_ms"]) +} diff --git a/interceptors/logging/examples/slog/example_test.go b/interceptors/logging/examples/slog/example_test.go index 0398b72d6..fda478a90 100644 --- a/interceptors/logging/examples/slog/example_test.go +++ b/interceptors/logging/examples/slog/example_test.go @@ -4,10 +4,18 @@ package slog_test import ( + "bytes" "context" "os" + "runtime" + "strings" + "testing" "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/logging" + "github.com/grpc-ecosystem/go-grpc-middleware/v2/testing/testpb" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + "github.com/stretchr/testify/suite" "golang.org/x/exp/slog" "google.golang.org/grpc" ) @@ -55,3 +63,45 @@ func ExampleInterceptorLogger() { ) // Output: } + +type slogExampleTestSuite struct { + *testpb.InterceptorTestSuite + logBuffer *bytes.Buffer +} + +func TestSuite(t *testing.T) { + if strings.HasPrefix(runtime.Version(), "go1.7") { + t.Skipf("Skipping due to json.RawMessage incompatibility with go1.7") + return + } + buffer := &bytes.Buffer{} + logger := InterceptorLogger(slog.New(slog.NewTextHandler(buffer))) + s := &slogExampleTestSuite{ + InterceptorTestSuite: &testpb.InterceptorTestSuite{ + TestService: &testpb.TestPingService{}, + }, + logBuffer: buffer, + } + + s.InterceptorTestSuite.ServerOpts = []grpc.ServerOption{ + grpc.StreamInterceptor(logging.StreamServerInterceptor(logger, logging.WithLogOnEvents(logging.StartCall))), + grpc.UnaryInterceptor(logging.UnaryServerInterceptor(logger, logging.WithLogOnEvents(logging.StartCall))), + } + + suite.Run(t, s) +} + +func (s *slogExampleTestSuite) TestPing() { + ctx := context.Background() + _, err := s.Client.Ping(ctx, testpb.GoodPing) + assert.NoError(s.T(), err, "there must be not be an on a successful call") + logStr := s.logBuffer.String() + require.Contains(s.T(), logStr, "started call") + require.Contains(s.T(), logStr, "protocol=grpc") + require.Contains(s.T(), logStr, "grpc.component=server") + require.Contains(s.T(), logStr, "grpc.service=testing.testpb.v1.TestService") + require.Contains(s.T(), logStr, "grpc.method=Ping") + require.Contains(s.T(), logStr, "grpc.method_type=unary") + require.Contains(s.T(), logStr, "start_time=") + require.Contains(s.T(), logStr, "grpc.time_ms=") +} diff --git a/interceptors/logging/examples/zap/example_test.go b/interceptors/logging/examples/zap/example_test.go index fd3041751..90ddb3f89 100644 --- a/interceptors/logging/examples/zap/example_test.go +++ b/interceptors/logging/examples/zap/example_test.go @@ -6,9 +6,17 @@ package zap_test import ( "context" "fmt" + "runtime" + "strings" + "testing" "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/logging" + "github.com/grpc-ecosystem/go-grpc-middleware/v2/testing/testpb" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + "github.com/stretchr/testify/suite" "go.uber.org/zap" + "go.uber.org/zap/zaptest/observer" "google.golang.org/grpc" ) @@ -17,34 +25,22 @@ import ( func InterceptorLogger(l *zap.Logger) logging.Logger { return logging.LoggerFunc(func(ctx context.Context, lvl logging.Level, msg string, fields ...any) { f := make([]zap.Field, 0, len(fields)/2) - - for i := 0; i < len(fields); i += 2 { - key := fields[i] - value := fields[i+1] - - switch v := value.(type) { - case string: - f = append(f, zap.String(key.(string), v)) - case int: - f = append(f, zap.Int(key.(string), v)) - case bool: - f = append(f, zap.Bool(key.(string), v)) - default: - f = append(f, zap.Any(key.(string), v)) - } + iter := logging.Fields(fields).Iterator() + for iter.Next() { + k, v := iter.At() + f = append(f, zap.Any(k, v)) } - - logger := l.WithOptions(zap.AddCallerSkip(1)).With(f...) + l = l.WithOptions(zap.AddCallerSkip(1)).With(f...) switch lvl { case logging.LevelDebug: - logger.Debug(msg) + l.Debug(msg) case logging.LevelInfo: - logger.Info(msg) + l.Info(msg) case logging.LevelWarn: - logger.Warn(msg) + l.Warn(msg) case logging.LevelError: - logger.Error(msg) + l.Error(msg) default: panic(fmt.Sprintf("unknown level %v", lvl)) } @@ -86,3 +82,50 @@ func ExampleInterceptorLogger() { ) // Output: } + +type zapExampleTestSuite struct { + *testpb.InterceptorTestSuite + observedLogs *observer.ObservedLogs +} + +func TestSuite(t *testing.T) { + if strings.HasPrefix(runtime.Version(), "go1.7") { + t.Skipf("Skipping due to json.RawMessage incompatibility with go1.7") + return + } + observedZapCore, observedLogs := observer.New(zap.DebugLevel) + logger := InterceptorLogger(zap.New(observedZapCore)) + s := &zapExampleTestSuite{ + InterceptorTestSuite: &testpb.InterceptorTestSuite{ + TestService: &testpb.TestPingService{}, + }, + observedLogs: observedLogs, + } + + s.InterceptorTestSuite.ServerOpts = []grpc.ServerOption{ + grpc.StreamInterceptor(logging.StreamServerInterceptor(logger)), + grpc.UnaryInterceptor(logging.UnaryServerInterceptor(logger)), + } + + suite.Run(t, s) +} + +func (s *zapExampleTestSuite) TestPing() { + ctx := context.Background() + _, err := s.Client.Ping(ctx, testpb.GoodPing) + assert.NoError(s.T(), err, "there must be not be an on a successful call") + require.Equal(s.T(), 2, s.observedLogs.Len()) + line := s.observedLogs.All()[0] + + contextMap := line.ContextMap() + require.Equal(s.T(), zap.InfoLevel, line.Level) + require.Equal(s.T(), "started call", line.Entry.Message) + + require.Equal(s.T(), "Ping", contextMap["grpc.method"]) + require.Equal(s.T(), "grpc", contextMap["protocol"]) + require.Equal(s.T(), "server", contextMap["grpc.component"]) + + require.Contains(s.T(), contextMap["peer.address"], "127.0.0.1") + require.NotEmpty(s.T(), contextMap["grpc.start_time"]) + require.NotEmpty(s.T(), contextMap["grpc.time_ms"]) +} diff --git a/interceptors/logging/examples/zerolog/example_test.go b/interceptors/logging/examples/zerolog/example_test.go index 76fe24403..5056ed8b5 100644 --- a/interceptors/logging/examples/zerolog/example_test.go +++ b/interceptors/logging/examples/zerolog/example_test.go @@ -4,12 +4,21 @@ package zerolog_test import ( + "bytes" "context" + "encoding/json" "fmt" "os" + "runtime" + "strings" + "testing" "github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/logging" + "github.com/grpc-ecosystem/go-grpc-middleware/v2/testing/testpb" "github.com/rs/zerolog" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + "github.com/stretchr/testify/suite" "google.golang.org/grpc" ) @@ -69,3 +78,49 @@ func ExampleInterceptorLogger() { ) // Output: } + +type zerologExampleTestSuite struct { + *testpb.InterceptorTestSuite + logBuffer *bytes.Buffer +} + +func TestSuite(t *testing.T) { + if strings.HasPrefix(runtime.Version(), "go1.7") { + t.Skipf("Skipping due to json.RawMessage incompatibility with go1.7") + return + } + buffer := &bytes.Buffer{} + logger := InterceptorLogger(zerolog.New(buffer)) + s := &zerologExampleTestSuite{ + InterceptorTestSuite: &testpb.InterceptorTestSuite{ + TestService: &testpb.TestPingService{}, + }, + logBuffer: buffer, + } + + s.InterceptorTestSuite.ServerOpts = []grpc.ServerOption{ + grpc.StreamInterceptor(logging.StreamServerInterceptor(logger, logging.WithLogOnEvents(logging.StartCall))), + grpc.UnaryInterceptor(logging.UnaryServerInterceptor(logger, logging.WithLogOnEvents(logging.StartCall))), + } + + suite.Run(t, s) +} + +func (s *zerologExampleTestSuite) TestPing() { + ctx := context.Background() + _, err := s.Client.Ping(ctx, testpb.GoodPing) + assert.NoError(s.T(), err, "there must be not be an on a successful call") + var logMap map[string]interface{} + err = json.Unmarshal(s.logBuffer.Bytes(), &logMap) + require.NoError(s.T(), err) + + require.Equal(s.T(), "started call", logMap["message"]) + require.Equal(s.T(), "grpc", logMap["protocol"]) + require.Equal(s.T(), "server", logMap["grpc.component"]) + require.Equal(s.T(), "testing.testpb.v1.TestService", logMap["grpc.service"]) + require.Equal(s.T(), "Ping", logMap["grpc.method"]) + require.Equal(s.T(), "unary", logMap["grpc.method_type"]) + require.Contains(s.T(), logMap["peer.address"], "127.0.0.1") + require.NotEmpty(s.T(), logMap["grpc.start_time"]) + require.NotEmpty(s.T(), logMap["grpc.time_ms"]) +}