|
| 1 | +package echolog |
| 2 | + |
| 3 | +import ( |
| 4 | + "bytes" |
| 5 | + "encoding/json" |
| 6 | + "fmt" |
| 7 | + "io" |
| 8 | + "net/http" |
| 9 | + "runtime/debug" |
| 10 | + "time" |
| 11 | + |
| 12 | + "github.com/google/uuid" |
| 13 | + "github.com/labstack/echo/v4" |
| 14 | + "github.com/rs/zerolog" |
| 15 | + "github.com/rs/zerolog/log" |
| 16 | +) |
| 17 | + |
| 18 | +// RequestIDHeader is the name of the HTTP Header which contains the request id. |
| 19 | +// Exported so that it can be changed by developers |
| 20 | +var RequestIDHeader = "X-Request-Id" |
| 21 | + |
| 22 | +type logFields struct { |
| 23 | + RemoteIP string |
| 24 | + Host string |
| 25 | + Method string |
| 26 | + Path string |
| 27 | + Body string |
| 28 | + StatusCode int |
| 29 | + Latency float64 |
| 30 | + Error error |
| 31 | + Stack []byte |
| 32 | +} |
| 33 | + |
| 34 | +func (l *logFields) MarshalZerologObject(e *zerolog.Event) { |
| 35 | + e. |
| 36 | + Str("remote_ip", l.RemoteIP). |
| 37 | + Str("host", l.Host). |
| 38 | + Str("method", l.Method). |
| 39 | + Str("path", l.Path). |
| 40 | + Str("body", l.Body). |
| 41 | + Int("status_code", l.StatusCode). |
| 42 | + Float64("latency", l.Latency). |
| 43 | + Str("tag", "request") |
| 44 | + |
| 45 | + if l.Error != nil { |
| 46 | + e.Err(l.Error) |
| 47 | + } |
| 48 | + |
| 49 | + if l.Stack != nil { |
| 50 | + e.Bytes("stack", l.Stack) |
| 51 | + } |
| 52 | +} |
| 53 | + |
| 54 | +// Middleware contains functionality of request_id, logger and recover for request traceability |
| 55 | +func Middleware(filter func(c echo.Context) bool) echo.MiddlewareFunc { |
| 56 | + return func(next echo.HandlerFunc) echo.HandlerFunc { |
| 57 | + return func(c echo.Context) error { |
| 58 | + |
| 59 | + if filter != nil && filter(c) { |
| 60 | + return next(c) |
| 61 | + } |
| 62 | + |
| 63 | + // Start timer |
| 64 | + start := time.Now() |
| 65 | + |
| 66 | + // Generate request ID |
| 67 | + // will search for a request ID header and set into the log context |
| 68 | + if c.Request().Header.Get(RequestIDHeader) == "" { |
| 69 | + c.Request().Header.Set(RequestIDHeader, uuid.New().String()) |
| 70 | + } |
| 71 | + |
| 72 | + ctx := log.With(). |
| 73 | + Str("request_id", c.Request().Header.Get(RequestIDHeader)). |
| 74 | + Logger(). |
| 75 | + WithContext(c.Request().Context()) |
| 76 | + |
| 77 | + // Read request body |
| 78 | + var buf []byte |
| 79 | + if c.Request().Body != nil { |
| 80 | + buf, _ = io.ReadAll(c.Request().Body) |
| 81 | + |
| 82 | + // Restore the io.ReadCloser to its original state |
| 83 | + c.Request().Body = io.NopCloser(bytes.NewBuffer(buf)) |
| 84 | + } |
| 85 | + |
| 86 | + // Create log fields |
| 87 | + fields := &logFields{ |
| 88 | + RemoteIP: c.RealIP(), |
| 89 | + Method: c.Request().Method, |
| 90 | + Host: c.Request().Host, |
| 91 | + Path: c.Request().RequestURI, |
| 92 | + Body: formatReqBody(buf), |
| 93 | + } |
| 94 | + |
| 95 | + defer func() { |
| 96 | + rvr := recover() |
| 97 | + |
| 98 | + if rvr != nil { |
| 99 | + if rvr == http.ErrAbortHandler { |
| 100 | + // We don't recover http.ErrAbortHandler so the response |
| 101 | + // to the client is aborted, this should not be logged |
| 102 | + panic(rvr) |
| 103 | + } |
| 104 | + |
| 105 | + err, ok := rvr.(error) |
| 106 | + if !ok { |
| 107 | + err = fmt.Errorf("%v", rvr) |
| 108 | + } |
| 109 | + |
| 110 | + fields.Error = err |
| 111 | + fields.Stack = debug.Stack() |
| 112 | + |
| 113 | + c.Error(err) |
| 114 | + } |
| 115 | + |
| 116 | + fields.StatusCode = c.Response().Status |
| 117 | + fields.Latency = float64(time.Since(start).Nanoseconds()/1e4) / 100.0 |
| 118 | + |
| 119 | + switch { |
| 120 | + case rvr != nil: |
| 121 | + log.Ctx(ctx).Error().EmbedObject(fields).Msg("panic recover") |
| 122 | + case fields.StatusCode >= 500: |
| 123 | + log.Ctx(ctx).Error().EmbedObject(fields).Msg("server error") |
| 124 | + case fields.StatusCode >= 400: |
| 125 | + log.Ctx(ctx).Error().EmbedObject(fields).Msg("client error") |
| 126 | + case fields.StatusCode >= 300: |
| 127 | + log.Ctx(ctx).Warn().EmbedObject(fields).Msg("redirect") |
| 128 | + case fields.StatusCode >= 200: |
| 129 | + log.Ctx(ctx).Info().EmbedObject(fields).Msg("success") |
| 130 | + case fields.StatusCode >= 100: |
| 131 | + log.Ctx(ctx).Info().EmbedObject(fields).Msg("informative") |
| 132 | + default: |
| 133 | + log.Ctx(ctx).Warn().EmbedObject(fields).Msg("unknown status") |
| 134 | + } |
| 135 | + |
| 136 | + }() |
| 137 | + |
| 138 | + newReq := c.Request().WithContext(ctx) |
| 139 | + c.SetRequest(newReq) |
| 140 | + |
| 141 | + return next(c) |
| 142 | + } |
| 143 | + } |
| 144 | +} |
| 145 | + |
| 146 | +func formatReqBody(data []byte) string { |
| 147 | + var js map[string]interface{} |
| 148 | + if json.Unmarshal(data, &js) != nil { |
| 149 | + return string(data) |
| 150 | + } |
| 151 | + |
| 152 | + result := new(bytes.Buffer) |
| 153 | + if err := json.Compact(result, data); err != nil { |
| 154 | + log.Error().Err(err).Msg("error compacting body request json") |
| 155 | + return "" |
| 156 | + } |
| 157 | + |
| 158 | + return result.String() |
| 159 | +} |
0 commit comments