chore(logging): add service logging package — handler chain and access-log sampler (S03 Step 2)
What
Step 2 of the S03 logging foundation: the internal/logging package — the
service-owned slog.Handler chain that wraps LabKit v2's base handler.
contextFieldHandlerattaches the context-derived baseline fields (correlation_idviacorrelation.ExtractFromContext,trace_id/span_idviaoteltrace.SpanFromContext) to every record when present, de-duplicating any key the record already carries (LabKit's access logger stampscorrelation_iditself).accessLogSamplerapplies the access-log volume rules: always forwardstatus >= 400andduration_s >= slow_threshold; drop fast 2xx/3xx with probability1 - success_fraction; drop everything whendisabled; pass non-"access"records through untouched.NewLogger(base, cfg)wires the chain (sampler → context-field → base) against a localSamplerConfig— nointernal/configimport, no HTTP wiring. Those land in Step 3.
Plan: docs/plans/2026-06-02-s03-logging.md, Step 2. Spec: docs/specs/S03-observability.md.
This is a chore (no operator-visible surface on its own); the wiring that
makes the running service use this chain is the feat in Step 3.
Spec coverage
Step 2 owns AC 2, 3, 4, 5, 6. AC 1/7/8 are owned by Step 1 / Step 3 per the plan's AC-coverage map and are listed here as out-of-scope rows.
Acceptance criteria
| # | Criterion | Tests |
|---|---|---|
| AC-1 | Base handler JSON on stderr by default | Out of scope (Step 3 wiring). Base handler is LabKit-owned; tests here use a buffer-backed JSON base. |
| AC-2 | Context-field handler attaches correlation_id/trace_id/span_id; no-op when absent; no double-stamp | TestHandler_CorrelationPresent, TestHandler_TraceSpanPresent, TestHandler_NoneWhenAbsent, TestHandler_NoDoubleStamp, TestHandler_NoBleed |
| AC-3 | Sampler always logs status >= 400 and duration_s >= slow_threshold regardless of fraction | TestSampler_ErrorAlwaysLogged, TestSampler_SlowAlwaysLogged |
| AC-4 | success_fraction = 0.0 drops fast 2xx/3xx, keeps errors and slow responses | TestSampler_FastSuccessDropped (drop at 0.0); error/slow preservation at 0.0 in TestSampler_ErrorAlwaysLogged, TestSampler_SlowAlwaysLogged (both run at fraction 0.0) |
| AC-5 | access_log.disabled = true emits nothing for 4xx/5xx/fast-2xx/slow-2xx | TestSampler_Disabled (table over all four) |
| AC-6 | Wide-event record carries outcome + duration_s; correlation_id/trace_id/span_id by chain | TestWideEvent_BaselineFields |
| AC-7 | LogConfig load/validate; omitted block defaults; invalid slow_threshold startup error | Out of scope (Step 1 load/defaults; Step 3 applied-before-serving). |
| AC-8 | success_fraction bounds + explicit-0.0 vs unset; level/format in: rejection | Out of scope (Step 1, proto + protovalidate + conversion). |
Supporting coverage:
- Sampler no-op for non-"access" records:
TestSampler_NonAccessPasses. - Fast success logged at fraction 1.0 regardless of the rand draw:
TestSampler_FractionOneLogs. - Record-clone overflow contract under concurrent fan-out:
TestContextHandler_OverflowFanout(regression guard for the lazyRecord.Clone()below — fails undergo test -racewithout it).
Error cases
| # | Condition | Tests |
|---|---|---|
| E-1 | Log pipeline saturated -> success_fraction < 1.0 caps volume | TestSampler_FastSuccessDropped exercises the drop path at fraction 0.0. |
| E-2 | access_log.disabled = true -> no records, rules bypassed, errors not preserved | TestSampler_Disabled (asserts 4xx/5xx also dropped). |
| E-3 | log.level / log.format omitted or "" | Out of scope (Step 1 config conversion). |
| E-4 | log.level / log.format outside in: set | Out of scope (Step 1 protovalidate). |
| E-5 | Invalid slow_threshold duration string | Out of scope (Step 1 config conversion). |
Security considerations
| # | Concern | Tests |
|---|---|---|
| S-1 | No secrets in logs | Wide-event emitters enforce per-event schema; no secret-bearing field exercised. Per-event emitters owned by format specs (out of scope for S03). |
| S-2 | X-Request-ID echo / sanitization | LabKit's CorrelationIDMiddleware-owned (S01). Not tested in this MR. |
Review fixes folded in
The branch-review pass surfaced three items, all addressed in the final commit:
- Clone before mutate —
contextFieldHandler.Handletakes a lazyrecord.Clone()beforeAddAttrs(slog's middleware contract: record copies share an overflow backing array). Lazy so the no-enrichment path stays allocation-free. - Kind-guarded sampler reads —
shouldLogguards itsstatus/duration_sreads withValue.Kind()checks;slog.Value.Int64/Float64panic on a kind mismatch and the sampler matches on key alone. - Overflow-path test —
TestContextHandler_OverflowFanoutexercises the5-attr overflow array under a concurrent fan-out; it fails under
-racewithout the clone.
go mod tidy also promotes go.opentelemetry.io/otel/trace from // indirect
to a direct require (it is now imported directly by handler.go), keeping the
CI go-mod-tidy check green.
Diff size
The diff is test-dominated — +499 test (handler_test.go) vs +213
implementation (handler.go), with a one-line go.mod change. The package is
small and the behavior (sampling rules across status/duration/disabled/
non-access combinations, context-field attach/no-op/no-double-stamp, and the
concurrency/overflow contracts) is exercised exhaustively, so the test file
legitimately outweighs the implementation.