summaryrefslogtreecommitdiff
path: root/modules/caddyhttp
diff options
context:
space:
mode:
authorMatt Holt <mholt@users.noreply.github.com>2021-02-22 11:57:21 -0700
committerGitHub <noreply@github.com>2021-02-22 11:57:21 -0700
commit6722ae3a835702073682e020d8736140fc04538e (patch)
treebc66fb7a9f1e4a085e2804a89f12722134394ca9 /modules/caddyhttp
parentedb362aa96bd8e79adfaca44fbd9f9ce5bff778d (diff)
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
Diffstat (limited to 'modules/caddyhttp')
-rw-r--r--modules/caddyhttp/app.go1
-rw-r--r--modules/caddyhttp/replacer.go6
-rw-r--r--modules/caddyhttp/reverseproxy/reverseproxy.go22
3 files changed, 23 insertions, 6 deletions
diff --git a/modules/caddyhttp/app.go b/modules/caddyhttp/app.go
index 4f5bc84..8285200 100644
--- a/modules/caddyhttp/app.go
+++ b/modules/caddyhttp/app.go
@@ -49,6 +49,7 @@ func init() {
// ------------|---------------
// `{http.request.body}` | The request body (⚠️ inefficient; use only for debugging)
// `{http.request.cookie.*}` | HTTP request cookie
+// `{http.request.duration}` | Time up to now spent handling the request (after decoding headers from client)
// `{http.request.header.*}` | Specific request header field
// `{http.request.host.labels.*}` | Request host labels (0-based from right); e.g. for foo.example.com: 0=com, 1=example, 2=foo
// `{http.request.host}` | The host part of the request's Host header
diff --git a/modules/caddyhttp/replacer.go b/modules/caddyhttp/replacer.go
index 5a0efce..d0767f0 100644
--- a/modules/caddyhttp/replacer.go
+++ b/modules/caddyhttp/replacer.go
@@ -36,6 +36,7 @@ import (
"path"
"strconv"
"strings"
+ "time"
"github.com/caddyserver/caddy/v2"
"github.com/caddyserver/caddy/v2/modules/caddytls"
@@ -52,6 +53,8 @@ func NewTestReplacer(req *http.Request) *caddy.Replacer {
}
func addHTTPVarsToReplacer(repl *caddy.Replacer, req *http.Request, w http.ResponseWriter) {
+ SetVar(req.Context(), "start_time", time.Now())
+
httpVars := func(key string) (interface{}, bool) {
if req != nil {
// query string parameters
@@ -140,6 +143,9 @@ func addHTTPVarsToReplacer(repl *caddy.Replacer, req *http.Request, w http.Respo
return dir, true
case "http.request.uri.query":
return req.URL.RawQuery, true
+ case "http.request.duration":
+ start := GetVar(req.Context(), "start_time").(time.Time)
+ return time.Since(start), true
case "http.request.body":
if req.Body == nil {
return "", true
diff --git a/modules/caddyhttp/reverseproxy/reverseproxy.go b/modules/caddyhttp/reverseproxy/reverseproxy.go
index 76506ca..d2d01e6 100644
--- a/modules/caddyhttp/reverseproxy/reverseproxy.go
+++ b/modules/caddyhttp/reverseproxy/reverseproxy.go
@@ -43,7 +43,7 @@ func init() {
// Handler implements a highly configurable and production-ready reverse proxy.
//
// Upon proxying, this module sets the following placeholders (which can be used
-// both within and after this handler):
+// both within and after this handler; for example, in response headers):
//
// Placeholder | Description
// ------------|-------------
@@ -54,6 +54,9 @@ func init() {
// `{http.reverse_proxy.upstream.requests}` | The approximate current number of requests to the upstream
// `{http.reverse_proxy.upstream.max_requests}` | The maximum approximate number of requests allowed to the upstream
// `{http.reverse_proxy.upstream.fails}` | The number of recent failed requests to the upstream
+// `{http.reverse_proxy.upstream.latency}` | How long it took the proxy upstream to write the response header.
+// `{http.reverse_proxy.upstream.duration}` | Time spent proxying to the upstream, including writing response body to client.
+// `{http.reverse_proxy.duration}` | Total time spent proxying, including selecting an upstream, retries, and writing response.
type Handler struct {
// Configures the method of transport for the proxy. A transport
// 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
}()
start := time.Now()
+ defer func() {
+ // total proxying duration, including time spent on LB and retries
+ repl.Set("http.reverse_proxy.duration", time.Since(start))
+ }()
var proxyErr error
for {
@@ -419,7 +426,7 @@ func (h *Handler) ServeHTTP(w http.ResponseWriter, r *http.Request, next caddyht
}
// proxy the request to that upstream
- proxyErr = h.reverseProxy(w, r, dialInfo, next)
+ proxyErr = h.reverseProxy(w, r, repl, dialInfo, next)
if proxyErr == nil || proxyErr == context.Canceled {
// context.Canceled happens when the downstream client
// cancels the request, which is not our failure
@@ -522,7 +529,7 @@ func (h Handler) prepareRequest(req *http.Request) error {
// reverseProxy performs a round-trip to the given backend and processes the response with the client.
// (This method is mostly the beginning of what was borrowed from the net/http/httputil package in the
// Go standard library which was used as the foundation.)
-func (h *Handler) reverseProxy(rw http.ResponseWriter, req *http.Request, di DialInfo, next caddyhttp.Handler) error {
+func (h *Handler) reverseProxy(rw http.ResponseWriter, req *http.Request, repl *caddy.Replacer, di DialInfo, next caddyhttp.Handler) error {
_ = di.Upstream.Host.CountRequest(1)
//nolint:errcheck
defer di.Upstream.Host.CountRequest(-1)
@@ -547,6 +554,9 @@ func (h *Handler) reverseProxy(rw http.ResponseWriter, req *http.Request, di Dia
zap.Object("headers", caddyhttp.LoggableHTTPHeader(res.Header)),
zap.Int("status", res.StatusCode))
+ // duration until upstream wrote response headers (roundtrip duration)
+ repl.Set("http.reverse_proxy.upstream.latency", duration)
+
// update circuit breaker on current conditions
if di.Upstream.cb != nil {
di.Upstream.cb.RecordMetric(res.StatusCode, duration)
@@ -579,8 +589,6 @@ func (h *Handler) reverseProxy(rw http.ResponseWriter, req *http.Request, di Dia
continue
}
- repl := req.Context().Value(caddy.ReplacerCtxKey).(*caddy.Replacer)
-
// if configured to only change the status code, do that then continue regular proxy response
if statusCodeStr := rh.StatusCode.String(); statusCodeStr != "" {
statusCode, err := strconv.Atoi(repl.ReplaceAll(statusCodeStr, ""))
@@ -625,7 +633,6 @@ func (h *Handler) reverseProxy(rw http.ResponseWriter, req *http.Request, di Dia
if h.Headers != nil && h.Headers.Response != nil {
if h.Headers.Response.Require == nil ||
h.Headers.Response.Require.Match(res.StatusCode, res.Header) {
- repl := req.Context().Value(caddy.ReplacerCtxKey).(*caddy.Replacer)
h.Headers.Response.ApplyTo(res.Header, repl)
}
}
@@ -673,6 +680,9 @@ func (h *Handler) reverseProxy(rw http.ResponseWriter, req *http.Request, di Dia
}
}
+ // total duration spent proxying, including writing response body
+ repl.Set("http.reverse_proxy.upstream.duration", duration)
+
if len(res.Trailer) == announcedTrailers {
copyHeader(rw.Header(), res.Trailer)
return nil