Fast and extensible multi-platform HTTP/1-2-3 web server with automatic HTTPS
Mirrored from https://github.com/Slazee/caddy.git
Synced Nov 14, 05:15 UTC
reverse_proxy: Structured logs
Matthew Holt committed
Oct 29, 2019 at 16:02 UTC
dccba71276796999f3e16a6560016dc5dd0a952a
2 files changed
+58
-19
modules/caddyhttp/reverseproxy/healthchecks.go
+45
-14
@@ -19,7 +19,6 @@ import (
19
"fmt"
20
"io"
21
"io/ioutil"
22
- "log"
22
"net"
23
"net/http"
24
"net/url"
@@ -29,6 +28,7 @@ import (
28
29
"github.com/caddyserver/caddy/v2"
30
"github.com/caddyserver/caddy/v2/modules/caddyhttp"
31
+ "go.uber.org/zap"
32
)
33
34
// HealthChecks holds configuration related to health checking.
@@ -53,6 +53,7 @@ type ActiveHealthChecks struct {
53
stopChan chan struct{}
54
httpClient *http.Client
55
bodyRegexp *regexp.Regexp
56
+ logger *zap.Logger
57
}
58
59
// PassiveHealthChecks holds configuration related to passive
@@ -64,6 +65,8 @@ type PassiveHealthChecks struct {
65
UnhealthyRequestCount int `json:"unhealthy_request_count,omitempty"`
66
UnhealthyStatus []int `json:"unhealthy_status,omitempty"`
67
UnhealthyLatency caddy.Duration `json:"unhealthy_latency,omitempty"`
68
+
69
+ logger *zap.Logger
70
}
71
72
// CircuitBreaker is a type that can act as an early-warning
@@ -101,11 +104,16 @@ func (h *Handler) doActiveHealthChecksForAllHosts() {
104
go func(networkAddr string, host Host) {
105
network, addrs, err := caddy.ParseNetworkAddress(networkAddr)
106
if err != nil {
104
- log.Printf("[ERROR] reverse_proxy: active health check for host %s: bad network address: %v", networkAddr, err)
107
+ h.HealthChecks.Active.logger.Error("bad network address",
108
+ zap.String("address", networkAddr),
109
+ zap.Error(err),
110
+ )
111
return
112
}
113
if len(addrs) != 1 {
108
- log.Printf("[ERROR] reverse_proxy: active health check for host %s: multiple addresses (upstream must map to only one address)", networkAddr)
114
+ h.HealthChecks.Active.logger.Error("multiple addresses (upstream must map to only one address)",
115
+ zap.String("address", networkAddr),
116
+ )
117
return
118
}
119
hostAddr := addrs[0]
@@ -117,7 +125,10 @@ func (h *Handler) doActiveHealthChecksForAllHosts() {
125
}
126
err = h.doActiveHealthCheck(DialInfo{Network: network, Address: addrs[0]}, hostAddr, host)
127
if err != nil {
120
- log.Printf("[ERROR] reverse_proxy: active health check for host %s: %v", networkAddr, err)
128
+ h.HealthChecks.Active.logger.Error("active health check failed",
129
+ zap.String("address", networkAddr),
130
+ zap.Error(err),
131
+ )
132
}
133
}(networkAddr, host)
134
@@ -171,7 +182,10 @@ func (h *Handler) doActiveHealthCheck(dialInfo DialInfo, hostAddr string, host H
182
// do the request, being careful to tame the response body
183
resp, err := h.HealthChecks.Active.httpClient.Do(req)
184
if err != nil {
174
- log.Printf("[INFO] reverse_proxy: active health check: %s is down (HTTP request failed: %v)", hostAddr, err)
185
+ h.HealthChecks.Active.logger.Info("HTTP request failed",
186
+ zap.String("host", hostAddr),
187
+ zap.Error(err),
188
+ )
189
_, err2 := host.SetHealthy(false)
190
if err2 != nil {
191
return fmt.Errorf("marking unhealthy: %v", err2)
@@ -191,7 +205,10 @@ func (h *Handler) doActiveHealthCheck(dialInfo DialInfo, hostAddr string, host H
205
// if status code is outside criteria, mark down
206
if h.HealthChecks.Active.ExpectStatus > 0 {
207
if !caddyhttp.StatusCodeMatches(resp.StatusCode, h.HealthChecks.Active.ExpectStatus) {
194
- log.Printf("[INFO] reverse_proxy: active health check: %s is down (status code %d unexpected)", hostAddr, resp.StatusCode)
208
+ h.HealthChecks.Active.logger.Info("unexpected status code",
209
+ zap.Int("status_code", resp.StatusCode),
210
+ zap.String("host", hostAddr),
211
+ )
212
_, err := host.SetHealthy(false)
213
if err != nil {
214
return fmt.Errorf("marking unhealthy: %v", err)
@@ -199,7 +216,10 @@ func (h *Handler) doActiveHealthCheck(dialInfo DialInfo, hostAddr string, host H
216
return nil
217
}
218
} else if resp.StatusCode < 200 || resp.StatusCode >= 400 {
202
- log.Printf("[INFO] reverse_proxy: active health check: %s is down (status code %d out of tolerances)", hostAddr, resp.StatusCode)
219
+ h.HealthChecks.Active.logger.Info("status code out of tolerances",
220
+ zap.Int("status_code", resp.StatusCode),
221
+ zap.String("host", hostAddr),
222
+ )
223
_, err := host.SetHealthy(false)
224
if err != nil {
225
return fmt.Errorf("marking unhealthy: %v", err)
@@ -211,7 +231,10 @@ func (h *Handler) doActiveHealthCheck(dialInfo DialInfo, hostAddr string, host H
231
if h.HealthChecks.Active.bodyRegexp != nil {
232
bodyBytes, err := ioutil.ReadAll(body)
233
if err != nil {
214
- log.Printf("[INFO] reverse_proxy: active health check: %s is down (failed to read response body)", hostAddr)
234
+ h.HealthChecks.Active.logger.Info("failed to read response body",
235
+ zap.String("host", hostAddr),
236
+ zap.Error(err),
237
+ )
238
_, err := host.SetHealthy(false)
239
if err != nil {
240
return fmt.Errorf("marking unhealthy: %v", err)
@@ -219,7 +242,9 @@ func (h *Handler) doActiveHealthCheck(dialInfo DialInfo, hostAddr string, host H
242
return nil
243
}
244
if !h.HealthChecks.Active.bodyRegexp.Match(bodyBytes) {
222
- log.Printf("[INFO] reverse_proxy: active health check: %s is down (response body failed expectations)", hostAddr)
245
+ h.HealthChecks.Active.logger.Info("response body failed expectations",
246
+ zap.String("host", hostAddr),
247
+ )
248
_, err := host.SetHealthy(false)
249
if err != nil {
250
return fmt.Errorf("marking unhealthy: %v", err)
@@ -231,7 +256,9 @@ func (h *Handler) doActiveHealthCheck(dialInfo DialInfo, hostAddr string, host H
256
// passed health check parameters, so mark as healthy
257
swapped, err := host.SetHealthy(true)
258
if swapped {
234
- log.Printf("[INFO] reverse_proxy: active health check: %s is back up", hostAddr)
259
+ h.HealthChecks.Active.logger.Info("host is up",
260
+ zap.String("host", hostAddr),
261
+ )
262
}
263
if err != nil {
264
return fmt.Errorf("marking healthy: %v", err)
@@ -258,8 +285,10 @@ func (h *Handler) countFailure(upstream *Upstream) {
285
// count failure immediately
286
err := upstream.Host.CountFail(1)
287
if err != nil {
261
- log.Printf("[ERROR] proxy: upstream %s: counting failure: %v",
262
- upstream.Dial, err)
288
+ h.HealthChecks.Passive.logger.Error("could not count failure",
289
+ zap.String("host", upstream.Dial),
290
+ zap.Error(err),
291
+ )
292
}
293
294
// forget it later
@@ -267,8 +296,10 @@ func (h *Handler) countFailure(upstream *Upstream) {
296
time.Sleep(failDuration)
297
err := host.CountFail(-1)
298
if err != nil {
270
- log.Printf("[ERROR] proxy: upstream %s: expiring failure: %v",
271
- upstream.Dial, err)
299
+ h.HealthChecks.Passive.logger.Error("could not forget failure",
300
+ zap.String("host", upstream.Dial),
301
+ zap.Error(err),
302
+ )
303
}
304
}(upstream.Host, failDuration)
305
}
modules/caddyhttp/reverseproxy/reverseproxy.go
+13
-5
@@ -28,6 +28,7 @@ import (
28
"github.com/caddyserver/caddy/v2"
29
"github.com/caddyserver/caddy/v2/modules/caddyhttp"
30
"github.com/caddyserver/caddy/v2/modules/caddyhttp/headers"
31
+ "go.uber.org/zap"
32
"golang.org/x/net/http/httpguts"
33
)
34
@@ -47,6 +48,8 @@ type Handler struct {
48
49
Transport http.RoundTripper `json:"-"`
50
CB CircuitBreaker `json:"-"`
51
+
52
+ logger *zap.Logger
53
}
54
55
// CaddyModule returns the Caddy module information.
@@ -59,6 +62,8 @@ func (Handler) CaddyModule() caddy.ModuleInfo {
62
63
// Provision ensures that h is set up properly before use.
64
func (h *Handler) Provision(ctx caddy.Context) error {
65
+ h.logger = ctx.Logger(h)
66
+
67
// start by loading modules
68
if h.TransportRaw != nil {
69
val, err := ctx.LoadModuleInline("protocol", "http.handlers.reverse_proxy.transport", h.TransportRaw)
@@ -129,6 +134,8 @@ func (h *Handler) Provision(ctx caddy.Context) error {
134
if h.HealthChecks != nil &&
135
h.HealthChecks.Active != nil &&
136
(h.HealthChecks.Active.Path != "" || h.HealthChecks.Active.Port != 0) {
137
+ h.HealthChecks.Active.logger = h.logger.Named("health_checker.active")
138
+
139
timeout := time.Duration(h.HealthChecks.Active.Timeout)
140
if timeout == 0 {
141
timeout = 10 * time.Second
@@ -174,11 +181,12 @@ func (h *Handler) Provision(ctx caddy.Context) error {
181
// without MaxRequests), copy the value into this upstream, since the
182
// value in the upstream (MaxRequests) is what is used during
183
// availability checks
177
- if h.HealthChecks != nil &&
178
- h.HealthChecks.Passive != nil &&
179
- h.HealthChecks.Passive.UnhealthyRequestCount > 0 &&
180
- upstream.MaxRequests == 0 {
181
- upstream.MaxRequests = h.HealthChecks.Passive.UnhealthyRequestCount
184
+ if h.HealthChecks != nil && h.HealthChecks.Passive != nil {
185
+ h.HealthChecks.Passive.logger = h.logger.Named("health_checker.passive")
186
+ if h.HealthChecks.Passive.UnhealthyRequestCount > 0 &&
187
+ upstream.MaxRequests == 0 {
188
+ upstream.MaxRequests = h.HealthChecks.Passive.UnhealthyRequestCount
189
+ }
190
}
191
192
// upstreams need independent access to the passive