// Package obs is the dependency free observability layer: structured JSON logging, an access log plus // metrics middleware, and a minimal Prometheus text /metrics endpoint. It deliberately pulls no metrics // library so the FIPS binary stays lean; a richer stack can be added at deploy time behind the same // endpoint. It records the chi request id on every line so a log entry and a metric ties back to one // request, and it NEVER logs a query string, a header, or a body, so no secret or PII reaches the logs. package obs import ( "fmt" "log/slog" "net/http" "os" "sort" "strconv" "sync" "sync/atomic" "time" "github.com/go-chi/chi/v5" "github.com/go-chi/chi/v5/middleware" ) // Setup installs a JSON slog logger as the process default at the given level (info unless debug is // set). Returns the logger so the caller can also use it directly. func Setup(debug bool) *slog.Logger { level := slog.LevelInfo if debug { level = slog.LevelDebug } h := slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{Level: level}) l := slog.New(h) slog.SetDefault(l) return l } // histogram buckets in seconds, the conventional Prometheus default ladder. var durBuckets = []float64{0.005, 0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1, 2.5, 5, 10} // Registry holds the in process HTTP metrics. All counters are atomic so the hot path is lock free. type Registry struct { total [6]atomic.Int64 // index 0 = other, 1..5 = 1xx..5xx bucketHits []atomic.Int64 // cumulative le buckets, plus one overflow slot durSum atomic.Uint64 // sum of durations in microseconds (integer, avoids float races) durCount atomic.Int64 inFlight atomic.Int64 // poolStats, when set, contributes gauge lines (for example pgxpool acquired/idle/total conns). poolStats func() map[string]float64 poolMu sync.RWMutex } // NewRegistry builds a metrics registry. func NewRegistry() *Registry { return &Registry{bucketHits: make([]atomic.Int64, len(durBuckets)+1)} } // SetPoolStats registers a callback that returns named gauge values (for example database pool stats). func (r *Registry) SetPoolStats(f func() map[string]float64) { r.poolMu.Lock() r.poolStats = f r.poolMu.Unlock() } func (r *Registry) observe(status int, d time.Duration) { class := status / 100 if class < 1 || class > 5 { class = 0 } r.total[class].Add(1) secs := d.Seconds() for i, b := range durBuckets { if secs <= b { r.bucketHits[i].Add(1) } } r.bucketHits[len(durBuckets)].Add(1) // +Inf r.durSum.Add(uint64(d.Microseconds())) r.durCount.Add(1) } // statusRecorder captures the response status and byte count without buffering the body. type statusRecorder struct { http.ResponseWriter status int bytes int } func (s *statusRecorder) WriteHeader(code int) { s.status = code s.ResponseWriter.WriteHeader(code) } func (s *statusRecorder) Write(b []byte) (int, error) { if s.status == 0 { s.status = http.StatusOK } n, err := s.ResponseWriter.Write(b) s.bytes += n return n, err } // Middleware times each request, records the metrics, and emits one structured access log line. It logs // the method, the route PATTERN (never the raw path or query string, so ids and secrets stay out of the // logs), the status, the latency, the bytes, and the chi request id. A 5xx logs at error level. func (r *Registry) Middleware(next http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) { r.inFlight.Add(1) defer r.inFlight.Add(-1) start := time.Now() rec := &statusRecorder{ResponseWriter: w} next.ServeHTTP(rec, req) dur := time.Since(start) if rec.status == 0 { rec.status = http.StatusOK } r.observe(rec.status, dur) pattern := routePattern(req) attrs := []any{ slog.String("request_id", middleware.GetReqID(req.Context())), slog.String("method", req.Method), slog.String("route", pattern), slog.Int("status", rec.status), slog.Int64("latency_ms", dur.Milliseconds()), slog.Int("bytes", rec.bytes), } switch { case rec.status >= 500: slog.Error("request", attrs...) case rec.status >= 400: slog.Warn("request", attrs...) default: slog.Info("request", attrs...) } }) } // routePattern returns the matched chi route pattern (for example /api/candidates/{candidateID}), so the // access log and the metrics never carry the concrete id segment. chi populates the RouteContext during // matching, so by the time the wrapped handler returns the pattern is set. Falls back to a constant when // the route did not match, to avoid an unbounded label set on 404s. func routePattern(req *http.Request) string { if rc := chi.RouteContext(req.Context()); rc != nil { if p := rc.RoutePattern(); p != "" { return p } } return "unmatched" } // Handler writes the metrics in Prometheus text exposition format. func (r *Registry) Handler() http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) { w.Header().Set("Content-Type", "text/plain; version=0.0.4") bw := w fmt.Fprintln(bw, "# HELP mm_http_requests_total Total HTTP requests by status class.") fmt.Fprintln(bw, "# TYPE mm_http_requests_total counter") classes := map[int]string{1: "1xx", 2: "2xx", 3: "3xx", 4: "4xx", 5: "5xx", 0: "other"} for class, label := range classes { fmt.Fprintf(bw, "mm_http_requests_total{class=%q} %d\n", label, r.total[class].Load()) } fmt.Fprintln(bw, "# HELP mm_http_request_duration_seconds HTTP request latency.") fmt.Fprintln(bw, "# TYPE mm_http_request_duration_seconds histogram") for i, b := range durBuckets { fmt.Fprintf(bw, "mm_http_request_duration_seconds_bucket{le=%q} %d\n", strconv.FormatFloat(b, 'g', -1, 64), r.bucketHits[i].Load()) } fmt.Fprintf(bw, "mm_http_request_duration_seconds_bucket{le=\"+Inf\"} %d\n", r.bucketHits[len(durBuckets)].Load()) fmt.Fprintf(bw, "mm_http_request_duration_seconds_sum %s\n", strconv.FormatFloat(float64(r.durSum.Load())/1e6, 'g', -1, 64)) fmt.Fprintf(bw, "mm_http_request_duration_seconds_count %d\n", r.durCount.Load()) fmt.Fprintln(bw, "# HELP mm_http_in_flight_requests In flight HTTP requests.") fmt.Fprintln(bw, "# TYPE mm_http_in_flight_requests gauge") fmt.Fprintf(bw, "mm_http_in_flight_requests %d\n", r.inFlight.Load()) r.poolMu.RLock() f := r.poolStats r.poolMu.RUnlock() if f != nil { stats := f() names := make([]string, 0, len(stats)) for k := range stats { names = append(names, k) } sort.Strings(names) fmt.Fprintln(bw, "# HELP mm_db_pool Database pool gauges.") fmt.Fprintln(bw, "# TYPE mm_db_pool gauge") for _, name := range names { fmt.Fprintf(bw, "mm_db_pool{stat=%q} %s\n", name, strconv.FormatFloat(stats[name], 'g', -1, 64)) } } }) }