diff --git a/cloudrequestlog/codetolevel.go b/cloudrequestlog/codetolevel.go index 480b8626..0c34785a 100644 --- a/cloudrequestlog/codetolevel.go +++ b/cloudrequestlog/codetolevel.go @@ -1,12 +1,15 @@ package cloudrequestlog import ( + "log/slog" + "go.uber.org/zap" "go.uber.org/zap/zapcore" "google.golang.org/grpc/codes" ) // CodeToLevel returns the default [zapcore.Level] for requests with the provided [codes.Code]. +// Deprecated: Zap has been replaced by slog. func CodeToLevel(code codes.Code) zapcore.Level { switch code { case codes.OK: @@ -30,3 +33,28 @@ func CodeToLevel(code codes.Code) zapcore.Level { return zap.ErrorLevel } } + +// CodeToLevel returns the default [slog.Level] for requests with the provided [codes.Code]. +func codeToLevel(code codes.Code) slog.Level { + switch code { + case codes.OK: + return slog.LevelInfo + case + codes.NotFound, + codes.InvalidArgument, + codes.AlreadyExists, + codes.FailedPrecondition, + codes.Unauthenticated, + codes.PermissionDenied, + codes.DeadlineExceeded, + codes.OutOfRange, + codes.Canceled, + codes.Aborted, + codes.Unavailable, + codes.ResourceExhausted, + codes.Unimplemented: + return slog.LevelWarn + default: + return slog.LevelError + } +} diff --git a/cloudrequestlog/middleware.go b/cloudrequestlog/middleware.go index 623661ac..e80d3c32 100644 --- a/cloudrequestlog/middleware.go +++ b/cloudrequestlog/middleware.go @@ -5,14 +5,10 @@ import ( "errors" "log/slog" "net/http" - "reflect" "runtime" "time" "go.einride.tech/cloudrunner/cloudstream" - "go.einride.tech/cloudrunner/cloudzap" - "go.uber.org/zap" - "go.uber.org/zap/zapcore" ltype "google.golang.org/genproto/googleapis/logging/type" "google.golang.org/grpc" "google.golang.org/grpc/codes" @@ -25,8 +21,6 @@ import ( type Middleware struct { // Config for the request logger middleware. Config Config - // MessageTransformer is an optional transform applied to proto.Message request and responses. - MessageTransformer func(proto.Message) proto.Message } // GRPCUnaryServerInterceptor implements request logging as a grpc.UnaryServerInterceptor. @@ -41,43 +35,41 @@ func (l *Middleware) GRPCUnaryServerInterceptor( // Clone request to ensure not using a mutated one later requestClone := proto.Clone(request.(proto.Message)) response, err := handler(ctx, request) - code := status.Code(err) - checkedEntry := l.logger(ctx).Check( - l.codeToLevel(code), - grpcServerLogMessage(code, info.FullMethod), - ) - if checkedEntry == nil { + responseStatus := status.Convert(err) + level := l.codeToLevel(responseStatus.Code()) + logger := slog.Default() + if !logger.Enabled(ctx, level) { return response, err } - grpcRequest := cloudzap.HTTPRequestObject{ + grpcRequest := <ype.HttpRequest{ Protocol: "gRPC", - Latency: time.Since(startTime), + Latency: durationpb.New(time.Since(startTime)), } - grpcRequest.RequestSize = proto.Size(requestClone) + grpcRequest.RequestSize = int64(proto.Size(requestClone)) if protoResponse, ok := response.(proto.Message); ok { - grpcRequest.ResponseSize = proto.Size(protoResponse) + grpcRequest.ResponseSize = int64(proto.Size(protoResponse)) + } + attrs := []slog.Attr{ + slog.String("code", responseStatus.Code().String()), + slog.Any("status", responseStatus), + slog.Any("httpRequest", grpcRequest), + slog.Any("request", requestClone), + slog.Any("response", response), } - fields := []zapcore.Field{ - zap.Stringer("code", code), - zap.Object("httpRequest", &grpcRequest), - l.messageField("request", requestClone), - l.messageField("response", response), - zap.Error(err), - ErrorDetails(err), + if err != nil { + attrs = append(attrs, slog.Any("error", err)) } - fields = appendFullMethodFields(info.FullMethod, fields) + attrs = appendFullMethodAttrs(info.FullMethod, attrs) if additionalFields, ok := GetAdditionalFields(ctx); ok { - fields = additionalFields.AppendTo(fields) + attrs = additionalFields.appendTo(attrs) } var errCaller interface { Caller() (pc uintptr, file string, line int, ok bool) } if errors.As(err, &errCaller) { - checkedEntry.Caller = zapcore.NewEntryCaller(errCaller.Caller()) - checkedEntry.Entry.Caller = checkedEntry.Caller + attrs = append(attrs, newSourceAttr(errCaller.Caller())) } - fields = append(fields, cloudzap.SourceLocationForCaller(checkedEntry.Caller)) - checkedEntry.Write(fields...) + logger.LogAttrs(ctx, level, grpcServerLogMessage(responseStatus.Code(), info.FullMethod), attrs...) return response, err } @@ -94,48 +86,38 @@ func (l *Middleware) GRPCStreamServerInterceptor( ctx := WithAdditionalFields(ss.Context()) ss = cloudstream.NewContextualServerStream(ctx, ss) err := handler(srv, ss) - code := status.Code(err) - checkedEntry := l.logger(ctx).Check( - l.codeToLevel(code), - grpcServerLogMessage(code, info.FullMethod), - ) - if checkedEntry == nil { + responseStatus := status.Convert(err) + level := l.codeToLevel(responseStatus.Code()) + logger := slog.Default() + if !logger.Enabled(ctx, level) { return err } - grpcRequest := cloudzap.HTTPRequestObject{ + grpcRequest := <ype.HttpRequest{ Protocol: "gRPC", - Latency: time.Since(startTime), + Latency: durationpb.New(time.Since(startTime)), } - fields := []zapcore.Field{ - zap.Stringer("code", code), - zap.Object("httpRequest", &grpcRequest), - zap.Error(err), - ErrorDetails(err), + attrs := []slog.Attr{ + slog.String("code", responseStatus.Code().String()), + slog.Any("status", responseStatus), + slog.Any("httpRequest", grpcRequest), } - fields = appendFullMethodFields(info.FullMethod, fields) + if err != nil { + attrs = append(attrs, slog.Any("error", err)) + } + attrs = appendFullMethodAttrs(info.FullMethod, attrs) if additionalFields, ok := GetAdditionalFields(ctx); ok { - fields = additionalFields.AppendTo(fields) + attrs = additionalFields.appendTo(attrs) } var errCaller interface { Caller() (pc uintptr, file string, line int, ok bool) } if errors.As(err, &errCaller) { - checkedEntry.Caller = zapcore.NewEntryCaller(errCaller.Caller()) - checkedEntry.Entry.Caller = checkedEntry.Caller + attrs = append(attrs, newSourceAttr(errCaller.Caller())) } - fields = append(fields, cloudzap.SourceLocationForCaller(checkedEntry.Caller)) - checkedEntry.Write(fields...) + logger.LogAttrs(ctx, level, grpcServerLogMessage(responseStatus.Code(), info.FullMethod), attrs...) return err } -func (l *Middleware) logger(ctx context.Context) *zap.Logger { - logger, ok := cloudzap.GetLogger(ctx) - if !ok { - panic("cloudrequestlog.Middleware requires a logger in the context") - } - return logger -} - // GRPCUnaryClientInterceptor provides request logging as a grpc.UnaryClientInterceptor. func (l *Middleware) GRPCUnaryClientInterceptor( ctx context.Context, @@ -150,39 +132,48 @@ func (l *Middleware) GRPCUnaryClientInterceptor( // Clone request to ensure not using a mutated one later requestClone := proto.Clone(request.(proto.Message)) err := invoker(ctx, fullMethod, request, response, cc, opts...) - code := status.Code(err) - checkedEntry := l.logger(ctx).Check( - l.codeToLevel(code), - grpcClientLogMessage(code, fullMethod), - ) - if checkedEntry == nil { + responseStatus := status.Convert(err) + level := l.codeToLevel(responseStatus.Code()) + logger := slog.Default() + if !logger.Enabled(ctx, level) { return err } - grpcRequest := cloudzap.HTTPRequestObject{ + grpcRequest := <ype.HttpRequest{ Protocol: "gRPC", - Latency: time.Since(startTime), + Latency: durationpb.New(time.Since(startTime)), } - grpcRequest.RequestSize = proto.Size(requestClone) + grpcRequest.RequestSize = int64(proto.Size(requestClone)) if protoResponse, ok := response.(proto.Message); ok { - grpcRequest.ResponseSize = proto.Size(protoResponse) + grpcRequest.ResponseSize = int64(proto.Size(protoResponse)) } - // assuming this middleware is first in the chain, the caller of the client method is 4 stack frames up - checkedEntry.Caller = zapcore.NewEntryCaller(runtime.Caller(4)) - checkedEntry.Entry.Caller = checkedEntry.Caller - fields := []zap.Field{ - zap.Stringer("code", code), - zap.Object("httpRequest", &grpcRequest), - l.messageField("request", requestClone), - l.messageField("response", response), - zap.Error(err), - ErrorDetails(err), - cloudzap.SourceLocationForCaller(checkedEntry.Caller), + attrs := []slog.Attr{ + slog.String("code", responseStatus.Code().String()), + slog.Any("status", responseStatus), + slog.Any("httpRequest", grpcRequest), + slog.Any("request", requestClone), + slog.Any("response", response), + // assuming this middleware is first in the chain, the caller of the client method is 4 stack frames up + newSourceAttr(runtime.Caller(4)), } - fields = appendFullMethodFields(fullMethod, fields) - checkedEntry.Write(fields...) + if err != nil { + attrs = append(attrs, slog.Any("error", err)) + } + attrs = appendFullMethodAttrs(fullMethod, attrs) + logger.LogAttrs(ctx, level, grpcClientLogMessage(responseStatus.Code(), fullMethod), attrs...) return err } +func newSourceAttr(pc uintptr, file string, line int, _ bool) slog.Attr { + return slog.Any( + slog.SourceKey, + &slog.Source{ + Function: runtime.FuncForPC(pc).Name(), + File: file, + Line: line, + }, + ) +} + func measureHeaderSize(h http.Header) int { var result int for k, vs := range h { @@ -204,7 +195,7 @@ func (l *Middleware) HTTPServer(next http.Handler) http.Handler { next.ServeHTTP(responseWriter, r) level := l.statusToLevel(responseWriter.Status()) logger := slog.Default() - if !logger.Enabled(ctx, levelToSlog(level)) { + if !logger.Enabled(ctx, level) { return } logMessage := httpServerLogMessage(responseWriter, r) @@ -227,63 +218,42 @@ func (l *Middleware) HTTPServer(next http.Handler) http.Handler { if additionalFields, ok := GetAdditionalFields(ctx); ok { attrs = additionalFields.appendTo(attrs) } - logger.LogAttrs(ctx, levelToSlog(level), logMessage, attrs...) + logger.LogAttrs(ctx, level, logMessage, attrs...) }) } -func (l *Middleware) messageField(key string, message interface{}) zap.Field { - protoMessage, ok := message.(proto.Message) - if !ok || protoMessage == nil || reflect.ValueOf(protoMessage).IsNil() { - return zap.Skip() - } - if l.Config.MessageSizeLimit > 0 { - size := proto.Size(protoMessage) - if size > l.Config.MessageSizeLimit { - return zap.Object(key, truncatedMessageField{size: size, sizeLimit: l.Config.MessageSizeLimit}) - } - } - return cloudzap.ProtoMessage(key, l.applyMessageTransform(protoMessage)) -} - -func (l *Middleware) applyMessageTransform(message proto.Message) proto.Message { - if l.MessageTransformer == nil { - return message - } - return l.MessageTransformer(message) -} - -func (l *Middleware) codeToLevel(code codes.Code) zapcore.Level { +func (l *Middleware) codeToLevel(code codes.Code) slog.Level { if level, ok := l.Config.CodeToLevel[code]; ok { - return slogToLevel(level) + return level } - return CodeToLevel(code) + return codeToLevel(code) } -func (l *Middleware) statusToLevel(status int) zapcore.Level { +func (l *Middleware) statusToLevel(status int) slog.Level { if level, ok := l.Config.StatusToLevel[status]; ok { - return slogToLevel(level) + return level } switch { case status < http.StatusBadRequest: - return zap.InfoLevel + return slog.LevelInfo case http.StatusBadRequest <= status && status < http.StatusInternalServerError: - return zap.WarnLevel + return slog.LevelWarn case status == http.StatusGatewayTimeout || status == http.StatusServiceUnavailable: // special case for 503 (unavailable) and 504 (timeout) to match severity for gRPC status codes - return zap.WarnLevel + return slog.LevelWarn default: - return zap.ErrorLevel + return slog.LevelError } } -func appendFullMethodFields(fullMethod string, dst []zap.Field) []zap.Field { +func appendFullMethodAttrs(fullMethod string, dst []slog.Attr) []slog.Attr { service, method, ok := splitFullMethod(fullMethod) if !ok { return dst } return append( dst, - zap.String("service", service), - zap.String("method", method), + slog.String("service", service), + slog.String("method", method), ) } diff --git a/cloudrequestlog/migration.go b/cloudrequestlog/migration.go index 21d6d669..816e39d0 100644 --- a/cloudrequestlog/migration.go +++ b/cloudrequestlog/migration.go @@ -9,34 +9,6 @@ import ( "go.uber.org/zap/zapcore" ) -func slogToLevel(l slog.Level) zapcore.Level { - switch { - case l >= slog.LevelError: - return zapcore.ErrorLevel - case l >= slog.LevelWarn: - return zapcore.WarnLevel - case l >= slog.LevelInfo: - return zapcore.InfoLevel - default: - return zapcore.DebugLevel - } -} - -func levelToSlog(l zapcore.Level) slog.Level { - switch l { - case zapcore.DebugLevel: - return slog.LevelDebug - case zapcore.InfoLevel: - return slog.LevelInfo - case zapcore.WarnLevel: - return slog.LevelWarn - case zapcore.ErrorLevel, zapcore.DPanicLevel, zapcore.PanicLevel, zapcore.FatalLevel: - return slog.LevelError - default: - return slog.LevelDebug - } -} - func attrToField(attr slog.Attr) zapcore.Field { if attr.Equal(slog.Attr{}) { // Ignore empty attrs. diff --git a/cloudrequestlog/truncatedmessagefield.go b/cloudrequestlog/truncatedmessagefield.go deleted file mode 100644 index 84e85fad..00000000 --- a/cloudrequestlog/truncatedmessagefield.go +++ /dev/null @@ -1,15 +0,0 @@ -package cloudrequestlog - -import "go.uber.org/zap/zapcore" - -type truncatedMessageField struct { - size int - sizeLimit int -} - -func (t truncatedMessageField) MarshalLogObject(e zapcore.ObjectEncoder) error { - e.AddString("message", "truncated due to size") - e.AddInt("size", t.size) - e.AddInt("sizeLimit", t.sizeLimit) - return nil -}