2024-04-28 13:08:41 +02:00
|
|
|
// SPDX-License-Identifier: MIT
|
|
|
|
// SPDX-FileCopyrightText: © 2015 LabStack LLC and Echo contributors
|
|
|
|
|
2020-02-11 19:33:19 +01:00
|
|
|
package middleware
|
|
|
|
|
|
|
|
import (
|
|
|
|
"bytes"
|
|
|
|
"encoding/json"
|
|
|
|
"io"
|
|
|
|
"strconv"
|
|
|
|
"strings"
|
|
|
|
"sync"
|
|
|
|
"time"
|
|
|
|
|
|
|
|
"github.com/labstack/echo/v4"
|
|
|
|
"github.com/labstack/gommon/color"
|
|
|
|
"github.com/valyala/fasttemplate"
|
|
|
|
)
|
|
|
|
|
2024-04-28 13:08:41 +02:00
|
|
|
// LoggerConfig defines the config for Logger middleware.
|
|
|
|
type LoggerConfig struct {
|
|
|
|
// Skipper defines a function to skip middleware.
|
|
|
|
Skipper Skipper
|
2020-02-11 19:33:19 +01:00
|
|
|
|
2024-04-28 13:08:41 +02:00
|
|
|
// 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
|
|
|
|
// - route
|
|
|
|
// - protocol
|
|
|
|
// - referer
|
|
|
|
// - user_agent
|
|
|
|
// - status
|
|
|
|
// - error
|
|
|
|
// - latency (In nanoseconds)
|
|
|
|
// - latency_human (Human readable)
|
|
|
|
// - bytes_in (Bytes received)
|
|
|
|
// - bytes_out (Bytes sent)
|
|
|
|
// - header:<NAME>
|
|
|
|
// - query:<NAME>
|
|
|
|
// - form:<NAME>
|
|
|
|
// - custom (see CustomTagFunc field)
|
|
|
|
//
|
|
|
|
// Example "${remote_ip} ${status}"
|
|
|
|
//
|
|
|
|
// Optional. Default value DefaultLoggerConfig.Format.
|
|
|
|
Format string `yaml:"format"`
|
2020-02-11 19:33:19 +01:00
|
|
|
|
2024-04-28 13:08:41 +02:00
|
|
|
// Optional. Default value DefaultLoggerConfig.CustomTimeFormat.
|
|
|
|
CustomTimeFormat string `yaml:"custom_time_format"`
|
2020-02-11 19:33:19 +01:00
|
|
|
|
2024-04-28 13:08:41 +02:00
|
|
|
// CustomTagFunc is function called for `${custom}` tag to output user implemented text by writing it to buf.
|
|
|
|
// Make sure that outputted text creates valid JSON string with other logged tags.
|
|
|
|
// Optional.
|
|
|
|
CustomTagFunc func(c echo.Context, buf *bytes.Buffer) (int, error)
|
2023-01-14 20:50:39 +01:00
|
|
|
|
2024-04-28 13:08:41 +02:00
|
|
|
// Output is a writer where logs in JSON format are written.
|
|
|
|
// Optional. Default value os.Stdout.
|
|
|
|
Output io.Writer
|
2020-02-11 19:33:19 +01:00
|
|
|
|
2024-04-28 13:08:41 +02:00
|
|
|
template *fasttemplate.Template
|
|
|
|
colorer *color.Color
|
|
|
|
pool *sync.Pool
|
|
|
|
}
|
2020-02-11 19:33:19 +01:00
|
|
|
|
2024-04-28 13:08:41 +02:00
|
|
|
// DefaultLoggerConfig is the default Logger middleware config.
|
|
|
|
var DefaultLoggerConfig = LoggerConfig{
|
|
|
|
Skipper: DefaultSkipper,
|
|
|
|
Format: `{"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}}` + "\n",
|
|
|
|
CustomTimeFormat: "2006-01-02 15:04:05.00000",
|
|
|
|
colorer: color.New(),
|
|
|
|
}
|
2020-02-11 19:33:19 +01:00
|
|
|
|
|
|
|
// Logger returns a middleware that logs HTTP requests.
|
|
|
|
func Logger() echo.MiddlewareFunc {
|
|
|
|
return LoggerWithConfig(DefaultLoggerConfig)
|
|
|
|
}
|
|
|
|
|
|
|
|
// LoggerWithConfig returns a Logger middleware with config.
|
|
|
|
// See: `Logger()`.
|
|
|
|
func LoggerWithConfig(config LoggerConfig) echo.MiddlewareFunc {
|
|
|
|
// Defaults
|
|
|
|
if config.Skipper == nil {
|
|
|
|
config.Skipper = DefaultLoggerConfig.Skipper
|
|
|
|
}
|
|
|
|
if config.Format == "" {
|
|
|
|
config.Format = DefaultLoggerConfig.Format
|
|
|
|
}
|
|
|
|
if config.Output == nil {
|
|
|
|
config.Output = DefaultLoggerConfig.Output
|
|
|
|
}
|
|
|
|
|
|
|
|
config.template = fasttemplate.New(config.Format, "${", "}")
|
|
|
|
config.colorer = color.New()
|
|
|
|
config.colorer.SetOutput(config.Output)
|
|
|
|
config.pool = &sync.Pool{
|
|
|
|
New: func() interface{} {
|
|
|
|
return bytes.NewBuffer(make([]byte, 256))
|
|
|
|
},
|
|
|
|
}
|
|
|
|
|
|
|
|
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()
|
|
|
|
buf := config.pool.Get().(*bytes.Buffer)
|
|
|
|
buf.Reset()
|
|
|
|
defer config.pool.Put(buf)
|
|
|
|
|
|
|
|
if _, err = config.template.ExecuteFunc(buf, func(w io.Writer, tag string) (int, error) {
|
|
|
|
switch tag {
|
2023-01-14 20:50:39 +01:00
|
|
|
case "custom":
|
|
|
|
if config.CustomTagFunc == nil {
|
|
|
|
return 0, nil
|
|
|
|
}
|
|
|
|
return config.CustomTagFunc(c, buf)
|
2020-02-11 19:33:19 +01:00
|
|
|
case "time_unix":
|
|
|
|
return buf.WriteString(strconv.FormatInt(time.Now().Unix(), 10))
|
2022-08-18 01:16:43 +02:00
|
|
|
case "time_unix_milli":
|
|
|
|
// go 1.17 or later, it supports time#UnixMilli()
|
|
|
|
return buf.WriteString(strconv.FormatInt(time.Now().UnixNano()/1000000, 10))
|
|
|
|
case "time_unix_micro":
|
|
|
|
// go 1.17 or later, it supports time#UnixMicro()
|
|
|
|
return buf.WriteString(strconv.FormatInt(time.Now().UnixNano()/1000, 10))
|
2020-02-11 19:33:19 +01:00
|
|
|
case "time_unix_nano":
|
|
|
|
return buf.WriteString(strconv.FormatInt(time.Now().UnixNano(), 10))
|
|
|
|
case "time_rfc3339":
|
|
|
|
return buf.WriteString(time.Now().Format(time.RFC3339))
|
|
|
|
case "time_rfc3339_nano":
|
|
|
|
return buf.WriteString(time.Now().Format(time.RFC3339Nano))
|
|
|
|
case "time_custom":
|
|
|
|
return buf.WriteString(time.Now().Format(config.CustomTimeFormat))
|
|
|
|
case "id":
|
|
|
|
id := req.Header.Get(echo.HeaderXRequestID)
|
|
|
|
if id == "" {
|
|
|
|
id = res.Header().Get(echo.HeaderXRequestID)
|
|
|
|
}
|
|
|
|
return buf.WriteString(id)
|
|
|
|
case "remote_ip":
|
|
|
|
return buf.WriteString(c.RealIP())
|
|
|
|
case "host":
|
|
|
|
return buf.WriteString(req.Host)
|
|
|
|
case "uri":
|
|
|
|
return buf.WriteString(req.RequestURI)
|
|
|
|
case "method":
|
|
|
|
return buf.WriteString(req.Method)
|
|
|
|
case "path":
|
|
|
|
p := req.URL.Path
|
|
|
|
if p == "" {
|
|
|
|
p = "/"
|
|
|
|
}
|
|
|
|
return buf.WriteString(p)
|
2023-01-14 20:50:39 +01:00
|
|
|
case "route":
|
|
|
|
return buf.WriteString(c.Path())
|
2020-02-11 19:33:19 +01:00
|
|
|
case "protocol":
|
|
|
|
return buf.WriteString(req.Proto)
|
|
|
|
case "referer":
|
|
|
|
return buf.WriteString(req.Referer())
|
|
|
|
case "user_agent":
|
|
|
|
return buf.WriteString(req.UserAgent())
|
|
|
|
case "status":
|
|
|
|
n := res.Status
|
|
|
|
s := config.colorer.Green(n)
|
|
|
|
switch {
|
|
|
|
case n >= 500:
|
|
|
|
s = config.colorer.Red(n)
|
|
|
|
case n >= 400:
|
|
|
|
s = config.colorer.Yellow(n)
|
|
|
|
case n >= 300:
|
|
|
|
s = config.colorer.Cyan(n)
|
|
|
|
}
|
|
|
|
return buf.WriteString(s)
|
|
|
|
case "error":
|
|
|
|
if err != nil {
|
|
|
|
// Error may contain invalid JSON e.g. `"`
|
|
|
|
b, _ := json.Marshal(err.Error())
|
|
|
|
b = b[1 : len(b)-1]
|
|
|
|
return buf.Write(b)
|
|
|
|
}
|
|
|
|
case "latency":
|
|
|
|
l := stop.Sub(start)
|
|
|
|
return buf.WriteString(strconv.FormatInt(int64(l), 10))
|
|
|
|
case "latency_human":
|
|
|
|
return buf.WriteString(stop.Sub(start).String())
|
|
|
|
case "bytes_in":
|
|
|
|
cl := req.Header.Get(echo.HeaderContentLength)
|
|
|
|
if cl == "" {
|
|
|
|
cl = "0"
|
|
|
|
}
|
|
|
|
return buf.WriteString(cl)
|
|
|
|
case "bytes_out":
|
|
|
|
return buf.WriteString(strconv.FormatInt(res.Size, 10))
|
|
|
|
default:
|
|
|
|
switch {
|
|
|
|
case strings.HasPrefix(tag, "header:"):
|
|
|
|
return buf.Write([]byte(c.Request().Header.Get(tag[7:])))
|
|
|
|
case strings.HasPrefix(tag, "query:"):
|
|
|
|
return buf.Write([]byte(c.QueryParam(tag[6:])))
|
|
|
|
case strings.HasPrefix(tag, "form:"):
|
|
|
|
return buf.Write([]byte(c.FormValue(tag[5:])))
|
|
|
|
case strings.HasPrefix(tag, "cookie:"):
|
|
|
|
cookie, err := c.Cookie(tag[7:])
|
|
|
|
if err == nil {
|
|
|
|
return buf.Write([]byte(cookie.Value))
|
|
|
|
}
|
|
|
|
}
|
|
|
|
}
|
|
|
|
return 0, nil
|
|
|
|
}); err != nil {
|
|
|
|
return
|
|
|
|
}
|
|
|
|
|
|
|
|
if config.Output == nil {
|
|
|
|
_, err = c.Logger().Output().Write(buf.Bytes())
|
|
|
|
return
|
|
|
|
}
|
|
|
|
_, err = config.Output.Write(buf.Bytes())
|
|
|
|
return
|
|
|
|
}
|
|
|
|
}
|
|
|
|
}
|