From 5ed0c006a050ea8dcd0099dea2f900cddfbd1ce5 Mon Sep 17 00:00:00 2001 From: Tony Chen Date: Thu, 3 Jun 2021 13:49:13 +0800 Subject: [PATCH] clean access logging (#996) --- examples/helloworld/client/main.go | 28 ++-- middleware/logging/grpc.go | 54 ++++++++ middleware/logging/http.go | 56 ++++++++ middleware/logging/logging.go | 202 +++++++---------------------- 4 files changed, 174 insertions(+), 166 deletions(-) create mode 100644 middleware/logging/grpc.go create mode 100644 middleware/logging/http.go diff --git a/examples/helloworld/client/main.go b/examples/helloworld/client/main.go index e49987c42..2e087efe0 100644 --- a/examples/helloworld/client/main.go +++ b/examples/helloworld/client/main.go @@ -2,11 +2,13 @@ package main import ( "context" - "log" + "fmt" pb "github.com/go-kratos/kratos/examples/helloworld/helloworld" "github.com/go-kratos/kratos/v2/errors" + "github.com/go-kratos/kratos/v2/log" "github.com/go-kratos/kratos/v2/middleware" + "github.com/go-kratos/kratos/v2/middleware/logging" "github.com/go-kratos/kratos/v2/middleware/recovery" transgrpc "github.com/go-kratos/kratos/v2/transport/grpc" transhttp "github.com/go-kratos/kratos/v2/transport/http" @@ -18,59 +20,63 @@ func main() { } func callHTTP() { + logger := log.DefaultLogger conn, err := transhttp.NewClient( context.Background(), transhttp.WithMiddleware( recovery.Recovery(), + logging.Client(logger), ), transhttp.WithEndpoint("127.0.0.1:8000"), ) if err != nil { - log.Fatal(err) + panic(err) } client := pb.NewGreeterHTTPClient(conn) reply, err := client.SayHello(context.Background(), &pb.HelloRequest{Name: "kratos"}) if err != nil { - log.Fatal(err) + panic(err) } - log.Printf("[http] SayHello %s\n", reply.Message) + logger.Log(log.LevelInfo, fmt.Sprintf("[http] SayHello %s\n", reply.Message)) // returns error reply, err = client.SayHello(context.Background(), &pb.HelloRequest{Name: "error"}) if err != nil { - log.Printf("[http] SayHello error: %v\n", err) + logger.Log(log.LevelInfo, fmt.Sprintf("[http] SayHello error: %v\n", err)) } if errors.IsBadRequest(err) { - log.Printf("[http] SayHello error is invalid argument: %v\n", err) + logger.Log(log.LevelInfo, fmt.Sprintf("[http] SayHello error is invalid argument: %v\n", err)) } } func callGRPC() { + logger := log.DefaultLogger conn, err := transgrpc.DialInsecure( context.Background(), transgrpc.WithEndpoint("127.0.0.1:9000"), transgrpc.WithMiddleware( middleware.Chain( recovery.Recovery(), + logging.Client(logger), ), ), ) if err != nil { - log.Fatal(err) + panic(err) } client := pb.NewGreeterClient(conn) reply, err := client.SayHello(context.Background(), &pb.HelloRequest{Name: "kratos"}) if err != nil { - log.Fatal(err) + panic(err) } - log.Printf("[grpc] SayHello %+v\n", reply) + logger.Log(log.LevelInfo, fmt.Sprintf("[grpc] SayHello %+v", reply)) // returns error _, err = client.SayHello(context.Background(), &pb.HelloRequest{Name: "error"}) if err != nil { - log.Printf("[grpc] SayHello error: %v\n", err) + logger.Log(log.LevelInfo, fmt.Sprintf("[grpc] SayHello error: %v", err)) } if errors.IsBadRequest(err) { - log.Printf("[grpc] SayHello error is invalid argument: %v\n", err) + logger.Log(log.LevelInfo, fmt.Sprintf("[grpc] SayHello error is invalid argument: %v", err)) } } diff --git a/middleware/logging/grpc.go b/middleware/logging/grpc.go new file mode 100644 index 000000000..33b0f2b2b --- /dev/null +++ b/middleware/logging/grpc.go @@ -0,0 +1,54 @@ +package logging + +import ( + "context" + + "github.com/go-kratos/kratos/v2/log" + "github.com/go-kratos/kratos/v2/transport/grpc" +) + +func grpcServerLog(logger log.Logger, ctx context.Context, args string, err error) { + info, ok := grpc.FromServerContext(ctx) + if !ok { + return + } + traceID, spanID := extractTrace(ctx) + code, errMsg := extractError(err) + level := log.LevelInfo + if err != nil { + level = log.LevelError + } + logger.Log(level, + "kind", "server", + "component", "grpc", + "trace_id", traceID, + "span_id", spanID, + "grpc.target", info.FullMethod, + "grpc.args", args, + "grpc.code", code, + "grpc.error", errMsg, + ) +} + +func grpcClientLog(logger log.Logger, ctx context.Context, args string, err error) { + info, ok := grpc.FromClientContext(ctx) + if !ok { + return + } + traceID, spanID := extractTrace(ctx) + code, errMsg := extractError(err) + level := log.LevelInfo + if err != nil { + level = log.LevelError + } + logger.Log(level, + "kind", "client", + "component", "grpc", + "trace_id", traceID, + "span_id", spanID, + "grpc.target", info.FullMethod, + "grpc.args", args, + "grpc.code", code, + "grpc.error", errMsg, + ) +} diff --git a/middleware/logging/http.go b/middleware/logging/http.go new file mode 100644 index 000000000..334aa854d --- /dev/null +++ b/middleware/logging/http.go @@ -0,0 +1,56 @@ +package logging + +import ( + "context" + + "github.com/go-kratos/kratos/v2/log" + "github.com/go-kratos/kratos/v2/transport/http" +) + +func httpServerLog(logger log.Logger, ctx context.Context, args string, err error) { + info, ok := http.FromServerContext(ctx) + if !ok { + return + } + traceID, spanID := extractTrace(ctx) + code, errMsg := extractError(err) + level := log.LevelInfo + if err != nil { + level = log.LevelError + } + logger.Log(level, + "kind", "server", + "component", "http", + "trace_id", traceID, + "span_id", spanID, + "http.target", info.Request.RequestURI, + "http.method", info.Request.Method, + "http.args", args, + "http.code", code, + "http.error", errMsg, + ) +} + +func httpClientLog(logger log.Logger, ctx context.Context, args string, err error) { + info, ok := http.FromClientContext(ctx) + if !ok { + return + } + traceID, spanID := extractTrace(ctx) + code, errMsg := extractError(err) + level := log.LevelInfo + if err != nil { + level = log.LevelError + } + logger.Log(level, + "kind", "client", + "component", "http", + "trace_id", traceID, + "span_id", spanID, + "http.target", info.Request.RequestURI, + "http.method", info.Request.Method, + "http.args", args, + "http.code", code, + "http.error", errMsg, + ) +} diff --git a/middleware/logging/logging.go b/middleware/logging/logging.go index dbc480d99..6d83e30b7 100644 --- a/middleware/logging/logging.go +++ b/middleware/logging/logging.go @@ -9,175 +9,67 @@ import ( "github.com/go-kratos/kratos/v2/errors" "github.com/go-kratos/kratos/v2/log" "github.com/go-kratos/kratos/v2/middleware" - "github.com/go-kratos/kratos/v2/transport/grpc" - "github.com/go-kratos/kratos/v2/transport/http" + "github.com/go-kratos/kratos/v2/transport" ) // Server is an server logging middleware. -func Server(l log.Logger) middleware.Middleware { - logger := log.NewHelper(l) +func Server(logger log.Logger) middleware.Middleware { return func(handler middleware.Handler) middleware.Handler { - return func(ctx context.Context, req interface{}) (interface{}, error) { - var ( - path string - method string - args string - component string - query string - traceID string - ) - if tid := trace.SpanContextFromContext(ctx).TraceID(); tid.IsValid() { - traceID = tid.String() - } - if stringer, ok := req.(fmt.Stringer); ok { - args = stringer.String() - } else { - args = fmt.Sprintf("%+v", req) - } - if info, ok := http.FromServerContext(ctx); ok { - component = "HTTP" - path = info.Request.URL.Path - method = info.Request.Method - query = info.Request.URL.RawQuery - } else if info, ok := grpc.FromServerContext(ctx); ok { - component = "gRPC" - path = info.FullMethod - method = "POST" - } - reply, err := handler(ctx, req) - if component == "HTTP" { - if err != nil { - logger.Errorw( - "kind", "server", - "component", component, - "traceID", traceID, - "path", path, - "method", method, - "args", args, - "query", query, - "code", uint32(errors.Code(err)), - "error", err.Error(), - ) - return nil, err + return func(ctx context.Context, req interface{}) (reply interface{}, err error) { + reply, err = handler(ctx, req) + if tr, ok := transport.FromContext(ctx); ok { + switch tr.Kind { + case transport.KindHTTP: + httpServerLog(logger, ctx, extractArgs(req), err) + case transport.KindGRPC: + grpcServerLog(logger, ctx, extractArgs(req), err) } - logger.Infow( - "kind", "server", - "component", component, - "traceID", traceID, - "path", path, - "method", method, - "args", args, - "query", query, - "code", 0, - ) - } else { - if err != nil { - logger.Errorw( - "kind", "server", - "component", component, - "traceID", traceID, - "path", path, - "method", method, - "args", args, - "code", uint32(errors.Code(err)), - "error", err.Error(), - ) - return nil, err - } - logger.Infow( - "kind", "server", - "component", component, - "traceID", traceID, - "path", path, - "method", method, - "args", args, - "code", 0, - ) } - return reply, nil + return } } } // Client is an client logging middleware. -func Client(l log.Logger) middleware.Middleware { - logger := log.NewHelper(l) +func Client(logger log.Logger) middleware.Middleware { return func(handler middleware.Handler) middleware.Handler { - return func(ctx context.Context, req interface{}) (interface{}, error) { - var ( - path string - method string - args string - component string - query string - traceID string - ) - if tid := trace.SpanContextFromContext(ctx).TraceID(); tid.IsValid() { - traceID = tid.String() - } - if info, ok := http.FromClientContext(ctx); ok { - component = "HTTP" - path = info.Request.URL.Path - method = info.Request.Method - args = req.(fmt.Stringer).String() - query = info.Request.URL.RawQuery - } else if info, ok := grpc.FromClientContext(ctx); ok { - path = info.FullMethod - method = "POST" - component = "gRPC" - args = req.(fmt.Stringer).String() - } - reply, err := handler(ctx, req) - if component == "HTTP" { - if err != nil { - logger.Errorw( - "kind", "client", - "component", component, - "traceID", traceID, - "path", path, - "method", method, - "args", args, - "query", query, - "code", uint32(errors.Code(err)), - "error", err.Error(), - ) - return nil, err - } - logger.Infow( - "kind", "client", - "component", component, - "traceID", traceID, - "path", path, - "method", method, - "args", args, - "query", query, - "code", 0, - ) - } else { - if err != nil { - logger.Errorw( - "kind", "client", - "component", component, - "traceID", traceID, - "path", path, - "method", method, - "args", args, - "code", uint32(errors.Code(err)), - "error", err.Error(), - ) - return nil, err + return func(ctx context.Context, req interface{}) (reply interface{}, err error) { + reply, err = handler(ctx, req) + if tr, ok := transport.FromContext(ctx); ok { + switch tr.Kind { + case transport.KindHTTP: + httpClientLog(logger, ctx, extractArgs(req), err) + case transport.KindGRPC: + grpcClientLog(logger, ctx, extractArgs(req), err) } - logger.Infow( - "kind", "client", - "component", component, - "traceID", traceID, - "path", path, - "method", method, - "args", args, - "code", 0, - ) } - return reply, nil + return } } } + +func extractArgs(req interface{}) string { + if stringer, ok := req.(fmt.Stringer); ok { + return stringer.String() + } + return fmt.Sprintf("%+v", req) +} + +func extractTrace(ctx context.Context) (traceID, spanID string) { + span := trace.SpanContextFromContext(ctx) + if span.HasTraceID() { + traceID = span.TraceID().String() + } + if span.HasSpanID() { + spanID = span.SpanID().String() + } + return +} + +func extractError(err error) (code int, errMsg string) { + if err != nil { + code = errors.Code(err) + errMsg = fmt.Sprintf("%+v", err) + } + return +}