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
reverseproxy: Add duration/latency placeholders (close #4012) (#4013)
* reverseproxy: Add duration/latency placeholders (close #4012) (and #2268) Adds 4 placeholders, one is actually outside reverse proxy though: {http.request.duration} is how long since the server decoded the HTTP request (headers). {http.reverse_proxy.upstream.latency} is how long it took a proxy upstream to write the response header. {http.reverse_proxy.upstream.duration} is total time proxying to the upstream, including writing response body to client. {http.reverse_proxy.duration} is total time spent proxying, including selecting an upstream and retries. Obviously, most of these are only useful at the end of a request, like when writing response headers or logs. See also: https://caddy.community/t/any-equivalent-of-request-time-and-upstream-header-time-from-nginx/11418 * Add new placeholders to documentation
Matt Holt committed
Feb 22, 2021 at 11:57 UTC
6722ae3a835702073682e020d8736140fc04538e
3 files changed
+23
-6
modules/caddyhttp/app.go
+1
@@ -49,6 +49,7 @@ func init() {
49
// ------------|---------------
50
// `{http.request.body}` | The request body (⚠️ inefficient; use only for debugging)
51
// `{http.request.cookie.*}` | HTTP request cookie
52
+// `{http.request.duration}` | Time up to now spent handling the request (after decoding headers from client)
53
// `{http.request.header.*}` | Specific request header field
54
// `{http.request.host.labels.*}` | Request host labels (0-based from right); e.g. for foo.example.com: 0=com, 1=example, 2=foo
55
// `{http.request.host}` | The host part of the request's Host header
modules/caddyhttp/replacer.go
+6
@@ -36,6 +36,7 @@ import (
36
"path"
37
"strconv"
38
"strings"
39
+ "time"
40
41
"github.com/caddyserver/caddy/v2"
42
"github.com/caddyserver/caddy/v2/modules/caddytls"
@@ -52,6 +53,8 @@ func NewTestReplacer(req *http.Request) *caddy.Replacer {
53
}
54
55
func addHTTPVarsToReplacer(repl *caddy.Replacer, req *http.Request, w http.ResponseWriter) {
56
+ SetVar(req.Context(), "start_time", time.Now())
57
+
58
httpVars := func(key string) (interface{}, bool) {
59
if req != nil {
60
// query string parameters
@@ -140,6 +143,9 @@ func addHTTPVarsToReplacer(repl *caddy.Replacer, req *http.Request, w http.Respo
143
return dir, true
144
case "http.request.uri.query":
145
return req.URL.RawQuery, true
146
+ case "http.request.duration":
147
+ start := GetVar(req.Context(), "start_time").(time.Time)
148
+ return time.Since(start), true
149
case "http.request.body":
150
if req.Body == nil {
151
return "", true
modules/caddyhttp/reverseproxy/reverseproxy.go
+16
-6
@@ -43,7 +43,7 @@ func init() {
43
// Handler implements a highly configurable and production-ready reverse proxy.
44
//
45
// Upon proxying, this module sets the following placeholders (which can be used
46
-// both within and after this handler):
46
+// both within and after this handler; for example, in response headers):
47
//
48
// Placeholder | Description
49
// ------------|-------------
@@ -54,6 +54,9 @@ func init() {
54
// `{http.reverse_proxy.upstream.requests}` | The approximate current number of requests to the upstream
55
// `{http.reverse_proxy.upstream.max_requests}` | The maximum approximate number of requests allowed to the upstream
56
// `{http.reverse_proxy.upstream.fails}` | The number of recent failed requests to the upstream
57
+// `{http.reverse_proxy.upstream.latency}` | How long it took the proxy upstream to write the response header.
58
+// `{http.reverse_proxy.upstream.duration}` | Time spent proxying to the upstream, including writing response body to client.
59
+// `{http.reverse_proxy.duration}` | Total time spent proxying, including selecting an upstream, retries, and writing response.
60
type Handler struct {
61
// Configures the method of transport for the proxy. A transport
62
// is what performs the actual "round trip" to the backend.
@@ -370,6 +373,10 @@ func (h *Handler) ServeHTTP(w http.ResponseWriter, r *http.Request, next caddyht
373
}()
374
375
start := time.Now()
376
+ defer func() {
377
+ // total proxying duration, including time spent on LB and retries
378
+ repl.Set("http.reverse_proxy.duration", time.Since(start))
379
+ }()
380
381
var proxyErr error
382
for {
@@ -419,7 +426,7 @@ func (h *Handler) ServeHTTP(w http.ResponseWriter, r *http.Request, next caddyht
426
}
427
428
// proxy the request to that upstream
422
- proxyErr = h.reverseProxy(w, r, dialInfo, next)
429
+ proxyErr = h.reverseProxy(w, r, repl, dialInfo, next)
430
if proxyErr == nil || proxyErr == context.Canceled {
431
// context.Canceled happens when the downstream client
432
// cancels the request, which is not our failure
@@ -522,7 +529,7 @@ func (h Handler) prepareRequest(req *http.Request) error {
529
// reverseProxy performs a round-trip to the given backend and processes the response with the client.
530
// (This method is mostly the beginning of what was borrowed from the net/http/httputil package in the
531
// Go standard library which was used as the foundation.)
525
-func (h *Handler) reverseProxy(rw http.ResponseWriter, req *http.Request, di DialInfo, next caddyhttp.Handler) error {
532
+func (h *Handler) reverseProxy(rw http.ResponseWriter, req *http.Request, repl *caddy.Replacer, di DialInfo, next caddyhttp.Handler) error {
533
_ = di.Upstream.Host.CountRequest(1)
534
//nolint:errcheck
535
defer di.Upstream.Host.CountRequest(-1)
@@ -547,6 +554,9 @@ func (h *Handler) reverseProxy(rw http.ResponseWriter, req *http.Request, di Dia
554
zap.Object("headers", caddyhttp.LoggableHTTPHeader(res.Header)),
555
zap.Int("status", res.StatusCode))
556
557
+ // duration until upstream wrote response headers (roundtrip duration)
558
+ repl.Set("http.reverse_proxy.upstream.latency", duration)
559
+
560
// update circuit breaker on current conditions
561
if di.Upstream.cb != nil {
562
di.Upstream.cb.RecordMetric(res.StatusCode, duration)
@@ -579,8 +589,6 @@ func (h *Handler) reverseProxy(rw http.ResponseWriter, req *http.Request, di Dia
589
continue
590
}
591
582
- repl := req.Context().Value(caddy.ReplacerCtxKey).(*caddy.Replacer)
583
-
592
// if configured to only change the status code, do that then continue regular proxy response
593
if statusCodeStr := rh.StatusCode.String(); statusCodeStr != "" {
594
statusCode, err := strconv.Atoi(repl.ReplaceAll(statusCodeStr, ""))
@@ -625,7 +633,6 @@ func (h *Handler) reverseProxy(rw http.ResponseWriter, req *http.Request, di Dia
633
if h.Headers != nil && h.Headers.Response != nil {
634
if h.Headers.Response.Require == nil ||
635
h.Headers.Response.Require.Match(res.StatusCode, res.Header) {
628
- repl := req.Context().Value(caddy.ReplacerCtxKey).(*caddy.Replacer)
636
h.Headers.Response.ApplyTo(res.Header, repl)
637
}
638
}
@@ -673,6 +680,9 @@ func (h *Handler) reverseProxy(rw http.ResponseWriter, req *http.Request, di Dia
680
}
681
}
682
683
+ // total duration spent proxying, including writing response body
684
+ repl.Set("http.reverse_proxy.upstream.duration", duration)
685
+
686
if len(res.Trailer) == announcedTrailers {
687
copyHeader(rw.Header(), res.Trailer)
688
return nil