Record proxy request metrics

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 |

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,23 +44,28 @@ 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,
 				RequestID:  requestID,
 				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) {

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)