Stage 7 · Master
Phase 17 — Observability
Structured Logging
Turn Phase 1 and Phase 2's separately-built logging pieces — a structured zerolog.Logger, a request-id middleware, a PII-redaction helper — into one enforced contract every future service must follow, and close the one gap this codebase already shipped with.
organization_service.go Already Violates the Contract It Should Be Following
Phase 2's Logging lesson built middleware.RequestID, threaded a request id into the JSON error envelope, and fixed a real PII leak with logutil.RedactEmail. What it did not do is connect the two: OrganizationService.Create's own log line — logger.Info().Str("org_id", org.ID.String()).Str("slug", org.Slug).Str("email", logutil.RedactEmail(org.ContactEmail)).Msg("organization created") — has no request_id field, despite RequestID middleware having existed in the same file since that same lesson. A support engineer holding one failed request's X-Request-ID header cannot grep this log line for it. This is not a hypothetical risk to guard against; it is the exact log line already shipped.
Five Fields Every Log Line In This Platform Must Carry
- service — set once, at construction, by pkg/logging.New; never repeated by call sites
- env — set once, at construction, alongside service
- request_id — present on every log line written while handling an HTTP request; absent only for background jobs, migrations, and startup/shutdown logging that happens outside any request
- org_id — present on every log line that concerns a specific organization's data, using that organization's own id, never its name or slug
- trace_id — added in this same module's OpenTelemetry lesson; every log line written inside a traced span carries the span's trace id automatically
The first two are already enforced structurally — pkg/logging.New binds them once and every derived logger inherits them through zerolog's own .With() chaining. The last three are not enforced at all today; they depend on a developer remembering to call RequestIDFromContext (or, after this lesson, an equivalent) at every single call site. A contract that depends on memory is not a contract. This lesson replaces "remember to pass request_id" with a function whose signature makes forgetting impossible.
pkg/logging Gains ForRequest, and a Context Pair to Carry the Result
package logging
import (
"context"
"github.com/rs/zerolog"
)
// ForRequest returns a derived logger with request_id (and, once a
// request also carries a trace span, trace_id — added by the
// OpenTelemetry lesson later in this module) bound in permanently. Every
// call site downstream logs through the returned logger instead of the
// bare zerolog.Logger main constructed, so request_id is present by
// construction, not by the call site remembering to attach it.
func ForRequest(base zerolog.Logger, requestID string) zerolog.Logger {
if requestID == "" {
return base
}
return base.With().Str("request_id", requestID).Logger()
}
// NewContext stores a logger for retrieval by FromContext. It is a thin,
// intention-revealing wrapper over zerolog.Logger.WithContext — the
// library's own mechanism for attaching a *zerolog.Logger to a
// context.Context — kept under this platform's logging package name so
// every call site says "logging.NewContext", not a mix of raw zerolog
// calls and this package's other helpers.
func NewContext(ctx context.Context, logger zerolog.Logger) context.Context {
return logger.WithContext(ctx)
}
// FromContext never returns a disabled, silently-dropping logger for code
// that has nothing to do with an HTTP request. zerolog.Ctx(ctx) itself
// never panics — it already falls back to a disabled Logger when the
// context carries none — but a disabled logger writes nothing at all.
// FromContext substitutes base instead, so a migration runner or a
// one-off script that receives a plain context.Background() still gets a
// fully working logger, the same never-panic-and-never-go-silent
// guarantee Phase 2's RequestIDFromContext already established for the
// id string alone.
func FromContext(ctx context.Context, base zerolog.Logger) zerolog.Logger {
if logger := zerolog.Ctx(ctx); logger.GetLevel() != zerolog.Disabled {
return *logger
}
return base
}
RequestID Now Populates the Context-Bound Logger, Not Just the Header
middleware.RequestID (Phase 2) already computes the id and stores it in the request's context. This lesson adds one more step to the same middleware: derive the request-scoped logger right there, once, and store it alongside the id, so every downstream handler and service reaches for logging.FromContext instead of separately calling RequestIDFromContext and building its own .With chain by hand.
-func RequestID() gin.HandlerFunc {
+func RequestID(logger zerolog.Logger) gin.HandlerFunc {
return func(c *gin.Context) {
// id generation and the X-Request-ID response header are unchanged
ctx := context.WithValue(c.Request.Context(), requestIDKey, id)
+ ctx = logging.NewContext(ctx, logging.ForRequest(logger, id))
c.Request = c.Request.WithContext(ctx)
c.Next()
}
}
RequestID's signature gains one parameter — the base zerolog.Logger constructed once in main — since it must now build a derived logger, not just an id string. Every other line is unchanged from Phase 2.
func New(orgHandler *handler.OrganizationHandler, m *metrics.Metrics, logger zerolog.Logger) *gin.Engine {
engine := gin.New()
engine.Use(middleware.RequestID(logger))
engine.Use(gin.Recovery())
engine.Use(middleware.ErrorHandler())
engine.Use(m.Middleware())
// routes unchanged below this line — healthz/readyz/metrics move to
// the internal listener in this module's Prometheus lesson
Create's Log Line Finally Carries request_id
- s.logger.Info().
- Str("org_id", org.ID.String()).
- Str("slug", org.Slug).
- Str("email", logutil.RedactEmail(org.ContactEmail)).
- Msg("organization created")
+ logging.FromContext(ctx, s.logger).Info().
+ Str("org_id", org.ID.String()).
+ Str("slug", org.Slug).
+ Str("email", logutil.RedactEmail(org.ContactEmail)).
+ Msg("organization created")
The domain construction, repository call, error mapping, and redaction remain exactly as Phase 2 implemented them, so repeating that function would hide the only new idea. The single changed receiver makes s.logger the fallback while logging.FromContext prefers the request-scoped logger carried by real HTTP requests.
Nothing stops a future call site from writing logger.Info() directly instead of going through logging.FromContext. Unlike a compile error, a missing request_id is only ever caught by code review or by the table-driven test this lesson's exercise asks you to write. Treat the contract as a strong convention this module documents, not a guarantee the type system enforces — a genuinely enforced version would require replacing zerolog.Logger itself with a wrapping type across every service, a much larger change out of scope here.
Confirm request_id Appears Without Any Call Site Asking For It By Name
Applied exercise
Write a table-driven test proving ForRequest never panics on an empty id
logging.ForRequest has one branch most callers will never exercise deliberately: an empty requestID. Prove it behaves correctly rather than assuming it from reading the code.
- Write pkg/logging/context_test.go with a table-driven test covering: a normal non-empty request id, an empty string, and confirming the returned logger in the empty case is reflect.DeepEqual to the exact same *base* value (not merely equivalent output) rather than a new .With().Str("request_id", "").Logger() copy that happens to look the same this one time.
- Run go test ./pkg/logging/... -run TestForRequest -v and confirm all cases pass.
- Explain in one sentence why returning base unchanged for an empty id (rather than binding request_id="") avoids a misleading log field.
Deliverable
The test file plus its passing output.
Completion checks
- The empty-id case specifically asserts reflect.DeepEqual equality with base, not just equivalent log output.
- The one-sentence explanation correctly identifies that binding an empty string would make every downstream log line claim a request_id value that doesn't actually identify any request.
Why did OrganizationService.Create's log line lack request_id even after Phase 2's Logging lesson introduced RequestID middleware in the very same file?
Mark this lesson complete to store local progress and unlock a cleaner resume path the next time you visit.