diff --git a/interceptors/logging/interceptors.go b/interceptors/logging/interceptors.go index 125028c78..d866689eb 100644 --- a/interceptors/logging/interceptors.go +++ b/interceptors/logging/interceptors.go @@ -136,6 +136,9 @@ func (c *reporter) PostMsgReceive(payload any, err error, duration time.Duration func reportable(logger Logger, opts *options) interceptors.CommonReportableFunc { return func(ctx context.Context, c interceptors.CallMeta) (interceptors.Reporter, context.Context) { + if !opts.shouldReport(c.FullMethod()) { + return interceptors.NoopReporter{}, ctx + } kind := KindServerFieldValue if c.IsClient { kind = KindClientFieldValue diff --git a/interceptors/logging/interceptors_test.go b/interceptors/logging/interceptors_test.go index 85eb8a6ac..067fb6a8d 100644 --- a/interceptors/logging/interceptors_test.go +++ b/interceptors/logging/interceptors_test.go @@ -28,6 +28,13 @@ import ( "google.golang.org/protobuf/proto" ) +const ( + // TODO: should import from testpb when we upgrade proto generator. + // It will look like Health service: + // https://github.com/grpc/grpc-go/blob/master/health/grpc_health_v1/health_grpc.pb.go#L39 + TestPingFullMethodName = "/testing.testpb.v1.TestService/Ping" +) + type testDisposableFields map[string]string func (f testDisposableFields) AssertField(t *testing.T, key, value string) testDisposableFields { @@ -773,6 +780,90 @@ func (s *loggingCustomGrpcLogFieldsSuite) TestCustomGrpcLogFieldsWithPingList() AssertField(s.T(), logging.ServiceFieldKey, testpb.TestServiceFullName).AssertNoMoreTags(s.T()) } +type loggingWithDeciderSuite struct { + *baseLoggingSuite +} + +func TestWithDeciderSuite(t *testing.T) { + if strings.HasPrefix(runtime.Version(), "go1.7") { + t.Skipf("Skipping due to json.RawMessage incompatibility with go1.7") + return + } + s := &loggingWithDeciderSuite{ + baseLoggingSuite: &baseLoggingSuite{ + logger: newMockLogger(), + InterceptorTestSuite: &testpb.InterceptorTestSuite{ + TestService: &testpb.TestPingService{}, + }, + }, + } + s.InterceptorTestSuite.ClientOpts = []grpc.DialOption{ + grpc.WithUnaryInterceptor(logging.UnaryClientInterceptor(s.logger, logging.WithDecider(loggingDecider()))), + grpc.WithStreamInterceptor(logging.StreamClientInterceptor(s.logger, logging.WithDecider(loggingDecider()))), + } + s.InterceptorTestSuite.ServerOpts = []grpc.ServerOption{ + grpc.StreamInterceptor(logging.StreamServerInterceptor(s.logger, logging.WithDecider(loggingDecider()))), + grpc.UnaryInterceptor(logging.UnaryServerInterceptor(s.logger, logging.WithDecider(loggingDecider()))), + } + suite.Run(t, s) +} + +// Test that do not have logs with using withDecider. Because this method is not allowed to report logs. +func (s *loggingWithDeciderSuite) TestDeciderWithPing() { + _, err := s.Client.Ping(s.SimpleCtx(), testpb.GoodPing) + assert.NoError(s.T(), err, "there must be not be an on a successful call") + + lines := s.logger.o.Lines() + sort.Sort(lines) + require.Len(s.T(), lines, 0) +} + +// Test that have logs with using withDecider. Because this method is allowed to report logs. +func (s *loggingWithDeciderSuite) TestDeciderWithPingList() { + stream, err := s.Client.PingList(s.SimpleCtx(), testpb.GoodPingList) + assert.NoError(s.T(), err, "there must be not be an on a successful call") + + require.NoError(s.T(), err, "should not fail on establishing the stream") + for { + _, err := stream.Recv() + if err == io.EOF { + break + } + require.NoError(s.T(), err, "reading stream should not fail") + } + + lines := s.logger.o.Lines() + sort.Sort(lines) + require.Len(s.T(), lines, 4) + + serverStartedCallLogLine := lines[3] + assert.Equal(s.T(), logging.LevelInfo, serverStartedCallLogLine.lvl) + assert.Equal(s.T(), "started call", serverStartedCallLogLine.msg) + _ = assertStandardFields(s.T(), logging.KindServerFieldValue, serverStartedCallLogLine.fields, "PingList", interceptors.ServerStream) + + clientStartedCallLogLine := lines[1] + assert.Equal(s.T(), logging.LevelDebug, clientStartedCallLogLine.lvl) + assert.Equal(s.T(), "started call", clientStartedCallLogLine.msg) + _ = assertStandardFields(s.T(), logging.KindClientFieldValue, clientStartedCallLogLine.fields, "PingList", interceptors.ServerStream) + + serverFinishCallLogLine := lines[2] + assert.Equal(s.T(), logging.LevelInfo, serverFinishCallLogLine.lvl) + assert.Equal(s.T(), "finished call", serverFinishCallLogLine.msg) + serverFinishCallFields := assertStandardFields(s.T(), logging.KindServerFieldValue, serverFinishCallLogLine.fields, "PingList", interceptors.ServerStream) + serverFinishCallFields.AssertFieldNotEmpty(s.T(), "peer.address"). + AssertFieldNotEmpty(s.T(), "grpc.start_time"). + AssertFieldNotEmpty(s.T(), "grpc.request.deadline"). + AssertField(s.T(), "grpc.code", "OK") + + clientFinishCallLogLine := lines[0] + assert.Equal(s.T(), logging.LevelDebug, clientFinishCallLogLine.lvl) + assert.Equal(s.T(), "finished call", clientFinishCallLogLine.msg) + clientFinishCallFields := assertStandardFields(s.T(), logging.KindClientFieldValue, clientFinishCallLogLine.fields, "PingList", interceptors.ServerStream) + clientFinishCallFields.AssertFieldNotEmpty(s.T(), "grpc.start_time"). + AssertFieldNotEmpty(s.T(), "grpc.request.deadline"). + AssertField(s.T(), "grpc.code", "OK") +} + // waitUntil executes f every interval seconds until timeout or no error is returned from f. func waitUntil(interval time.Duration, stopc <-chan struct{}, f func() error) error { tick := time.NewTicker(interval) @@ -790,3 +881,9 @@ func waitUntil(interval time.Duration, stopc <-chan struct{}, f func() error) er } } } + +func loggingDecider() logging.Decider { + return func(fullMethodName string) bool { + return fullMethodName != TestPingFullMethodName + } +} diff --git a/interceptors/logging/options.go b/interceptors/logging/options.go index 5308d8b3f..ee1f1c3fd 100644 --- a/interceptors/logging/options.go +++ b/interceptors/logging/options.go @@ -51,6 +51,7 @@ var ( levelFunc: nil, timestampFormat: time.RFC3339, disableGrpcLogFields: nil, + shouldReport: DefaultDeciderMethod, } ) @@ -62,6 +63,7 @@ type options struct { timestampFormat string fieldsFromCtxCallMetaFn fieldsFromCtxCallMetaFn disableGrpcLogFields []string + shouldReport Decider } type Option func(*options) @@ -213,3 +215,19 @@ func WithDisableLoggingFields(disableGrpcLogFields ...string) Option { o.disableGrpcLogFields = disableGrpcLogFields } } + +// Decider function defines rules for suppressing any interceptor logs +type Decider func(fullMethodName string) bool + +// WithDecider customizes the function for deciding if the gRPC interceptor logs should log. +func WithDecider(f Decider) Option { + return func(o *options) { + o.shouldReport = 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(fullMethodName string) bool { + return true +}