-
-
Notifications
You must be signed in to change notification settings - Fork 105
/
middleware.go
179 lines (142 loc) · 4.76 KB
/
middleware.go
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
// Copyright © 2023 Ory Corp
// SPDX-License-Identifier: Apache-2.0
package reqlog
import (
"net/http"
"sync"
"time"
"github.com/sirupsen/logrus"
"github.com/urfave/negroni"
"github.com/ory/x/logrusx"
)
type timer interface {
Now() time.Time
Since(time.Time) time.Duration
}
type realClock struct{}
func (rc *realClock) Now() time.Time {
return time.Now()
}
func (rc *realClock) Since(t time.Time) time.Duration {
return time.Since(t)
}
// Middleware is a middleware handler that logs the request as it goes in and the response as it goes out.
type Middleware struct {
// Logger is the log.Logger instance used to log messages with the Logger middleware
Logger *logrusx.Logger
// Name is the name of the application as recorded in latency metrics
Name string
Before func(*logrusx.Logger, *http.Request, string) *logrusx.Logger
After func(*logrusx.Logger, *http.Request, negroni.ResponseWriter, time.Duration, string) *logrusx.Logger
logStarting bool
clock timer
logLevel logrus.Level
// Silence log for specific URL paths
silencePaths map[string]bool
sync.RWMutex
}
// NewMiddleware returns a new *Middleware, yay!
func NewMiddleware() *Middleware {
return NewCustomMiddleware(logrus.InfoLevel, &logrus.TextFormatter{}, "web")
}
// NewCustomMiddleware builds a *Middleware with the given level and formatter
func NewCustomMiddleware(level logrus.Level, formatter logrus.Formatter, name string) *Middleware {
log := logrusx.New(name, "", logrusx.ForceFormatter(formatter), logrusx.ForceLevel(level))
return &Middleware{
Logger: log,
Name: name,
Before: DefaultBefore,
After: DefaultAfter,
logLevel: logrus.InfoLevel,
logStarting: true,
clock: &realClock{},
silencePaths: map[string]bool{},
}
}
// NewMiddlewareFromLogger returns a new *Middleware which writes to a given logrus logger.
func NewMiddlewareFromLogger(logger *logrusx.Logger, name string) *Middleware {
return &Middleware{
Logger: logger,
Name: name,
Before: DefaultBefore,
After: DefaultAfter,
logLevel: logrus.InfoLevel,
logStarting: true,
clock: &realClock{},
silencePaths: map[string]bool{},
}
}
// SetLogStarting accepts a bool to control the logging of "started handling
// request" prior to passing to the next middleware
func (m *Middleware) SetLogStarting(v bool) {
m.logStarting = v
}
// ExcludePaths adds new URL paths to be ignored during logging. The URL u is parsed, hence the returned error
func (m *Middleware) ExcludePaths(paths ...string) *Middleware {
for _, path := range paths {
m.Lock()
m.silencePaths[path] = true
m.Unlock()
}
return m
}
func (m *Middleware) ServeHTTP(rw http.ResponseWriter, r *http.Request, next http.HandlerFunc) {
if m.Before == nil {
m.Before = DefaultBefore
}
if m.After == nil {
m.After = DefaultAfter
}
logLevel := m.logLevel
m.RLock()
if _, ok := m.silencePaths[r.URL.Path]; ok {
logLevel = logrus.TraceLevel
}
m.RUnlock()
start := m.clock.Now()
// Try to get the real IP
remoteAddr := r.RemoteAddr
if realIP := r.Header.Get("X-Real-IP"); realIP != "" {
remoteAddr = realIP
}
entry := m.Logger.NewEntry()
entry = m.Before(entry, r, remoteAddr)
if m.logStarting {
entry.Log(logLevel, "started handling request")
}
nrw, ok := rw.(negroni.ResponseWriter)
if !ok {
nrw = negroni.NewResponseWriter(rw)
}
r = r.WithContext(WithEnableExternalLatencyMeasurement(r.Context()))
next(nrw, r)
latency := m.clock.Since(start)
m.After(entry, r, nrw, latency, m.Name).Log(logLevel, "completed handling request")
}
// BeforeFunc is the func type used to modify or replace the *logrusx.Logger prior
// to calling the next func in the middleware chain
type BeforeFunc func(*logrusx.Logger, *http.Request, string) *logrusx.Logger
// AfterFunc is the func type used to modify or replace the *logrusx.Logger after
// calling the next func in the middleware chain
type AfterFunc func(*logrusx.Logger, negroni.ResponseWriter, time.Duration, string) *logrusx.Logger
// DefaultBefore is the default func assigned to *Middleware.Before
func DefaultBefore(entry *logrusx.Logger, req *http.Request, remoteAddr string) *logrusx.Logger {
return entry.WithRequest(req)
}
// DefaultAfter is the default func assigned to *Middleware.After
func DefaultAfter(entry *logrusx.Logger, req *http.Request, res negroni.ResponseWriter, latency time.Duration, name string) *logrusx.Logger {
e := entry.WithRequest(req).WithField("http_response", map[string]any{
"status": res.Status(),
"size": res.Size(),
"text_status": http.StatusText(res.Status()),
"took": latency,
"headers": entry.HTTPHeadersRedacted(res.Header()),
})
if el := totalExternalLatency(req.Context()); el > 0 {
e = e.WithFields(map[string]any{
"took_internal": latency - el,
"took_external": el,
})
}
return e
}