diff --git a/internal/server/scope_latency_profile_v3_test.go b/internal/server/scope_latency_profile_v3_test.go index fb0ad44c7..6cf710de1 100644 --- a/internal/server/scope_latency_profile_v3_test.go +++ b/internal/server/scope_latency_profile_v3_test.go @@ -86,15 +86,6 @@ func TestScopeLatency_ProfileV3VsLegacy(t *testing.T) { const warmup = 20 const timed = 200 - measure := func(ctx context.Context) []time.Duration { - req := mcp.CallToolRequest{} - req.Params.Arguments = map[string]interface{}{"query": query, "limit": float64(limit)} - return measureLatency(t, ctx, warmup, timed, func(ctx context.Context) error { - _, err := proxy.handleRetrieveTools(ctx, req) - return err - }) - } - legacyCtx := profile.WithProfileScope(context.Background(), proxy.profileScopeForSlug("legacy-samescope")) v3Ctx := profile.WithProfileScope(context.Background(), proxy.profileScopeForSlug("v3-cap-read")) @@ -118,8 +109,15 @@ func TestScopeLatency_ProfileV3VsLegacy(t *testing.T) { "%s: per-profile index must hold real matching documents, not an empty ForProfile index never populated by RebuildProfileFromShared", slug) } - legacyDurations := measure(legacyCtx) - v3Durations := measure(v3Ctx) + req := mcp.CallToolRequest{} + req.Params.Arguments = map[string]interface{}{"query": query, "limit": float64(limit)} + // Arms interleaved (measureInterleaved) so a runner noise burst cannot land + // on one arm alone. + legacyDurations, v3Durations := measureInterleaved(t, legacyCtx, v3Ctx, warmup, timed, + func(ctx context.Context) error { + _, err := proxy.handleRetrieveTools(ctx, req) + return err + }) pLegacy, pV3 := p95(legacyDurations), p95(v3Durations) gap := pV3 - pLegacy diff --git a/internal/server/scope_latency_test.go b/internal/server/scope_latency_test.go index 38827240e..c2a6144e8 100644 --- a/internal/server/scope_latency_test.go +++ b/internal/server/scope_latency_test.go @@ -105,27 +105,15 @@ func TestRetrieveTools_ScopeLatency_ScopedVsAdmin(t *testing.T) { const warmup = 20 const timed = 200 - measure := func(ctx context.Context) []time.Duration { - req := mcp.CallToolRequest{} - req.Params.Arguments = map[string]interface{}{"query": query, "limit": float64(limit)} - - for i := 0; i < warmup; i++ { - _, err := proxy.handleRetrieveTools(ctx, req) - require.NoError(t, err) - } - - durations := make([]time.Duration, 0, timed) - for i := 0; i < timed; i++ { - start := time.Now() + req := mcp.CallToolRequest{} + req.Params.Arguments = map[string]interface{}{"query": query, "limit": float64(limit)} + // Arms interleaved (see measureInterleaved): a runner noise burst must not + // land on one arm alone. + scopedDurations, adminDurations := measureInterleaved(t, scopedCtx, adminScopeCtx, warmup, timed, + func(ctx context.Context) error { _, err := proxy.handleRetrieveTools(ctx, req) - durations = append(durations, time.Since(start)) - require.NoError(t, err) - } - return durations - } - - scopedDurations := measure(scopedCtx) - adminDurations := measure(adminScopeCtx) + return err + }) p95Scoped := p95(scopedDurations) p95Admin := p95(adminDurations) @@ -154,7 +142,13 @@ func TestRetrieveTools_ScopeLatency_ScopedVsAdmin(t *testing.T) { // same reason as T078. // measureLatency runs warm-up then timed calls of fn under ctx and returns -// the timed durations. +// the timed durations. Single-arm; two-arm comparisons use measureInterleaved. +// +// Kept (unused here) because scope-latency.yml copies this file over a +// merge-base checkout whose own scope_latency_profile_v3_test.go may still +// call it. +// +//nolint:unused func measureLatency(t *testing.T, ctx context.Context, warmup, timed int, fn func(context.Context) error) []time.Duration { t.Helper() for i := 0; i < warmup; i++ { @@ -169,6 +163,41 @@ func measureLatency(t *testing.T, ctx context.Context, warmup, timed int, fn fun return durations } +// measureInterleaved is measureLatency for a two-arm comparison (scoped vs +// admin, legacy vs v3). Both arms are warmed up, then each timed iteration +// times ONE call of each arm back to back, alternating which arm goes first +// (arm A first on even i, arm B first on odd i) so ordering bias cancels. +// +// Why interleave: measuring one arm's 200 calls and then the other's lets a +// shared-runner noise burst land on a single arm and show up as a false p95 +// gap (#1465: 29.6 ms on read_cache; #1387). Interleaved, a burst hits both +// arms alike. The budget, p95 and recordAdminLatencyResult are unchanged; only +// the sampling order differs. measureLatency is kept for merge-base callers. +func measureInterleaved(t *testing.T, ctxA, ctxB context.Context, warmup, timed int, fn func(context.Context) error) (a, b []time.Duration) { + t.Helper() + for i := 0; i < warmup; i++ { + require.NoError(t, fn(ctxA)) + require.NoError(t, fn(ctxB)) + } + a = make([]time.Duration, 0, timed) + b = make([]time.Duration, 0, timed) + timeOne := func(ctx context.Context) time.Duration { + start := time.Now() + require.NoError(t, fn(ctx)) + return time.Since(start) + } + for i := 0; i < timed; i++ { + if i%2 == 0 { + a = append(a, timeOne(ctxA)) + b = append(b, timeOne(ctxB)) + } else { + b = append(b, timeOne(ctxB)) + a = append(a, timeOne(ctxA)) + } + } + return a, b +} + // assertScopedWithinBudget is the FR-011 SC-006 assertion shared by every // operation below. func assertScopedWithinBudget(t *testing.T, op string, scoped, admin []time.Duration) { @@ -226,8 +255,7 @@ func TestScopeLatency_ReadCache_ScopedVsAdmin(t *testing.T) { return nil } - adminDurations := measureLatency(t, adminCtx(), 20, 200, call) - scopedDurations := measureLatency(t, scopedCtx, 20, 200, call) + scopedDurations, adminDurations := measureInterleaved(t, scopedCtx, adminCtx(), 20, 200, call) assertScopedWithinBudget(t, "read_cache", scopedDurations, adminDurations) } @@ -301,8 +329,7 @@ func TestScopeLatency_PromptsList_ScopedVsAdmin(t *testing.T) { } return nil } - adminDurations := measureLatency(t, adminCtx(), 20, 200, call) - scopedDurations := measureLatency(t, scopedCtx, 20, 200, call) + scopedDurations, adminDurations := measureInterleaved(t, scopedCtx, adminCtx(), 20, 200, call) assertScopedWithinBudget(t, "prompts/list", scopedDurations, adminDurations) } @@ -367,8 +394,7 @@ func TestScopeLatency_ToolsList_ScopedVsAdmin(t *testing.T) { } return nil } - adminDurations := measureLatency(t, adminCtx(), 20, 200, call) - scopedDurations := measureLatency(t, scopedCtx, 20, 200, call) + scopedDurations, adminDurations := measureInterleaved(t, scopedCtx, adminCtx(), 20, 200, call) assertScopedWithinBudget(t, "tools/list", scopedDurations, adminDurations) } @@ -430,3 +456,50 @@ func p95(durations []time.Duration) time.Duration { } return sorted[idx] } + +// TestMeasureInterleaved pins the sampler's contract: warm-up excluded, equal +// sample counts, alternating order, and a contiguous slow burst spreads over +// both arms instead of landing on one. +func TestMeasureInterleaved(t *testing.T) { + type key struct{} + ctxA := context.WithValue(context.Background(), key{}, "A") + ctxB := context.WithValue(context.Background(), key{}, "B") + + var order []string + calls := 0 + const warmup, timed = 3, 10 + a, b := measureInterleaved(t, ctxA, ctxB, warmup, timed, func(ctx context.Context) error { + calls++ + order = append(order, ctx.Value(key{}).(string)) + // A slow burst over a contiguous run of calls in the timed phase. + if calls > 2*warmup+4 && calls <= 2*warmup+8 { + time.Sleep(3 * time.Millisecond) + } + return nil + }) + require.Len(t, a, timed) + require.Len(t, b, timed) + require.Equal(t, 2*warmup+2*timed, calls) + + timedOrder := order[2*warmup:] + for i := 0; i < timed; i++ { + first, second := "A", "B" + if i%2 == 1 { + first, second = "B", "A" + } + require.Equal(t, first, timedOrder[2*i], "iteration %d first arm", i) + require.Equal(t, second, timedOrder[2*i+1], "iteration %d second arm", i) + } + + slow := func(ds []time.Duration) int { + n := 0 + for _, d := range ds { + if d >= 2*time.Millisecond { + n++ + } + } + return n + } + require.Positive(t, slow(a), "burst must reach arm A") + require.Positive(t, slow(b), "burst must reach arm B") +} diff --git a/internal/server/workspace.go b/internal/server/workspace.go index 4e4f22b7f..fdd2935f1 100644 --- a/internal/server/workspace.go +++ b/internal/server/workspace.go @@ -71,26 +71,10 @@ func fetchWorkspaceRoot(ctx context.Context, srv *mcpserver.MCPServer, store *Se // client answers, and its context dies with it. base := context.WithoutCancel(ctx) - var result *mcp.ListRootsResult - var err error - for attempt := 1; attempt <= workspaceFetchAttempts; attempt++ { - // Stop if the client went away mid-fetch — no point asking a ghost, and - // no point holding a goroutine open for it. - if store.GetSession(sessionID) == nil { - return - } - - fetchCtx, cancel := context.WithTimeout(base, workspaceFetchTimeout) - result, err = srv.RequestRoots(fetchCtx, mcp.ListRootsRequest{}) - cancel() - - if err == nil && result != nil && len(result.Roots) > 0 { - break - } - if attempt < workspaceFetchAttempts { - time.Sleep(workspaceFetchRetryDelay) - } - } + result, err := fetchRootsWithRetry(base, store, sessionID, workspaceFetchRetryDelay, + func(fetchCtx context.Context) (*mcp.ListRootsResult, error) { + return srv.RequestRoots(fetchCtx, mcp.ListRootsRequest{}) + }) if err != nil { // Entirely expected for clients that do not support roots (measured: @@ -121,6 +105,43 @@ func fetchWorkspaceRoot(ctx context.Context, srv *mcpserver.MCPServer, store *Se ) } +// fetchRootsWithRetry runs request up to workspaceFetchAttempts times, stopping +// early on a non-empty answer or once the session is gone. +// +// "Gone" includes soft-closed: RemoveSession keeps the entry (marked closed) for +// closedSessionTTL, so a plain GetSession()==nil test would keep asking a +// disconnected client for the rest of the retry budget. A session reopened on +// the same id is open again and keeps fetching. +func fetchRootsWithRetry( + base context.Context, + store *SessionStore, + sessionID string, + retryDelay time.Duration, + request func(context.Context) (*mcp.ListRootsResult, error), +) (*mcp.ListRootsResult, error) { + var result *mcp.ListRootsResult + var err error + for attempt := 1; attempt <= workspaceFetchAttempts; attempt++ { + // Stop if the client went away mid-fetch — no point asking a ghost, and + // no point holding a goroutine open for it. + if info := store.GetSession(sessionID); info == nil || info.closed { + return result, err + } + + fetchCtx, cancel := context.WithTimeout(base, workspaceFetchTimeout) + result, err = request(fetchCtx) + cancel() + + if err == nil && result != nil && len(result.Roots) > 0 { + break + } + if attempt < workspaceFetchAttempts { + time.Sleep(retryDelay) + } + } + return result, err +} + // principalFromContext identifies who is making the request, for work-session // grouping (Spec 082 FR-006). // diff --git a/internal/server/workspace_test.go b/internal/server/workspace_test.go new file mode 100644 index 000000000..e171da0bb --- /dev/null +++ b/internal/server/workspace_test.go @@ -0,0 +1,52 @@ +package server + +import ( + "context" + "errors" + "testing" + "time" + + "github.com/mark3labs/mcp-go/mcp" + "go.uber.org/zap" +) + +func TestFetchRootsWithRetry_StopsWhenSessionSoftClosed(t *testing.T) { + store := NewSessionStore(zap.NewNop()) + store.SetSession("s1", "client", "1", true, false, nil) + + calls := 0 + req := func(context.Context) (*mcp.ListRootsResult, error) { + calls++ + store.RemoveSession("s1") // client disconnects after the first attempt + return nil, errors.New("no roots") + } + + start := time.Now() + _, err := fetchRootsWithRetry(context.Background(), store, "s1", 5*time.Millisecond, req) + if err == nil { + t.Fatal("expected the last error to be returned") + } + if calls != 1 { + t.Fatalf("RequestRoots calls = %d, want 1 (no fetch for a closed session)", calls) + } + if time.Since(start) > time.Second { + t.Fatalf("did not return promptly: %v", time.Since(start)) + } +} + +func TestFetchRootsWithRetry_ReopenedSessionKeepsFetching(t *testing.T) { + store := NewSessionStore(zap.NewNop()) + store.SetSession("s1", "client", "1", true, false, nil) + store.RemoveSession("s1") + store.Reopen("s1") + + calls := 0 + req := func(context.Context) (*mcp.ListRootsResult, error) { + calls++ + return nil, errors.New("not yet") + } + _, _ = fetchRootsWithRetry(context.Background(), store, "s1", time.Millisecond, req) + if calls != workspaceFetchAttempts { + t.Fatalf("calls = %d, want %d", calls, workspaceFetchAttempts) + } +}