diff --git a/README.md b/README.md index 625e24dc1..61a4448d5 100644 --- a/README.md +++ b/README.md @@ -59,6 +59,7 @@ myServer := grpc.NewServer( * [`grpc_zap`](logging/zap/) - integration of [zap](https://github.com/uber-go/zap) logging library into gRPC handlers. * [`grpc_logrus`](logging/logrus/) - integration of [logrus](https://github.com/sirupsen/logrus) logging library into gRPC handlers. * [`grpc_kit`](logging/kit/) - integration of [go-kit](https://github.com/go-kit/kit/tree/master/log) logging library into gRPC handlers. + * [`grpc_grpc_logsettable`](logging/settable/) - a wrapper around `grpclog.LoggerV2` that allows to replace loggers in runtime (thread-safe). #### Monitoring * [`grpc_prometheus`⚡](https://github.com/grpc-ecosystem/go-grpc-prometheus) - Prometheus client-side and server-side monitoring middleware diff --git a/logging/doc.go b/logging/doc.go index f492d38e6..d8fcea081 100644 --- a/logging/doc.go +++ b/logging/doc.go @@ -1,6 +1,3 @@ -// Copyright 2017 Michal Witkowski. All Rights Reserved. -// See LICENSE for licensing terms. - // /* grpc_logging is a "parent" package for gRPC logging middlewares. diff --git a/logging/settable/doc.go b/logging/settable/doc.go new file mode 100644 index 000000000..c447ec6b9 --- /dev/null +++ b/logging/settable/doc.go @@ -0,0 +1,16 @@ +// +/* +grpc_logsettable contains a thread-safe wrapper around grpc-logging +infrastructure. + +The go-grpc assumes that logger can be only configured once as the `SetLoggerV2` +method is: +```Not mutex-protected, should be called before any gRPC functions.``` + +This package allows to supply parent logger once ("before any grpc"), but +later change underlying implementation in thread-safe way when needed. + +It's in particular useful for testing, where each testcase might need its own +logger. +*/ +package grpc_logsettable diff --git a/logging/settable/logsettable.go b/logging/settable/logsettable.go new file mode 100644 index 000000000..9e403b2b2 --- /dev/null +++ b/logging/settable/logsettable.go @@ -0,0 +1,99 @@ +package grpc_logsettable + +import ( + "io/ioutil" + "sync" + + "google.golang.org/grpc/grpclog" +) + +// SettableLoggerV2 is thread-safe. +type SettableLoggerV2 interface { + grpclog.LoggerV2 + // Sets given logger as the underlying implementation. + Set(loggerv2 grpclog.LoggerV2) + // Sets `discard` logger as the underlying implementation. + Reset() +} + +// ReplaceGrpcLoggerV2 creates and configures SettableLoggerV2 as grpc logger. +func ReplaceGrpcLoggerV2() SettableLoggerV2 { + settable := &settableLoggerV2{} + settable.Reset() + grpclog.SetLoggerV2(settable) + return settable +} + +// SettableLoggerV2 implements SettableLoggerV2 +type settableLoggerV2 struct { + log grpclog.LoggerV2 + mu sync.RWMutex +} + +func (s *settableLoggerV2) Set(log grpclog.LoggerV2) { + s.mu.Lock() + defer s.mu.Unlock() + s.log = log +} + +func (s *settableLoggerV2) Reset() { + s.Set(grpclog.NewLoggerV2(ioutil.Discard, ioutil.Discard, ioutil.Discard)) +} + +func (s *settableLoggerV2) get() grpclog.LoggerV2 { + s.mu.RLock() + defer s.mu.RUnlock() + return s.log +} + +func (s *settableLoggerV2) Info(args ...interface{}) { + s.get().Info(args) +} + +func (s *settableLoggerV2) Infoln(args ...interface{}) { + s.get().Infoln(args) +} + +func (s *settableLoggerV2) Infof(format string, args ...interface{}) { + s.get().Infof(format, args) +} + +func (s *settableLoggerV2) Warning(args ...interface{}) { + s.get().Warning(args) +} + +func (s *settableLoggerV2) Warningln(args ...interface{}) { + s.get().Warningln(args) +} + +func (s *settableLoggerV2) Warningf(format string, args ...interface{}) { + s.get().Warningf(format, args) +} + +func (s *settableLoggerV2) Error(args ...interface{}) { + s.get().Error(args) +} + +func (s *settableLoggerV2) Errorln(args ...interface{}) { + s.get().Errorln(args) +} + +func (s *settableLoggerV2) Errorf(format string, args ...interface{}) { + s.get().Errorf(format, args) +} + +func (s *settableLoggerV2) Fatal(args ...interface{}) { + s.get().Fatal(args) +} + +func (s *settableLoggerV2) Fatalln(args ...interface{}) { + s.get().Fatalln(args) +} + +func (s *settableLoggerV2) Fatalf(format string, args ...interface{}) { + s.get().Fatalf(format, args) +} + +func (s *settableLoggerV2) V(l int) bool { + return s.get().V(l) +} diff --git a/logging/settable/logsettable_test.go b/logging/settable/logsettable_test.go new file mode 100644 index 000000000..fc8d8426b --- /dev/null +++ b/logging/settable/logsettable_test.go @@ -0,0 +1,48 @@ +package grpc_logsettable_test + +import ( + "bytes" + "io/ioutil" + "os" + "testing" + + grpc_logsettable "github.com/grpc-ecosystem/go-grpc-middleware/logging/settable" + "github.com/stretchr/testify/assert" + "google.golang.org/grpc/grpclog" +) + +func ExampleSettableLoggerV2_init() { + l1 := grpclog.NewLoggerV2(ioutil.Discard, ioutil.Discard, ioutil.Discard) + l2 := grpclog.NewLoggerV2(os.Stdout, os.Stdout, os.Stdout) + + settableLogger := grpc_logsettable.ReplaceGrpcLoggerV2() + grpclog.Info("Discarded by default") + + settableLogger.Set(l1) + grpclog.Info("Discarded log by l1") + + settableLogger.Set(l2) + grpclog.Info("Emitted log by l2") + // Expected output: INFO: 2021/03/15 12:59:54 [Emitted log by l2] +} + +func TestSettableLoggerV2_init(t *testing.T) { + l1buffer := &bytes.Buffer{} + l1 := grpclog.NewLoggerV2(l1buffer, l1buffer, l1buffer) + + l2buffer := &bytes.Buffer{} + l2 := grpclog.NewLoggerV2(l2buffer, l2buffer, l2buffer) + + settableLogger := grpc_logsettable.ReplaceGrpcLoggerV2() + grpclog.Info("Discarded by default") + + settableLogger.Set(l1) + grpclog.SetLoggerV2(settableLogger) + grpclog.Info("Emitted log by l1") + + settableLogger.Set(l2) + grpclog.Info("Emitted log by l2") + + assert.Contains(t, l1buffer.String(), "Emitted log by l1") + assert.Contains(t, l2buffer.String(), "Emitted log by l2") +} diff --git a/logging/zap/doc.go b/logging/zap/doc.go index 14735fc38..ffa6b5c31 100644 --- a/logging/zap/doc.go +++ b/logging/zap/doc.go @@ -70,5 +70,6 @@ Note - due to implementation ZAP differs from Logrus in the "grpc.request.conten Please see examples and tests for examples of use. +Please see settable_test.go for canonical integration through "zaptest" with golang testing infrastructure. */ package grpc_zap diff --git a/logging/zap/grpclogger.go b/logging/zap/grpclogger.go index 42842c991..85fc2100a 100644 --- a/logging/zap/grpclogger.go +++ b/logging/zap/grpclogger.go @@ -6,6 +6,7 @@ package grpc_zap import ( "fmt" + grpc_logsettable "github.com/grpc-ecosystem/go-grpc-middleware/logging/settable" "go.uber.org/zap" "google.golang.org/grpc/grpclog" ) @@ -47,11 +48,13 @@ func (l *zapGrpcLogger) Println(args ...interface{}) { } // ReplaceGrpcLoggerV2 replaces the grpc_log.LoggerV2 with the provided logger. +// It should be called before any gRPC functions. func ReplaceGrpcLoggerV2(logger *zap.Logger) { ReplaceGrpcLoggerV2WithVerbosity(logger, 0) } // ReplaceGrpcLoggerV2WithVerbosity replaces the grpc_.LoggerV2 with the provided logger and verbosity. +// It should be called before any gRPC functions. func ReplaceGrpcLoggerV2WithVerbosity(logger *zap.Logger, verbosity int) { zgl := &zapGrpcLoggerV2{ logger: logger.With(SystemField, zap.Bool("grpc_log", true)), @@ -60,6 +63,22 @@ func ReplaceGrpcLoggerV2WithVerbosity(logger *zap.Logger, verbosity int) { grpclog.SetLoggerV2(zgl) } +// SetGrpcLoggerV2 replaces the grpc_log.LoggerV2 with the provided logger. +// It can be used even when grpc infrastructure was initialized. +func SetGrpcLoggerV2(settable grpc_logsettable.SettableLoggerV2, logger *zap.Logger) { + SetGrpcLoggerV2WithVerbosity(settable, logger, 0) +} + +// SetGrpcLoggerV2WithVerbosity replaces the grpc_.LoggerV2 with the provided logger and verbosity. +// It can be used even when grpc infrastructure was initialized. +func SetGrpcLoggerV2WithVerbosity(settable grpc_logsettable.SettableLoggerV2, logger *zap.Logger, verbosity int) { + zgl := &zapGrpcLoggerV2{ + logger: logger.With(SystemField, zap.Bool("grpc_log", true)), + verbosity: verbosity, + } + settable.Set(zgl) +} + type zapGrpcLoggerV2 struct { logger *zap.Logger verbosity int diff --git a/logging/zap/settable_test.go b/logging/zap/settable_test.go new file mode 100644 index 000000000..7e6cc4888 --- /dev/null +++ b/logging/zap/settable_test.go @@ -0,0 +1,33 @@ +package grpc_zap_test + +import ( + "testing" + + grpc_logsettable "github.com/grpc-ecosystem/go-grpc-middleware/logging/settable" + grpc_zap "github.com/grpc-ecosystem/go-grpc-middleware/logging/zap" + "go.uber.org/zap/zaptest" +) + +var grpc_logger grpc_logsettable.SettableLoggerV2 + +func init() { + grpc_logger = grpc_logsettable.ReplaceGrpcLoggerV2() +} + +func beforeTest(t testing.TB) { + grpc_zap.SetGrpcLoggerV2(grpc_logger, zaptest.NewLogger(t)) + + // Starting from go-1.15+ automated 'reset' can also be set: + // t.Cleanup(func() { + // grpc_logger.Reset() + // }) +} + +// This test illustrates setting up a testing harness that attributes +// all grpc logs emitted during the test to the test-specific log. +// +// In case of test failure, only logs emitted by this testcase will be printed. +func TestSpecificLogging(t *testing.T) { + beforeTest(t) + grpc_logger.Info("Test specific log-line") +}