From 03116a97d14b0c8a3e969446ca5254efc88076f7 Mon Sep 17 00:00:00 2001 From: Oliver Kieselbach Date: Sat, 5 Sep 2026 01:33:44 +0200 Subject: [PATCH] =?UTF-8?q?mcp:=20one=20correlation=20id=20per=20tool=20ca?= =?UTF-8?q?ll=20=E2=80=94=20sent=20to=20the=20backend,=20logged,=20shown?= =?UTF-8?q?=20in=20every=20error?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit withToolTelemetry mints a UUID per tool call and runs the handler in a ToolCallContext (tool name + correlation id); apiFetch stamps it as X-Correlation-ID next to X-MCP-Tool-Name, so every backend request of the call (pagination scans included) and the MCP_TOOL_LOGGING tool_call line carry the same id — a row-level join between the MCP log and the backend's request rows. ApiError reads the X-Correlation-ID response header (body correlationId as fallback), and the error handler names it in every branch — 5xx, quota 429, structured 4xx and the unstructured 401/403/404/429 texts that had none. The handler reads the envelope's `code` (errorCode as the pre-envelope fallback), the quota body's `error`, and the log proxy's `upstreamCode`. Co-Authored-By: Claude Fable 5.1 --- .../src/__tests__/client-headers.test.ts | 69 +++++++++++++++++++ .../src/__tests__/error-handler.test.ts | 44 ++++++++++++ .../src/__tests__/telemetry.test.ts | 2 + .../autopilot-monitor-mcp/src/client.ts | 42 ++++++++--- .../autopilot-monitor-mcp/src/telemetry.ts | 11 ++- .../src/tools/error-handler.ts | 55 ++++++++++----- 6 files changed, 193 insertions(+), 30 deletions(-) create mode 100644 src/McpServer/autopilot-monitor-mcp/src/__tests__/client-headers.test.ts diff --git a/src/McpServer/autopilot-monitor-mcp/src/__tests__/client-headers.test.ts b/src/McpServer/autopilot-monitor-mcp/src/__tests__/client-headers.test.ts new file mode 100644 index 00000000..909ae4a3 --- /dev/null +++ b/src/McpServer/autopilot-monitor-mcp/src/__tests__/client-headers.test.ts @@ -0,0 +1,69 @@ +import { afterEach, describe, expect, it, vi } from 'vitest'; +import { ApiError, apiFetch, getCurrentCorrelationId, getCurrentToolName, runWithCaller, runWithToolCall } from '../client.js'; + +/** + * The backend request headers apiFetch stamps: the tool name (per-tool aggregation in App Insights) + * and the per-call correlation id (row-level join between the MCP_TOOL_LOGGING line and the backend + * request rows), plus the header-borne correlation id on a failed response. + */ +afterEach(() => vi.unstubAllGlobals()); + +function stubFetch(status: number, body: unknown, headers: Record = {}) { + const calls: Array<{ url: string; headers: Record }> = []; + vi.stubGlobal('fetch', vi.fn(async (url: string, init: RequestInit) => { + calls.push({ url: String(url), headers: (init.headers as Record) ?? {} }); + return { + ok: status < 400, + status, + headers: { get: (name: string) => headers[name.toLowerCase()] ?? null }, + json: async () => body, + text: async () => JSON.stringify(body), + } as unknown as Response; + })); + return calls; +} + +describe('apiFetch headers', () => { + it('sends X-Client-Source, X-MCP-Tool-Name and X-Correlation-ID from the tool-call context', async () => { + const calls = stubFetch(200, { success: true }); + + await runWithCaller({ token: 'tok', isGlobalAdmin: true }, () => + runWithToolCall('get_session', 'cid-tool-1', async () => { + expect(getCurrentToolName()).toBe('get_session'); + expect(getCurrentCorrelationId()).toBe('cid-tool-1'); + await apiFetch('/api/global/sessions/x'); + await apiFetch('/api/global/sessions/x/events'); + }), + ); + + expect(calls).toHaveLength(2); + for (const call of calls) { + expect(call.headers['X-Client-Source']).toBe('mcp'); + expect(call.headers['X-MCP-Tool-Name']).toBe('get_session'); + // Every request of one tool call carries the SAME id — the call is the join granularity. + expect(call.headers['X-Correlation-ID']).toBe('cid-tool-1'); + } + }); + + it('sends no tool headers outside a tool-call context', async () => { + const calls = stubFetch(200, { success: true }); + + await runWithCaller({ token: 'tok', isGlobalAdmin: true }, () => apiFetch('/api/global/health')); + + expect(calls[0].headers['X-Client-Source']).toBe('mcp'); + expect(calls[0].headers['X-MCP-Tool-Name']).toBeUndefined(); + expect(calls[0].headers['X-Correlation-ID']).toBeUndefined(); + }); + + it('carries the response header correlation id into ApiError, falling back to the body', async () => { + stubFetch(404, { error: 'Session not found', code: 'NotFound', correlationId: 'body-cid' }, { 'x-correlation-id': 'hdr-cid' }); + const fromHeader = await runWithCaller({ token: 'tok', isGlobalAdmin: true }, () => apiFetch('/api/global/sessions/x')).catch((e) => e); + expect(fromHeader).toBeInstanceOf(ApiError); + expect((fromHeader as ApiError).correlationId).toBe('hdr-cid'); + expect((fromHeader as ApiError).parsed?.code).toBe('NotFound'); + + stubFetch(500, { error: 'boom', code: 'InternalError', correlationId: 'body-only' }); + const fromBody = await runWithCaller({ token: 'tok', isGlobalAdmin: true }, () => apiFetch('/api/global/sessions/x')).catch((e) => e); + expect((fromBody as ApiError).correlationId).toBe('body-only'); + }); +}); diff --git a/src/McpServer/autopilot-monitor-mcp/src/__tests__/error-handler.test.ts b/src/McpServer/autopilot-monitor-mcp/src/__tests__/error-handler.test.ts index 73f9c46b..9eda3378 100644 --- a/src/McpServer/autopilot-monitor-mcp/src/__tests__/error-handler.test.ts +++ b/src/McpServer/autopilot-monitor-mcp/src/__tests__/error-handler.test.ts @@ -3,6 +3,50 @@ import { toolError } from '../tools/error-handler.js'; import { ApiError } from '../client.js'; describe('toolError', () => { + it('names the correlation id from the response header on an unstructured 404 (no body id)', () => { + const err = new ApiError(404, 'not found', 'hdr-cid-1'); + const text = toolError('get_session', { sessionId: 'x' }, err).content[0].text; + expect(text).toContain('Not found in get_session'); + expect(text).toContain('**Correlation ID**: hdr-cid-1'); + }); + + it('prefers the header id over the body id and reads the envelope `code`', () => { + const err = new ApiError(403, JSON.stringify({ error: 'Access denied.', code: 'CrossTenantAccessDenied', correlationId: 'body-cid' }), 'hdr-cid'); + const text = toolError('search_sessions', {}, err).content[0].text; + expect(text).toContain('Access denied.'); + expect(text).toContain('**Correlation ID**: hdr-cid'); + expect(text).not.toContain('body-cid'); + expect(text).toContain('**Error code**: CrossTenantAccessDenied'); + }); + + it('names the correlation id and the envelope code on a sanitized 5xx', () => { + const err = new ApiError(500, JSON.stringify({ error: 'QueryTable failed.', code: 'InternalError', correlationId: 'cid-500', hint: 'internal' }), null); + const text = toolError('query_table', {}, err).content[0].text; + expect(text).toContain('**Correlation ID**: cid-500'); + expect(text).toContain('**Error code**: InternalError'); + expect(text).not.toContain('QueryTable failed.'); + expect(text).not.toContain('internal'); + }); + + it('renders the envelope quota body (error + correlationId) and the upstream code of a KQL rejection', () => { + const quota = new ApiError(429, JSON.stringify({ + error: "MCP daily request quota exceeded for plan 'community'. Resets at 2026-09-06T00:00:00Z.", + code: 'QuotaExceeded', correlationId: 'cid-q', quotaExceeded: true, plan: 'community', scope: 'daily', level: 'user', limit: 200, used: 200, resetUtc: '2026-09-06T00:00:00Z', + })); + const quotaText = toolError('search_sessions', {}, quota).content[0].text; + expect(quotaText).toContain("quota exceeded for plan 'community'"); + expect(quotaText).toContain('**Correlation ID**: cid-q'); + + const kql = new ApiError(400, JSON.stringify({ + error: "Query could not be parsed at 'takee'", code: 'BadRequest', correlationId: 'cid-k', + upstreamCode: 'SyntaxError', statusCode: 400, source: 'web', hint: 'Fix the KQL.', upstream: '{"error":{"code":"BadArgumentError"}}', + })); + const kqlText = toolError('query_backend_logs', { query: 'x' }, kql).content[0].text; + expect(kqlText).toContain('**Error code**: BadRequest'); + expect(kqlText).toContain('**Upstream code**: SyntaxError'); + expect(kqlText).toContain('BadArgumentError'); + }); + it('detects a real AbortSignal.timeout DOMException (name TimeoutError, non-matching message)', () => { // This is exactly what fetch rejects with under AbortSignal.timeout(): the // message does NOT contain "TimeoutError", only the name does — so a diff --git a/src/McpServer/autopilot-monitor-mcp/src/__tests__/telemetry.test.ts b/src/McpServer/autopilot-monitor-mcp/src/__tests__/telemetry.test.ts index f3365eb3..21a1cd0e 100644 --- a/src/McpServer/autopilot-monitor-mcp/src/__tests__/telemetry.test.ts +++ b/src/McpServer/autopilot-monitor-mcp/src/__tests__/telemetry.test.ts @@ -108,6 +108,8 @@ describe('withToolTelemetry', () => { const line = lastLoggedJson(spy); expect(line.type).toBe('tool_call'); expect(line.tool).toBe('search_sessions'); + // The per-call correlation id: the join key to the backend's request rows (X-Correlation-ID). + expect(String(line.correlationId)).toMatch(/^[0-9a-f]{8}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{12}$/); expect(typeof line.durationMs).toBe('number'); expect(line.isError).toBe(false); expect(line.resultChars).toBe(10); diff --git a/src/McpServer/autopilot-monitor-mcp/src/client.ts b/src/McpServer/autopilot-monitor-mcp/src/client.ts index 2f72159a..f904b7e1 100644 --- a/src/McpServer/autopilot-monitor-mcp/src/client.ts +++ b/src/McpServer/autopilot-monitor-mcp/src/client.ts @@ -15,8 +15,14 @@ export class ApiError extends Error { readonly status: number; readonly body: string; readonly parsed: Record | null; + /** + * The request's correlation id: the X-Correlation-ID response header (every backend answer + * carries it — the MCP is server-side, no CORS in the way), else the error envelope's + * `correlationId`. The handle an operator pivots on in the backend logs. + */ + readonly correlationId: string | null; - constructor(status: number, body: string) { + constructor(status: number, body: string, correlationIdHeader: string | null = null) { super(`API error ${status}: ${body}`); this.name = 'ApiError'; this.status = status; @@ -26,6 +32,8 @@ export class ApiError extends Error { } catch { this.parsed = null; } + const fromBody = typeof this.parsed?.correlationId === 'string' && this.parsed.correlationId ? this.parsed.correlationId : null; + this.correlationId = correlationIdHeader || fromBody; } } @@ -287,17 +295,29 @@ export function enforceDelegatedTenantForPage(tenantId?: string, continuation?: } /** - * Per-request tool name store. Carries the MCP tool name through the async - * context so apiFetch can send it as X-MCP-Tool-Name header to the backend. + * Per-tool-call context. Carries the MCP tool name and the call's correlation id through the + * async context so apiFetch can send them as X-MCP-Tool-Name / X-Correlation-ID: every backend + * request a tool call makes (pagination scans included) shares the call's id, which is also + * what the MCP_TOOL_LOGGING `tool_call` line records — the row-level join between the MCP log + * and the backend's App Insights requests. */ -const toolNameStore = new AsyncLocalStorage(); +export interface ToolCallContext { + toolName: string; + correlationId: string; +} -export function runWithToolName(toolName: string, fn: () => T | Promise): T | Promise { - return toolNameStore.run(toolName, fn); +const toolCallStore = new AsyncLocalStorage(); + +export function runWithToolCall(toolName: string, correlationId: string, fn: () => T | Promise): T | Promise { + return toolCallStore.run({ toolName, correlationId }, fn); } export function getCurrentToolName(): string | undefined { - return toolNameStore.getStore(); + return toolCallStore.getStore()?.toolName; +} + +export function getCurrentCorrelationId(): string | undefined { + return toolCallStore.getStore()?.correlationId; } async function apiFetch(path: string, options: RequestInit = {}): Promise { @@ -314,8 +334,10 @@ async function apiFetch(path: string, options: RequestInit = {}): Promise) ?? {}), }; - const toolName = getCurrentToolName(); - if (toolName) headers['X-MCP-Tool-Name'] = toolName; + const call = toolCallStore.getStore(); + if (call?.toolName) headers['X-MCP-Tool-Name'] = call.toolName; + // The backend honours an inbound id matching ^[A-Za-z0-9_-]{1,128}$ (a UUID does) and echoes it. + if (call?.correlationId) headers['X-Correlation-ID'] = call.correlationId; // Apply timeout to prevent hanging on unresponsive backend const signal = options.signal ?? AbortSignal.timeout(API_TIMEOUT_MS); @@ -323,7 +345,7 @@ async function apiFetch(path: string, options: RequestInit = {}): Promise( fn: () => T | Promise, argPolicy?: ArgPolicy, ): Promise { + // One correlation id per tool call — sent on every backend request the call makes and written + // into the tool_call line below, so an MCP log line and the backend request rows join on it. + const correlationId = randomUUID(); if (!toolLoggingEnabled) { - return runWithToolName(toolName, fn) as Promise; + return runWithToolCall(toolName, correlationId, fn) as Promise; } const start = Date.now(); @@ -103,7 +107,7 @@ export async function withToolTelemetry( let thrownMessage: string | undefined; let result: T | undefined; try { - result = await runWithToolName(toolName, fn); + result = await runWithToolCall(toolName, correlationId, fn); return result; } catch (err) { threw = true; @@ -124,6 +128,7 @@ export async function withToolTelemetry( console.error(JSON.stringify({ type: 'tool_call', tool: toolName, + correlationId, durationMs: Date.now() - start, isError, errorMessage, diff --git a/src/McpServer/autopilot-monitor-mcp/src/tools/error-handler.ts b/src/McpServer/autopilot-monitor-mcp/src/tools/error-handler.ts index 9350cbd7..713928c5 100644 --- a/src/McpServer/autopilot-monitor-mcp/src/tools/error-handler.ts +++ b/src/McpServer/autopilot-monitor-mcp/src/tools/error-handler.ts @@ -6,13 +6,28 @@ interface ToolErrorResult { content: Array<{ type: 'text'; text: string }>; } +/** + * The correlation id line every backend failure carries — from the X-Correlation-ID response + * header (present on every backend answer) or the error envelope's `correlationId`. It is the + * one handle an operator needs to find the request in the backend logs, so no branch may drop it. + */ +function correlationLine(error: ApiError): string | null { + return error.correlationId ? `**Correlation ID**: ${error.correlationId}` : null; +} + +/** Machine-readable code of the error envelope (`code`); `errorCode` is the pre-envelope spelling. */ +function errorCodeOf(p: Record | null): string | null { + const code = p?.code ?? p?.errorCode; + return typeof code === 'string' && code.length > 0 ? code : null; +} + /** * Format any error into an MCP-compliant `{ isError: true }` response with * structured, AI-consumable details. Never throws — always returns a result * the SDK can send back to the model. * * Handles: - * - Structured backend errors (ApiError with parsed JSON body) + * - Structured backend errors (ApiError with the error envelope: error, code, correlationId, hint?) * - Authentication errors * - Timeouts (AbortError / timeout signals) * - Legacy unstructured errors (fallback formatting) @@ -26,14 +41,15 @@ export function toolError( if (error instanceof ApiError && error.status >= 500) { // Sanitize ALL 5xx — structured or not. Even structured backend errors - // can carry internal fingerprints (CLR exception types, stack frames, - // hint strings that name internal services), and the model has no - // legitimate reason to act on them. correlationId + errorCode stay — - // those are operational handles the operator can pivot on, not - // internals. + // can carry internal fingerprints (stack frames, hint strings that name + // internal services), and the model has no legitimate reason to act on + // them. correlationId + code stay — those are operational handles the + // operator can pivot on, not internals. parts.push(`**Backend error in ${toolName}** (HTTP ${error.status}): the server returned an error.`); - if (error.parsed?.correlationId) parts.push(`**Correlation ID**: ${error.parsed.correlationId}`); - if (error.parsed?.errorCode) parts.push(`**Error code**: ${error.parsed.errorCode}`); + const cid = correlationLine(error); + if (cid) parts.push(cid); + const code = errorCodeOf(error.parsed); + if (code) parts.push(`**Error code**: ${code}`); parts.push('**Suggestion**: retry in a few seconds; if persistent, ask an operator to inspect backend logs.'); } else if (error instanceof ApiError && error.status === 429 && error.parsed?.quotaExceeded === true) { // Backend MCP quota (McpQuotaExceededResponse): the daily/monthly budget of the caller's own plan @@ -48,7 +64,8 @@ export function toolError( ? p.targetTenantId : undefined; const whose = managedTenant ? `the managed tenant ${managedTenant}'s` : p.level === 'tenant' ? "your organization's" : 'your'; - parts.push(`**Quota exceeded in ${toolName}**: ${p.message ?? `${whose} MCP ${p.scope ?? ''} request quota is exhausted.`}`); + // `error` is the envelope's message; `message` is the pre-envelope spelling. + parts.push(`**Quota exceeded in ${toolName}**: ${p.error ?? p.message ?? `${whose} MCP ${p.scope ?? ''} request quota is exhausted.`}`); if (p.limit != null && p.used != null) parts.push(`**Budget**: ${p.used} of ${p.limit} requests used (${p.scope ?? 'window'}, ${p.level ?? 'user'} level).`); if (p.resetUtc) parts.push(`**Resets at**: ${p.resetUtc}`); parts.push( @@ -58,18 +75,20 @@ export function toolError( ? '**Suggestion**: do not retry before the reset — the window is shared by every member of the tenant; a tenant admin can review consumption under Configuration → Reporting → MCP Usage.' : '**Suggestion**: do not retry before the reset; narrow further queries, or ask an administrator about a larger usage plan.', ); + const cid = correlationLine(error); + if (cid) parts.push(cid); } else if (error instanceof ApiError && error.parsed) { - // Structured backend error (4xx) — extract rich details + // Structured backend error (4xx) — the error envelope: error, code, correlationId, hint? const p = error.parsed; parts.push(`**Error in ${toolName}**: ${p.error ?? error.message}`); if (p.hint) parts.push(`**Suggestion**: ${p.hint}`); - if (p.correlationId) parts.push(`**Correlation ID**: ${p.correlationId}`); - // exceptionType (CLR type names) is an internal fingerprint the model has no - // legitimate reason to act on — deliberately NOT surfaced here, mirroring the - // 5xx sanitization above. correlationId + errorCode remain as operator handles. - if (p.errorCode) parts.push(`**Error code**: ${p.errorCode}`); - // The operator log proxy forwards the telemetry store's own error JSON (query_backend_logs): - // that is what `az monitor … query` prints, and the parity promise is that nothing of it is lost. + const cid = correlationLine(error); + if (cid) parts.push(cid); + const code = errorCodeOf(p); + if (code) parts.push(`**Error code**: ${code}`); + // The operator log proxy (query_backend_logs) forwards the telemetry store's own error code and + // JSON: that is what `az monitor … query` prints, and the parity promise is that nothing of it is lost. + if (typeof p.upstreamCode === 'string' && p.upstreamCode.length > 0) parts.push(`**Upstream code**: ${p.upstreamCode}`); if (typeof p.upstream === 'string' && p.upstream.length > 0) { parts.push(`**Upstream response**:\n\`\`\`json\n${p.upstream.length > 4000 ? p.upstream.slice(0, 4000) + '…' : p.upstream}\n\`\`\``); } @@ -89,6 +108,8 @@ export function toolError( const truncated = body.length > 500 ? body.slice(0, 500) + '…' : body; parts.push(`**Error in ${toolName}** (HTTP ${error.status}): ${truncated}`); } + const cid = correlationLine(error); + if (cid) parts.push(cid); } else { const message = error instanceof Error ? error.message : String(error); if (message.includes('No authentication token')) {