Observability

Field	Value
Type	Skill Resource
Source	~/.copilot/skills/backend/references/observability.md
Description	Not specified

Source Content

Observability

Wired from the first commit, not a later milestone (ADR-023). The first handler ships with logs, traces, and metrics already correlated — so the moment something breaks, the request is queryable end to end.

Contents

• Middleware order
• Zap with OTel trace correlation
• Wide events (ADR-023)
• OpenTelemetry tracing
• Prometheus RED metrics
• pprof on a gated internal port

Middleware order

The order is load-bearing — it determines which middleware sees which context.

recover  ->  otel  ->  zap  ->  metrics  ->  auth  ->  routes

• recover outermost so a panic anywhere below is caught and turned into a 500.
• otel next so a span exists before anything logs — the logger reads trace_id from it.
• zap after otel so every log line carries the trace correlation.
• metrics records duration/status for everything that reaches a route.
• auth last before routes so unauthenticated requests are still traced, logged, and counted.

Zap with OTel trace correlation

Every log entry carries trace_id and span_id pulled from the active span. This is what links a log line to its trace in Grafana (Loki ↔ Tempo).

import (
  "context"

  "go.opentelemetry.io/otel/trace"
  "go.uber.org/zap"
)

// FromContext returns a logger annotated with the current trace and span IDs.
func FromContext(ctx context.Context, base *zap.Logger) *zap.Logger {
  sc := trace.SpanContextFromContext(ctx)
  if !sc.IsValid() {
    return base
  }
  return base.With(
    zap.String("trace_id", sc.TraceID().String()),
    zap.String("span_id", sc.SpanID().String()),
  )
}

Construct the base logger once as production JSON:

func NewLogger(env, service, version string) (*zap.Logger, error) {
  cfg := zap.NewProductionConfig() // JSON encoder, ISO8601 timestamps
  logger, err := cfg.Build()
  if err != nil {
    return nil, fmt.Errorf("build zap logger: %w", err)
  }
  return logger.With(
    zap.String("service", service),
    zap.String("version", version),
    zap.String("env", env),
  ), nil
}

STANDARDS.md and golang-fiber-bootstrapper standardize on Zap for Go services. ADR-023’s wide-events discipline (one wide line per operation, static msg, dynamic values in fields) applies to whichever logger the service uses — Zap here.

Wide events (ADR-023)

• One log line per meaningful operation, with all context attached to that single wide event.
• msg is static and grep-stable: log.Info("request completed", ...), never "request completed for user 123". Dynamic values go in fields.
• event is dot-namespaced: zap.String("event", "billing.payment_failed").
• Never log the never-log list — PII, secrets, payloads over 2 KB. The canonical list lives in ADR-025 (the adr skill); do not restate it.
• Stack traces go in a data.stack field, never sprinkled across top-level fields.

log := observability.FromContext(ctx, base)
log.Info("invoice finalized",
  zap.String("event", "billing.invoice_finalized"),
  zap.String("invoice_id", string(inv.ID)),
  zap.Int64("total_cents", inv.TotalCents),
)

OpenTelemetry tracing

Use the otelfiber middleware so every HTTP request opens a root span, and propagate the context downward so service and repository spans nest under it — one unbroken tree.

import "github.com/gofiber/contrib/otelfiber/v2"

app.Use(otelfiber.Middleware())

In the service and repository, start child spans from the incoming context:

ctx, span := tracer.Start(ctx, "InvoiceService.Finalize")
defer span.End()

Because the context threads through (references/concurrency.md), the repository’s pgx query lands as a child span of the handler — the trace shows HTTP → service → SQL in one view.

Prometheus RED metrics

Expose /metrics and record Rate, Errors, Duration on every handler via middleware. RED is the standard request-level golden-signal set.

import (
  "github.com/gofiber/fiber/v2"
  "github.com/prometheus/client_golang/prometheus"
  "github.com/prometheus/client_golang/prometheus/promhttp"
  "github.com/ansrivas/fiberprometheus/v2"
)

func wireMetrics(app *fiber.App, service string) {
  pm := fiberprometheus.New(service)
  pm.RegisterAt(app, "/metrics")
  app.Use(pm.Middleware) // records http_requests_total + duration histogram, labeled by route+status
}

• Label by route template and status, never by raw path (high-cardinality /invoice/inv_42 blows up Prometheus).
• The Go runtime collectors (goroutines, GC, heap) come free with the default registry.

Exemplars: linking a metric to its trace

A histogram tells you the p99 latency moved; it does not tell you which request landed in that slow bucket. An exemplar attaches a sampled trace_id to the specific observation that fell into a bucket, so a latency spike in Grafana links straight through to the one slow trace in Tempo that caused it.

import "github.com/prometheus/client_golang/prometheus"

// histogram is a *prometheus.HistogramVec created at startup, as usual.
if obs, ok := histogram.WithLabelValues(route, status).(prometheus.ExemplarObserver); ok {
  sc := trace.SpanContextFromContext(ctx)
  obs.ObserveWithExemplar(duration.Seconds(), prometheus.Labels{
    "trace_id": sc.TraceID().String(),
  })
}

Exemplars require the OpenMetrics exposition format (promhttp.HandlerFor with EnableOpenMetrics: true) and a Prometheus server configured to store them — without both, the call above is a harmless no-op.

Burn-rate alerting beats a flat threshold

A flat error_rate > 1% alert can’t tell a five-minute total outage from a slow week-long leak — both cross 1% eventually, but they need different urgency. Burn-rate alerting compares the rate at which an error budget is being consumed against multiple time windows, so severity falls out of the math instead of a second hand-tuned threshold.

Window	Burn rate	Meaning	Page?
1 hour	14.4x	budget exhausted in ~2 days at this rate	yes, immediately
6 hours	6x	budget exhausted in ~5 days at this rate	yes, immediately
3 days	1x	budget exhausted exactly on schedule	ticket, not a page

Pair a short and a long window on the same alert (e.g. 1h and 5m both breaching 14.4x) so a single short blip doesn’t page on its own — this is the standard multi-window, multi-burn-rate shape from Google’s SRE workbook, and it composes with the RED metrics above: the burn rate is computed from the same error-count and total-count series already being recorded.

pprof on a gated internal port

Profiling is mounted on a separate internal listener, gated by DEBUG=true — never on the public HTTP listener in production.

import "net/http"
import _ "net/http/pprof" // registers handlers on the default mux

func startPprof(cfg Config, log *zap.Logger) {
  if !cfg.Debug {
    return
  }
  go func() {
    // separate port, internal only — not the public app listener
    if err := http.ListenAndServe("127.0.0.1:6060", nil); err != nil {
      log.Error("pprof listener stopped", zap.Error(err))
    }
  }()
}

• Bind to loopback or an internal-only interface; pprof must never be internet-reachable.
• DEBUG=true is the only switch that turns it on — default off in every deployed environment.