diff --git a/README.md b/README.md index ab3d835..dc61ef2 100644 --- a/README.md +++ b/README.md @@ -849,6 +849,8 @@ The proxy exposes Prometheus metrics at `GET /metrics`. All metric names are pre | Metric | Type | Labels | Description | |--------|------|--------|-------------| +| `proxy_requests_total` | counter | `ecosystem`, `status` | Proxy responses by package ecosystem and HTTP status | +| `proxy_request_duration_seconds` | histogram | `ecosystem`, `status` | Proxy request duration | | `proxy_cache_hits_total` | counter | `ecosystem` | Cache hits | | `proxy_cache_misses_total` | counter | `ecosystem` | Cache misses | | `proxy_cache_size_bytes` | gauge | | Total size of cached artifacts | diff --git a/internal/server/middleware.go b/internal/server/middleware.go index 4332718..52f9b91 100644 --- a/internal/server/middleware.go +++ b/internal/server/middleware.go @@ -3,10 +3,12 @@ package server import ( "context" "net/http" + "strings" "sync/atomic" "time" "github.com/git-pkgs/proxy/internal/accesslog" + "github.com/git-pkgs/proxy/internal/metrics" "github.com/go-chi/chi/v5/middleware" ) @@ -42,15 +44,20 @@ func (s *Server) LoggerMiddleware(next http.Handler) http.Handler { rw := &responseWriter{ResponseWriter: w, status: http.StatusOK} next.ServeHTTP(rw, r) + duration := time.Since(start) s.logger.Info("request", "request_id", requestID, "method", r.Method, "path", r.URL.Path, "status", rw.status, - "duration", time.Since(start), + "duration", duration, "remote", r.RemoteAddr) + if r.URL.Path != "/metrics" { + metrics.RecordRequest(requestEcosystem(r.URL.Path), rw.status, duration) + } + if s.accessLog != nil { if err := s.accessLog.Write(accesslog.Entry{ Event: accesslog.EventRequest, @@ -58,7 +65,7 @@ func (s *Server) LoggerMiddleware(next http.Handler) http.Handler { Method: r.Method, Path: r.URL.EscapedPath(), StatusCode: rw.status, - DurationMS: time.Since(start).Milliseconds(), + DurationMS: duration.Milliseconds(), RemoteAddr: r.RemoteAddr, }); err != nil { s.logger.Error("failed to write access log", "error", err) @@ -67,6 +74,25 @@ func (s *Server) LoggerMiddleware(next http.Handler) http.Handler { }) } +func requestEcosystem(path string) string { + segment, _, _ := strings.Cut(strings.TrimPrefix(path, "/"), "/") + switch segment { + case "npm", "cargo", "hex", "pub", "pypi", "maven", "gradle", "nuget", + "conan", "conda", "cran", "julia", "debian", "rpm": + return segment + case "gem": + return "rubygems" + case "go": + return "golang" + case "composer": + return "packagist" + case "v2": + return "oci" + default: + return "other" + } +} + // ActiveRequestsMiddleware tracks the number of active requests using Prometheus metrics. func ActiveRequestsMiddleware(next http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { diff --git a/internal/server/middleware_test.go b/internal/server/middleware_test.go index 1923461..eb81881 100644 --- a/internal/server/middleware_test.go +++ b/internal/server/middleware_test.go @@ -12,7 +12,11 @@ import ( "testing" "github.com/git-pkgs/proxy/internal/accesslog" + "github.com/git-pkgs/proxy/internal/metrics" "github.com/go-chi/chi/v5/middleware" + "github.com/prometheus/client_golang/prometheus" + "github.com/prometheus/client_golang/prometheus/testutil" + dto "github.com/prometheus/client_model/go" ) func TestRequestIDMiddleware(t *testing.T) { @@ -125,6 +129,89 @@ func TestLoggerMiddleware(t *testing.T) { } } +func TestLoggerMiddlewareRecordsRequestMetrics(t *testing.T) { + before := testutil.ToFloat64(metrics.RequestsTotal.WithLabelValues("rubygems", "404")) + durationMetric := metrics.RequestDuration.WithLabelValues("rubygems", "404") + beforeDurationCount := histogramSampleCount(t, durationMetric) + + logger := slog.New(slog.NewTextHandler(io.Discard, nil)) + s := &Server{logger: logger} + handler := s.LoggerMiddleware(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) { + w.WriteHeader(http.StatusNotFound) + })) + + req := httptest.NewRequest(http.MethodGet, "/gem/downloads/missing.gem", nil) + rec := httptest.NewRecorder() + handler.ServeHTTP(rec, req) + + after := testutil.ToFloat64(metrics.RequestsTotal.WithLabelValues("rubygems", "404")) + if got := after - before; got != 1 { + t.Errorf("request counter delta = %.0f, want 1", got) + } + afterDurationCount := histogramSampleCount(t, durationMetric) + if got := afterDurationCount - beforeDurationCount; got != 1 { + t.Errorf("request duration sample delta = %d, want 1", got) + } +} + +func histogramSampleCount(t *testing.T, observer prometheus.Observer) uint64 { + t.Helper() + + metric, ok := observer.(prometheus.Metric) + if !ok { + t.Fatal("histogram observer does not implement prometheus.Metric") + } + + var value dto.Metric + if err := metric.Write(&value); err != nil { + t.Fatalf("writing histogram metric: %v", err) + } + return value.GetHistogram().GetSampleCount() +} + +func TestLoggerMiddlewareSkipsMetricsEndpointMetrics(t *testing.T) { + before := testutil.ToFloat64(metrics.RequestsTotal.WithLabelValues("other", "200")) + + logger := slog.New(slog.NewTextHandler(io.Discard, nil)) + s := &Server{logger: logger} + handler := s.LoggerMiddleware(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) { + w.WriteHeader(http.StatusOK) + })) + + req := httptest.NewRequest(http.MethodGet, "/metrics", nil) + rec := httptest.NewRecorder() + handler.ServeHTTP(rec, req) + + after := testutil.ToFloat64(metrics.RequestsTotal.WithLabelValues("other", "200")) + if got := after - before; got != 0 { + t.Errorf("request counter delta = %.0f, want 0", got) + } +} + +func TestRequestEcosystem(t *testing.T) { + tests := []struct { + path string + want string + }{ + {path: "/npm/lodash", want: "npm"}, + {path: "/gem/downloads/rails.gem", want: "rubygems"}, + {path: "/go/example.com/module/@v/list", want: "golang"}, + {path: "/composer/vendor/package", want: "packagist"}, + {path: "/v2/library/alpine/manifests/latest", want: "oci"}, + {path: "/ui/", want: "other"}, + {path: "/api/package/npm/lodash", want: "other"}, + {path: "/", want: "other"}, + } + + for _, tt := range tests { + t.Run(tt.path, func(t *testing.T) { + if got := requestEcosystem(tt.path); got != tt.want { + t.Errorf("requestEcosystem(%q) = %q, want %q", tt.path, got, tt.want) + } + }) + } +} + func TestLoggerMiddlewareWritesAccessLog(t *testing.T) { path := filepath.Join(t.TempDir(), "access.jsonl") activityLog, err := accesslog.Open(path)