diff --git a/interceptors/logging/interceptors.go b/interceptors/logging/interceptors.go index 0d878de1..7e400dbf 100644 --- a/interceptors/logging/interceptors.go +++ b/interceptors/logging/interceptors.go @@ -40,6 +40,9 @@ func (c *reporter) PostCall(err error, duration time.Duration) { fields = fields.AppendUnique(Fields{"grpc.code", code.String()}) if err != nil { fields = fields.AppendUnique(Fields{"grpc.error", fmt.Sprintf("%v", err)}) + if c.opts.errorToFieldsFunc != nil { + fields = fields.AppendUnique(c.opts.errorToFieldsFunc(err)) + } } if c.opts.fieldsFromCtxCallMetaFn != nil { // fieldsFromCtxFn dups override the existing fields. @@ -53,6 +56,9 @@ func (c *reporter) PostMsgSend(payload any, err error, duration time.Duration) { fields := c.fields.WithUnique(ExtractFields(c.ctx)) if err != nil { fields = fields.AppendUnique(Fields{"grpc.error", fmt.Sprintf("%v", err)}) + if c.opts.errorToFieldsFunc != nil { + fields = fields.AppendUnique(c.opts.errorToFieldsFunc(err)) + } } if c.opts.fieldsFromCtxCallMetaFn != nil { // fieldsFromCtxFn dups override the existing fields. @@ -104,6 +110,9 @@ func (c *reporter) PostMsgReceive(payload any, err error, duration time.Duration fields := c.fields.WithUnique(ExtractFields(c.ctx)) if err != nil { fields = fields.AppendUnique(Fields{"grpc.error", fmt.Sprintf("%v", err)}) + if c.opts.errorToFieldsFunc != nil { + fields = fields.AppendUnique(c.opts.errorToFieldsFunc(err)) + } } if c.opts.fieldsFromCtxCallMetaFn != nil { // fieldsFromCtxFn dups override the existing fields. diff --git a/interceptors/logging/interceptors_test.go b/interceptors/logging/interceptors_test.go index 54a568fe..d40dbd65 100644 --- a/interceptors/logging/interceptors_test.go +++ b/interceptors/logging/interceptors_test.go @@ -205,9 +205,12 @@ func TestSuite(t *testing.T) { logging.StreamClientInterceptor(s.logger, logging.WithLevels(customClientCodeToLevel), logging.WithFieldsFromContext(customFields)), ), } + errorFields := func(err error) logging.Fields { + return testpb.ExtractErrorFields(err) + } s.InterceptorTestSuite.ServerOpts = []grpc.ServerOption{ - grpc.StreamInterceptor(logging.StreamServerInterceptor(s.logger, logging.WithLevels(customClientCodeToLevel), logging.WithFieldsFromContext(customFields))), - grpc.UnaryInterceptor(logging.UnaryServerInterceptor(s.logger, logging.WithLevels(customClientCodeToLevel), logging.WithFieldsFromContext(customFields))), + grpc.StreamInterceptor(logging.StreamServerInterceptor(s.logger, logging.WithLevels(customClientCodeToLevel), logging.WithFieldsFromContext(customFields), logging.WithErrorFields(errorFields))), + grpc.UnaryInterceptor(logging.UnaryServerInterceptor(s.logger, logging.WithLevels(customClientCodeToLevel), logging.WithFieldsFromContext(customFields), logging.WithErrorFields(errorFields))), } suite.Run(t, s) } @@ -367,6 +370,7 @@ func (s *loggingClientServerSuite) TestPingError_WithCustomLevels() { 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())). + AssertField(t, "error-field", "plop"). AssertFieldNotEmpty(s.T(), "grpc.time_ms").AssertNoMoreTags(s.T()) clientFinishCallLogLine := lines[0] diff --git a/interceptors/logging/options.go b/interceptors/logging/options.go index d293e00b..7a43bbd0 100644 --- a/interceptors/logging/options.go +++ b/interceptors/logging/options.go @@ -57,6 +57,7 @@ var ( type options struct { levelFunc CodeToLevel loggableEvents []LoggableEvent + errorToFieldsFunc ErrorToFields codeFunc ErrorToCode durationFieldFunc DurationToFields timestampFormat string @@ -89,6 +90,9 @@ func evaluateClientOpt(opts []Option) *options { // DurationToFields function defines how to produce duration fields for logging. type DurationToFields func(duration time.Duration) Fields +// ErrorToFields function extract fields from error. +type ErrorToFields func(err error) 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 @@ -169,6 +173,13 @@ func WithLogOnEvents(events ...LoggableEvent) Option { } } +// WithErrorFields allows to extract logging fields from an error. +func WithErrorFields(f ErrorToFields) Option { + return func(o *options) { + o.errorToFieldsFunc = f + } +} + // WithLevels customizes the function for mapping gRPC return codes and interceptor log level statements. func WithLevels(f CodeToLevel) Option { return func(o *options) { diff --git a/testing/testpb/interceptor_suite.go b/testing/testpb/interceptor_suite.go index ca66bfb8..91f81f73 100644 --- a/testing/testpb/interceptor_suite.go +++ b/testing/testpb/interceptor_suite.go @@ -11,6 +11,7 @@ import ( "crypto/x509" "crypto/x509/pkix" "encoding/pem" + "errors" "flag" "math/big" "net" @@ -20,8 +21,10 @@ import ( "github.com/stretchr/testify/require" "github.com/stretchr/testify/suite" "google.golang.org/grpc" + "google.golang.org/grpc/codes" "google.golang.org/grpc/credentials" "google.golang.org/grpc/credentials/insecure" + "google.golang.org/grpc/status" ) var ( @@ -150,6 +153,40 @@ func ExtractCtxTestNumber(ctx context.Context) *int { return &zero } +type wrappedErrFields struct { + wrappedErr error + fields []any +} + +func (err *wrappedErrFields) Unwrap() error { + return err.wrappedErr +} + +func (err *wrappedErrFields) Error() string { + // Ideally we print wrapped fields as well + return err.wrappedErr.Error() +} + +func (err *wrappedErrFields) GRPCStatus() *status.Status { + if s, ok := status.FromError(err.wrappedErr); ok { + return s + } + return status.New(codes.Unknown, err.Error()) +} + +func WrapFieldsInError(err error, fields []any) error { + return &wrappedErrFields{err, fields} +} + +func ExtractErrorFields(err error) []any { + var e *wrappedErrFields + ok := errors.As(err, &e) + if !ok { + return nil + } + return e.fields +} + // UnaryServerInterceptor returns a new unary server interceptors that adds query information logging. func UnaryServerInterceptor() grpc.UnaryServerInterceptor { return func(ctx context.Context, req any, _ *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (any, error) { diff --git a/testing/testpb/pingservice.go b/testing/testpb/pingservice.go index 42908388..a5d1090e 100644 --- a/testing/testpb/pingservice.go +++ b/testing/testpb/pingservice.go @@ -45,7 +45,7 @@ func (s *TestPingService) Ping(ctx context.Context, ping *PingRequest) (*PingRes func (s *TestPingService) PingError(_ context.Context, ping *PingErrorRequest) (*PingErrorResponse, error) { code := codes.Code(ping.ErrorCodeReturned) - return nil, status.Error(code, "Userspace error") + return nil, WrapFieldsInError(status.Error(code, "Userspace error"), []any{"error-field", "plop"}) } func (s *TestPingService) PingList(ping *PingListRequest, stream TestService_PingListServer) error {