feat(server): WithLogger consolidates structured logging onto *slog.Logger#892
feat(server): WithLogger consolidates structured logging onto *slog.Logger#892QuentinBisson wants to merge 1 commit into
Conversation
|
Connected to Huly®: MCP_G-457 |
|
Note Reviews pausedIt looks like this branch is under active development. To avoid overwhelming you with review comments due to an influx of new commits, CodeRabbit has automatically paused this review. You can configure this behavior by changing the Use the following commands to manage reviews:
Use the checkboxes below for quick actions:
WalkthroughMigrate logging from a custom util.Logger to Go's log/slog across client transports and server; add structured per-request and per-tool server logs; introduce an OTEL slog bridge and tests; update tests to capture slog records and remove the legacy util logger. ChangesStructured logger migration
Estimated code review effort🎯 4 (Complex) | ⏱️ ~75 minutes Possibly related PRs
Suggested labels
Suggested reviewers
🚥 Pre-merge checks | ✅ 4 | ❌ 1❌ Failed checks (1 warning)
✅ Passed checks (4 passed)
✏️ Tip: You can configure your own custom pre-merge checks in the settings. ✨ Finishing Touches🧪 Generate unit tests (beta)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
86b4abe to
6b9a6da
Compare
6b9a6da to
39e19a1
Compare
|
@ezynda3 — would love your read on this PR's direction before going further. Two concrete questions:
Either way, the protocol-level lines this option emits (`mcp.request`, `mcp.tool`, with matching attributes to `WithTracer`) are the part that actually matters; happy to break the PR up if the consolidation is too much in one go. |
There was a problem hiding this comment.
🧹 Nitpick comments (1)
server/logger_test.go (1)
46-163: ⚡ Quick winAlign this suite with repo test conventions (
testify+ table-driven format).These new tests currently rely on
t.Fatalfand one-off test bodies; please migrate to table-driven tests usingassert/requirefor consistency and maintainability.As per coding guidelines
**/*_test.go: "Usetestify/assertandtestify/requirefor testing; implement table-driven tests withtests := []struct{ name, ... }."🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@server/logger_test.go` around lines 46 - 163, The tests in TestWithLogger_* use t.Fatalf and one-off bodies instead of the repo convention of table-driven tests with testify; refactor each TestWithLogger_* (e.g., TestWithLogger_NilIsNoOp, TestWithLogger_EmitsRequestLineOnHandled, TestWithLogger_EmitsErrorOnJSONRPCError, TestWithLogger_RegistersToolMiddleware, TestWithLogger_ToolMiddleware_HandlerError, TestWithLogger_ToolMiddleware_IsErrorResult) into table-driven subtests using a tests := []struct{name string; ...} slice and t.Run for each case, replace t.Fatalf checks with testify/require or assert calls (require for fatal preconditions, assert for expectations), and keep existing helpers (newLoggerCapturingTo, s.startMessageLog, toolLoggingMiddleware, decodeLines, findLine) while consolidating repeated setup into the table entries to reduce duplication and improve readability.
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Nitpick comments:
In `@server/logger_test.go`:
- Around line 46-163: The tests in TestWithLogger_* use t.Fatalf and one-off
bodies instead of the repo convention of table-driven tests with testify;
refactor each TestWithLogger_* (e.g., TestWithLogger_NilIsNoOp,
TestWithLogger_EmitsRequestLineOnHandled,
TestWithLogger_EmitsErrorOnJSONRPCError, TestWithLogger_RegistersToolMiddleware,
TestWithLogger_ToolMiddleware_HandlerError,
TestWithLogger_ToolMiddleware_IsErrorResult) into table-driven subtests using a
tests := []struct{name string; ...} slice and t.Run for each case, replace
t.Fatalf checks with testify/require or assert calls (require for fatal
preconditions, assert for expectations), and keep existing helpers
(newLoggerCapturingTo, s.startMessageLog, toolLoggingMiddleware, decodeLines,
findLine) while consolidating repeated setup into the table entries to reduce
duplication and improve readability.
ℹ️ Review info
⚙️ Run configuration
Configuration used: Repository UI
Review profile: CHILL
Plan: Pro
Run ID: 2a7eeacc-d058-45b7-a0f1-7f2a060561a8
⛔ Files ignored due to path filters (1)
server/internal/gen/request_handler.go.tmplis excluded by!**/gen/**
📒 Files selected for processing (13)
client/transport/panic_recovery_test.goclient/transport/sse.goclient/transport/sse_test.goclient/transport/stdio.goclient/transport/stdio_test.goclient/transport/streamable_http.goclient/transport/streamable_http_test.goserver/logger.goserver/logger_test.goserver/request_handler.goserver/server.goserver/streamable_http.goutil/logger.go
💤 Files with no reviewable changes (1)
- util/logger.go
39e19a1 to
9b20cf3
Compare
|
Pushed an OTEL convenience pair on the `otel/` submodule so users wiring all three observability signals get parallel call sites — `otel.WithServerLogging(provider, scope)` alongside the existing `otel.WithServerTracing` / `otel.WithServerMetrics`. Implementation is a one-liner over `go.opentelemetry.io/contrib/bridges/otelslog`: ```go Core `server.WithLogger` still takes `*slog.Logger` directly — non-OTEL users (Loki/stdlib JSON/plain stderr) keep that path. Reasoning: `tracing` and `metrics` abstract because Go has no stdlib equivalent; `slog` is stdlib, so taking it directly is the more idiomatic choice and lets handlers compose. The `server.WithLogger` docstring now points at `otel.WithServerLogging` for callers who want OTEL log correlation, so the discoverability path is clear. |
There was a problem hiding this comment.
Actionable comments posted: 1
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Inline comments:
In `@otel/logger_test.go`:
- Around line 68-73: The test incorrectly calls kv.Value.AsString() for all
attributes in records[0].WalkAttributes, which fails for Float64 attributes like
"duration_s"; update the attribute handling in the WalkAttributes callback to
switch on kv.Value.Type() (or use the provided type methods) and call AsString()
for string values and AsFloat64() for float values (or convert AsFloat64() to a
string if you must keep the attrs map as map[string]string), then assert
"duration_s" using the numeric value or its formatted string; reference the
WalkAttributes callback, log.KeyValue, kv.Value.AsString(),
kv.Value.AsFloat64(), and the "duration_s" key when making the change.
🪄 Autofix (Beta)
Fix all unresolved CodeRabbit comments on this PR:
- Push a commit to this branch (recommended)
- Create a new PR with the fixes
ℹ️ Review info
⚙️ Run configuration
Configuration used: Repository UI
Review profile: CHILL
Plan: Pro
Run ID: 05fc97b6-88c5-49e8-bca1-253b810a74c3
⛔ Files ignored due to path filters (2)
otel/go.sumis excluded by!**/*.sumserver/internal/gen/request_handler.go.tmplis excluded by!**/gen/**
📒 Files selected for processing (16)
client/transport/panic_recovery_test.goclient/transport/sse.goclient/transport/sse_test.goclient/transport/stdio.goclient/transport/stdio_test.goclient/transport/streamable_http.goclient/transport/streamable_http_test.gootel/go.modotel/logger.gootel/logger_test.goserver/logger.goserver/logger_test.goserver/request_handler.goserver/server.goserver/streamable_http.goutil/logger.go
💤 Files with no reviewable changes (1)
- util/logger.go
✅ Files skipped from review due to trivial changes (1)
- client/transport/stdio_test.go
🚧 Files skipped from review as they are similar to previous changes (11)
- client/transport/sse_test.go
- server/request_handler.go
- server/server.go
- client/transport/panic_recovery_test.go
- server/logger.go
- client/transport/streamable_http_test.go
- client/transport/stdio.go
- client/transport/sse.go
- server/logger_test.go
- server/streamable_http.go
- client/transport/streamable_http.go
9b20cf3 to
f763122
Compare
|
@coderabbitai — addressed in the latest push. The five `TestWithLogger_*` tests are consolidated into three table-driven test functions using `testify/assert` + `testify/require`:
All assertions migrated to `require` (fatal preconditions) / `assert` (expectations). 6 subtests in total, all green. |
|
Tip For best results, initiate chat on the files or code changes.
If you found this review helpful, would you consider giving us a shout-out on X? Thank you for using CodeRabbit! |
There was a problem hiding this comment.
Actionable comments posted: 2
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Inline comments:
In `@client/transport/streamable_http.go`:
- Around line 76-82: The option closure WithHTTPLogger currently mutates the
captured parameter `logger` (e.g., `logger = slog.Default()`), which can cause
races when the same option is reused; change the closure to avoid reassigning
the captured variable by setting `sc.logger` directly: inside the returned
function check `if logger == nil` and assign `sc.logger = slog.Default()` else
`sc.logger = logger`, leaving the captured `logger` unchanged—this fixes the
race while keeping the behavior of `WithHTTPLogger` on `StreamableHTTP` via the
`StreamableHTTPCOption` type.
🪄 Autofix (Beta)
Fix all unresolved CodeRabbit comments on this PR:
- Push a commit to this branch (recommended)
- Create a new PR with the fixes
ℹ️ Review info
⚙️ Run configuration
Configuration used: Repository UI
Review profile: CHILL
Plan: Pro
Run ID: a9518314-32c8-4c55-b409-0873fcd1b19d
⛔ Files ignored due to path filters (2)
otel/go.sumis excluded by!**/*.sumserver/internal/gen/request_handler.go.tmplis excluded by!**/gen/**
📒 Files selected for processing (16)
client/transport/panic_recovery_test.goclient/transport/sse.goclient/transport/sse_test.goclient/transport/stdio.goclient/transport/stdio_test.goclient/transport/streamable_http.goclient/transport/streamable_http_test.gootel/go.modotel/logger.gootel/logger_test.goserver/logger.goserver/logger_test.goserver/request_handler.goserver/server.goserver/streamable_http.goutil/logger.go
💤 Files with no reviewable changes (1)
- util/logger.go
✅ Files skipped from review due to trivial changes (2)
- client/transport/sse_test.go
- otel/logger.go
🚧 Files skipped from review as they are similar to previous changes (11)
- client/transport/stdio_test.go
- server/request_handler.go
- otel/logger_test.go
- client/transport/streamable_http_test.go
- otel/go.mod
- server/logger.go
- client/transport/sse.go
- server/server.go
- server/streamable_http.go
- client/transport/panic_recovery_test.go
- client/transport/stdio.go
f763122 to
c3e2ff3
Compare
|
@coderabbitai — addressed the otel/logger_test.go bug. `kv.Value.AsString()` was being called on every attribute including the `duration_s` Float64, which would silently return garbage. Switched to a type-aware walker that uses `AsString` for the method key and `AsFloat64` for the duration, with separate assertions: ```go Force-pushed. |
|
Tip For best results, initiate chat on the files or code changes. 🧩 Analysis chain🏁 Script executed: Length of output: 2244
One minor nit worth a second look: require.Equal(t, 0.001, gotDuration) // explicit exact equality
// or
require.InDelta(t, 0.001, gotDuration, 1e-9) // still deterministic, but reads as "float comparison with tolerance"Neither is broken; it's purely a readability call. |
There was a problem hiding this comment.
🧹 Nitpick comments (1)
client/transport/sse_test.go (1)
786-793: 💤 Low valueConsider using testify assertions for consistency.
The test uses
requirefor some assertions (lines 775, 782) but reverts to manualt.Errorfandt.Fatalfor the log message checks. For consistency with the coding guidelines and the rest of the test, consider using testify assertions.♻️ Refactor to use testify consistently
// Wait for the error log message about unmarshaling select { case logMsg := <-logChan: - if !strings.Contains(logMsg, "Error unmarshaling message") { - t.Errorf("Expected error log about unmarshaling message, got: %s", logMsg) - } + require.Contains(t, logMsg, "Error unmarshaling message", "Expected error log about unmarshaling message") case <-time.After(3 * time.Second): - t.Fatal("Timeout waiting for error log message") + require.Fail(t, "Timeout waiting for error log message") }As per coding guidelines, use
testify/assertandtestify/requirefor testing.🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@client/transport/sse_test.go` around lines 786 - 793, The test mixes manual t.Errorf/t.Fatal with testify; replace the select block that reads from logChan and uses strings.Contains and t.Errorf/t.Fatal with testify assertions for consistency: use require.Eventually (or require.Eventuallyf) to wait up to 3s for a message on logChan and then use assert.Contains to assert the message contains "Error unmarshaling message"; update the code referencing logChan and strings.Contains and remove the t.Errorf/t.Fatal calls so the test uses testify/assert and testify/require consistently.
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Nitpick comments:
In `@client/transport/sse_test.go`:
- Around line 786-793: The test mixes manual t.Errorf/t.Fatal with testify;
replace the select block that reads from logChan and uses strings.Contains and
t.Errorf/t.Fatal with testify assertions for consistency: use require.Eventually
(or require.Eventuallyf) to wait up to 3s for a message on logChan and then use
assert.Contains to assert the message contains "Error unmarshaling message";
update the code referencing logChan and strings.Contains and remove the
t.Errorf/t.Fatal calls so the test uses testify/assert and testify/require
consistently.
ℹ️ Review info
⚙️ Run configuration
Configuration used: Repository UI
Review profile: CHILL
Plan: Pro
Run ID: 4cf604e6-4af7-4fe6-a5e7-862a3fa5224b
⛔ Files ignored due to path filters (2)
otel/go.sumis excluded by!**/*.sumserver/internal/gen/request_handler.go.tmplis excluded by!**/gen/**
📒 Files selected for processing (16)
client/transport/panic_recovery_test.goclient/transport/sse.goclient/transport/sse_test.goclient/transport/stdio.goclient/transport/stdio_test.goclient/transport/streamable_http.goclient/transport/streamable_http_test.gootel/go.modotel/logger.gootel/logger_test.goserver/logger.goserver/logger_test.goserver/request_handler.goserver/server.goserver/streamable_http.goutil/logger.go
💤 Files with no reviewable changes (1)
- util/logger.go
✅ Files skipped from review due to trivial changes (1)
- client/transport/stdio_test.go
🚧 Files skipped from review as they are similar to previous changes (12)
- client/transport/panic_recovery_test.go
- otel/logger.go
- server/request_handler.go
- server/server.go
- client/transport/streamable_http_test.go
- server/logger.go
- otel/go.mod
- server/streamable_http.go
- client/transport/sse.go
- server/logger_test.go
- client/transport/stdio.go
- client/transport/streamable_http.go
c3e2ff3 to
4b9cc49
Compare
|
@coderabbitai — both addressed in the latest push. Closure variable mutation (race): the `With*Logger` options previously did `if logger == nil { logger = slog.Default() }` which reassigned the captured parameter; reusing the same option across multiple servers/transports would race. Fixed across all four sites (`WithCommandLogger`, `WithSSELogger`, `WithHTTPLogger`, `WithStreamableHTTPLogger`) by assigning the default directly to the field and early-returning: ```go `server.WithLogger` (the protocol-level option) didn't have this pattern — it never reassigned `logger` — but checked it anyway. Test assertion consistency in sse_test.go: the unmarshaling-error select block mixed `t.Errorf` / `t.Fatal` with the surrounding `require` style. Switched to `require.Contains` / `require.Fail`: ```go Force-pushed; `go test ./...` clean. |
|
Tip For best results, initiate chat on the files or code changes. 🧩 Analysis chain🏁 Script executed: Length of output: 1515
Closure variable mutation: All four sites follow the safe pattern — the captured if logger == nil {
s.logger = slog.Default()
return
}
s.logger = loggerThis correctly eliminates the race when an option closure is reused across multiple server/transport instances.
Both look great. 🐇✨ |
…ogger
Replace the bespoke util.Logger printf interface with stdlib *slog.Logger
across the server and client transports. Promote the new
WithRequestLogger option to WithLogger as the single canonical entry
point for server-side structured logging; rename the existing
transport-server WithLogger to WithStreamableHTTPLogger so the two no
longer compete for the same name in package server.
Concrete surface:
- util.Logger and util.DefaultLogger are removed; the util/ package
is gone.
- All transport logger fields and With*Logger options now take
*slog.Logger; nil falls back to slog.Default(). Affected:
server.WithStreamableHTTPLogger (renamed from WithLogger),
transport.WithCommandLogger, transport.WithSSELogger,
transport.WithHTTPLogger, transport.WithLogger (deprecated alias).
- server.WithLogger installs a server-wide *slog.Logger that emits
one mcp.request line per JSON-RPC dispatch (attributes mcp.method,
mcp.session.id, mcp.protocol.version, duration_s, outcome, error)
and one mcp.tool line per tool handler invocation (mcp.tool.name,
duration_s, outcome, error). Lines inherit the active span's
TraceID/SpanID when WithTracer is installed.
- Every existing Infof/Errorf call site is rewritten to slog Info/Error
with structured key-value pairs (err, panic, method, session, …).
Behavioural change for callers: WithLogger no longer takes
util.Logger. Pre-1.0 library; callers who construct their own
util.Logger implementation switch to *slog.Logger.
4b9cc49 to
5deabdc
Compare
|
@coderabbitai — addressed the payload-logging concern at both sites in `client/transport/streamable_http.go`. The original code at those sites already logged the raw payloads (`Errorf("...:%s", data)` / `Errorf("...:%s", body)`) so my slog rewrite carried the regression forward; this PR is the right moment to tighten: ```go // line 1132 Operators who need the raw payload for debugging can still capture it via a transport-level interceptor or by bumping log verbosity in a wrapper; the default no longer leaks request/response bodies into log pipelines. Force-pushed. |
|
Tip For best results, initiate chat on the files or code changes. 🧩 Analysis chain🏁 Script executed: Length of output: 569
Both fixes are clean. Logging the byte length still gives operators a useful signal (e.g. unexpectedly large or empty payloads) without risking credential or PII leakage into log pipelines. |
Why
The server has `WithTracer` for OTEL spans on every dispatched JSON-RPC method (#856) but no symmetric primitive for structured logging. The existing logger surface is fragmented:
Users who want structured logs today either wrap individual tool handlers in their own `ToolHandlerMiddleware` (only sees `tools/call`) or implement `util.Logger` against their slog backend twice — once per transport.
What
Single `*slog.Logger`-based logging concept across the server and the client transports.
`util.Logger` removed. The `util/` package is gone. Every `util.Logger` field and every `With*Logger` option now takes `*slog.Logger`. A nil logger falls back to `slog.Default()`. Every `Infof`/`Errorf` call site is rewritten to slog `Info`/`Error` with structured key-value pairs (`err`, `panic`, `method`, `session`, …).
*`server.WithLogger(slog.Logger) ServerOption` (new) — server-wide structured logger. The server emits:
Lines inherit the active span's TraceID/SpanID via slog's context-aware handlers when a Tracer is installed via `WithTracer`, so log records can be joined with spans in observability backends.
Renames to free the `WithLogger` name on `MCPServer`:
Design parity with WithTracer
Breaking changes
Pre-1.0 library, no soft-deprecation period.
Validation
`go test ./...` clean — 14 packages, every transport's test suite included. Five new tests on `WithLogger` (server) cover nil-noop, request-line OK, JSON-RPC error outcome, tool middleware OK, tool middleware error, tool middleware IsError. Existing transport tests' bespoke `testLogger` / `panicTestLogger` types were rewritten to implement `slog.Handler` instead of `util.Logger`; they continue to capture messages for assertions.
Summary by CodeRabbit
New Features
Refactor
Tests