From f454cde050ab422450fb4eecbc255821c387a752 Mon Sep 17 00:00:00 2001 From: fiammamuscari Date: Thu, 19 Mar 2026 22:52:49 -0300 Subject: [PATCH 1/2] feat(xmcp): add execution observability for tools, prompts, and resources --- .../compiler/config/__tests__/config.test.ts | 25 +++ packages/xmcp/src/compiler/config/index.ts | 4 + .../xmcp/src/compiler/config/injection.ts | 18 ++- .../xmcp/src/compiler/config/schemas/index.ts | 4 + .../compiler/config/schemas/observability.ts | 24 +++ packages/xmcp/src/compiler/config/utils.ts | 12 ++ .../get-injected-variables.ts | 3 + .../utils/__tests__/execution-logger.test.ts | 152 ++++++++++++++++++ .../src/runtime/utils/execution-logger.ts | 140 ++++++++++++++++ packages/xmcp/src/runtime/utils/prompts.ts | 11 +- packages/xmcp/src/runtime/utils/resources.ts | 38 ++++- packages/xmcp/src/runtime/utils/tools.ts | 15 +- 12 files changed, 438 insertions(+), 8 deletions(-) create mode 100644 packages/xmcp/src/compiler/config/schemas/observability.ts create mode 100644 packages/xmcp/src/runtime/utils/__tests__/execution-logger.test.ts create mode 100644 packages/xmcp/src/runtime/utils/execution-logger.ts diff --git a/packages/xmcp/src/compiler/config/__tests__/config.test.ts b/packages/xmcp/src/compiler/config/__tests__/config.test.ts index dba3273e7..cd1225b0f 100644 --- a/packages/xmcp/src/compiler/config/__tests__/config.test.ts +++ b/packages/xmcp/src/compiler/config/__tests__/config.test.ts @@ -8,6 +8,7 @@ import { getResolvedTypescriptConfig, getResolvedExperimentalConfig, getResolvedCorsConfig, + getResolvedObservabilityConfig, } from "../utils"; import { injectHttpVariables, @@ -18,6 +19,7 @@ import { injectAdapterVariables, injectStdioVariables, injectServerInfoVariables, + injectObservabilityVariables, } from "../injection"; import { configSchema } from "../index"; @@ -75,6 +77,14 @@ describe("Config System - Zod Defaults", () => { assert.equal(corsConfig.maxAge, 86400); } }); + + it("should apply observability defaults", () => { + const parsed = configSchema.parse({ observability: {} }); + const resolved = getResolvedObservabilityConfig(parsed); + + assert.equal(resolved.enabled, false); + assert.equal(resolved.includeInput, true); + }); }); describe("Config System - Boolean Transformations", () => { @@ -314,6 +324,21 @@ describe("Config System - Injection Functions", () => { assert.equal(typeof serverInfo.version, "string"); assert.notEqual(serverInfo.version, ""); }); + + it("should inject observability variables", () => { + const config = configSchema.parse({ + observability: { + enabled: true, + includeInput: false, + }, + }); + const variables = injectObservabilityVariables(config); + + assert.notEqual(variables.OBSERVABILITY_CONFIG, undefined); + const observability = JSON.parse(variables.OBSERVABILITY_CONFIG); + assert.equal(observability.enabled, true); + assert.equal(observability.includeInput, false); + }); }); describe("Config System - Edge Cases", () => { diff --git a/packages/xmcp/src/compiler/config/index.ts b/packages/xmcp/src/compiler/config/index.ts index 13041cef7..acbf4e07f 100644 --- a/packages/xmcp/src/compiler/config/index.ts +++ b/packages/xmcp/src/compiler/config/index.ts @@ -7,6 +7,7 @@ import { templateConfigSchema, typescriptConfigSchema, bundlerConfigSchema, + observabilityConfigSchema, } from "./schemas"; import type { RspackOptions } from "@rspack/core"; @@ -21,6 +22,7 @@ export const configSchema = z.object({ bundler: bundlerConfigSchema.optional(), template: templateConfigSchema.optional(), typescript: typescriptConfigSchema.optional(), + observability: observabilityConfigSchema.optional(), }); type BundlerConfigType = { bundler?: (config: RspackOptions) => RspackOptions }; @@ -44,6 +46,7 @@ export type { ResolvedStdioConfig, ResolvedPathsConfig, ResolvedExperimentalConfig, + ResolvedObservabilityConfig, } from "./utils"; // Template, TypeScript, and CORS configs don't need resolved types @@ -59,4 +62,5 @@ export type { BundlerConfig, TemplateConfig, TypescriptConfig, + ObservabilityConfig, } from "./schemas"; diff --git a/packages/xmcp/src/compiler/config/injection.ts b/packages/xmcp/src/compiler/config/injection.ts index 168e97a4e..5fc374b65 100644 --- a/packages/xmcp/src/compiler/config/injection.ts +++ b/packages/xmcp/src/compiler/config/injection.ts @@ -7,6 +7,7 @@ import { getResolvedTemplateConfig, getResolvedExperimentalConfig, getResolvedTypescriptConfig, + getResolvedObservabilityConfig, } from "./utils"; import type { ResolvedHttpConfig, XmcpConfigOutputSchema } from "./index"; import type { HttpTransportConfig } from "./schemas/transport/http"; @@ -198,6 +199,20 @@ export function injectTypescriptVariables(userConfig: XmcpConfigOutputSchema) { export type TypescriptVariables = ReturnType; +export function injectObservabilityVariables( + userConfig: XmcpConfigOutputSchema +) { + const observabilityConfig = getResolvedObservabilityConfig(userConfig); + + return { + OBSERVABILITY_CONFIG: JSON.stringify(observabilityConfig), + }; +} + +export type ObservabilityVariables = ReturnType< + typeof injectObservabilityVariables +>; + export type InjectedVariables = | HttpVariables | CorsVariables @@ -206,4 +221,5 @@ export type InjectedVariables = | TemplateVariables | ServerInfoVariables | AdapterVariables - | TypescriptVariables; + | TypescriptVariables + | ObservabilityVariables; diff --git a/packages/xmcp/src/compiler/config/schemas/index.ts b/packages/xmcp/src/compiler/config/schemas/index.ts index e9e15ec74..7add96c4f 100644 --- a/packages/xmcp/src/compiler/config/schemas/index.ts +++ b/packages/xmcp/src/compiler/config/schemas/index.ts @@ -18,3 +18,7 @@ export { pathsConfigSchema, type PathsConfig, DEFAULT_PATHS } from "./paths"; export { bundlerConfigSchema, type BundlerConfig } from "./bundler"; export { templateConfigSchema, type TemplateConfig } from "./template"; export { typescriptConfigSchema, type TypescriptConfig } from "./typescript"; +export { + observabilityConfigSchema, + type ObservabilityConfig, +} from "./observability"; diff --git a/packages/xmcp/src/compiler/config/schemas/observability.ts b/packages/xmcp/src/compiler/config/schemas/observability.ts new file mode 100644 index 000000000..d11cbb582 --- /dev/null +++ b/packages/xmcp/src/compiler/config/schemas/observability.ts @@ -0,0 +1,24 @@ +import { z } from "zod/v3"; + +const observabilityConfigBaseSchema = z.object({ + /** Enables execution logs for tools, prompts, and resources */ + enabled: z.boolean().default(false), + /** Includes the incoming input payload in start logs */ + includeInput: z.boolean().default(true), +}); + +export const observabilityConfigSchema = observabilityConfigBaseSchema + .partial() + .transform((val) => { + const defaults = observabilityConfigBaseSchema.parse({}); + const provided = Object.fromEntries( + Object.entries(val).filter(([_, value]) => value !== undefined) + ); + + return { + ...defaults, + ...provided, + }; + }); + +export type ObservabilityConfig = z.infer; diff --git a/packages/xmcp/src/compiler/config/utils.ts b/packages/xmcp/src/compiler/config/utils.ts index 5a4972482..320adfb9c 100644 --- a/packages/xmcp/src/compiler/config/utils.ts +++ b/packages/xmcp/src/compiler/config/utils.ts @@ -6,6 +6,7 @@ import { typescriptConfigSchema, corsConfigSchema, experimentalConfigSchema, + observabilityConfigSchema, DEFAULT_PATHS, } from "./schemas"; import type { z } from "zod/v3"; @@ -166,3 +167,14 @@ export function getResolvedTypescriptConfig( const typescript = userConfig?.typescript; return typescriptConfigSchema.parse(typescript ?? {}); } + +export type ResolvedObservabilityConfig = z.output< + typeof observabilityConfigSchema +>; + +export function getResolvedObservabilityConfig( + userConfig: XmcpConfigOutputSchema +): ResolvedObservabilityConfig { + const observability = userConfig?.observability; + return observabilityConfigSchema.parse(observability ?? {}); +} diff --git a/packages/xmcp/src/compiler/get-bundler-config/get-injected-variables.ts b/packages/xmcp/src/compiler/get-bundler-config/get-injected-variables.ts index d3ce2a488..7339f83b9 100644 --- a/packages/xmcp/src/compiler/get-bundler-config/get-injected-variables.ts +++ b/packages/xmcp/src/compiler/get-bundler-config/get-injected-variables.ts @@ -10,6 +10,7 @@ import { injectServerInfoVariables, injectAdapterVariables, injectTypescriptVariables, + injectObservabilityVariables, } from "../config/injection"; import { getResolvedHttpConfig } from "../config/utils"; @@ -32,6 +33,7 @@ export function getInjectedVariables( const serverInfoVariables = injectServerInfoVariables(xmcpConfig); const adapterVariables = injectAdapterVariables(xmcpConfig); const typescriptVariables = injectTypescriptVariables(xmcpConfig); + const observabilityVariables = injectObservabilityVariables(xmcpConfig); return { ...httpVariables, @@ -42,5 +44,6 @@ export function getInjectedVariables( ...serverInfoVariables, ...adapterVariables, ...typescriptVariables, + ...observabilityVariables, }; } diff --git a/packages/xmcp/src/runtime/utils/__tests__/execution-logger.test.ts b/packages/xmcp/src/runtime/utils/__tests__/execution-logger.test.ts new file mode 100644 index 000000000..0510a4188 --- /dev/null +++ b/packages/xmcp/src/runtime/utils/__tests__/execution-logger.test.ts @@ -0,0 +1,152 @@ +import assert from "node:assert"; +import { describe, it } from "node:test"; +import { + withExecutionLogging, + type ExecutionLogConfig, +} from "../execution-logger"; + +describe("withExecutionLogging", () => { + it("should not emit logs when disabled", async () => { + const writes: string[] = []; + const originalWrite = process.stderr.write.bind(process.stderr); + process.stderr.write = ((chunk: any) => { + writes.push(String(chunk)); + return true; + }) as typeof process.stderr.write; + + try { + const result = await withExecutionLogging( + { + kind: "tool", + name: "greet", + input: { name: "Ada" }, + handler: async () => "ok", + }, + { + enabled: false, + includeInput: true, + } + ); + + assert.equal(result, "ok"); + assert.deepEqual(writes, []); + } finally { + process.stderr.write = originalWrite; + } + }); + + it("should emit start and success logs when enabled", async () => { + const writes: string[] = []; + const originalWrite = process.stderr.write.bind(process.stderr); + process.stderr.write = ((chunk: any) => { + writes.push(String(chunk)); + return true; + }) as typeof process.stderr.write; + + try { + const config: ExecutionLogConfig = { + enabled: true, + includeInput: true, + }; + + await withExecutionLogging( + { + kind: "tool", + name: "greet", + input: { name: "Ada" }, + handler: async () => "ok", + }, + config + ); + + assert.equal(writes.length, 2); + + const startLog = JSON.parse(writes[0]); + const finishLog = JSON.parse(writes[1]); + + assert.equal(startLog.event, "execution.start"); + assert.equal(startLog.kind, "tool"); + assert.equal(startLog.name, "greet"); + assert.deepEqual(startLog.input, { name: "Ada" }); + + assert.equal(finishLog.event, "execution.end"); + assert.equal(finishLog.success, true); + assert.equal(typeof finishLog.durationMs, "number"); + } finally { + process.stderr.write = originalWrite; + } + }); + + it("should emit failure logs with an error message", async () => { + const writes: string[] = []; + const originalWrite = process.stderr.write.bind(process.stderr); + process.stderr.write = ((chunk: any) => { + writes.push(String(chunk)); + return true; + }) as typeof process.stderr.write; + + try { + await assert.rejects( + withExecutionLogging( + { + kind: "resource", + name: "profile", + input: { uri: "users://1/profile" }, + handler: async () => { + throw new Error("boom"); + }, + }, + { + enabled: true, + includeInput: false, + } + ), + /boom/ + ); + + assert.equal(writes.length, 2); + + const startLog = JSON.parse(writes[0]); + const finishLog = JSON.parse(writes[1]); + + assert.equal(startLog.input, undefined); + assert.equal(finishLog.success, false); + assert.equal(finishLog.error, "boom"); + } finally { + process.stderr.write = originalWrite; + } + }); + + it("should not crash when input contains circular references", async () => { + const writes: string[] = []; + const originalWrite = process.stderr.write.bind(process.stderr); + process.stderr.write = ((chunk: any) => { + writes.push(String(chunk)); + return true; + }) as typeof process.stderr.write; + + const input: Record = { name: "Ada" }; + input.self = input; + + try { + await withExecutionLogging( + { + kind: "tool", + name: "circular", + input, + handler: async () => "ok", + }, + { + enabled: true, + includeInput: true, + } + ); + + assert.equal(writes.length, 2); + const startLog = JSON.parse(writes[0]); + assert.equal(startLog.input.self, "[Circular]"); + } finally { + process.stderr.write = originalWrite; + } + }); +}); diff --git a/packages/xmcp/src/runtime/utils/execution-logger.ts b/packages/xmcp/src/runtime/utils/execution-logger.ts new file mode 100644 index 000000000..6e1d4d5a8 --- /dev/null +++ b/packages/xmcp/src/runtime/utils/execution-logger.ts @@ -0,0 +1,140 @@ +export type ExecutionKind = "tool" | "prompt" | "resource"; + +export type ExecutionLogConfig = { + enabled: boolean; + includeInput: boolean; +}; + +type ExecutionLogEvent = "execution.start" | "execution.end"; + +type ExecutionLogPayload = { + event: ExecutionLogEvent; + kind: ExecutionKind; + name: string; + timestamp: string; + durationMs?: number; + success?: boolean; + input?: unknown; + error?: string; +}; + +declare const OBSERVABILITY_CONFIG: ExecutionLogConfig | undefined; + +const defaultExecutionLogConfig: ExecutionLogConfig = { + enabled: false, + includeInput: true, +}; + +export function getExecutionLogConfig(): ExecutionLogConfig { + if (typeof OBSERVABILITY_CONFIG === "undefined") { + return defaultExecutionLogConfig; + } + + return { + ...defaultExecutionLogConfig, + ...OBSERVABILITY_CONFIG, + }; +} + +function safeSerializeError(error: unknown): string { + if (error instanceof Error) { + return error.message; + } + + if (typeof error === "string") { + return error; + } + + try { + return JSON.stringify(error); + } catch { + return String(error); + } +} + +function safeStringify(value: unknown): string { + const seen = new WeakSet(); + + return JSON.stringify(value, (_key, currentValue) => { + if (typeof currentValue === "object" && currentValue !== null) { + if (seen.has(currentValue)) { + return "[Circular]"; + } + + seen.add(currentValue); + } + + return currentValue; + }); +} + +function writeExecutionLog(payload: ExecutionLogPayload): void { + const line = safeStringify({ + scope: "xmcp", + ...payload, + }); + + if ( + typeof process !== "undefined" && + process?.stderr && + typeof process.stderr.write === "function" + ) { + process.stderr.write(`${line}\n`); + return; + } + + console.error(line); +} + +export async function withExecutionLogging( + options: { + kind: ExecutionKind; + name: string; + input?: unknown; + handler: () => T | Promise; + }, + config: ExecutionLogConfig = getExecutionLogConfig() +): Promise { + if (!config.enabled) { + return options.handler(); + } + + const startedAt = Date.now(); + writeExecutionLog({ + event: "execution.start", + kind: options.kind, + name: options.name, + timestamp: new Date(startedAt).toISOString(), + ...(config.includeInput ? { input: options.input } : {}), + }); + + try { + const result = await options.handler(); + const finishedAt = Date.now(); + + writeExecutionLog({ + event: "execution.end", + kind: options.kind, + name: options.name, + timestamp: new Date(finishedAt).toISOString(), + durationMs: finishedAt - startedAt, + success: true, + }); + + return result; + } catch (error) { + const finishedAt = Date.now(); + + writeExecutionLog({ + event: "execution.end", + kind: options.kind, + name: options.name, + timestamp: new Date(finishedAt).toISOString(), + durationMs: finishedAt - startedAt, + success: false, + error: safeSerializeError(error), + }); + + throw error; + } +} diff --git a/packages/xmcp/src/runtime/utils/prompts.ts b/packages/xmcp/src/runtime/utils/prompts.ts index a3d88ab04..5e68e5b2a 100644 --- a/packages/xmcp/src/runtime/utils/prompts.ts +++ b/packages/xmcp/src/runtime/utils/prompts.ts @@ -3,6 +3,7 @@ import { ZodOptional, ZodType, ZodTypeDef, ZodRawShape } from "zod/v3"; import { PromptFile } from "./server"; import { isZodRawShape, pathToName } from "./tools"; import { transformPromptHandler } from "./transformers/prompt"; +import { withExecutionLogging } from "./execution-logger"; interface PromptMetadata { name: string; @@ -53,6 +54,14 @@ export function addPromptsToServer( ); } + const loggedHandler = async (args: PromptArgsRawShape, extra: any) => + withExecutionLogging({ + kind: "prompt", + name: promptConfig.name, + input: args, + handler: () => transformedHandler(args, extra), + }); + // server as any prevents infinite type recursion (server as any).registerPrompt( promptConfig.name, @@ -61,7 +70,7 @@ export function addPromptsToServer( description: promptConfig.description, argsSchema: schema, }, - transformedHandler + loggedHandler ); }); diff --git a/packages/xmcp/src/runtime/utils/resources.ts b/packages/xmcp/src/runtime/utils/resources.ts index 413e2b56f..f1c58cf2a 100644 --- a/packages/xmcp/src/runtime/utils/resources.ts +++ b/packages/xmcp/src/runtime/utils/resources.ts @@ -13,6 +13,7 @@ import { flattenMeta } from "./ui/flatten-meta"; import { generateUIHTML } from "./react/generate-html"; import { pathToToolNameMd5, pathToToolNameDjb2 } from "./path-to-tool-name"; import { uIResourceRegistry } from "./ext-apps-registry"; +import { withExecutionLogging } from "./execution-logger"; // Client bundles can be injected at compile time for Cloudflare Workers // This variable is defined by DefinePlugin at compile time @@ -225,12 +226,20 @@ export function addResourcesToServer( }; }; + const loggedHandler = async (uri: URL, extra: any) => + withExecutionLogging({ + kind: "resource", + name: resourceConfig.name, + input: { uri: uri.href }, + handler: () => transformedHandler(uri, extra), + }); + // Register as a direct resource server.registerResource( autoResource.name, autoResource.uri, resourceConfig, - transformedHandler + loggedHandler ); }); @@ -282,11 +291,19 @@ export function addResourcesToServer( if (resourceInfo.type === "direct") { // register as a direct resource (static composed URI) + const loggedHandler = async (uri: URL, extra: any) => + withExecutionLogging({ + kind: "resource", + name: resourceConfig.name, + input: { uri: uri.href }, + handler: () => transformedHandler(uri, extra), + }); + server.registerResource( resourceConfig.name as string, uri, resourceConfig, - transformedHandler + loggedHandler ); } else { // register as a resource template (dynamic URI with parameters) @@ -326,11 +343,26 @@ export function addResourcesToServer( : response; }; + const loggedTemplateHandler = async ( + uri: URL, + variables: any, + extra: any + ) => + withExecutionLogging({ + kind: "resource", + name: resourceConfig.name, + input: { + uri: uri.href, + variables, + }, + handler: () => templateCallback(uri, variables, extra), + }); + server.registerResource( resourceConfig.name as string, resourceTemplate, resourceConfig, - templateCallback + loggedTemplateHandler ); } }); diff --git a/packages/xmcp/src/runtime/utils/tools.ts b/packages/xmcp/src/runtime/utils/tools.ts index ec69c7922..1ec052dca 100644 --- a/packages/xmcp/src/runtime/utils/tools.ts +++ b/packages/xmcp/src/runtime/utils/tools.ts @@ -3,12 +3,13 @@ import { z } from "zod"; import { ZodRawShape } from "zod/v3"; import { ToolFile } from "./server"; import { ToolMetadata } from "@/types/tool"; -import { transformToolHandler } from "./transformers/tool"; +import { McpToolHandler, transformToolHandler } from "./transformers/tool"; import { isReactFile } from "./react"; import { uIResourceRegistry } from "./ext-apps-registry"; import { flattenMeta, hasUIMeta } from "./ui/flatten-meta"; import { splitUIMetaNested } from "./ui/split-meta"; import { isPaidHandler, getX402Registry } from "@/plugins/x402"; +import { withExecutionLogging } from "./execution-logger"; /** Validates if a value is a valid Zod schema object */ export function isZodRawShape(value: unknown): value is ZodRawShape { @@ -136,7 +137,7 @@ export function addToolsToServer( const flattenedToolMeta = flattenMeta(toolSpecificMeta); const meta = uiWidget ? flattenedToolMeta : undefined; - let transformedHandler; + let transformedHandler: McpToolHandler; if (isReactFile(path) && uiWidget) { transformedHandler = async (args: any, extra: any) => ({ @@ -168,11 +169,19 @@ export function addToolsToServer( _meta: flattenedToolMeta, // Use flattened metadata for MCP protocol }; + const loggedHandler = async (args: any, extra: any) => + withExecutionLogging({ + kind: "tool", + name: toolConfig.name, + input: args, + handler: () => transformedHandler(args, extra), + }); + // server as any prevents infinite type recursion (server as any).registerTool( toolConfig.name, toolConfigFormatted, - transformedHandler + loggedHandler ); }); From 55ab518b62b2f7fe2d4f7746a102631d7ffb54f6 Mon Sep 17 00:00:00 2001 From: fiammamuscari Date: Thu, 19 Mar 2026 23:36:03 -0300 Subject: [PATCH 2/2] fix(xmcp): harden observability logging and classify tool error results --- .../utils/__tests__/execution-logger.test.ts | 59 ++++++++++++++ .../__tests__/tools-observability.test.ts | 73 +++++++++++++++++ .../src/runtime/utils/execution-logger.ts | 80 +++++++++++++++---- packages/xmcp/src/runtime/utils/tools.ts | 34 ++++++++ 4 files changed, 232 insertions(+), 14 deletions(-) create mode 100644 packages/xmcp/src/runtime/utils/__tests__/tools-observability.test.ts diff --git a/packages/xmcp/src/runtime/utils/__tests__/execution-logger.test.ts b/packages/xmcp/src/runtime/utils/__tests__/execution-logger.test.ts index 0510a4188..7f8395bcc 100644 --- a/packages/xmcp/src/runtime/utils/__tests__/execution-logger.test.ts +++ b/packages/xmcp/src/runtime/utils/__tests__/execution-logger.test.ts @@ -149,4 +149,63 @@ describe("withExecutionLogging", () => { process.stderr.write = originalWrite; } }); + + it("should not crash when input contains BigInt values", async () => { + const writes: string[] = []; + const originalWrite = process.stderr.write.bind(process.stderr); + process.stderr.write = ((chunk: any) => { + writes.push(String(chunk)); + return true; + }) as typeof process.stderr.write; + + try { + await withExecutionLogging( + { + kind: "tool", + name: "bigint", + input: { count: BigInt(42) }, + handler: async () => "ok", + }, + { + enabled: true, + includeInput: true, + } + ); + + assert.equal(writes.length, 2); + const startLog = JSON.parse(writes[0]); + assert.equal(startLog.input.count, "42"); + } finally { + process.stderr.write = originalWrite; + } + }); + + it("should not throw when stderr write fails", async () => { + const originalWrite = process.stderr.write.bind(process.stderr); + let writes = 0; + process.stderr.write = ((_: any) => { + writes += 1; + throw new Error("stderr unavailable"); + }) as typeof process.stderr.write; + + try { + const result = await withExecutionLogging( + { + kind: "tool", + name: "write-failure", + input: { name: "Ada" }, + handler: async () => "ok", + }, + { + enabled: true, + includeInput: true, + } + ); + + assert.equal(result, "ok"); + assert.equal(writes >= 2, true); + } finally { + process.stderr.write = originalWrite; + } + }); }); diff --git a/packages/xmcp/src/runtime/utils/__tests__/tools-observability.test.ts b/packages/xmcp/src/runtime/utils/__tests__/tools-observability.test.ts new file mode 100644 index 000000000..77bfb5f61 --- /dev/null +++ b/packages/xmcp/src/runtime/utils/__tests__/tools-observability.test.ts @@ -0,0 +1,73 @@ +import assert from "node:assert"; +import { describe, it } from "node:test"; +import { addToolsToServer } from "../tools"; +import { ToolFile } from "../server"; + +describe("tool observability integration", () => { + it("should mark isError tool results as failed and log to stderr", async () => { + (globalThis as { OBSERVABILITY_CONFIG?: { enabled: boolean; includeInput: boolean } }).OBSERVABILITY_CONFIG = + { + enabled: true, + includeInput: true, + }; + + let registeredHandler: + | ((args: Record, extra: unknown) => Promise) + | undefined; + + const server = { + registerTool: ( + _name: string, + _config: unknown, + handler: (args: Record, extra: unknown) => Promise + ) => { + registeredHandler = handler; + }, + }; + + const toolModule: ToolFile = { + metadata: { + name: "failing-tool", + description: "Returns isError", + }, + schema: {}, + default: async () => ({ + isError: true, + content: [{ type: "text", text: "tool failed gracefully" }], + }), + }; + + addToolsToServer(server as any, new Map([["src/tools/failing-tool.ts", toolModule]])); + + assert.notEqual(registeredHandler, undefined); + + const writes: string[] = []; + const originalWrite = process.stderr.write.bind(process.stderr); + process.stderr.write = ((chunk: any) => { + writes.push(String(chunk)); + return true; + }) as typeof process.stderr.write; + + try { + const result = (await registeredHandler!( + { id: 123 }, + {} + )) as { isError?: boolean }; + + assert.equal(result.isError, true); + assert.equal(writes.length, 2); + + const startLog = JSON.parse(writes[0]); + const endLog = JSON.parse(writes[1]); + + assert.equal(startLog.event, "execution.start"); + assert.deepEqual(startLog.input, { id: 123 }); + assert.equal(endLog.event, "execution.end"); + assert.equal(endLog.success, false); + assert.equal(endLog.error, "tool failed gracefully"); + } finally { + process.stderr.write = originalWrite; + delete (globalThis as { OBSERVABILITY_CONFIG?: unknown }).OBSERVABILITY_CONFIG; + } + }); +}); diff --git a/packages/xmcp/src/runtime/utils/execution-logger.ts b/packages/xmcp/src/runtime/utils/execution-logger.ts index 6e1d4d5a8..58467e5dc 100644 --- a/packages/xmcp/src/runtime/utils/execution-logger.ts +++ b/packages/xmcp/src/runtime/utils/execution-logger.ts @@ -26,6 +26,18 @@ const defaultExecutionLogConfig: ExecutionLogConfig = { }; export function getExecutionLogConfig(): ExecutionLogConfig { + if ( + typeof OBSERVABILITY_CONFIG === "undefined" && + typeof globalThis !== "undefined" && + "OBSERVABILITY_CONFIG" in globalThis + ) { + return { + ...defaultExecutionLogConfig, + ...((globalThis as { OBSERVABILITY_CONFIG?: ExecutionLogConfig }) + .OBSERVABILITY_CONFIG ?? {}), + }; + } + if (typeof OBSERVABILITY_CONFIG === "undefined") { return defaultExecutionLogConfig; } @@ -41,6 +53,10 @@ function safeSerializeError(error: unknown): string { return error.message; } + if (typeof error === "bigint") { + return error.toString(); + } + if (typeof error === "string") { return error; } @@ -56,6 +72,10 @@ function safeStringify(value: unknown): string { const seen = new WeakSet(); return JSON.stringify(value, (_key, currentValue) => { + if (typeof currentValue === "bigint") { + return currentValue.toString(); + } + if (typeof currentValue === "object" && currentValue !== null) { if (seen.has(currentValue)) { return "[Circular]"; @@ -69,21 +89,47 @@ function safeStringify(value: unknown): string { } function writeExecutionLog(payload: ExecutionLogPayload): void { - const line = safeStringify({ - scope: "xmcp", - ...payload, - }); + try { + const line = safeStringify({ + scope: "xmcp", + ...payload, + }); - if ( - typeof process !== "undefined" && - process?.stderr && - typeof process.stderr.write === "function" - ) { - process.stderr.write(`${line}\n`); - return; + if ( + typeof process !== "undefined" && + process?.stderr && + typeof process.stderr.write === "function" + ) { + process.stderr.write(`${line}\n`); + return; + } + } catch { + try { + const fallbackLine = JSON.stringify({ + scope: "xmcp", + event: payload.event, + kind: payload.kind, + name: payload.name, + timestamp: payload.timestamp, + durationMs: payload.durationMs, + success: payload.success, + error: + payload.error ?? + "Failed to serialize observability payload; emitted fallback log", + }); + + if ( + typeof process !== "undefined" && + process?.stderr && + typeof process.stderr.write === "function" + ) { + process.stderr.write(`${fallbackLine}\n`); + return; + } + } catch { + return; + } } - - console.error(line); } export async function withExecutionLogging( @@ -92,6 +138,8 @@ export async function withExecutionLogging( name: string; input?: unknown; handler: () => T | Promise; + isFailureResult?: (result: T) => boolean; + getFailureError?: (result: T) => string | undefined; }, config: ExecutionLogConfig = getExecutionLogConfig() ): Promise { @@ -111,6 +159,7 @@ export async function withExecutionLogging( try { const result = await options.handler(); const finishedAt = Date.now(); + const isFailureResult = options.isFailureResult?.(result) ?? false; writeExecutionLog({ event: "execution.end", @@ -118,7 +167,10 @@ export async function withExecutionLogging( name: options.name, timestamp: new Date(finishedAt).toISOString(), durationMs: finishedAt - startedAt, - success: true, + success: !isFailureResult, + ...(isFailureResult + ? { error: options.getFailureError?.(result) } + : {}), }); return result; diff --git a/packages/xmcp/src/runtime/utils/tools.ts b/packages/xmcp/src/runtime/utils/tools.ts index 1ec052dca..49f3e8dae 100644 --- a/packages/xmcp/src/runtime/utils/tools.ts +++ b/packages/xmcp/src/runtime/utils/tools.ts @@ -11,6 +11,38 @@ import { splitUIMetaNested } from "./ui/split-meta"; import { isPaidHandler, getX402Registry } from "@/plugins/x402"; import { withExecutionLogging } from "./execution-logger"; +function isToolExecutionError(result: unknown): boolean { + return !!( + result && + typeof result === "object" && + "isError" in result && + (result as { isError?: unknown }).isError === true + ); +} + +function getToolExecutionError(result: unknown): string | undefined { + if (!isToolExecutionError(result)) { + return undefined; + } + + if ( + result && + typeof result === "object" && + "content" in result && + Array.isArray((result as { content?: unknown[] }).content) + ) { + const textItem = (result as { content: Array<{ type?: string; text?: string }> }).content.find( + (item) => item?.type === "text" && typeof item.text === "string" + ); + + if (textItem?.text) { + return textItem.text; + } + } + + return "Tool execution failed"; +} + /** Validates if a value is a valid Zod schema object */ export function isZodRawShape(value: unknown): value is ZodRawShape { if (typeof value !== "object" || value === null) { @@ -175,6 +207,8 @@ export function addToolsToServer( name: toolConfig.name, input: args, handler: () => transformedHandler(args, extra), + isFailureResult: isToolExecutionError, + getFailureError: getToolExecutionError, }); // server as any prevents infinite type recursion