From 32b978a2b96065bbac5ef3da5969abd68d866733 Mon Sep 17 00:00:00 2001 From: Mike Crute Date: Sun, 8 Oct 2023 15:45:11 -0700 Subject: echo: build a proper JSON logger --- echo/echo_default.go | 20 +++- echo/middleware/json_logger.go | 205 +++++++++++++++++++++++++++++++++++++++++ 2 files changed, 224 insertions(+), 1 deletion(-) create mode 100644 echo/middleware/json_logger.go diff --git a/echo/echo_default.go b/echo/echo_default.go index 8d5e1a9..9f7e19e 100644 --- a/echo/echo_default.go +++ b/echo/echo_default.go @@ -93,7 +93,25 @@ func NewEchoWrapper(ctx context.Context, debug bool) (*EchoWrapper, error) { e.Logger.SetLevel(log.DEBUG) } - e.Use(middleware.Logger()) + e.Use(glmw.JsonLoggerWithConfig(glmw.JsonLoggerConfig{ + Format: map[string]string{ + "time": "time_rfc3339_nano", + "id": "id", + "remote_ip": "remote_ip", + "host": "host", + "method": "method", + "uri": "uri", + "user_agent": "user_agent", + "status": "status", + "error": "error", + "latency": "latency", + "latency_human": "latency_human", + "bytes_in": "bytes_in", + "bytes_out": "bytes_out", + "protocol": "protocol", + }, + Output: e.Logger.Output(), + })) e.Use(glmw.Recover()) return &EchoWrapper{ diff --git a/echo/middleware/json_logger.go b/echo/middleware/json_logger.go new file mode 100644 index 0000000..1aa7e9d --- /dev/null +++ b/echo/middleware/json_logger.go @@ -0,0 +1,205 @@ +package middleware + +import ( + "encoding/json" + "io" + "strings" + "sync" + "time" + + "github.com/labstack/echo/v4" + "github.com/labstack/echo/v4/middleware" +) + +// This is very close in functionality to the echo.Logger middleware +// (it started as a copy) but instead of using string functions to +// write JSON data it uses a proper JSON encoder for safety, speed, and +// simplicity. It also removes color output because it's pointless. + +type JsonLoggerConfig struct { + Skipper middleware.Skipper + + // Tags to construct the logger format. + // + // - time_unix + // - time_unix_milli + // - time_unix_micro + // - time_unix_nano + // - time_rfc3339 + // - time_rfc3339_nano + // - time_custom + // - id (Request ID) + // - remote_ip + // - uri + // - host + // - method + // - path + // - protocol + // - referer + // - user_agent + // - status + // - error + // - latency (In nanoseconds) + // - latency_human (Human readable) + // - bytes_in (Bytes received) + // - bytes_out (Bytes sent) + // - header: + // - query: + // - form: + // + // Optional. Default value DefaultLoggerConfig.Format. + Format map[string]string + + CustomTimeFormat string + Output io.Writer + + encoder *json.Encoder + pool *sync.Pool +} + +var DefaultLoggerConfig = JsonLoggerConfig{ + Skipper: middleware.DefaultSkipper, + Format: map[string]string{ + "time": "time_rfc3339_nano", + "id": "id", + "remote_ip": "remote_ip", + "host": "host", + "method": "method", + "uri": "uri", + "user_agent": "user_agent", + "status": "status", + "error": "error", + "latency": "latency", + "latency_human": "latency_human", + "bytes_in": "bytes_in", + "bytes_out": "bytes_out", + }, + CustomTimeFormat: "2006-01-02 15:04:05.00000", +} + +func JsonLoggerWithConfig(config JsonLoggerConfig) echo.MiddlewareFunc { + if config.Skipper == nil { + config.Skipper = DefaultLoggerConfig.Skipper + } + if config.CustomTimeFormat == "" { + config.CustomTimeFormat = DefaultLoggerConfig.CustomTimeFormat + } + if config.Format == nil { + panic("LoggerWithConfig: constructed without a logging format") + } + if config.Output == nil { + panic("LoggerWithConfig: constructed without a logging output") + } + + config.encoder = json.NewEncoder(config.Output) + config.encoder.SetEscapeHTML(false) + + config.pool = &sync.Pool{ + New: func() any { + return make(map[string]any, len(config.Format)) + }, + } + + return func(next echo.HandlerFunc) echo.HandlerFunc { + return func(c echo.Context) (err error) { + if config.Skipper(c) { + return next(c) + } + + req := c.Request() + res := c.Response() + start := time.Now() + if err = next(c); err != nil { + c.Error(err) + } + stop := time.Now() + + template := config.pool.Get().(map[string]any) + defer config.pool.Put(template) + + for k, v := range config.Format { + switch v { + case "time_unix": + template[k] = time.Now().Unix() + case "time_unix_milli": + // go 1.17 or later, it supports time#UnixMilli() + template[k] = time.Now().UnixNano() / 1000000 + case "time_unix_micro": + // go 1.17 or later, it supports time#UnixMicro() + template[k] = time.Now().UnixNano() / 1000 + case "time_unix_nano": + template[k] = time.Now().UnixNano() + case "time_rfc3339": + template[k] = time.Now().Format(time.RFC3339) + case "time_rfc3339_nano": + template[k] = time.Now().Format(time.RFC3339Nano) + case "time_custom": + template[k] = time.Now().Format(config.CustomTimeFormat) + case "id": + id := req.Header.Get(echo.HeaderXRequestID) + if id == "" { + id = res.Header().Get(echo.HeaderXRequestID) + } + template[k] = id + case "remote_ip": + template[k] = c.RealIP() + case "host": + template[k] = req.Host + case "uri": + template[k] = req.RequestURI + case "method": + template[k] = req.Method + case "path": + p := req.URL.Path + if p == "" { + p = "/" + } + template[k] = p + case "protocol": + template[k] = req.Proto + case "referer": + template[k] = req.Referer() + case "user_agent": + template[k] = req.UserAgent() + case "status": + template[k] = res.Status + case "error": + if err != nil { + template[k] = err.Error() + } else { + template[k] = "" + } + case "latency": + template[k] = stop.Sub(start) + case "latency_human": + template[k] = stop.Sub(start).String() + case "bytes_in": + cl := req.Header.Get(echo.HeaderContentLength) + if cl == "" { + cl = "0" + } + template[k] = cl + case "bytes_out": + template[k] = res.Size + default: + switch { + case strings.HasPrefix(v, "header:"): + template[k] = c.Request().Header.Get(v[7:]) + case strings.HasPrefix(v, "query:"): + template[k] = c.QueryParam(v[6:]) + case strings.HasPrefix(v, "form:"): + template[k] = c.FormValue(v[5:]) + case strings.HasPrefix(v, "cookie:"): + cookie, err := c.Cookie(v[7:]) + if err == nil { + template[k] = cookie.Value + } + } + } + } + + config.encoder.Encode(template) + return + } + } +} -- cgit v1.2.3