Skip to content

Commit 8a60b54

Browse files
ankursankurs
authored
feat: slog-native Handler with context field injection and typed attrs (#27)
* feat: slog-native Handler with context field injection and typed attrs Replace BaseLogger abstraction with a custom slog.Handler as the extension point. Native slog.LogAttrs calls now automatically get ColdBrew context fields (trace ID, gRPC method, etc.) after SetDefault wires the Handler. Key changes: - New Handler implementing slog.Handler with context field injection, caller caching, per-request level override, composable WithAttrs/WithGroup - SetDefault(h) sets global handler + slog.SetDefault for native slog support - AddAttrsToContext for typed slog.Attr context fields (zero interface boxing) - toAttr handles slog.Attr and slog.Value to prevent double-wrapping - Exported ToSlogLevel/FromSlogLevel for cross-package use - Deprecated: BaseLogger, SetLogger, NewLogger (backward compat kept) - Deleted: gokit, logrus, zap, stdlog, slog backends; gokitwrap bridge - Removed direct deps: go-kit/log, logrus, zap Performance: 16B/1alloc per log call (down from 80B/3allocs), native slog path adds ~30ns overhead over raw slog. * fix: address PR review comments - Fix NewHandler creating double levelVar (Copilot) — construct Handler directly instead of calling NewHandlerWithInner - Fix SetLevel not propagating to BaseLogger adapter (Copilot) — add type assertion to forward level changes to inner handler - Fix AddAttrsToContext doc overstating zero-boxing (Copilot) — clarify that context storage still goes through any, boxing is avoided at log emission time via toAttr type switch - Fix tests leaking slog.Default global state (Copilot + CodeRabbit) — extract setDefaultForTest helper that saves/restores both defaultHandler and slog.Default in t.Cleanup - Fix ExampleAddAttrsToContext missing SetDefault call (Copilot) - Fix documentation.go using undefined ctx variable (CodeRabbit) - Fix wrap test not restoring slog.Default (Copilot) * fix: Enabled respects per-request override over inner handler level * fix: nil inner panic, SetLevel propagation to baseLoggerAdapter, wrap test cleanup
1 parent a80f7ca commit 8a60b54

28 files changed

Lines changed: 996 additions & 1949 deletions

‎bench_test.go‎

Lines changed: 40 additions & 162 deletions
Original file line numberDiff line numberDiff line change
@@ -3,19 +3,11 @@ package log_test
33
import (
44
"context"
55
"io"
6-
stdlogpkg "log"
76
"log/slog"
8-
"os"
97
"testing"
108

119
"github.com/go-coldbrew/log"
1210
"github.com/go-coldbrew/log/loggers"
13-
"github.com/go-coldbrew/log/loggers/gokit"
14-
"github.com/go-coldbrew/log/loggers/logrus"
15-
cbslog "github.com/go-coldbrew/log/loggers/slog"
16-
"github.com/go-coldbrew/log/loggers/stdlog"
17-
"github.com/go-coldbrew/log/loggers/zap"
18-
"github.com/go-coldbrew/log/wrap"
1911
)
2012

2113
// Common options: JSON output, no caller info (to isolate serialization cost).
@@ -30,82 +22,27 @@ var (
3022
}
3123
)
3224

33-
// discardStdout redirects os.Stdout to /dev/null for the duration of a
34-
// benchmark. This is necessary for backends (gokit, zap, logrus, stdlog)
35-
// that unconditionally write to os.Stdout.
36-
func discardStdout(b *testing.B) {
25+
func setupHandler(b *testing.B, inner slog.Handler, opts ...loggers.Option) {
3726
b.Helper()
38-
devNull, err := os.OpenFile(os.DevNull, os.O_WRONLY, 0)
39-
if err != nil {
40-
b.Fatalf("failed to open /dev/null: %v", err)
41-
}
42-
origStdout := os.Stdout
43-
os.Stdout = devNull
44-
b.Cleanup(func() {
45-
os.Stdout = origStdout
46-
devNull.Close()
47-
})
48-
}
49-
50-
func setupLogger(b *testing.B, backend loggers.BaseLogger) {
51-
b.Helper()
52-
log.SetLogger(log.NewLogger(backend))
27+
h := log.NewHandlerWithInner(inner, opts...)
28+
log.SetDefault(h)
5329
b.ResetTimer()
5430
}
5531

56-
// --- Backend benchmarks: log.Info() with each backend ---
57-
58-
func BenchmarkBackend_Gokit_JSON(b *testing.B) {
59-
discardStdout(b)
60-
setupLogger(b, gokit.NewLogger(jsonNoCaller...))
61-
ctx := context.Background()
62-
for b.Loop() {
63-
log.Info(ctx, "msg", "benchmark message", "key1", "value1", "key2", 42)
64-
}
65-
}
66-
67-
func BenchmarkBackend_Zap_JSON(b *testing.B) {
68-
discardStdout(b)
69-
setupLogger(b, zap.NewLogger(jsonNoCaller...))
70-
ctx := context.Background()
71-
for b.Loop() {
72-
log.Info(ctx, "msg", "benchmark message", "key1", "value1", "key2", 42)
73-
}
74-
}
75-
76-
func BenchmarkBackend_Logrus_JSON(b *testing.B) {
77-
discardStdout(b)
78-
setupLogger(b, logrus.NewLogger(jsonNoCaller...))
79-
ctx := context.Background()
80-
for b.Loop() {
81-
log.Info(ctx, "msg", "benchmark message", "key1", "value1", "key2", 42)
82-
}
83-
}
32+
// --- Backend benchmarks: log.Info() with ColdBrew Handler ---
8433

8534
func BenchmarkBackend_Slog_JSON(b *testing.B) {
86-
handler := slog.NewJSONHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug})
87-
setupLogger(b, cbslog.NewLoggerWithHandler(handler, jsonNoCaller...))
35+
inner := slog.NewJSONHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug})
36+
setupHandler(b, inner, jsonNoCaller...)
8837
ctx := context.Background()
8938
for b.Loop() {
9039
log.Info(ctx, "msg", "benchmark message", "key1", "value1", "key2", 42)
9140
}
9241
}
9342

9443
func BenchmarkBackend_Slog_Text(b *testing.B) {
95-
handler := slog.NewTextHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug})
96-
setupLogger(b, cbslog.NewLoggerWithHandler(handler, loggers.WithJSONLogs(false), loggers.WithCallerInfo(false)))
97-
ctx := context.Background()
98-
for b.Loop() {
99-
log.Info(ctx, "msg", "benchmark message", "key1", "value1", "key2", 42)
100-
}
101-
}
102-
103-
func BenchmarkBackend_Stdlog(b *testing.B) {
104-
discardStdout(b)
105-
origWriter := stdlogpkg.Writer()
106-
stdlogpkg.SetOutput(io.Discard)
107-
b.Cleanup(func() { stdlogpkg.SetOutput(origWriter) })
108-
setupLogger(b, stdlog.NewLogger())
44+
inner := slog.NewTextHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug})
45+
setupHandler(b, inner, loggers.WithJSONLogs(false), loggers.WithCallerInfo(false))
10946
ctx := context.Background()
11047
for b.Loop() {
11148
log.Info(ctx, "msg", "benchmark message", "key1", "value1", "key2", 42)
@@ -114,18 +51,9 @@ func BenchmarkBackend_Stdlog(b *testing.B) {
11451

11552
// --- Backend benchmarks with caller info ---
11653

117-
func BenchmarkBackend_Gokit_JSON_Caller(b *testing.B) {
118-
discardStdout(b)
119-
setupLogger(b, gokit.NewLogger(jsonWithCaller...))
120-
ctx := context.Background()
121-
for b.Loop() {
122-
log.Info(ctx, "msg", "benchmark message", "key1", "value1", "key2", 42)
123-
}
124-
}
125-
12654
func BenchmarkBackend_Slog_JSON_Caller(b *testing.B) {
127-
handler := slog.NewJSONHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug})
128-
setupLogger(b, cbslog.NewLoggerWithHandler(handler, jsonWithCaller...))
55+
inner := slog.NewJSONHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug})
56+
setupHandler(b, inner, jsonWithCaller...)
12957
ctx := context.Background()
13058
for b.Loop() {
13159
log.Info(ctx, "msg", "benchmark message", "key1", "value1", "key2", 42)
@@ -134,33 +62,9 @@ func BenchmarkBackend_Slog_JSON_Caller(b *testing.B) {
13462

13563
// --- Backend benchmarks with context fields ---
13664

137-
func BenchmarkBackend_Gokit_JSON_CtxFields(b *testing.B) {
138-
discardStdout(b)
139-
setupLogger(b, gokit.NewLogger(jsonNoCaller...))
140-
ctx := context.Background()
141-
ctx = loggers.AddToLogContext(ctx, "trace_id", "abc-123")
142-
ctx = loggers.AddToLogContext(ctx, "service", "bench-svc")
143-
ctx = loggers.AddToLogContext(ctx, "request_id", "req-456")
144-
for b.Loop() {
145-
log.Info(ctx, "msg", "benchmark message", "key1", "value1", "key2", 42)
146-
}
147-
}
148-
14965
func BenchmarkBackend_Slog_JSON_CtxFields(b *testing.B) {
150-
handler := slog.NewJSONHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug})
151-
setupLogger(b, cbslog.NewLoggerWithHandler(handler, jsonNoCaller...))
152-
ctx := context.Background()
153-
ctx = loggers.AddToLogContext(ctx, "trace_id", "abc-123")
154-
ctx = loggers.AddToLogContext(ctx, "service", "bench-svc")
155-
ctx = loggers.AddToLogContext(ctx, "request_id", "req-456")
156-
for b.Loop() {
157-
log.Info(ctx, "msg", "benchmark message", "key1", "value1", "key2", 42)
158-
}
159-
}
160-
161-
func BenchmarkBackend_Zap_JSON_CtxFields(b *testing.B) {
162-
discardStdout(b)
163-
setupLogger(b, zap.NewLogger(jsonNoCaller...))
66+
inner := slog.NewJSONHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug})
67+
setupHandler(b, inner, jsonNoCaller...)
16468
ctx := context.Background()
16569
ctx = loggers.AddToLogContext(ctx, "trace_id", "abc-123")
16670
ctx = loggers.AddToLogContext(ctx, "service", "bench-svc")
@@ -170,53 +74,50 @@ func BenchmarkBackend_Zap_JSON_CtxFields(b *testing.B) {
17074
}
17175
}
17276

173-
// --- Frontend benchmarks: slog.Info() through the bridge ---
77+
// --- Backend benchmarks with typed context attrs ---
17478

175-
func BenchmarkFrontend_SlogBridge_GokitBackend(b *testing.B) {
176-
discardStdout(b)
177-
log.SetLogger(log.NewLogger(gokit.NewLogger(jsonNoCaller...)))
178-
sl := wrap.ToSlogLogger(log.GetLogger())
79+
func BenchmarkBackend_Slog_JSON_CtxAttrs(b *testing.B) {
80+
inner := slog.NewJSONHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug})
81+
setupHandler(b, inner, jsonNoCaller...)
17982
ctx := context.Background()
180-
b.ResetTimer()
83+
ctx = log.AddAttrsToContext(ctx,
84+
slog.String("trace_id", "abc-123"),
85+
slog.String("service", "bench-svc"),
86+
slog.String("request_id", "req-456"),
87+
)
18188
for b.Loop() {
182-
sl.InfoContext(ctx, "benchmark message", "key1", "value1", "key2", 42)
89+
slog.InfoContext(ctx, "benchmark message", "key1", "value1", "key2", 42)
18390
}
18491
}
18592

186-
func BenchmarkFrontend_SlogBridge_SlogBackend(b *testing.B) {
187-
handler := slog.NewJSONHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug})
188-
log.SetLogger(log.NewLogger(cbslog.NewLoggerWithHandler(handler, jsonNoCaller...)))
189-
sl := wrap.ToSlogLogger(log.GetLogger())
190-
ctx := context.Background()
191-
b.ResetTimer()
192-
for b.Loop() {
193-
sl.InfoContext(ctx, "benchmark message", "key1", "value1", "key2", 42)
194-
}
195-
}
93+
// --- Native slog benchmarks: slog.InfoContext() through ColdBrew Handler ---
19694

197-
func BenchmarkFrontend_SlogBridge_WithAttrs(b *testing.B) {
198-
handler := slog.NewJSONHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug})
199-
log.SetLogger(log.NewLogger(cbslog.NewLoggerWithHandler(handler, jsonNoCaller...)))
200-
sl := wrap.ToSlogLogger(log.GetLogger()).With("service", "bench-svc", "version", "1.0")
95+
func BenchmarkFrontend_NativeSlog_ColdBrewHandler(b *testing.B) {
96+
inner := slog.NewJSONHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug})
97+
h := log.NewHandlerWithInner(inner, jsonNoCaller...)
98+
log.SetDefault(h)
20199
ctx := context.Background()
202100
b.ResetTimer()
203101
for b.Loop() {
204-
sl.InfoContext(ctx, "benchmark message", "key1", "value1")
102+
slog.InfoContext(ctx, "benchmark message", "key1", "value1", "key2", 42)
205103
}
206104
}
207105

208-
func BenchmarkFrontend_SlogBridge_WithGroup(b *testing.B) {
209-
handler := slog.NewJSONHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug})
210-
log.SetLogger(log.NewLogger(cbslog.NewLoggerWithHandler(handler, jsonNoCaller...)))
211-
sl := wrap.ToSlogLogger(log.GetLogger()).WithGroup("request")
106+
func BenchmarkFrontend_NativeSlog_ColdBrewHandler_CtxFields(b *testing.B) {
107+
inner := slog.NewJSONHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug})
108+
h := log.NewHandlerWithInner(inner, jsonNoCaller...)
109+
log.SetDefault(h)
212110
ctx := context.Background()
111+
ctx = loggers.AddToLogContext(ctx, "trace_id", "abc-123")
112+
ctx = loggers.AddToLogContext(ctx, "service", "bench-svc")
113+
ctx = loggers.AddToLogContext(ctx, "request_id", "req-456")
213114
b.ResetTimer()
214115
for b.Loop() {
215-
sl.InfoContext(ctx, "benchmark message", "method", "GET", "path", "/api/v1")
116+
slog.InfoContext(ctx, "benchmark message", "key1", "value1", "key2", 42)
216117
}
217118
}
218119

219-
// --- Frontend benchmark: native slog (baseline, no ColdBrew overhead) ---
120+
// --- Baseline: native slog without ColdBrew (no overhead) ---
220121

221122
func BenchmarkFrontend_NativeSlog_JSON(b *testing.B) {
222123
handler := slog.NewJSONHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug})
@@ -238,34 +139,11 @@ func BenchmarkFrontend_NativeSlog_Text(b *testing.B) {
238139
}
239140
}
240141

241-
// --- Frontend benchmark: go-kit wrapped (existing pattern) ---
242-
243-
func BenchmarkFrontend_GoKitWrap(b *testing.B) {
244-
discardStdout(b)
245-
log.SetLogger(log.NewLogger(gokit.NewLogger(jsonNoCaller...)))
246-
gk := wrap.ToGoKitLogger(log.GetLogger())
247-
b.ResetTimer()
248-
for b.Loop() {
249-
_ = gk.Log("msg", "benchmark message", "key1", "value1", "key2", 42)
250-
}
251-
}
252-
253142
// --- Filtered (disabled level) benchmarks ---
254143

255-
func BenchmarkFiltered_Gokit(b *testing.B) {
256-
discardStdout(b)
257-
setupLogger(b, gokit.NewLogger(jsonNoCaller...))
258-
log.SetLevel(loggers.ErrorLevel)
259-
ctx := context.Background()
260-
b.ResetTimer()
261-
for b.Loop() {
262-
log.Debug(ctx, "msg", "should be filtered")
263-
}
264-
}
265-
266144
func BenchmarkFiltered_Slog(b *testing.B) {
267-
handler := slog.NewJSONHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug})
268-
setupLogger(b, cbslog.NewLoggerWithHandler(handler, jsonNoCaller...))
145+
inner := slog.NewJSONHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug})
146+
setupHandler(b, inner, jsonNoCaller...)
269147
log.SetLevel(loggers.ErrorLevel)
270148
ctx := context.Background()
271149
b.ResetTimer()
@@ -282,4 +160,4 @@ func BenchmarkFiltered_NativeSlog(b *testing.B) {
282160
for b.Loop() {
283161
sl.DebugContext(ctx, "should be filtered")
284162
}
285-
}
163+
}

‎documentation.go‎

Lines changed: 48 additions & 21 deletions
Original file line numberDiff line numberDiff line change
@@ -1,36 +1,63 @@
11
/*
2-
Package log provides a minimal interface for structured logging in services. ColdBrew uses this log package for all logs.
3-
It provides a simple interface to log errors, warnings, info and debug messages.
4-
It also provides a mechanism to add contextual information to logs.
5-
available implementations of BaseLogger are in loggers package. You can also implement your own BaseLogger to use with this package.
2+
Package log provides structured logging for ColdBrew microservices.
63
7-
# How To Use
4+
It uses a custom slog.Handler that automatically injects per-request context
5+
fields (added via [AddToContext] or [AddAttrsToContext]) into every log record.
86
9-
The simplest way to use this package is by calling static log functions to report particular level (error/warning/info/debug)
7+
# Quick Start
108
11-
log.Error(...)
12-
log.Warn(...)
13-
log.Info(...)
14-
log.Debug(...)
9+
Use the package-level functions for simple logging:
1510
16-
You can also initialize a new logger by calling 'log.NewLogger' and passing a loggers.BaseLogger implementation (loggers package provides a number of pre built implementations)
11+
log.Info(ctx, "msg", "order processed", "order_id", "ORD-123")
12+
log.Error(ctx, "msg", "connection failed", "host", "db.internal")
1713
18-
logger := log.NewLogger(gokit.NewLogger())
19-
logger.Info(ctx, "key", "value")
14+
# Native slog Support
2015
21-
Note:
16+
After calling [SetDefault], native slog calls automatically get ColdBrew
17+
context fields:
2218
23-
Preferred logging output is in either logfmt or json format, so to facilitate these log function arguments should be in pairs of key-value
19+
log.SetDefault(log.NewHandler())
20+
ctx := context.Background()
21+
ctx = log.AddToContext(ctx, "trace_id", "abc-123")
22+
slog.InfoContext(ctx, "request handled", "status", 200) // includes trace_id
2423
25-
# Contextual Logs
24+
# Adding Context Fields
2625
27-
log package uses context.Context to pass additional information to logs, you can use 'loggers.AddToLogContext' function to add additional information to logs. For example in access log from service
26+
Use [AddAttrsToContext] to add typed slog.Attr fields, or [AddToContext] for
27+
untyped key-value pairs. Both are included in all subsequent logs for that
28+
request:
2829
29-
{"@timestamp":"2018-07-30T09:58:18.262948679Z","caller":"http/http.go:66","error":null,"grpcMethod":"/AuthSvc.AuthService/Authenticate","level":"info","method":"POST","path":"/2.0/authenticate/","took":"1.356812ms","trace":"15592e1b-93df-11e8-bdfd-0242ac110002","transport":"http"}
30+
ctx := context.Background()
31+
ctx = log.AddAttrsToContext(ctx,
32+
slog.String("trace_id", id),
33+
slog.Int("user_id", uid),
34+
)
3035
31-
we pass 'grpcMethod' from context, this information gets automatically added to all log calls called inside the service and makes debugging services much easier.
32-
ColdBrew also generates a 'trace' ID per request, this can be used to trace an entire request path in logs.
36+
[AddAttrsToContext] stores each slog.Attr in the context. At log time, the
37+
Handler recovers the typed Attr and emits it directly. Context storage goes
38+
through an any-typed API internally (one boxing per field per request), but
39+
the Attr's type information is preserved for emission.
3340
34-
this package is based on https://github.com/carousell/Orion/tree/master/utils/log
41+
# High-Performance Logging
42+
43+
Combine [AddAttrsToContext] with [slog.LogAttrs] for the lowest-overhead path.
44+
Per-call attributes passed to [slog.LogAttrs] avoid interface boxing entirely:
45+
46+
slog.LogAttrs(ctx, slog.LevelInfo, "request handled",
47+
slog.Int("status", 200),
48+
slog.Duration("latency", elapsed),
49+
)
50+
51+
# Custom Handlers
52+
53+
Use [NewHandlerWithInner] to compose ColdBrew's context injection with any
54+
slog.Handler:
55+
56+
multi := slogmulti.Fanout(jsonHandler, textHandler)
57+
h := log.NewHandlerWithInner(multi)
58+
log.SetDefault(h)
59+
60+
ColdBrew interceptors automatically add grpcMethod, trace ID, and HTTP path
61+
to the context, so these fields appear in all service logs.
3562
*/
3663
package log

0 commit comments

Comments
 (0)