/
context.go
200 lines (176 loc) · 6.59 KB
/
context.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
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
package web
import (
"context"
"crypto"
"crypto/ecdsa"
"crypto/rsa"
"encoding/json"
"fmt"
"net"
"net/http"
"strings"
"time"
blog "github.com/letsencrypt/boulder/log"
)
// RequestEvent is a structured record of the metadata we care about for a
// single web request. It is generated when a request is received, passed to
// the request handler which can populate its fields as appropriate, and then
// logged when the request completes.
type RequestEvent struct {
// These fields are not rendered in JSON; instead, they are rendered
// whitespace-separated ahead of the JSON. This saves bytes in the logs since
// we don't have to include field names, quotes, or commas -- all of these
// fields are known to not include whitespace.
Method string `json:"-"`
Endpoint string `json:"-"`
Requester int64 `json:"-"`
Code int `json:"-"`
Latency float64 `json:"-"`
RealIP string `json:"-"`
Slug string `json:",omitempty"`
InternalErrors []string `json:",omitempty"`
Error string `json:",omitempty"`
UserAgent string `json:"ua,omitempty"`
// Origin is sent by the browser from XHR-based clients.
Origin string `json:",omitempty"`
Extra map[string]interface{} `json:",omitempty"`
// For endpoints that create objects, the ID of the newly created object.
Created string `json:",omitempty"`
// For challenge and authorization GETs and POSTs:
// the status of the authorization at the time the request began.
Status string `json:",omitempty"`
// The DNS name, if there is a single relevant name, for instance
// in an authorization or challenge request.
DNSName string `json:",omitempty"`
// The set of DNS names, if there are potentially multiple relevant
// names, for instance in a new-order, finalize, or revoke request.
DNSNames []string `json:",omitempty"`
// For challenge POSTs, the challenge type.
ChallengeType string `json:",omitempty"`
// suppressed controls whether this event will be logged when the request
// completes. If true, no log line will be emitted. Can only be set by
// calling .Suppress(); automatically unset by adding an internal error.
suppressed bool `json:"-"`
}
// AddError formats the given message with the given args and appends it to the
// list of internal errors that have occurred as part of handling this event.
// If the RequestEvent has been suppressed, this un-suppresses it.
func (e *RequestEvent) AddError(msg string, args ...interface{}) {
e.InternalErrors = append(e.InternalErrors, fmt.Sprintf(msg, args...))
e.suppressed = false
}
// Suppress causes the RequestEvent to not be logged at all when the request
// is complete. This is a no-op if an internal error has been added to the event
// (logging errors takes precedence over suppressing output).
func (e *RequestEvent) Suppress() {
if len(e.InternalErrors) == 0 {
e.suppressed = true
}
}
type WFEHandlerFunc func(context.Context, *RequestEvent, http.ResponseWriter, *http.Request)
func (f WFEHandlerFunc) ServeHTTP(e *RequestEvent, w http.ResponseWriter, r *http.Request) {
f(r.Context(), e, w, r)
}
type wfeHandler interface {
ServeHTTP(e *RequestEvent, w http.ResponseWriter, r *http.Request)
}
type TopHandler struct {
wfe wfeHandler
log blog.Logger
}
func NewTopHandler(log blog.Logger, wfe wfeHandler) *TopHandler {
return &TopHandler{
wfe: wfe,
log: log,
}
}
// responseWriterWithStatus satisfies http.ResponseWriter, but keeps track of the
// status code for logging.
type responseWriterWithStatus struct {
http.ResponseWriter
code int
}
// WriteHeader stores a status code for generating stats.
func (r *responseWriterWithStatus) WriteHeader(code int) {
r.code = code
r.ResponseWriter.WriteHeader(code)
}
func (th *TopHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
// Check that this header is well-formed, since we assume it is when logging.
realIP := r.Header.Get("X-Real-IP")
if net.ParseIP(realIP) == nil {
realIP = "0.0.0.0"
}
logEvent := &RequestEvent{
RealIP: realIP,
Method: r.Method,
UserAgent: r.Header.Get("User-Agent"),
Origin: r.Header.Get("Origin"),
Extra: make(map[string]interface{}),
}
// We specifically override the default r.Context() because we would prefer
// for clients to not be able to cancel our operations in arbitrary places.
// Instead we start a new context, and apply timeouts in our various RPCs.
ctx := context.WithoutCancel(r.Context())
r = r.WithContext(ctx)
// Some clients will send a HTTP Host header that includes the default port
// for the scheme that they are using. Previously when we were fronted by
// Akamai they would rewrite the header and strip out the unnecessary port,
// now that they are not in our request path we need to strip these ports out
// ourselves.
//
// The main reason we want to strip these ports out is so that when this header
// is sent to the /directory endpoint we don't reply with directory URLs that
// also contain these ports.
//
// We unconditionally strip :443 even when r.TLS is nil because the WFE2
// may be deployed HTTP-only behind another service that terminates HTTPS on
// its behalf.
r.Host = strings.TrimSuffix(r.Host, ":443")
r.Host = strings.TrimSuffix(r.Host, ":80")
begin := time.Now()
rwws := &responseWriterWithStatus{w, 0}
defer func() {
logEvent.Code = rwws.code
if logEvent.Code == 0 {
// If we haven't explicitly set a status code golang will set it
// to 200 itself when writing to the wire
logEvent.Code = http.StatusOK
}
logEvent.Latency = time.Since(begin).Seconds()
th.logEvent(logEvent)
}()
th.wfe.ServeHTTP(logEvent, rwws, r)
}
func (th *TopHandler) logEvent(logEvent *RequestEvent) {
if logEvent.suppressed {
return
}
var msg string
jsonEvent, err := json.Marshal(logEvent)
if err != nil {
th.log.AuditErrf("failed to marshal logEvent - %s - %#v", msg, err)
return
}
th.log.Infof("%s %s %d %d %d %s JSON=%s",
logEvent.Method, logEvent.Endpoint, logEvent.Requester, logEvent.Code,
int(logEvent.Latency*1000), logEvent.RealIP, jsonEvent)
}
// GetClientAddr returns a comma-separated list of HTTP clients involved in
// making this request, starting with the original requester and ending with the
// remote end of our TCP connection (which is typically our own proxy).
func GetClientAddr(r *http.Request) string {
if xff := r.Header.Get("X-Forwarded-For"); xff != "" {
return xff + "," + r.RemoteAddr
}
return r.RemoteAddr
}
func KeyTypeToString(pub crypto.PublicKey) string {
switch pk := pub.(type) {
case *rsa.PublicKey:
return fmt.Sprintf("RSA %d", pk.N.BitLen())
case *ecdsa.PublicKey:
return fmt.Sprintf("ECDSA %s", pk.Params().Name)
}
return "unknown"
}