satellite/console/consoleweb: Trace HTTP endpoints

Trace all the requests that the HTTP API endpoints receive.

We want to trace them with Monkit because we want to break them down by
request type and response code for seeing if they succeeded or failed.

Also log them with DEBUG level with the IP client.

Change-Id: Ia7b013351c788f131e775818f27091f3014ea861
This commit is contained in:
Ivan Fraixedes 2022-06-30 19:44:17 +02:00 committed by Storj Robot
parent d571b04ac8
commit 7aaab3c4c4
3 changed files with 512 additions and 0 deletions

View File

@ -26,6 +26,7 @@ import (
"github.com/spacemonkeygo/monkit/v3"
"github.com/zeebo/errs"
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
"golang.org/x/sync/errgroup"
"storj.io/common/errs2"
@ -238,6 +239,9 @@ func NewServer(logger *zap.Logger, config Config, service *console.Service, oidc
}
router := mux.NewRouter()
// N.B. This middleware has to be the first one because it has to be called
// the earliest in the HTTP chain.
router.Use(newTraceRequestMiddleware(logger, router))
if server.config.GeneratedAPIEnabled {
consoleapi.NewProjectManagement(logger, server.service, router, &apiAuth{&server})
@ -956,3 +960,100 @@ func NewUserIDRateLimiter(config web.RateLimiterConfig) *web.RateLimiter {
return user.ID.String(), nil
})
}
// responseWriterStatusCode is a wrapper of an http.ResponseWriter to track the
// response status code for having access to it after calling
// http.ResponseWriter.WriteHeader.
type responseWriterStatusCode struct {
http.ResponseWriter
code int
}
func (w *responseWriterStatusCode) WriteHeader(code int) {
w.code = code
w.ResponseWriter.WriteHeader(code)
}
// newTraceRequestMiddleware returns middleware for tracing each request to a
// registered endpoint through Monkit.
//
// It also log in DEBUG level each request.
func newTraceRequestMiddleware(log *zap.Logger, root *mux.Router) mux.MiddlewareFunc {
log = log.Named("trace-request-middleware")
return func(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
begin := time.Now()
ctx := r.Context()
respWCode := responseWriterStatusCode{ResponseWriter: w, code: 0}
defer func() {
// Preallocate the maximum fields that we are going to use for avoiding
// reallocations
fields := make([]zapcore.Field, 0, 6)
fields = append(fields,
zap.String("method", r.Method),
zap.String("URI", r.RequestURI),
zap.String("IP", getClientIP(r)),
zap.Int("response-code", respWCode.code),
zap.Duration("elapse", time.Since(begin)),
)
span := monkit.SpanFromCtx(ctx)
if span != nil {
fields = append(fields, zap.Int64("trace-id", span.Trace().Id()))
}
log.Debug("client HTTP request", fields...)
}()
match := mux.RouteMatch{}
root.Match(r, &match)
pathTpl, err := match.Route.GetPathTemplate()
if err != nil {
log.Warn("error when getting the route template path",
zap.Error(err), zap.String("request-uri", r.RequestURI),
)
next.ServeHTTP(&respWCode, r)
return
}
// Limit the values accepted as an HTTP method for avoiding to create an
// unbounded amount of metrics.
boundMethod := r.Method
switch r.Method {
case http.MethodDelete:
case http.MethodGet:
case http.MethodHead:
case http.MethodOptions:
case http.MethodPatch:
case http.MethodPost:
case http.MethodPut:
default:
boundMethod = "INVALID"
}
stop := mon.TaskNamed(pathTpl, monkit.NewSeriesTag("method", boundMethod))(&ctx)
r = r.WithContext(ctx)
defer func() {
var err error
if respWCode.code >= http.StatusBadRequest {
err = fmt.Errorf("%d", respWCode.code)
}
stop(&err)
// Count the status codes returned by each endpoint.
mon.Event(pathTpl,
monkit.NewSeriesTag("method", boundMethod),
monkit.NewSeriesTag("code", strconv.Itoa(respWCode.code)),
)
}()
// Count the requests to each endpoint.
mon.Event(pathTpl, monkit.NewSeriesTag("method", boundMethod))
next.ServeHTTP(&respWCode, r)
})
}
}

View File

@ -5,9 +5,12 @@ package consoleweb
import (
"encoding/json"
"fmt"
"io/ioutil"
"mime"
"net/http"
"regexp"
"strings"
"github.com/zeebo/errs"
@ -65,3 +68,107 @@ func queryPOST(w http.ResponseWriter, req *http.Request) (query graphqlJSON, err
return query, errs.New("can't parse request body of type %s", typ)
}
}
// getClientIPRegExp is used by the function getClientIP.
var getClientIPRegExp = regexp.MustCompile(`(?i:(?:^|;)for=([^,; ]+))`)
// getClientIP gets the IP of the proxy (that's the value of the field
// r.RemoteAddr) and the client from the first exiting header in this order:
// 'Forwarded', 'X-Forwarded-For', or 'X-Real-Ip'.
// It returns a string of the format "{{proxy ip}} ({{client ip}})" or if there
// isn't any of those headers then it returns "{{client ip}}" where "client ip"
// is the value of the field r.RemoteAddr.
//
// The 'for' field of the 'Forwarded' may contain the IP with a port, as defined
// in the RFC 7239. When the header contains the IP with a port, the port is
// striped, so only the IP is returned.
//
// NOTE: it doesn't check that the IP value get from wherever source is a well
// formatted IP v4 nor v6; an invalid formatted IP will return an undefined
// result.
func getClientIP(r *http.Request) string {
requestIPs := func(clientIP string) string {
return fmt.Sprintf("%s (%s)", r.RemoteAddr, clientIP)
}
h := r.Header.Get("Forwarded")
if h != "" {
// Get the first value of the 'for' identifier present in the header because
// its the one that contains the client IP.
// see: https://datatracker.ietf.org/doc/html/rfc7230
matches := getClientIPRegExp.FindStringSubmatch(h)
if len(matches) > 1 {
ip := strings.Trim(matches[1], `"`)
ip = stripPort(ip)
if ip[0] == '[' {
ip = ip[1 : len(ip)-1]
}
return requestIPs(ip)
}
}
h = r.Header.Get("X-Forwarded-For")
if h != "" {
// Get the first the value IP because it's the client IP.
// Header sysntax: X-Forwarded-For: <client>, <proxy1>, <proxy2>
// See https://developer.mozilla.org/en-US/docs/Web/HTTP/Headers/X-Forwarded-For
ips := strings.SplitN(h, ",", 2)
if len(ips) > 0 {
return requestIPs(ips[0])
}
}
h = r.Header.Get("X-Real-Ip")
if h != "" {
// Get the value of the header because its value is just the client IP.
// This header is mostly sent by NGINX.
// See https://www.nginx.com/resources/wiki/start/topics/examples/forwarded/
return requestIPs(h)
}
return r.RemoteAddr
}
// stripPort strips the port from addr when it has it and return the host
// part. A host can be a hostname or an IP v4 or an IP v6.
//
// NOTE: this function expects a well-formatted address. When it's hostname or
// IP v4, the port at the end and separated with a colon, nor hostname or IP can
// have colons; when it's a IP v6 with port the IP part is enclosed with square
// brackets (.i.e []) and the port separated with a colon, otherwise the IP
// isn't enclosed by square brackets.
// An invalid addr produce an unspecified value.
func stripPort(addr string) string {
// Ensure to strip the port out if r.RemoteAddr has it.
// We don't use net.SplitHostPort because the function returns an error if the
// address doesn't contain the port and the returned host is an empty string,
// besides it doesn't return an error that can be distinguished from others
// unless that the error message is compared, which is discouraging.
if addr == "" {
return ""
}
// It's an IP v6 with port.
if addr[0] == '[' {
idx := strings.LastIndex(addr, ":")
if idx <= 1 {
return addr
}
return addr[1 : idx-1]
}
// It's a IP v4 with port.
if strings.Count(addr, ":") == 1 {
idx := strings.LastIndex(addr, ":")
if idx < 0 {
return addr
}
return addr[0:idx]
}
// It's a IP v4 or v6 without port.
return addr
}

View File

@ -0,0 +1,304 @@
// Copyright (C) 2022 Storj Labs, Inc.
// See LICENSE for copying information.
package consoleweb
import (
"net/http"
"testing"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)
func TestGetClientIP(t *testing.T) {
testCases := []struct {
desc string
r *http.Request
ip string
}{
{
desc: "'Forwarded' single 'for'",
r: &http.Request{
RemoteAddr: "10.5.2.23",
Header: map[string][]string{"Forwarded": {"for=172.17.5.10"}},
},
ip: "10.5.2.23 (172.17.5.10)",
},
{
desc: "'Forwarded' multiple 'for'",
r: &http.Request{
RemoteAddr: "192.168.5.2",
Header: map[string][]string{
"Forwarded": {"for=172.31.254.250,for=172.17.5.10"},
},
},
ip: "192.168.5.2 (172.31.254.250)",
},
{
desc: "'Forwarded' multiple 'for' with space after comma",
r: &http.Request{
RemoteAddr: "10.5.2.23",
Header: map[string][]string{
"Forwarded": {"for=192.168.5.250, for=172.17.5.10"},
},
},
ip: "10.5.2.23 (192.168.5.250)",
},
{
desc: "'Forwarded' multiple 'for' with other pairs",
r: &http.Request{
RemoteAddr: "172.20.20.20",
Header: map[string][]string{
"Forwarded": {
"by=storj;for=172.31.254.15,for=172.17.5.10;host=example.test;proto=https",
"for=172.28.15.15",
},
},
},
ip: "172.20.20.20 (172.31.254.15)",
},
{
desc: "'Forwarded' single capitalized 'For'",
r: &http.Request{
RemoteAddr: "10.5.2.23",
Header: map[string][]string{"Forwarded": {"For=172.17.5.10"}},
},
ip: "10.5.2.23 (172.17.5.10)",
},
{
desc: "'Forwarded' multiple capitalized 'For'",
r: &http.Request{
RemoteAddr: "192.168.5.2",
Header: map[string][]string{
"Forwarded": {"For=172.31.254.250,For=172.17.5.10"},
},
},
ip: "192.168.5.2 (172.31.254.250)",
},
{
desc: "'Forwarded' multiple uppercase 'For' with space after comma",
r: &http.Request{
RemoteAddr: "10.5.2.23",
Header: map[string][]string{
"Forwarded": {"FOR=192.168.5.250, For=172.17.5.10"},
},
},
ip: "10.5.2.23 (192.168.5.250)",
},
{
desc: "'Forwarded' multiple capitalized 'For' with other pairs",
r: &http.Request{
RemoteAddr: "172.20.20.20",
Header: map[string][]string{
"Forwarded": {
"by=storj;For=172.31.254.15,for=172.17.5.10;host=example.test;proto=https",
"For=172.28.15.15",
},
},
},
ip: "172.20.20.20 (172.31.254.15)",
},
{
desc: "'Forwarded' 'for' IPv4 with port",
r: &http.Request{
RemoteAddr: "172.20.20.20",
Header: map[string][]string{
"Forwarded": {
`by=storj;for="172.31.254.15:9089",for=172.17.5.10;host=example.test;proto=https`,
"for=172.28.15.15",
},
},
},
ip: "172.20.20.20 (172.31.254.15)",
},
{
desc: "'Forwarded' 'for' IPv6",
r: &http.Request{
RemoteAddr: "172.20.20.20",
Header: map[string][]string{
"Forwarded": {
`by=storj;for="6934:9e20:e075:a5f6:c8d2:21d1:124d:94b7",for=172.17.5.10;host=example.test;proto=https`,
"for=172.28.15.15",
},
},
},
ip: "172.20.20.20 (6934:9e20:e075:a5f6:c8d2:21d1:124d:94b7)",
},
{
desc: "'Forwarded' 'for' IPv6 with port",
r: &http.Request{
RemoteAddr: "172.20.20.20",
Header: map[string][]string{
"Forwarded": {
`by=storj;for="[6934:9e20:e075:a5f6:c8d2:21d1:124d:94b7]:7896",for=172.17.5.10;host=example.test;proto=https`,
"for=172.28.15.15",
},
},
},
ip: "172.20.20.20 (6934:9e20:e075:a5f6:c8d2:21d1:124d:94b7)",
},
{
desc: "'Forwarded' with a extension whose field name has 'for' postfix",
r: &http.Request{
RemoteAddr: "172.20.20.20",
Header: map[string][]string{
"Forwarded": {
"by=storj;xfor=172.31.254.15;for=172.17.5.10,for=172.17.5.12;host=example.test;proto=https",
"For=172.28.15.15",
},
},
},
ip: "172.20.20.20 (172.17.5.10)",
},
{
desc: "'X-Forwarded-For' single IP",
r: &http.Request{
RemoteAddr: "192.168.50.2",
Header: map[string][]string{"X-Forwarded-For": {"172.31.254.80"}},
},
ip: "192.168.50.2 (172.31.254.80)",
},
{
desc: "'X-Forwarded-For' multiple IPs",
r: &http.Request{
RemoteAddr: "192.168.50.2",
Header: map[string][]string{
"X-Forwarded-For": {"172.28.254.80, 192.168.80.25"},
},
},
ip: "192.168.50.2 (172.28.254.80)",
},
{
desc: "'X-Real-Ip'",
r: &http.Request{
RemoteAddr: "192.168.50.2",
Header: map[string][]string{"X-Real-Ip": {"172.31.254.85"}},
},
ip: "192.168.50.2 (172.31.254.85)",
},
{
desc: "multiple headers",
r: &http.Request{
RemoteAddr: "10.5.2.23",
Header: map[string][]string{
"X-Forwarded-For": {"172.28.254.80, 192.168.80.25"},
"Forwarded": {"for=192.168.5.250, for=172.17.5.10"},
"X-Real-Ip": {"172.31.254.85"},
},
},
ip: "10.5.2.23 (192.168.5.250)",
},
{
desc: "no headers",
r: &http.Request{
RemoteAddr: "192.168.50.60",
},
ip: "192.168.50.60",
},
}
for _, tC := range testCases {
tC := tC
t.Run(tC.desc, func(t *testing.T) {
ip := getClientIP(tC.r)
assert.Equal(t, tC.ip, ip)
})
}
}
func TestStripPort(t *testing.T) {
testCases := []struct {
desc string
addr string
exp string
}{
{
desc: "hostname no port",
addr: "storj.test",
exp: "storj.test",
},
{
desc: "hostname port",
addr: "storj.test:1234",
exp: "storj.test",
},
{
desc: "hostname invalid",
addr: "storj:test:123:",
exp: "storj:test:123:",
},
{
desc: "IPv4 no port",
addr: "192.168.1.78",
exp: "192.168.1.78",
},
{
desc: "IPv4 port",
addr: "192.168.7.69:7888",
exp: "192.168.7.69",
},
{
desc: "IPv4 invalid",
addr: "1985:5849.15.15:8080:",
exp: "1985:5849.15.15:8080:",
},
{
desc: "IPv6 no port",
addr: "6934:9e20:e075:a5f6:c8d2:21d1:124d:94b7",
exp: "6934:9e20:e075:a5f6:c8d2:21d1:124d:94b7",
},
{
desc: "IPv6 port",
addr: "[6934:9e20:e075:a5f6:c8d2:21d1:124d:94b7]:9898",
exp: "6934:9e20:e075:a5f6:c8d2:21d1:124d:94b7",
},
{
desc: "IPv6 invalid not closing bracket",
addr: "[6934:9e20:e075:a5f6:c8d2:21d1:124d:94b7:9898",
exp: "6934:9e20:e075:a5f6:c8d2:21d1:124d:94b",
},
{
desc: "IPv6 invalid port without brackets",
addr: "6934:9e20:e075:a5f6:c8d2:21d1:124d:94b7:9898",
exp: "6934:9e20:e075:a5f6:c8d2:21d1:124d:94b7:9898",
},
{
desc: "IPv6 invalid brackets no port",
addr: "[6934:9e20:e075:a5f6:c8d2:21d1:124d:94b7]",
exp: "6934:9e20:e075:a5f6:c8d2:21d1:124",
},
{
desc: "empty address",
addr: "",
exp: "",
},
{
desc: "invalid address bracket",
addr: "[",
exp: "[",
},
{
desc: "invalid address bracket-colon",
addr: "[:",
exp: "[:",
},
{
desc: "invalid address brackets",
addr: "[]",
exp: "[]",
},
{
desc: "invalid address colon",
addr: ":",
exp: "",
},
}
for _, tC := range testCases {
t.Run(tC.desc, func(t *testing.T) {
host := stripPort(tC.addr)
require.Equal(t, tC.exp, host)
})
}
}