aboutsummaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorMike Crute <mike@crute.us>2023-10-08 15:45:11 -0700
committerMike Crute <mike@crute.us>2023-10-08 15:45:11 -0700
commit32b978a2b96065bbac5ef3da5969abd68d866733 (patch)
treed8177d161b255382b00fc31749f5cd7ead7691b3
parent2a305880351281897399dddf9554c03fbb076f0e (diff)
downloadgolib-32b978a2b96065bbac5ef3da5969abd68d866733.tar.bz2
golib-32b978a2b96065bbac5ef3da5969abd68d866733.tar.xz
golib-32b978a2b96065bbac5ef3da5969abd68d866733.zip
echo: build a proper JSON loggerecho/v0.14.0
-rw-r--r--echo/echo_default.go20
-rw-r--r--echo/middleware/json_logger.go205
2 files changed, 224 insertions, 1 deletions
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) {
93 e.Logger.SetLevel(log.DEBUG) 93 e.Logger.SetLevel(log.DEBUG)
94 } 94 }
95 95
96 e.Use(middleware.Logger()) 96 e.Use(glmw.JsonLoggerWithConfig(glmw.JsonLoggerConfig{
97 Format: map[string]string{
98 "time": "time_rfc3339_nano",
99 "id": "id",
100 "remote_ip": "remote_ip",
101 "host": "host",
102 "method": "method",
103 "uri": "uri",
104 "user_agent": "user_agent",
105 "status": "status",
106 "error": "error",
107 "latency": "latency",
108 "latency_human": "latency_human",
109 "bytes_in": "bytes_in",
110 "bytes_out": "bytes_out",
111 "protocol": "protocol",
112 },
113 Output: e.Logger.Output(),
114 }))
97 e.Use(glmw.Recover()) 115 e.Use(glmw.Recover())
98 116
99 return &EchoWrapper{ 117 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 @@
1package middleware
2
3import (
4 "encoding/json"
5 "io"
6 "strings"
7 "sync"
8 "time"
9
10 "github.com/labstack/echo/v4"
11 "github.com/labstack/echo/v4/middleware"
12)
13
14// This is very close in functionality to the echo.Logger middleware
15// (it started as a copy) but instead of using string functions to
16// write JSON data it uses a proper JSON encoder for safety, speed, and
17// simplicity. It also removes color output because it's pointless.
18
19type JsonLoggerConfig struct {
20 Skipper middleware.Skipper
21
22 // Tags to construct the logger format.
23 //
24 // - time_unix
25 // - time_unix_milli
26 // - time_unix_micro
27 // - time_unix_nano
28 // - time_rfc3339
29 // - time_rfc3339_nano
30 // - time_custom
31 // - id (Request ID)
32 // - remote_ip
33 // - uri
34 // - host
35 // - method
36 // - path
37 // - protocol
38 // - referer
39 // - user_agent
40 // - status
41 // - error
42 // - latency (In nanoseconds)
43 // - latency_human (Human readable)
44 // - bytes_in (Bytes received)
45 // - bytes_out (Bytes sent)
46 // - header:<NAME>
47 // - query:<NAME>
48 // - form:<NAME>
49 //
50 // Optional. Default value DefaultLoggerConfig.Format.
51 Format map[string]string
52
53 CustomTimeFormat string
54 Output io.Writer
55
56 encoder *json.Encoder
57 pool *sync.Pool
58}
59
60var DefaultLoggerConfig = JsonLoggerConfig{
61 Skipper: middleware.DefaultSkipper,
62 Format: map[string]string{
63 "time": "time_rfc3339_nano",
64 "id": "id",
65 "remote_ip": "remote_ip",
66 "host": "host",
67 "method": "method",
68 "uri": "uri",
69 "user_agent": "user_agent",
70 "status": "status",
71 "error": "error",
72 "latency": "latency",
73 "latency_human": "latency_human",
74 "bytes_in": "bytes_in",
75 "bytes_out": "bytes_out",
76 },
77 CustomTimeFormat: "2006-01-02 15:04:05.00000",
78}
79
80func JsonLoggerWithConfig(config JsonLoggerConfig) echo.MiddlewareFunc {
81 if config.Skipper == nil {
82 config.Skipper = DefaultLoggerConfig.Skipper
83 }
84 if config.CustomTimeFormat == "" {
85 config.CustomTimeFormat = DefaultLoggerConfig.CustomTimeFormat
86 }
87 if config.Format == nil {
88 panic("LoggerWithConfig: constructed without a logging format")
89 }
90 if config.Output == nil {
91 panic("LoggerWithConfig: constructed without a logging output")
92 }
93
94 config.encoder = json.NewEncoder(config.Output)
95 config.encoder.SetEscapeHTML(false)
96
97 config.pool = &sync.Pool{
98 New: func() any {
99 return make(map[string]any, len(config.Format))
100 },
101 }
102
103 return func(next echo.HandlerFunc) echo.HandlerFunc {
104 return func(c echo.Context) (err error) {
105 if config.Skipper(c) {
106 return next(c)
107 }
108
109 req := c.Request()
110 res := c.Response()
111 start := time.Now()
112 if err = next(c); err != nil {
113 c.Error(err)
114 }
115 stop := time.Now()
116
117 template := config.pool.Get().(map[string]any)
118 defer config.pool.Put(template)
119
120 for k, v := range config.Format {
121 switch v {
122 case "time_unix":
123 template[k] = time.Now().Unix()
124 case "time_unix_milli":
125 // go 1.17 or later, it supports time#UnixMilli()
126 template[k] = time.Now().UnixNano() / 1000000
127 case "time_unix_micro":
128 // go 1.17 or later, it supports time#UnixMicro()
129 template[k] = time.Now().UnixNano() / 1000
130 case "time_unix_nano":
131 template[k] = time.Now().UnixNano()
132 case "time_rfc3339":
133 template[k] = time.Now().Format(time.RFC3339)
134 case "time_rfc3339_nano":
135 template[k] = time.Now().Format(time.RFC3339Nano)
136 case "time_custom":
137 template[k] = time.Now().Format(config.CustomTimeFormat)
138 case "id":
139 id := req.Header.Get(echo.HeaderXRequestID)
140 if id == "" {
141 id = res.Header().Get(echo.HeaderXRequestID)
142 }
143 template[k] = id
144 case "remote_ip":
145 template[k] = c.RealIP()
146 case "host":
147 template[k] = req.Host
148 case "uri":
149 template[k] = req.RequestURI
150 case "method":
151 template[k] = req.Method
152 case "path":
153 p := req.URL.Path
154 if p == "" {
155 p = "/"
156 }
157 template[k] = p
158 case "protocol":
159 template[k] = req.Proto
160 case "referer":
161 template[k] = req.Referer()
162 case "user_agent":
163 template[k] = req.UserAgent()
164 case "status":
165 template[k] = res.Status
166 case "error":
167 if err != nil {
168 template[k] = err.Error()
169 } else {
170 template[k] = ""
171 }
172 case "latency":
173 template[k] = stop.Sub(start)
174 case "latency_human":
175 template[k] = stop.Sub(start).String()
176 case "bytes_in":
177 cl := req.Header.Get(echo.HeaderContentLength)
178 if cl == "" {
179 cl = "0"
180 }
181 template[k] = cl
182 case "bytes_out":
183 template[k] = res.Size
184 default:
185 switch {
186 case strings.HasPrefix(v, "header:"):
187 template[k] = c.Request().Header.Get(v[7:])
188 case strings.HasPrefix(v, "query:"):
189 template[k] = c.QueryParam(v[6:])
190 case strings.HasPrefix(v, "form:"):
191 template[k] = c.FormValue(v[5:])
192 case strings.HasPrefix(v, "cookie:"):
193 cookie, err := c.Cookie(v[7:])
194 if err == nil {
195 template[k] = cookie.Value
196 }
197 }
198 }
199 }
200
201 config.encoder.Encode(template)
202 return
203 }
204 }
205}