Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 5 additions & 3 deletions pkg/telemetry/middleware.go
Original file line number Diff line number Diff line change
Expand Up @@ -697,11 +697,13 @@ func (m *HTTPMiddleware) recordMetrics(ctx context.Context, r *http.Request, rw
m.requestDuration.Record(ctx, duration.Seconds(), attrs)

// Record OTEL MCP spec mcp.server.operation.duration for actual MCP requests.
// mcpMethod should never be "unknown" for requests reaching the MCP middleware;
// if it is, the middleware chain is misconfigured (see #3687).
// Only POST requests carry a JSON-RPC body; GET (SSE stream open) and DELETE
// (session termination) are valid Streamable HTTP lifecycle requests with no
// MCP method to record. An unknown method on a POST indicates either a
// misconfigured middleware chain (see #3687) or a parse failure.
if mcpMethod != "unknown" {
m.recordOperationDuration(ctx, r, mcpMethod, mcpResourceID, rw.statusCode, duration)
} else {
} else if r.Method == http.MethodPost {
//nolint:gosec // G706: HTTP method and URL path from request
slog.Warn("mcp method could not be determined, middleware may be misconfigured",
"http_method", r.Method, "path", r.URL.Path)
Expand Down
123 changes: 123 additions & 0 deletions pkg/telemetry/middleware_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -4,8 +4,10 @@
package telemetry

import (
"bytes"
"context"
"encoding/json"
"log/slog"
"net/http"
"net/http/httptest"
"os"
Expand Down Expand Up @@ -2209,6 +2211,127 @@ func TestHTTPMiddleware_OperationDuration(t *testing.T) {
}
}

// TestHTTPMiddleware_UnknownMethodWarning pins down the truth table for the
// "method could not be determined" diagnostic introduced in #3687 and refined
// in #4451:
//
// HTTP method | parsed MCP method | warn? | record operation duration?
// ------------+-------------------+-------+---------------------------
// POST | tools/call | no | yes
// POST | <none> | yes | no
// GET | <none> | no | no
// DELETE | <none> | no | no
//
// GET (SSE stream open) and DELETE (session termination) are valid Streamable
// HTTP lifecycle requests with no JSON-RPC body, so warning on them produces
// noise rather than signal. POST without a parsed method retains the warning
// because it indicates a real misconfiguration on the JSON-RPC path.
//
// Subtests redirect slog.Default (process-global), so they must not run in
// parallel.
//
//nolint:paralleltest,tparallel // Subtests redirect slog.Default, which is process-global state
func TestHTTPMiddleware_UnknownMethodWarning(t *testing.T) {
tests := []struct {
name string
httpMethod string
mcpRequest *mcpparser.ParsedMCPRequest
expectWarn bool
expectMetric bool
}{
{
name: "POST with parsed MCP method records duration and does not warn",
httpMethod: http.MethodPost,
mcpRequest: &mcpparser.ParsedMCPRequest{
Method: "tools/call",
ID: "1",
IsRequest: true,
},
expectWarn: false,
expectMetric: true,
},
{
name: "POST without parsed MCP method warns and does not record duration",
httpMethod: http.MethodPost,
mcpRequest: nil,
expectWarn: true,
expectMetric: false,
},
{
name: "GET to /mcp does not warn (SSE stream open)",
httpMethod: http.MethodGet,
mcpRequest: nil,
expectWarn: false,
expectMetric: false,
},
{
name: "DELETE to /mcp does not warn (session termination)",
httpMethod: http.MethodDelete,
mcpRequest: nil,
expectWarn: false,
expectMetric: false,
},
}

for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
var buf bytes.Buffer
handler := slog.NewJSONHandler(&buf, &slog.HandlerOptions{Level: slog.LevelWarn})
orig := slog.Default()
slog.SetDefault(slog.New(handler))
t.Cleanup(func() { slog.SetDefault(orig) })

reader := sdkmetric.NewManualReader()
meterProvider := sdkmetric.NewMeterProvider(sdkmetric.WithReader(reader))

middleware := NewHTTPMiddleware(
Config{ServiceName: "test-service", ServiceVersion: "1.0.0"},
tracenoop.NewTracerProvider(),
meterProvider,
"test-server",
"streamable-http",
)

wrappedHandler := middleware(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
w.WriteHeader(http.StatusOK)
}))

req := httptest.NewRequest(tt.httpMethod, "/mcp", nil)
if tt.mcpRequest != nil {
ctx := context.WithValue(req.Context(), mcpparser.MCPRequestContextKey, tt.mcpRequest)
req = req.WithContext(ctx)
}
rec := httptest.NewRecorder()
wrappedHandler.ServeHTTP(rec, req)

logged := buf.String()
if tt.expectWarn {
require.Contains(t, logged, "mcp method could not be determined",
"expected WARN for %s with no parsed MCP method", tt.httpMethod)
// Operators rely on these attributes to identify the offending traffic.
assert.Contains(t, logged, `"http_method":"`+tt.httpMethod+`"`)
assert.Contains(t, logged, `"path":"/mcp"`)
} else {
assert.NotContains(t, logged, "mcp method could not be determined",
"unexpected WARN for %s /mcp", tt.httpMethod)
}

var rm metricdata.ResourceMetrics
require.NoError(t, reader.Collect(context.Background(), &rm))
var hasOperationDuration bool
for _, sm := range rm.ScopeMetrics {
for _, m := range sm.Metrics {
if m.Name == metricOperationDuration {
hasOperationDuration = true
}
}
}
assert.Equal(t, tt.expectMetric, hasOperationDuration,
"mcp.server.operation.duration presence should match expectation")
})
}
}

func TestRecordSSEConnection_DualEmission(t *testing.T) {
t.Parallel()

Expand Down
Loading