2022-10-22 13:29:39 +02:00
|
|
|
package telemetry
|
2022-10-21 16:24:13 +02:00
|
|
|
|
|
|
|
import (
|
|
|
|
"context"
|
|
|
|
"fmt"
|
2023-05-19 11:42:25 +02:00
|
|
|
"net/http"
|
|
|
|
"strings"
|
2024-05-27 08:39:18 +02:00
|
|
|
"time"
|
2023-05-19 11:42:25 +02:00
|
|
|
|
2024-07-03 11:33:02 +02:00
|
|
|
"github.com/google/uuid"
|
2022-10-21 16:24:13 +02:00
|
|
|
log "github.com/sirupsen/logrus"
|
2023-05-19 16:56:15 +02:00
|
|
|
"go.opentelemetry.io/otel/attribute"
|
2022-10-22 13:29:39 +02:00
|
|
|
"go.opentelemetry.io/otel/metric"
|
2024-07-03 11:33:02 +02:00
|
|
|
|
|
|
|
"github.com/netbirdio/netbird/formatter"
|
|
|
|
nbContext "github.com/netbirdio/netbird/management/server/context"
|
2022-10-21 16:24:13 +02:00
|
|
|
)
|
|
|
|
|
|
|
|
const (
|
|
|
|
httpRequestCounterPrefix = "management.http.request.counter"
|
|
|
|
httpResponseCounterPrefix = "management.http.response.counter"
|
2023-05-19 11:42:25 +02:00
|
|
|
httpRequestDurationPrefix = "management.http.request.duration.ms"
|
2022-10-21 16:24:13 +02:00
|
|
|
)
|
|
|
|
|
|
|
|
// WrappedResponseWriter is a wrapper for http.ResponseWriter that allows the
|
|
|
|
// written HTTP status code to be captured for metrics reporting or logging purposes.
|
|
|
|
type WrappedResponseWriter struct {
|
|
|
|
http.ResponseWriter
|
|
|
|
status int
|
|
|
|
wroteHeader bool
|
|
|
|
}
|
|
|
|
|
|
|
|
// WrapResponseWriter wraps original http.ResponseWriter
|
|
|
|
func WrapResponseWriter(w http.ResponseWriter) *WrappedResponseWriter {
|
|
|
|
return &WrappedResponseWriter{ResponseWriter: w}
|
|
|
|
}
|
|
|
|
|
|
|
|
// Status returns response status
|
|
|
|
func (rw *WrappedResponseWriter) Status() int {
|
|
|
|
return rw.status
|
|
|
|
}
|
|
|
|
|
|
|
|
// WriteHeader wraps http.ResponseWriter.WriteHeader method
|
|
|
|
func (rw *WrappedResponseWriter) WriteHeader(code int) {
|
|
|
|
if rw.wroteHeader {
|
|
|
|
return
|
|
|
|
}
|
|
|
|
|
|
|
|
rw.status = code
|
|
|
|
rw.ResponseWriter.WriteHeader(code)
|
|
|
|
rw.wroteHeader = true
|
|
|
|
}
|
|
|
|
|
2022-10-22 11:50:21 +02:00
|
|
|
// HTTPMiddleware handler used to collect metrics of every request/response coming to the API.
|
2022-10-21 16:24:13 +02:00
|
|
|
// Also adds request tracing (logging).
|
2022-10-22 11:50:21 +02:00
|
|
|
type HTTPMiddleware struct {
|
2022-10-22 13:29:39 +02:00
|
|
|
meter metric.Meter
|
|
|
|
ctx context.Context
|
2023-05-19 11:42:25 +02:00
|
|
|
// all HTTP requests by endpoint & method
|
2024-05-27 08:39:18 +02:00
|
|
|
httpRequestCounters map[string]metric.Int64Counter
|
2023-05-19 11:42:25 +02:00
|
|
|
// all HTTP responses by endpoint & method & status code
|
2024-05-27 08:39:18 +02:00
|
|
|
httpResponseCounters map[string]metric.Int64Counter
|
2022-10-22 10:07:13 +02:00
|
|
|
// all HTTP requests
|
2024-05-27 08:39:18 +02:00
|
|
|
totalHTTPRequestsCounter metric.Int64Counter
|
2022-10-22 10:07:13 +02:00
|
|
|
// all HTTP responses
|
2024-05-27 08:39:18 +02:00
|
|
|
totalHTTPResponseCounter metric.Int64Counter
|
2022-10-22 10:07:13 +02:00
|
|
|
// all HTTP responses by status code
|
2024-05-27 08:39:18 +02:00
|
|
|
totalHTTPResponseCodeCounters map[int]metric.Int64Counter
|
2023-05-19 11:42:25 +02:00
|
|
|
// all HTTP requests durations by endpoint and method
|
2024-05-27 08:39:18 +02:00
|
|
|
httpRequestDurations map[string]metric.Int64Histogram
|
2023-05-19 11:42:25 +02:00
|
|
|
// all HTTP requests durations
|
2024-05-27 08:39:18 +02:00
|
|
|
totalHTTPRequestDuration metric.Int64Histogram
|
2023-05-19 11:42:25 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
// NewMetricsMiddleware creates a new HTTPMiddleware
|
|
|
|
func NewMetricsMiddleware(ctx context.Context, meter metric.Meter) (*HTTPMiddleware, error) {
|
2024-05-27 08:39:18 +02:00
|
|
|
totalHTTPRequestsCounter, err := meter.Int64Counter(fmt.Sprintf("%s_total", httpRequestCounterPrefix), metric.WithUnit("1"))
|
2023-05-19 11:42:25 +02:00
|
|
|
if err != nil {
|
|
|
|
return nil, err
|
|
|
|
}
|
2024-05-27 08:39:18 +02:00
|
|
|
|
|
|
|
totalHTTPResponseCounter, err := meter.Int64Counter(fmt.Sprintf("%s_total", httpResponseCounterPrefix), metric.WithUnit("1"))
|
2023-05-19 11:42:25 +02:00
|
|
|
if err != nil {
|
|
|
|
return nil, err
|
|
|
|
}
|
|
|
|
|
2024-05-27 08:39:18 +02:00
|
|
|
totalHTTPRequestDuration, err := meter.Int64Histogram(fmt.Sprintf("%s_total", httpRequestDurationPrefix), metric.WithUnit("milliseconds"))
|
2023-05-19 11:42:25 +02:00
|
|
|
if err != nil {
|
|
|
|
return nil, err
|
|
|
|
}
|
|
|
|
|
|
|
|
return &HTTPMiddleware{
|
|
|
|
ctx: ctx,
|
2024-05-27 08:39:18 +02:00
|
|
|
httpRequestCounters: map[string]metric.Int64Counter{},
|
|
|
|
httpResponseCounters: map[string]metric.Int64Counter{},
|
|
|
|
httpRequestDurations: map[string]metric.Int64Histogram{},
|
|
|
|
totalHTTPResponseCodeCounters: map[int]metric.Int64Counter{},
|
2023-05-19 11:42:25 +02:00
|
|
|
meter: meter,
|
|
|
|
totalHTTPRequestsCounter: totalHTTPRequestsCounter,
|
|
|
|
totalHTTPResponseCounter: totalHTTPResponseCounter,
|
|
|
|
totalHTTPRequestDuration: totalHTTPRequestDuration,
|
|
|
|
},
|
|
|
|
nil
|
2022-10-21 16:24:13 +02:00
|
|
|
}
|
|
|
|
|
2022-10-22 11:50:21 +02:00
|
|
|
// AddHTTPRequestResponseCounter adds a new meter for an HTTP defaultEndpoint and Method (GET, POST, etc)
|
2022-10-21 16:24:13 +02:00
|
|
|
// Creates one request counter and multiple response counters (one per http response status code).
|
2022-10-22 11:50:21 +02:00
|
|
|
func (m *HTTPMiddleware) AddHTTPRequestResponseCounter(endpoint string, method string) error {
|
2022-10-21 16:24:13 +02:00
|
|
|
meterKey := getRequestCounterKey(endpoint, method)
|
2024-05-27 08:39:18 +02:00
|
|
|
httpReqCounter, err := m.meter.Int64Counter(meterKey, metric.WithUnit("1"))
|
2022-10-21 16:24:13 +02:00
|
|
|
if err != nil {
|
|
|
|
return err
|
|
|
|
}
|
|
|
|
m.httpRequestCounters[meterKey] = httpReqCounter
|
2024-05-27 08:39:18 +02:00
|
|
|
|
2023-05-19 11:42:25 +02:00
|
|
|
durationKey := getRequestDurationKey(endpoint, method)
|
2024-05-27 08:39:18 +02:00
|
|
|
requestDuration, err := m.meter.Int64Histogram(durationKey, metric.WithUnit("milliseconds"))
|
2023-05-19 11:42:25 +02:00
|
|
|
if err != nil {
|
|
|
|
return err
|
|
|
|
}
|
|
|
|
m.httpRequestDurations[durationKey] = requestDuration
|
2024-05-27 08:39:18 +02:00
|
|
|
|
2022-10-22 10:07:13 +02:00
|
|
|
respCodes := []int{200, 204, 400, 401, 403, 404, 500, 502, 503}
|
2022-10-21 16:24:13 +02:00
|
|
|
for _, code := range respCodes {
|
|
|
|
meterKey = getResponseCounterKey(endpoint, method, code)
|
2024-05-27 08:39:18 +02:00
|
|
|
httpRespCounter, err := m.meter.Int64Counter(meterKey, metric.WithUnit("1"))
|
2022-10-21 16:24:13 +02:00
|
|
|
if err != nil {
|
|
|
|
return err
|
|
|
|
}
|
|
|
|
m.httpResponseCounters[meterKey] = httpRespCounter
|
2022-10-22 10:07:13 +02:00
|
|
|
|
|
|
|
meterKey = fmt.Sprintf("%s_%d_total", httpResponseCounterPrefix, code)
|
2024-05-27 08:39:18 +02:00
|
|
|
totalHTTPResponseCodeCounter, err := m.meter.Int64Counter(meterKey, metric.WithUnit("1"))
|
2022-10-22 10:07:13 +02:00
|
|
|
if err != nil {
|
|
|
|
return err
|
|
|
|
}
|
|
|
|
m.totalHTTPResponseCodeCounters[code] = totalHTTPResponseCodeCounter
|
2022-10-21 16:24:13 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
return nil
|
|
|
|
}
|
|
|
|
|
2024-05-27 08:39:18 +02:00
|
|
|
func replaceEndpointChars(endpoint string) string {
|
|
|
|
endpoint = strings.ReplaceAll(endpoint, "/", "_")
|
|
|
|
endpoint = strings.ReplaceAll(endpoint, "{", "")
|
|
|
|
endpoint = strings.ReplaceAll(endpoint, "}", "")
|
|
|
|
return endpoint
|
|
|
|
}
|
|
|
|
|
2022-10-21 16:24:13 +02:00
|
|
|
func getRequestCounterKey(endpoint, method string) string {
|
2024-05-27 08:39:18 +02:00
|
|
|
endpoint = replaceEndpointChars(endpoint)
|
|
|
|
return fmt.Sprintf("%s%s_%s", httpRequestCounterPrefix, endpoint, method)
|
2022-10-21 16:24:13 +02:00
|
|
|
}
|
|
|
|
|
2023-05-19 11:42:25 +02:00
|
|
|
func getRequestDurationKey(endpoint, method string) string {
|
2024-05-27 08:39:18 +02:00
|
|
|
endpoint = replaceEndpointChars(endpoint)
|
|
|
|
return fmt.Sprintf("%s%s_%s", httpRequestDurationPrefix, endpoint, method)
|
2023-05-19 11:42:25 +02:00
|
|
|
}
|
|
|
|
|
2022-10-21 16:24:13 +02:00
|
|
|
func getResponseCounterKey(endpoint, method string, status int) string {
|
2024-05-27 08:39:18 +02:00
|
|
|
endpoint = replaceEndpointChars(endpoint)
|
|
|
|
return fmt.Sprintf("%s%s_%s_%d", httpResponseCounterPrefix, endpoint, method, status)
|
2022-10-21 16:24:13 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
// Handler logs every request and response and adds the, to metrics.
|
2022-10-22 11:50:21 +02:00
|
|
|
func (m *HTTPMiddleware) Handler(h http.Handler) http.Handler {
|
2022-10-21 16:24:13 +02:00
|
|
|
fn := func(rw http.ResponseWriter, r *http.Request) {
|
2023-05-19 11:42:25 +02:00
|
|
|
reqStart := time.Now()
|
2024-07-03 11:33:02 +02:00
|
|
|
|
|
|
|
//nolint
|
|
|
|
ctx := context.WithValue(r.Context(), formatter.ExecutionContextKey, formatter.HTTPSource)
|
|
|
|
|
|
|
|
reqID := uuid.New().String()
|
|
|
|
//nolint
|
|
|
|
ctx = context.WithValue(ctx, nbContext.RequestIDKey, reqID)
|
|
|
|
|
|
|
|
log.WithContext(ctx).Tracef("HTTP request %v: %v %v", reqID, r.Method, r.URL)
|
2022-10-21 16:24:13 +02:00
|
|
|
|
|
|
|
metricKey := getRequestCounterKey(r.URL.Path, r.Method)
|
|
|
|
|
|
|
|
if c, ok := m.httpRequestCounters[metricKey]; ok {
|
|
|
|
c.Add(m.ctx, 1)
|
|
|
|
}
|
2022-10-22 10:07:13 +02:00
|
|
|
m.totalHTTPRequestsCounter.Add(m.ctx, 1)
|
2022-10-21 16:24:13 +02:00
|
|
|
|
|
|
|
w := WrapResponseWriter(rw)
|
|
|
|
|
2024-07-03 11:33:02 +02:00
|
|
|
h.ServeHTTP(w, r.WithContext(ctx))
|
2022-10-21 16:24:13 +02:00
|
|
|
|
|
|
|
if w.Status() > 399 {
|
2024-07-03 11:33:02 +02:00
|
|
|
log.WithContext(ctx).Errorf("HTTP response %v: %v %v status %v", reqID, r.Method, r.URL, w.Status())
|
2022-10-21 16:24:13 +02:00
|
|
|
} else {
|
2024-07-03 11:33:02 +02:00
|
|
|
log.WithContext(ctx).Tracef("HTTP response %v: %v %v status %v", reqID, r.Method, r.URL, w.Status())
|
2022-10-21 16:24:13 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
metricKey = getResponseCounterKey(r.URL.Path, r.Method, w.Status())
|
|
|
|
if c, ok := m.httpResponseCounters[metricKey]; ok {
|
|
|
|
c.Add(m.ctx, 1)
|
|
|
|
}
|
2022-10-22 10:07:13 +02:00
|
|
|
|
|
|
|
m.totalHTTPResponseCounter.Add(m.ctx, 1)
|
|
|
|
if c, ok := m.totalHTTPResponseCodeCounters[w.Status()]; ok {
|
|
|
|
c.Add(m.ctx, 1)
|
|
|
|
}
|
2023-05-19 11:42:25 +02:00
|
|
|
|
|
|
|
durationKey := getRequestDurationKey(r.URL.Path, r.Method)
|
|
|
|
reqTook := time.Since(reqStart)
|
|
|
|
if c, ok := m.httpRequestDurations[durationKey]; ok {
|
|
|
|
c.Record(m.ctx, reqTook.Milliseconds())
|
|
|
|
}
|
2024-07-03 11:33:02 +02:00
|
|
|
log.WithContext(ctx).Debugf("request %s %s took %d ms and finished with status %d", r.Method, r.URL.Path, reqTook.Milliseconds(), w.Status())
|
2023-05-22 16:26:36 +02:00
|
|
|
|
|
|
|
if w.Status() == 200 && (r.Method == http.MethodPut || r.Method == http.MethodPost || r.Method == http.MethodDelete) {
|
2024-05-27 08:39:18 +02:00
|
|
|
opts := metric.WithAttributeSet(attribute.NewSet(attribute.String("type", "write")))
|
|
|
|
m.totalHTTPRequestDuration.Record(m.ctx, reqTook.Milliseconds(), opts)
|
2023-05-22 16:26:36 +02:00
|
|
|
} else {
|
2024-05-27 08:39:18 +02:00
|
|
|
opts := metric.WithAttributeSet(attribute.NewSet(attribute.String("type", "read")))
|
|
|
|
m.totalHTTPRequestDuration.Record(m.ctx, reqTook.Milliseconds(), opts)
|
2023-05-22 16:26:36 +02:00
|
|
|
}
|
2023-05-19 11:42:25 +02:00
|
|
|
|
2022-10-21 16:24:13 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
return http.HandlerFunc(fn)
|
|
|
|
}
|