common/logctx: relocate from api repo to canonical common module

logctx/handler.go

@@ -0,0 +1,108 @@
+package logctx
+
+import (
+	"context"
+	"log/slog"
+	"os"
+)
+
+// Field-name constants — never inline these strings in tests or callers.
+// The schema is part of our log contract and grep-ability across services
+// requires that every Go file uses the same identifiers.
+const (
+	FieldService  = "service"
+	FieldCommitID = "commit_id"
+	FieldTraceID  = "trace_id"
+	FieldTID      = "tid"
+	FieldTeamID   = "team_id"
+)
+
+// commitID returns the build's git SHA. Track 1 of the observability rollout
+// adds a real `instant.dev/common/buildinfo` package whose GitSHA var is set
+// via `-ldflags -X`. Until that package merges, we fall back to the
+// COMMIT_ID env var (set by the Dockerfile / k8s deployment) so this package
+// does not block on track 1. The sentinel "dev" matches the buildinfo
+// package's planned default so log readers see a single consistent value
+// across both implementations.
+func commitID() string {
+	if v := os.Getenv("COMMIT_ID"); v != "" {
+		return v
+	}
+	return "dev"
+}
+
+// Handler wraps an underlying slog.Handler and injects the five mandatory
+// observability fields onto every record:
+//
+//	service    — constant supplied at construction time ("api" / "worker" / "provisioner")
+//	commit_id  — git SHA of the running binary (compile-time or env)
+//	trace_id   — pulled from ctx via TraceIDFromContext
+//	tid        — pulled from ctx via TIDFromContext
+//	team_id    — pulled from ctx via TeamIDFromContext
+//
+// Missing ctx fields are emitted as empty strings — never dropped — so log
+// schema is stable across every line. A nil ctx is treated identically to
+// context.Background; the handler MUST NOT panic on a nil ctx.
+type Handler struct {
+	base     slog.Handler
+	service  string
+	commitID string
+}
+
+// NewHandler wraps base so that every record emitted through the wrapper
+// carries the five mandatory observability fields. The returned handler is
+// safe for concurrent use to the same degree base is.
+//
+// service is the binary name ("api", "worker", "provisioner") and is emitted
+// on every record. base is any slog.Handler — typically slog.NewJSONHandler
+// over stdout with AddSource=true.
+func NewHandler(service string, base slog.Handler) slog.Handler {
+	return &Handler{
+		base:     base,
+		service:  service,
+		commitID: commitID(),
+	}
+}
+
+// Enabled forwards to the wrapped handler unchanged. Wrapping must not change
+// which records get emitted — that decision belongs to the base handler's
+// configured level.
+func (h *Handler) Enabled(ctx context.Context, level slog.Level) bool {
+	return h.base.Enabled(ctx, level)
+}
+
+// Handle annotates the record with the five mandatory fields and forwards.
+// A nil ctx is tolerated — getters return empty strings rather than panic.
+func (h *Handler) Handle(ctx context.Context, r slog.Record) error {
+	// AddAttrs mutates the record in place; the standard library reserves
+	// the right to do this exactly once per Record value, which is fine
+	// here because every record reaches the wrapper at most once.
+	r.AddAttrs(
+		slog.String(FieldService, h.service),
+		slog.String(FieldCommitID, h.commitID),
+		slog.String(FieldTraceID, TraceIDFromContext(ctx)),
+		slog.String(FieldTID, TIDFromContext(ctx)),
+		slog.String(FieldTeamID, TeamIDFromContext(ctx)),
+	)
+	return h.base.Handle(ctx, r)
+}
+
+// WithAttrs returns a new wrapper around base.WithAttrs(attrs). The injected
+// service / commit_id stay attached to the new wrapper so child loggers
+// (built via slog.Logger.With) still carry the mandatory fields.
+func (h *Handler) WithAttrs(attrs []slog.Attr) slog.Handler {
+	return &Handler{
+		base:     h.base.WithAttrs(attrs),
+		service:  h.service,
+		commitID: h.commitID,
+	}
+}
+
+// WithGroup returns a new wrapper around base.WithGroup(name).
+func (h *Handler) WithGroup(name string) slog.Handler {
+	return &Handler{
+		base:     h.base.WithGroup(name),
+		service:  h.service,
+		commitID: h.commitID,
+	}
+}

logctx/handler_test.go

@@ -0,0 +1,161 @@
+package logctx
+
+import (
+	"bytes"
+	"context"
+	"encoding/json"
+	"log/slog"
+	"strings"
+	"testing"
+	"time"
+)
+
+// newTestHandler builds a logctx Handler over a fresh JSON handler writing to
+// the returned buffer. Tests inspect the buffer after each emit. Level is set
+// to Debug so nothing is filtered unless the test explicitly disables it.
+func newTestHandler(t *testing.T, service string) (*bytes.Buffer, slog.Handler) {
+	t.Helper()
+	buf := &bytes.Buffer{}
+	base := slog.NewJSONHandler(buf, &slog.HandlerOptions{Level: slog.LevelDebug})
+	return buf, NewHandler(service, base)
+}
+
+// decode reads the buffer as a single JSON-line slog record and returns the
+// parsed map. Fails the test on bad JSON or empty input.
+func decode(t *testing.T, buf *bytes.Buffer) map[string]any {
+	t.Helper()
+	raw := strings.TrimSpace(buf.String())
+	if raw == "" {
+		t.Fatal("no log line emitted")
+	}
+	out := map[string]any{}
+	if err := json.Unmarshal([]byte(raw), &out); err != nil {
+		t.Fatalf("malformed log JSON %q: %v", raw, err)
+	}
+	return out
+}
+
+// newRecord constructs a slog.Record at INFO with a fixed message. Tests
+// never need the source frame in this package.
+func newRecord(msg string) slog.Record {
+	return slog.NewRecord(time.Now(), slog.LevelInfo, msg, 0)
+}
+
+// Test 1: with a bare context (no setters called) the handler emits service,
+// commit_id, and empty values for the three ctx-sourced fields.
+func TestHandler_NoCtx(t *testing.T) {
+	buf, h := newTestHandler(t, "api")
+	if err := h.Handle(context.Background(), newRecord("hello")); err != nil {
+		t.Fatalf("Handle: %v", err)
+	}
+
+	rec := decode(t, buf)
+	if rec[FieldService] != "api" {
+		t.Errorf("service = %v, want api", rec[FieldService])
+	}
+	// commit_id default is "dev" (see commitID()).
+	if rec[FieldCommitID] != "dev" {
+		t.Errorf("commit_id = %v, want dev", rec[FieldCommitID])
+	}
+	for _, f := range []string{FieldTraceID, FieldTID, FieldTeamID} {
+		if got, ok := rec[f]; !ok || got != "" {
+			t.Errorf("%s = %v present=%v, want empty string present=true", f, got, ok)
+		}
+	}
+}
+
+// Test 2: WithTraceID propagates through Handle.
+func TestHandler_WithTraceID(t *testing.T) {
+	buf, h := newTestHandler(t, "api")
+	ctx := WithTraceID(context.Background(), "abc")
+	if err := h.Handle(ctx, newRecord("hello")); err != nil {
+		t.Fatalf("Handle: %v", err)
+	}
+	rec := decode(t, buf)
+	if rec[FieldTraceID] != "abc" {
+		t.Errorf("trace_id = %v, want abc", rec[FieldTraceID])
+	}
+	// Sibling ctx fields untouched stay empty.
+	if rec[FieldTID] != "" || rec[FieldTeamID] != "" {
+		t.Errorf("sibling fields not empty: tid=%v team_id=%v", rec[FieldTID], rec[FieldTeamID])
+	}
+}
+
+// Test 3: all three setters compose; all three values reach the record.
+func TestHandler_WithAll(t *testing.T) {
+	buf, h := newTestHandler(t, "worker")
+	ctx := context.Background()
+	ctx = WithTraceID(ctx, "trace-xyz")
+	ctx = WithTID(ctx, "tid-77")
+	ctx = WithTeamID(ctx, "team-42")
+	if err := h.Handle(ctx, newRecord("hello")); err != nil {
+		t.Fatalf("Handle: %v", err)
+	}
+	rec := decode(t, buf)
+	if rec[FieldService] != "worker" {
+		t.Errorf("service = %v, want worker", rec[FieldService])
+	}
+	if rec[FieldTraceID] != "trace-xyz" {
+		t.Errorf("trace_id = %v, want trace-xyz", rec[FieldTraceID])
+	}
+	if rec[FieldTID] != "tid-77" {
+		t.Errorf("tid = %v, want tid-77", rec[FieldTID])
+	}
+	if rec[FieldTeamID] != "team-42" {
+		t.Errorf("team_id = %v, want team-42", rec[FieldTeamID])
+	}
+}
+
+// Test 4: nil ctx must NOT panic. The defensive nil checks in keys.go and
+// handler.go are load-bearing — slog will hand us a nil ctx from
+// (*Logger).Log when callers pass nil.
+func TestHandler_NilCtx(t *testing.T) {
+	buf, h := newTestHandler(t, "api")
+	defer func() {
+		if r := recover(); r != nil {
+			t.Fatalf("Handle(nil ctx) panicked: %v", r)
+		}
+	}()
+	// Pass an explicitly nil context. The handler must treat it as empty.
+	if err := h.Handle(nil, newRecord("hello")); err != nil {
+		t.Fatalf("Handle: %v", err)
+	}
+	rec := decode(t, buf)
+	if rec[FieldTraceID] != "" || rec[FieldTID] != "" || rec[FieldTeamID] != "" {
+		t.Errorf("nil ctx produced non-empty fields: %v", rec)
+	}
+}
+
+// disabledHandler is a stub base handler that always reports Enabled=false.
+// Tests use it to verify the wrapper does not override the base's filtering.
+type disabledHandler struct{ slog.Handler }
+
+func (disabledHandler) Enabled(context.Context, slog.Level) bool { return false }
+
+// Test 5: when the base handler says Enabled=false, the wrapper says false
+// too. The wrapper must never widen the set of emitted records.
+func TestHandler_EnabledPassthrough(t *testing.T) {
+	base := disabledHandler{Handler: slog.NewJSONHandler(&bytes.Buffer{}, nil)}
+	h := NewHandler("api", base)
+	if h.Enabled(context.Background(), slog.LevelError) {
+		t.Error("wrapper widened Enabled — base said false, wrapper said true")
+	}
+}
+
+// Bonus: WithAttrs / WithGroup preserve the injected service+commit_id on
+// the returned child handler. Belt-and-braces guard against regressions
+// where someone refactors the struct and forgets to copy the fields.
+func TestHandler_WithAttrsPreservesService(t *testing.T) {
+	buf, h := newTestHandler(t, "provisioner")
+	child := h.WithAttrs([]slog.Attr{slog.String("extra", "v")})
+	if err := child.Handle(context.Background(), newRecord("hi")); err != nil {
+		t.Fatalf("Handle: %v", err)
+	}
+	rec := decode(t, buf)
+	if rec[FieldService] != "provisioner" {
+		t.Errorf("WithAttrs dropped service: %v", rec[FieldService])
+	}
+	if rec["extra"] != "v" {
+		t.Errorf("WithAttrs dropped extra attr")
+	}
+}

logctx/keys.go

@@ -0,0 +1,87 @@
+// Package logctx provides a slog.Handler wrapper that auto-injects mandatory
+// observability fields (service, commit_id, trace_id, tid, team_id) onto every
+// log record by reading them from a context.Context.
+//
+// Setters and getters on this file are the only sanctioned way to put those
+// fields onto a context; the handler in handler.go is the only sanctioned way
+// to read them off again when emitting a record.
+package logctx
+
+import "context"
+
+// Unexported context keys — these prevent collisions with other packages that
+// might want to store strings on a context under the same name. Each type is
+// a distinct empty struct so equality is identity, not value-based.
+type (
+	traceIDCtxKey struct{}
+	tidCtxKey     struct{}
+	teamIDCtxKey  struct{}
+)
+
+// WithTraceID returns a copy of ctx carrying the supplied trace_id. The trace
+// id is the W3C TraceContext trace ID when an OpenTelemetry span is in flight,
+// falling back to the upstream request_id for non-span paths. Passing an empty
+// string is permitted and behaves like no annotation — the handler will emit
+// an empty trace_id field.
+func WithTraceID(ctx context.Context, v string) context.Context {
+	if ctx == nil {
+		ctx = context.Background()
+	}
+	return context.WithValue(ctx, traceIDCtxKey{}, v)
+}
+
+// TraceIDFromContext extracts the trace_id previously stored by WithTraceID.
+// Returns an empty string when ctx is nil or carries no trace id — callers
+// should NEVER panic on a missing field.
+func TraceIDFromContext(ctx context.Context) string {
+	if ctx == nil {
+		return ""
+	}
+	if v, ok := ctx.Value(traceIDCtxKey{}).(string); ok {
+		return v
+	}
+	return ""
+}
+
+// WithTID returns a copy of ctx carrying the supplied tid (River job task ID
+// for worker jobs; empty for non-job code paths).
+func WithTID(ctx context.Context, v string) context.Context {
+	if ctx == nil {
+		ctx = context.Background()
+	}
+	return context.WithValue(ctx, tidCtxKey{}, v)
+}
+
+// TIDFromContext extracts the tid previously stored by WithTID. Returns an
+// empty string when absent or when ctx is nil.
+func TIDFromContext(ctx context.Context) string {
+	if ctx == nil {
+		return ""
+	}
+	if v, ok := ctx.Value(tidCtxKey{}).(string); ok {
+		return v
+	}
+	return ""
+}
+
+// WithTeamID returns a copy of ctx carrying the supplied team_id (the JWT
+// team_id claim, propagated from the auth middleware).
+func WithTeamID(ctx context.Context, v string) context.Context {
+	if ctx == nil {
+		ctx = context.Background()
+	}
+	return context.WithValue(ctx, teamIDCtxKey{}, v)
+}
+
+// TeamIDFromContext extracts the team_id previously stored by WithTeamID.
+// Returns an empty string when absent (unauthenticated request) or when ctx
+// is nil.
+func TeamIDFromContext(ctx context.Context) string {
+	if ctx == nil {
+		return ""
+	}
+	if v, ok := ctx.Value(teamIDCtxKey{}).(string); ok {
+		return v
+	}
+	return ""
+}