Skip to content

Commit ebdb8a9

Browse files
committed
[jaegermcp] Log tool name in MCP middleware for tools/call requests
The logging middleware currently logs the MCP method (e.g. "tools/call") but not which tool was invoked. This makes it difficult for operators to identify tool-level usage patterns, latency, and errors from logs alone. Extract the tool name from CallToolParamsRaw on tools/call requests and include it as a "tool" field in both request and response log entries. Signed-off-by: lopster568 <lopster568@users.noreply.github.com>
1 parent 766c82d commit ebdb8a9

File tree

2 files changed

+98
-30
lines changed

2 files changed

+98
-30
lines changed

cmd/jaeger/internal/extension/jaegermcp/logging_middleware.go

Lines changed: 24 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -12,6 +12,7 @@ import (
1212
)
1313

1414
// createLoggingMiddleware creates an MCP middleware that logs method calls.
15+
// For tools/call requests it also logs the tool name.
1516
func createLoggingMiddleware(logger *zap.Logger) mcp.Middleware {
1617
return func(next mcp.MethodHandler) mcp.MethodHandler {
1718
return func(
@@ -22,31 +23,40 @@ func createLoggingMiddleware(logger *zap.Logger) mcp.Middleware {
2223
start := time.Now()
2324
sessionID := req.GetSession().ID()
2425

25-
// Log request details.
26-
logger.Info("MCP request",
26+
fields := []zap.Field{
2727
zap.String("session_id", sessionID),
28-
zap.String("method", method))
28+
zap.String("method", method),
29+
}
30+
if toolName := extractToolName(method, req); toolName != "" {
31+
fields = append(fields, zap.String("tool", toolName))
32+
}
33+
34+
logger.Info("MCP request", fields...)
2935

3036
// Call the actual handler.
3137
result, err := next(ctx, method, req)
3238

3339
// Log response details.
34-
duration := time.Since(start)
35-
40+
fields = append(fields, zap.Duration("duration", time.Since(start)))
3641
if err != nil {
37-
logger.Error("MCP response",
38-
zap.String("session_id", sessionID),
39-
zap.String("method", method),
40-
zap.Duration("duration", duration),
41-
zap.Error(err))
42+
fields = append(fields, zap.Error(err))
43+
logger.Error("MCP response", fields...)
4244
} else {
43-
logger.Info("MCP response",
44-
zap.String("session_id", sessionID),
45-
zap.String("method", method),
46-
zap.Duration("duration", duration))
45+
logger.Info("MCP response", fields...)
4746
}
4847

4948
return result, err
5049
}
5150
}
5251
}
52+
53+
// extractToolName returns the tool name from a tools/call request, or empty string otherwise.
54+
func extractToolName(method string, req mcp.Request) string {
55+
if method != "tools/call" {
56+
return ""
57+
}
58+
if params, ok := req.GetParams().(*mcp.CallToolParamsRaw); ok {
59+
return params.Name
60+
}
61+
return ""
62+
}

cmd/jaeger/internal/extension/jaegermcp/logging_middleware_test.go

Lines changed: 74 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -17,37 +17,55 @@ import (
1717
"go.uber.org/zap/zaptest/observer"
1818
)
1919

20-
func TestLoggingMiddleware(t *testing.T) {
21-
zapCore, logs := observer.New(zapcore.DebugLevel)
22-
_, addr := startTestServerWithQueryService(t, nil, zap.New(zapCore))
23-
24-
// Send an MCP initialize request, which passes through the logging middleware.
25-
initReq := `{"jsonrpc":"2.0","id":1,"method":"initialize","params":{"protocolVersion":"2025-03-26","capabilities":{},"clientInfo":{"name":"test","version":"1.0"}}}`
20+
// sendMCPRequest sends a JSON-RPC request to the MCP endpoint and returns
21+
// the session ID from the response.
22+
func sendMCPRequest(t *testing.T, addr, sessionID, body string) string {
23+
t.Helper()
2624
httpReq, err := http.NewRequest(
2725
http.MethodPost,
2826
fmt.Sprintf("http://%s/mcp", addr),
29-
bytes.NewReader([]byte(initReq)),
27+
bytes.NewReader([]byte(body)),
3028
)
3129
require.NoError(t, err)
3230
httpReq.Header.Set("Content-Type", "application/json")
3331
httpReq.Header.Set("Accept", "application/json, text/event-stream")
32+
if sessionID != "" {
33+
httpReq.Header.Set("Mcp-Session-Id", sessionID)
34+
}
3435

3536
resp, err := http.DefaultClient.Do(httpReq)
3637
require.NoError(t, err)
3738
defer resp.Body.Close()
3839
_, err = io.ReadAll(resp.Body)
3940
require.NoError(t, err)
4041

41-
// Clean up the MCP session to avoid goroutine leaks.
42-
sessionID := resp.Header.Get("Mcp-Session-Id")
43-
if sessionID != "" {
44-
delReq, err := http.NewRequest(http.MethodDelete, fmt.Sprintf("http://%s/mcp", addr), http.NoBody)
45-
require.NoError(t, err)
46-
delReq.Header.Set("Mcp-Session-Id", sessionID)
47-
resp2, err := http.DefaultClient.Do(delReq)
48-
require.NoError(t, err)
49-
resp2.Body.Close()
42+
if sid := resp.Header.Get("Mcp-Session-Id"); sid != "" {
43+
return sid
5044
}
45+
return sessionID
46+
}
47+
48+
// deleteMCPSession cleans up an MCP session to avoid goroutine leaks.
49+
func deleteMCPSession(t *testing.T, addr, sessionID string) {
50+
t.Helper()
51+
if sessionID == "" {
52+
return
53+
}
54+
delReq, err := http.NewRequest(http.MethodDelete, fmt.Sprintf("http://%s/mcp", addr), http.NoBody)
55+
require.NoError(t, err)
56+
delReq.Header.Set("Mcp-Session-Id", sessionID)
57+
resp, err := http.DefaultClient.Do(delReq)
58+
require.NoError(t, err)
59+
resp.Body.Close()
60+
}
61+
62+
func TestLoggingMiddleware(t *testing.T) {
63+
zapCore, logs := observer.New(zapcore.DebugLevel)
64+
_, addr := startTestServerWithQueryService(t, nil, zap.New(zapCore))
65+
66+
initReq := `{"jsonrpc":"2.0","id":1,"method":"initialize","params":{"protocolVersion":"2025-03-26","capabilities":{},"clientInfo":{"name":"test","version":"1.0"}}}`
67+
sessionID := sendMCPRequest(t, addr, "", initReq)
68+
t.Cleanup(func() { deleteMCPSession(t, addr, sessionID) })
5169

5270
// The middleware should have emitted one "MCP request" and one "MCP response" entry.
5371
requestLogs := logs.FilterMessage("MCP request").All()
@@ -63,3 +81,43 @@ func TestLoggingMiddleware(t *testing.T) {
6381
assert.NotEmpty(t, respFields["session_id"])
6482
assert.Contains(t, respFields, "duration")
6583
}
84+
85+
func TestLoggingMiddlewareToolName(t *testing.T) {
86+
zapCore, logs := observer.New(zapcore.DebugLevel)
87+
_, addr := startTestServerWithQueryService(t, nil, zap.New(zapCore))
88+
89+
// Initialize session first
90+
initReq := `{"jsonrpc":"2.0","id":1,"method":"initialize","params":{"protocolVersion":"2025-03-26","capabilities":{},"clientInfo":{"name":"test","version":"1.0"}}}`
91+
sessionID := sendMCPRequest(t, addr, "", initReq)
92+
require.NotEmpty(t, sessionID)
93+
t.Cleanup(func() { deleteMCPSession(t, addr, sessionID) })
94+
95+
// Call the health tool
96+
toolReq := `{"jsonrpc":"2.0","id":2,"method":"tools/call","params":{"name":"health","arguments":{}}}`
97+
sendMCPRequest(t, addr, sessionID, toolReq)
98+
99+
// Find the tools/call log entries
100+
allRequests := logs.FilterMessage("MCP request").All()
101+
var toolCallLog *observer.LoggedEntry
102+
for i := range allRequests {
103+
if allRequests[i].ContextMap()["method"] == "tools/call" {
104+
toolCallLog = &allRequests[i]
105+
break
106+
}
107+
}
108+
require.NotNil(t, toolCallLog, "should have a tools/call request log")
109+
assert.Equal(t, "health", toolCallLog.ContextMap()["tool"])
110+
111+
// Verify the response log also has the tool name
112+
allResponses := logs.FilterMessage("MCP response").All()
113+
var toolRespLog *observer.LoggedEntry
114+
for i := range allResponses {
115+
if allResponses[i].ContextMap()["method"] == "tools/call" {
116+
toolRespLog = &allResponses[i]
117+
break
118+
}
119+
}
120+
require.NotNil(t, toolRespLog, "should have a tools/call response log")
121+
assert.Equal(t, "health", toolRespLog.ContextMap()["tool"])
122+
assert.Contains(t, toolRespLog.ContextMap(), "duration")
123+
}

0 commit comments

Comments
 (0)