feat(server): wire enriched logger into composition root and request context (S03 Step 3)
What
Step 3 (final) of the S03 logging foundation: wire the enriched logger into the
running service. This is the feat step where the service actually honors
log.level/log.format, samples access logs, and enriches every record with
context fields — Steps 1 (config) and 2 (handler chain) are inert until this lands.
- Composition root (
cmd/artifact-registry/main.go): mapcfg.Logintoapp.Config.Log(viaappLogConfig) soapp.Appbuilds the base handler at the configured level/format, then build the enriched logger by wrappinga.Logger().Handler()with the Step 2 chain (logging.NewLogger(...), sampler keyed bysamplerConfig(cfg.Log.AccessLog)) and hand it toserver.New. Wrapping (not building a fresh handler) preserves app.App's baked-inversion/commit/build-dateattributes. - Request-context logger (
internal/server):ContextLoggerMiddlewarestores the enriched logger vialog.WithLogger, installed as the outermost application middleware inbuildMiddleware(inside LabKit's correlation middleware, outside the mux), solog.FromContext(ctx)returns it at every handler withcorrelation_idalready in context. - Docs (
docs/dev/logging.md): corrected the LabKit-usage guidance (log.AppendFieldsnotlog.WithFields;statusnotstatus_code;error_messagenoterror;urinotpath; the no-auto-stamp note) — paired with the implementation that introduces these primitives.
Plan: docs/plans/2026-06-02-s03-logging.md, Step 3. Spec: docs/specs/S03-observability.md.
Spec coverage
This step owns AC #1 and the applied-before-serving half of AC #7 (closed); the remaining ACs are owned by Steps 1/2 and listed for completeness.
Acceptance criteria
| # | Criterion | Tests |
|---|---|---|
| AC-1 | Base handler writes JSON to stderr by default; level honored; version/commit/build-date survive wrap | TestWiring_WrapAppLogger, TestWiring_ConfigLogDrivesAppLevel |
| AC-2 | context-field handler attaches correlation_id/trace_id/span_id; no-op when absent | Step 2: TestHandler_CorrelationPresent, TestHandler_TraceSpanPresent, TestHandler_NoneWhenAbsent |
| AC-3 | sampler always logs status>=400 and slow responses | Step 2: TestSampler_ErrorAlwaysLogged, TestSampler_SlowAlwaysLogged |
| AC-4 | success_fraction=0.0 drops fast 2xx/3xx, keeps errors/slow | Step 2: TestSampler_FastSuccessDropped, TestSampler_ErrorAlwaysLogged |
| AC-5 | access_log.disabled=true emits nothing | Step 2: TestSampler_Disabled |
| AC-6 | wide-event emitter carries outcome+duration_s; context fields by chain | Step 2: TestWideEvent_BaselineFields |
| AC-7 | LogConfig loaded/validated and applied before serving; FromContext returns enriched logger | Step 1: internal/config TestLog_*. Applied-before-serving (this step): TestWiring_ContextLogger, TestContextLoggerMiddleware_InstallsLogger, TestContextLoggerMiddleware_EnrichesFromContext |
| AC-8 | success_fraction bounds + explicit-0.0 vs unset; level/format in: rejection | Step 1: internal/config TestLog_FractionOutOfRange, TestLog_ExplicitZeroFraction, TestLog_InvalidLevel |
Sampler-through-the-assembled-logger (plan Step 3 Tests)
| Behavior | Tests |
|---|---|
| Logger handed to the server is the sampling logger (error preserved) | TestWiring_AccessLogSampling |
| Wide events are never dropped by the access sampler | TestWiring_NonAccessWideEventNotSampled |
Plus direct mapping tests for the composition-root helpers: TestAppLogConfig
(level + UseTextFormat) and TestSamplerConfig (Disabled / SuccessFraction /
SlowThreshold).
Error cases
| # | Condition | Tests |
|---|---|---|
| E-1 | Log pipeline saturated → success_fraction<1.0 caps volume | Indirect: TestWiring_AccessLogSampling drop path; the service does not observe downstream pressure |
| E-2 | access_log.disabled=true → no records, rules bypassed | Step 2: TestSampler_Disabled |
| E-3 | log.level/log.format omitted or "" → default applied | Step 1: TestLog_OmittedBlock, TestLog_EmptyEnums |
| E-4 | log.level/log.format outside in: set → protovalidate rejection | Step 1: TestLog_InvalidLevel |
| E-5 | invalid slow_threshold → startup error naming the field | Step 1: TestLog_InvalidSlowThreshold |
Security considerations
| # | Concern | Tests |
|---|---|---|
| S-1 | No secrets in logs (per-event schema) | Enforced by the typed-emitter convention; no concrete emitter in S03 (owned by format specs). Not exercised here. |
| S-2 | X-Request-ID echo / correlation sanitization | LabKit-owned (CorrelationIDMiddleware regex). Not tested here. |
Review notes
This branch went through /validate-step → /review-branch → /validate-step; all findings are resolved:
- Spec amendment included (out of plan
Files, deliberate)./review-branchfound that the spec's LabKit-mapping table claimedlog.formatoverridesGITLAB_LOG_FORMATunconditionally, but LabKit applies theUseTextFormatoverride only whentrue— solog.format: jsondoes not override an env-setGITLAB_LOG_FORMAT=text. The implementation is correct (it's a LabKit library behavior), sodocs/specs/S03-observability.md:377was corrected to document the one-directional precedence rather than changing code. Flagging that this spec edit rides this MR rather than a standalone spec MR. - Data race fixed. The build-info wiring tests pinned LabKit's process-global
app.Version/Commit/Dateper-test undert.Parallel(), racing reads in sibling tests. Now pinned once ininit(); verified clean undergo test -race -count=3. - Added direct
appLogConfig/samplerConfigtests and corrected a misleading helper comment.
Diff size
Test- and docs-dominated: ~64 LOC of reviewable production code
(main.go + middleware.go + server.go); the rest is wiring tests and the
paired docs/spec corrections.