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
|
|
|
"hash/fnv"
|
|
|
|
"net/http"
|
|
|
|
"strings"
|
|
|
|
time "time"
|
|
|
|
|
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"
|
2022-10-21 16:24:13 +02:00
|
|
|
"go.opentelemetry.io/otel/metric/instrument"
|
|
|
|
"go.opentelemetry.io/otel/metric/instrument/syncint64"
|
|
|
|
)
|
|
|
|
|
|
|
|
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
|
2022-10-22 10:07:13 +02:00
|
|
|
httpRequestCounters map[string]syncint64.Counter
|
2023-05-19 11:42:25 +02:00
|
|
|
// all HTTP responses by endpoint & method & status code
|
2022-10-21 16:24:13 +02:00
|
|
|
httpResponseCounters map[string]syncint64.Counter
|
2022-10-22 10:07:13 +02:00
|
|
|
// all HTTP requests
|
|
|
|
totalHTTPRequestsCounter syncint64.Counter
|
|
|
|
// all HTTP responses
|
|
|
|
totalHTTPResponseCounter syncint64.Counter
|
|
|
|
// all HTTP responses by status code
|
|
|
|
totalHTTPResponseCodeCounters map[int]syncint64.Counter
|
2023-05-19 11:42:25 +02:00
|
|
|
// all HTTP requests durations by endpoint and method
|
|
|
|
httpRequestDurations map[string]syncint64.Histogram
|
|
|
|
// all HTTP requests durations
|
|
|
|
totalHTTPRequestDuration syncint64.Histogram
|
|
|
|
}
|
|
|
|
|
|
|
|
// NewMetricsMiddleware creates a new HTTPMiddleware
|
|
|
|
func NewMetricsMiddleware(ctx context.Context, meter metric.Meter) (*HTTPMiddleware, error) {
|
|
|
|
|
|
|
|
totalHTTPRequestsCounter, err := meter.SyncInt64().Counter(
|
|
|
|
fmt.Sprintf("%s_total", httpRequestCounterPrefix),
|
|
|
|
instrument.WithUnit("1"))
|
|
|
|
if err != nil {
|
|
|
|
return nil, err
|
|
|
|
}
|
|
|
|
totalHTTPResponseCounter, err := meter.SyncInt64().Counter(
|
|
|
|
fmt.Sprintf("%s_total", httpResponseCounterPrefix),
|
|
|
|
instrument.WithUnit("1"))
|
|
|
|
if err != nil {
|
|
|
|
return nil, err
|
|
|
|
}
|
|
|
|
|
|
|
|
totalHTTPRequestDuration, err := meter.SyncInt64().Histogram(
|
|
|
|
fmt.Sprintf("%s_total", httpRequestDurationPrefix),
|
|
|
|
instrument.WithUnit("milliseconds"))
|
|
|
|
|
|
|
|
if err != nil {
|
|
|
|
return nil, err
|
|
|
|
}
|
|
|
|
|
|
|
|
return &HTTPMiddleware{
|
|
|
|
ctx: ctx,
|
|
|
|
httpRequestCounters: map[string]syncint64.Counter{},
|
|
|
|
httpResponseCounters: map[string]syncint64.Counter{},
|
|
|
|
httpRequestDurations: map[string]syncint64.Histogram{},
|
|
|
|
totalHTTPResponseCodeCounters: map[int]syncint64.Counter{},
|
|
|
|
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)
|
2022-10-22 13:29:39 +02:00
|
|
|
httpReqCounter, err := m.meter.SyncInt64().Counter(meterKey, instrument.WithUnit("1"))
|
2022-10-21 16:24:13 +02:00
|
|
|
if err != nil {
|
|
|
|
return err
|
|
|
|
}
|
|
|
|
m.httpRequestCounters[meterKey] = httpReqCounter
|
2023-05-19 11:42:25 +02:00
|
|
|
durationKey := getRequestDurationKey(endpoint, method)
|
|
|
|
requestDuration, err := m.meter.SyncInt64().Histogram(durationKey, instrument.WithUnit("milliseconds"))
|
|
|
|
if err != nil {
|
|
|
|
return err
|
|
|
|
}
|
|
|
|
m.httpRequestDurations[durationKey] = requestDuration
|
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)
|
2022-10-22 13:29:39 +02:00
|
|
|
httpRespCounter, err := m.meter.SyncInt64().Counter(meterKey, instrument.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)
|
2022-10-22 13:29:39 +02:00
|
|
|
totalHTTPResponseCodeCounter, err := m.meter.SyncInt64().Counter(meterKey, instrument.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
|
|
|
|
}
|
|
|
|
|
|
|
|
func getRequestCounterKey(endpoint, method string) string {
|
|
|
|
return fmt.Sprintf("%s%s_%s", httpRequestCounterPrefix,
|
|
|
|
strings.ReplaceAll(endpoint, "/", "_"), method)
|
|
|
|
}
|
|
|
|
|
2023-05-19 11:42:25 +02:00
|
|
|
func getRequestDurationKey(endpoint, method string) string {
|
|
|
|
return fmt.Sprintf("%s%s_%s", httpRequestDurationPrefix,
|
|
|
|
strings.ReplaceAll(endpoint, "/", "_"), method)
|
|
|
|
}
|
|
|
|
|
2022-10-21 16:24:13 +02:00
|
|
|
func getResponseCounterKey(endpoint, method string, status int) string {
|
|
|
|
return fmt.Sprintf("%s%s_%s_%d", httpResponseCounterPrefix,
|
|
|
|
strings.ReplaceAll(endpoint, "/", "_"), method, status)
|
|
|
|
}
|
|
|
|
|
|
|
|
// 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()
|
2022-10-21 16:24:13 +02:00
|
|
|
traceID := hash(fmt.Sprintf("%v", r))
|
|
|
|
log.Tracef("HTTP request %v: %v %v", traceID, r.Method, r.URL)
|
|
|
|
|
|
|
|
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)
|
|
|
|
|
|
|
|
h.ServeHTTP(w, r)
|
|
|
|
|
|
|
|
if w.Status() > 399 {
|
|
|
|
log.Errorf("HTTP response %v: %v %v status %v", traceID, r.Method, r.URL, w.Status())
|
|
|
|
} else {
|
|
|
|
log.Tracef("HTTP response %v: %v %v status %v", traceID, r.Method, r.URL, w.Status())
|
|
|
|
}
|
|
|
|
|
|
|
|
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())
|
|
|
|
}
|
2023-05-22 16:26:36 +02:00
|
|
|
log.Debugf("request %s %s took %d ms and finished with status %d", r.Method, r.URL.Path, reqTook.Milliseconds(), w.Status())
|
|
|
|
|
|
|
|
if w.Status() == 200 && (r.Method == http.MethodPut || r.Method == http.MethodPost || r.Method == http.MethodDelete) {
|
|
|
|
m.totalHTTPRequestDuration.Record(m.ctx, reqTook.Milliseconds(), attribute.String("type", "write"))
|
|
|
|
} else {
|
|
|
|
m.totalHTTPRequestDuration.Record(m.ctx, reqTook.Milliseconds(), attribute.String("type", "read"))
|
|
|
|
}
|
2023-05-19 11:42:25 +02:00
|
|
|
|
2022-10-21 16:24:13 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
return http.HandlerFunc(fn)
|
|
|
|
}
|
|
|
|
|
|
|
|
func hash(s string) uint32 {
|
|
|
|
h := fnv.New32a()
|
|
|
|
_, err := h.Write([]byte(s))
|
|
|
|
if err != nil {
|
|
|
|
panic(err)
|
|
|
|
}
|
|
|
|
return h.Sum32()
|
|
|
|
}
|