I'm using Go's standard log/slog package and have created a custom handler middleware (ContextHandler) to automatically add request-scoped attributes (like session_id) from the context.Context to log records. This middleware wraps a base handler (like slog.JSONHandler or devslog.Handler).
The middleware looks roughly like this:
// ContextHandler middleware
type ContextHandler struct {
slog.Handler
}
func NewContextHandler(handler slog.Handler) *ContextHandler {
return &ContextHandler{Handler: handler}
}
func (h *ContextHandler) Handle(ctx context.Context, r slog.Record) error {
// Example: Get session ID from context
if sessionID, ok := contextkeys.GetSessionID(ctx); ok {
r.AddAttrs(slog.String("session_id", sessionID)) // Add attribute to record
}
// Pass record to the next handler
return h.Handler.Handle(ctx, r)
}
// Logger creation wraps the base handler
func NewLogger( /* ... */ ) *slog.Logger {
var baseHandler slog.Handler
// ... logic to create baseHandler (JSON, devslog, etc.) ...
contextAwareHandler := NewContextHandler(baseHandler)
logger := slog.New(contextAwareHandler)
return logger
}
In my gRPC handler, I inject the logger created by NewLogger:
type AuthHandler struct {
// ... other fields
logger *slog.Logger
}
func NewAuthHandler( /* ... */ logger *slog.Logger) *AuthHandler {
return &AuthHandler{ /* ... */ logger: logger}
}
The Observation:
// Inside handler method
func (h *AuthHandler) SomeMethod(ctx context.Context, /* ... */) {
// ...
h.logger.InfoContext(ctx, "Operation successful")
// Output includes "session_id=xyz"
}
// Inside handler method
func (h *AuthHandler) SomeMethod(ctx context.Context, /* ... */) {
const op = "Handler.SomeMethod"
// Create derived logger
log := h.logger.With(slog.String("op", op))
// ...
log.InfoContext(ctx, "Operation successful")
// Output includes "op=Handler.SomeMethod" BUT NOT "session_id=xyz"
}
Question:
Is this behavior expected? Why might attributes added dynamically to a slog.Record via r.AddAttrs in handler middleware fail to appear in the final output when the logging call is made using a logger instance derived from logger.With(...)? Is there a standard or recommended way to ensure attributes added by handler middleware work reliably even when .With is used?
Go 1.24.2
logger.With(...)
internally calls handler.WithAttrs(...)
.
Since you haven't re-implemented WithAttrs(...)
on your specific ContextHandler
type, calling h.WithAttrs(...)
on your handler is just syntactic sugar for h.Handler.WithAttrs(...)
, and the inner type will not return a ContextHandler
.
You will have to implement func (h *ContextHandler) WithAttrs(...)
for your type.
In a a similar way: you probably want to implement WithGroup(...)
for your type.
I think this can be as simple as:
func (h *ContextHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
inner := h.Handler.WithAttrs(attrs)
return &ContextHandler{inner}
}
func (h *ContextHandler) WithGroup(name string) slog.Handler {
inner := h.Handler.WithGroup(name)
return &ContextHandler{inner}
}
If you have some reason to handle such attributes in a specific way in your ContextHandler.Handle()
method (ordering the fields in a different order, different formatting ...), you may want to do something extra, like adding a attrs []slog.Attr
to your struct, and using that field in your Handle(...)
method.