diff --git a/apps/e2e/demo-e2e-dts-consumer/e2e/dts-consumer.e2e.spec.ts b/apps/e2e/demo-e2e-dts-consumer/e2e/dts-consumer.e2e.spec.ts index 4183ee0a8..e5bbbe45e 100644 --- a/apps/e2e/demo-e2e-dts-consumer/e2e/dts-consumer.e2e.spec.ts +++ b/apps/e2e/demo-e2e-dts-consumer/e2e/dts-consumer.e2e.spec.ts @@ -90,7 +90,7 @@ describe('@frontmcp/sdk declarations in a strict consumer project', () => { expect(describeEach(inFixtureFile('prompts-must-compile.ts'))).toEqual([]); }); - it('types the prompt and completion hooks, the scope channel accessors and server-level adapters', () => { + it('types the prompt, completion and Finally hooks, the scope channel accessors and server-level adapters', () => { expect(describeEach(inFixtureFile('hooks-must-compile.ts'))).toEqual([]); }); diff --git a/apps/e2e/demo-e2e-dts-consumer/fixture/hooks-must-compile.ts b/apps/e2e/demo-e2e-dts-consumer/fixture/hooks-must-compile.ts index 626ba3a03..c98ffdb31 100644 --- a/apps/e2e/demo-e2e-dts-consumer/fixture/hooks-must-compile.ts +++ b/apps/e2e/demo-e2e-dts-consumer/fixture/hooks-must-compile.ts @@ -7,6 +7,7 @@ import { FrontMcp, ListPromptsHook, PromptHook, + ToolHook, type FlowCtxOf, type FrontMcpAdapterResponse, type ScopeEntry, @@ -37,6 +38,19 @@ export class PromptAudit { @CompletionHook.Did('complete') afterComplete(): void {} + + @GetPrompt.Finally('execute') + afterPromptWhateverItsOutcome(ctx: FlowCtxOf<'prompts:get-prompt'>): void { + void ctx.state.flowError?.message; + } +} + +// Finally hooks run after a stage whatever its outcome, and read the failure from state.flowError. +export class CallAudit { + @ToolHook.Finally('finalize') + afterCall(ctx: FlowCtxOf<'tools:call-tool'>): void { + void ctx.state.flowError?.message; + } } // ScopeEntry declares the channel accessors, so no cast is needed. diff --git a/apps/e2e/demo-e2e-hooks/e2e/finally-hooks.e2e.spec.ts b/apps/e2e/demo-e2e-hooks/e2e/finally-hooks.e2e.spec.ts new file mode 100644 index 000000000..e7c026e08 --- /dev/null +++ b/apps/e2e/demo-e2e-hooks/e2e/finally-hooks.e2e.spec.ts @@ -0,0 +1,81 @@ +/** + * E2E: Finally hooks run after a stage whatever its outcome, and never change what the client gets. + * + * The finally-recorder plugin records how the `execute` and `finalize` stages of a call ended. Before its + * recorders run, two other Finally hooks of `finalize` try to answer in place of the call and to fail it: both + * are ignored. `refused-answer` answers with a value its output schema refuses (a `finalize` failure, which used + * to skip every hook after the stage), and `failing-execute` fails in `execute`. + */ +import { expect, test, type ServerFixture } from '@frontmcp/testing'; + +interface FinallyLog { + entries: Array<{ stage: string; outcome: string }>; +} + +/** The server's logs once they contain `text`, or as they are after `timeoutMs`: its output reaches us after the reply. */ +async function logsOnceTheyContain(server: ServerFixture, text: string, timeoutMs = 5000): Promise { + const deadline = Date.now() + timeoutMs; + while (!server.getLogs().join('\n').includes(text) && Date.now() < deadline) { + await new Promise((resolve) => setTimeout(resolve, 50)); + } + return server.getLogs().join('\n'); +} + +test.describe('Finally hooks E2E', () => { + test.use({ + server: 'apps/e2e/demo-e2e-hooks/src/main.ts', + project: 'demo-e2e-hooks', + publicMode: true, + }); + + test('see an answer the output schema refuses, and the client still gets INVALID_OUTPUT', async ({ mcp }) => { + await mcp.tools.call('clear-audit-log', {}); + + const result = await mcp.tools.call('refused-answer', {}); + + expect(result).toBeError(); + expect(result.raw._meta?.['code']).toBe('INVALID_OUTPUT'); + expect(result).not.toHaveTextContent('replaced by a Finally hook'); + const log = await mcp.tools.call('get-finally-log', { toolName: 'refused-answer' }); + expect(log.json().entries).toEqual([ + { stage: 'execute', outcome: 'ok' }, + { stage: 'finalize', outcome: 'InvalidOutputError' }, + ]); + }); + + test('see an execute that failed, and the client still gets its error', async ({ mcp }) => { + await mcp.tools.call('clear-audit-log', {}); + + const result = await mcp.tools.call('failing-execute', {}); + + expect(result).toBeError(); + expect(result.text()).toBe('The ledger is unreachable'); + const log = await mcp.tools.call('get-finally-log', { toolName: 'failing-execute' }); + expect(log.json().entries).toEqual([ + { stage: 'execute', outcome: 'PublicMcpError' }, + { stage: 'finalize', outcome: 'PublicMcpError' }, + ]); + }); + + test('see a call that succeeded, and its answer is left as it was', async ({ mcp }) => { + await mcp.tools.call('clear-audit-log', {}); + + const result = await mcp.tools.call('audited-tool', { message: 'finally' }); + + expect(result).toBeSuccessful(); + expect(result.json<{ message: string }>().message).toBe('Processed: finally'); + const log = await mcp.tools.call('get-finally-log', { toolName: 'audited-tool' }); + expect(log.json().entries).toEqual([ + { stage: 'execute', outcome: 'ok' }, + { stage: 'finalize', outcome: 'ok' }, + ]); + }); + + test('log what an ignored Finally hook threw', async ({ mcp, server }) => { + server.clearLogs(); + + await mcp.tools.call('audited-tool', { message: 'logged' }); + + expect(await logsOnceTheyContain(server, 'the recorder store is down')).toContain('the recorder store is down'); + }); +}); diff --git a/apps/e2e/demo-e2e-hooks/src/apps/audit/data/finally-log.ts b/apps/e2e/demo-e2e-hooks/src/apps/audit/data/finally-log.ts new file mode 100644 index 000000000..f592ae1af --- /dev/null +++ b/apps/e2e/demo-e2e-hooks/src/apps/audit/data/finally-log.ts @@ -0,0 +1,26 @@ +/** + * What the Finally hooks of the finally-recorder plugin saw, per tool call stage. + */ +export interface FinallyEntry { + toolName: string; + stage: string; + outcome: string; +} + +class FinallyLogStore { + private entries: FinallyEntry[] = []; + + add(entry: FinallyEntry): void { + this.entries.push(entry); + } + + entriesFor(toolName: string): FinallyEntry[] { + return this.entries.filter((entry) => entry.toolName === toolName); + } + + clear(): void { + this.entries = []; + } +} + +export const finallyLog = new FinallyLogStore(); diff --git a/apps/e2e/demo-e2e-hooks/src/apps/audit/index.ts b/apps/e2e/demo-e2e-hooks/src/apps/audit/index.ts index 9ddb5a292..a112818ce 100644 --- a/apps/e2e/demo-e2e-hooks/src/apps/audit/index.ts +++ b/apps/e2e/demo-e2e-hooks/src/apps/audit/index.ts @@ -1,17 +1,30 @@ import { App } from '@frontmcp/sdk'; import AuditPlugin from './plugins/audit.plugin'; +import FinallyRecorderPlugin from './plugins/finally-recorder.plugin'; import AuditSummaryPrompt from './prompts/audit-summary.prompt'; import AuditLogResource from './resources/audit-log.resource'; import AuditedTool from './tools/audited.tool'; import ClearAuditLogTool from './tools/clear-audit-log.tool'; +import FailingExecuteTool from './tools/failing-execute.tool'; import GetAuditLogTool from './tools/get-audit-log.tool'; +import GetFinallyLogTool from './tools/get-finally-log.tool'; +import RefusedAnswerTool from './tools/refused-answer.tool'; import { PlainEchoTool, StaticGuardedEchoTool } from './tools/static-guarded.tool'; @App({ name: 'audit', - plugins: [AuditPlugin], - tools: [AuditedTool, GetAuditLogTool, ClearAuditLogTool, StaticGuardedEchoTool, PlainEchoTool], + plugins: [AuditPlugin, FinallyRecorderPlugin], + tools: [ + AuditedTool, + GetAuditLogTool, + ClearAuditLogTool, + StaticGuardedEchoTool, + PlainEchoTool, + RefusedAnswerTool, + FailingExecuteTool, + GetFinallyLogTool, + ], resources: [AuditLogResource], prompts: [AuditSummaryPrompt], }) diff --git a/apps/e2e/demo-e2e-hooks/src/apps/audit/plugins/finally-recorder.plugin.ts b/apps/e2e/demo-e2e-hooks/src/apps/audit/plugins/finally-recorder.plugin.ts new file mode 100644 index 000000000..52c80881f --- /dev/null +++ b/apps/e2e/demo-e2e-hooks/src/apps/audit/plugins/finally-recorder.plugin.ts @@ -0,0 +1,44 @@ +import { Plugin, ToolHook, type FlowCtxOf } from '@frontmcp/sdk'; + +import { finallyLog } from '../data/finally-log'; + +type CallToolFlow = FlowCtxOf<'tools:call-tool'>; + +const RECORDED_TOOLS = new Set(['audited-tool', 'refused-answer', 'failing-execute']); + +const isRecorded = (flowCtx: CallToolFlow) => RECORDED_TOOLS.has(String(flowCtx.state.input?.name)); + +function record(flowCtx: CallToolFlow, stage: string): void { + finallyLog.add({ + toolName: String(flowCtx.state.input?.name), + stage, + outcome: flowCtx.state.flowError?.name ?? 'ok', + }); +} + +/** The first two Finally hooks try to answer and to fail the call: both are ignored, and the recorders still run. */ +@Plugin({ + name: 'finally-recorder', + description: 'Records how the execute and finalize stages of a tool call ended', +}) +export default class FinallyRecorderPlugin { + @ToolHook.Finally('finalize', { priority: -10, filter: isRecorded }) + replaceAnswer(flowCtx: CallToolFlow) { + flowCtx.respond({ content: [{ type: 'text', text: 'replaced by a Finally hook' }] }); + } + + @ToolHook.Finally('finalize', { priority: -5, filter: isRecorded }) + failRecorder() { + throw new Error('the recorder store is down'); + } + + @ToolHook.Finally('execute', { filter: isRecorded }) + recordExecute(flowCtx: CallToolFlow) { + record(flowCtx, 'execute'); + } + + @ToolHook.Finally('finalize', { filter: isRecorded }) + recordFinalize(flowCtx: CallToolFlow) { + record(flowCtx, 'finalize'); + } +} diff --git a/apps/e2e/demo-e2e-hooks/src/apps/audit/tools/clear-audit-log.tool.ts b/apps/e2e/demo-e2e-hooks/src/apps/audit/tools/clear-audit-log.tool.ts index 1cc9b55f2..1aadacd9f 100644 --- a/apps/e2e/demo-e2e-hooks/src/apps/audit/tools/clear-audit-log.tool.ts +++ b/apps/e2e/demo-e2e-hooks/src/apps/audit/tools/clear-audit-log.tool.ts @@ -2,6 +2,7 @@ import { z } from '@frontmcp/lazy-zod'; import { Tool, ToolContext } from '@frontmcp/sdk'; import { auditLog } from '../data/audit-log'; +import { finallyLog } from '../data/finally-log'; const inputSchema = {}; @@ -15,13 +16,14 @@ type Output = z.infer; @Tool({ name: 'clear-audit-log', - description: 'Clear all audit log entries', + description: 'Clear all audit log and Finally log entries', inputSchema, outputSchema, }) export default class ClearAuditLogTool extends ToolContext { async execute(_input: Input): Promise { auditLog.clear(); + finallyLog.clear(); return { success: true, diff --git a/apps/e2e/demo-e2e-hooks/src/apps/audit/tools/failing-execute.tool.ts b/apps/e2e/demo-e2e-hooks/src/apps/audit/tools/failing-execute.tool.ts new file mode 100644 index 000000000..c46afb1ee --- /dev/null +++ b/apps/e2e/demo-e2e-hooks/src/apps/audit/tools/failing-execute.tool.ts @@ -0,0 +1,18 @@ +import { z } from '@frontmcp/lazy-zod'; +import { PublicMcpError, Tool, ToolContext } from '@frontmcp/sdk'; + +const outputSchema = z.object({ posted: z.boolean() }); + +type Output = z.infer; + +@Tool({ + name: 'failing-execute', + description: 'Fails while it runs', + inputSchema: {}, + outputSchema, +}) +export default class FailingExecuteTool extends ToolContext { + async execute(): Promise { + throw new PublicMcpError('The ledger is unreachable'); + } +} diff --git a/apps/e2e/demo-e2e-hooks/src/apps/audit/tools/get-finally-log.tool.ts b/apps/e2e/demo-e2e-hooks/src/apps/audit/tools/get-finally-log.tool.ts new file mode 100644 index 000000000..ddb9c56e4 --- /dev/null +++ b/apps/e2e/demo-e2e-hooks/src/apps/audit/tools/get-finally-log.tool.ts @@ -0,0 +1,28 @@ +import { z } from '@frontmcp/lazy-zod'; +import { Tool, ToolContext } from '@frontmcp/sdk'; + +import { finallyLog } from '../data/finally-log'; + +const inputSchema = { + toolName: z.string().describe('The tool whose calls to list'), +}; + +const outputSchema = z.object({ + entries: z.array(z.object({ stage: z.string(), outcome: z.string() })), +}); + +type Input = z.infer>; +type Output = z.infer; + +@Tool({ + name: 'get-finally-log', + description: 'How the execute and finalize stages of the calls of one tool ended, as its Finally hooks saw them', + inputSchema, + outputSchema, +}) +export default class GetFinallyLogTool extends ToolContext { + async execute(input: Input): Promise { + const entries = finallyLog.entriesFor(input.toolName).map(({ stage, outcome }) => ({ stage, outcome })); + return { entries }; + } +} diff --git a/apps/e2e/demo-e2e-hooks/src/apps/audit/tools/refused-answer.tool.ts b/apps/e2e/demo-e2e-hooks/src/apps/audit/tools/refused-answer.tool.ts new file mode 100644 index 000000000..b187bf3bf --- /dev/null +++ b/apps/e2e/demo-e2e-hooks/src/apps/audit/tools/refused-answer.tool.ts @@ -0,0 +1,18 @@ +import { z } from '@frontmcp/lazy-zod'; +import { Tool, ToolContext } from '@frontmcp/sdk'; + +const outputSchema = z.object({ total: z.number() }); + +type Output = z.infer; + +@Tool({ + name: 'refused-answer', + description: 'Answers with a total its own output schema refuses', + inputSchema: {}, + outputSchema, +}) +export default class RefusedAnswerTool extends ToolContext { + async execute(): Promise { + return { total: 'twelve' } as unknown as Output; + } +} diff --git a/apps/e2e/demo-e2e-standalone/e2e/observability-refused-answer.e2e.spec.ts b/apps/e2e/demo-e2e-standalone/e2e/observability-refused-answer.e2e.spec.ts new file mode 100644 index 000000000..c845d3548 --- /dev/null +++ b/apps/e2e/demo-e2e-standalone/e2e/observability-refused-answer.e2e.spec.ts @@ -0,0 +1,33 @@ +/** + * E2E: `@frontmcp/observability` closes the `tools/call` span and records the failure on the request log when + * a tool's output schema refuses its answer. The refusal fails the `finalize` stage, which skips that stage's + * Did hooks, so the span stayed open and the request log recorded no error. Observability closes them in a + * Finally hook now. + */ +import { expect, test } from '@frontmcp/testing'; + +interface Telemetry { + spans: Array<{ tool: string; call: string }>; + requestLogs: Array<{ status: string; errorCode?: string }>; +} + +test.describe('Observability of an answer the output schema refuses', () => { + test.use({ + server: 'apps/e2e/demo-e2e-standalone/src/main-observability.ts', + project: 'demo-e2e-standalone', + publicMode: true, + }); + + test('closes the tools/call span as failed and records INVALID_OUTPUT on the request log', async ({ mcp }) => { + const result = await mcp.tools.call('refused-answer', {}); + expect(result).toBeError(); + expect(result.raw._meta?.['code']).toBe('INVALID_OUTPUT'); + + const telemetry = await mcp.tools.call('get-telemetry', { toolName: 'refused-answer' }); + + expect(telemetry.json()).toEqual({ + spans: [{ tool: 'ok', call: 'error' }], + requestLogs: [{ status: 'error', errorCode: 'INVALID_OUTPUT' }], + }); + }); +}); diff --git a/apps/e2e/demo-e2e-standalone/src/apps/observability-probe/index.ts b/apps/e2e/demo-e2e-standalone/src/apps/observability-probe/index.ts new file mode 100644 index 000000000..ca7062f44 --- /dev/null +++ b/apps/e2e/demo-e2e-standalone/src/apps/observability-probe/index.ts @@ -0,0 +1,16 @@ +import { App } from '@frontmcp/sdk'; + +import GetTelemetryTool from './tools/get-telemetry.tool'; +import RefusedAnswerTool from './tools/refused-answer.tool'; + +export { recordRequestLog } from './telemetry-records'; + +/** + * Reports what `@frontmcp/observability` recorded for a call whose answer its output schema refuses. + */ +@App({ + name: 'observability-probe', + description: 'A tool whose answer its output schema refuses, and what observability recorded for it', + tools: [RefusedAnswerTool, GetTelemetryTool], +}) +export class ObservabilityProbeApp {} diff --git a/apps/e2e/demo-e2e-standalone/src/apps/observability-probe/telemetry-records.ts b/apps/e2e/demo-e2e-standalone/src/apps/observability-probe/telemetry-records.ts new file mode 100644 index 000000000..6b52c47bd --- /dev/null +++ b/apps/e2e/demo-e2e-standalone/src/apps/observability-probe/telemetry-records.ts @@ -0,0 +1,42 @@ +import { SpanStatusCode, trace } from '@opentelemetry/api'; +import { + BasicTracerProvider, + InMemorySpanExporter, + SimpleSpanProcessor, + type ReadableSpan, +} from '@opentelemetry/sdk-trace-base'; + +/** Registered when this module loads, before the server starts, so observability records into this exporter. */ +const exporter = new InMemorySpanExporter(); +trace.setGlobalTracerProvider(new BasicTracerProvider({ spanProcessors: [new SimpleSpanProcessor(exporter)] })); + +interface RecordedRequestLog { + tool_name?: string; + status?: string; + error?: { code?: string }; +} + +const requestLogs: RecordedRequestLog[] = []; + +export function recordRequestLog(log: unknown): void { + requestLogs.push(log as RecordedRequestLog); +} + +const statusOf = (span: ReadableSpan) => (span.status.code === SpanStatusCode.ERROR ? 'error' : 'ok'); + +/** For each finished span of the tool, its status and the status of its `tools/call` span, or 'open'. */ +export function callSpanStatuses(toolName: string): Array<{ tool: string; call: string }> { + const finished = exporter.getFinishedSpans(); + return finished + .filter((span) => span.name === `tool ${toolName}`) + .map((toolSpan) => { + const callSpan = finished.find((span) => span.spanContext().spanId === toolSpan.parentSpanContext?.spanId); + return { tool: statusOf(toolSpan), call: callSpan ? statusOf(callSpan) : 'open' }; + }); +} + +export function toolRequestLogs(toolName: string): Array<{ status: string; errorCode?: string }> { + return requestLogs + .filter((log) => log.tool_name === toolName) + .map((log) => ({ status: String(log.status), errorCode: log.error?.code })); +} diff --git a/apps/e2e/demo-e2e-standalone/src/apps/observability-probe/tools/get-telemetry.tool.ts b/apps/e2e/demo-e2e-standalone/src/apps/observability-probe/tools/get-telemetry.tool.ts new file mode 100644 index 000000000..0f28e4628 --- /dev/null +++ b/apps/e2e/demo-e2e-standalone/src/apps/observability-probe/tools/get-telemetry.tool.ts @@ -0,0 +1,28 @@ +import { z } from '@frontmcp/lazy-zod'; +import { Tool, ToolContext } from '@frontmcp/sdk'; + +import { callSpanStatuses, toolRequestLogs } from '../telemetry-records'; + +const inputSchema = { + toolName: z.string().describe('The tool whose calls to report'), +}; + +const outputSchema = z.object({ + spans: z.array(z.object({ tool: z.string(), call: z.string() })), + requestLogs: z.array(z.object({ status: z.string(), errorCode: z.string().optional() })), +}); + +type Input = z.infer>; +type Output = z.infer; + +@Tool({ + name: 'get-telemetry', + description: 'The span statuses and the request logs of the calls of one tool', + inputSchema, + outputSchema, +}) +export default class GetTelemetryTool extends ToolContext { + async execute(input: Input): Promise { + return { spans: callSpanStatuses(input.toolName), requestLogs: toolRequestLogs(input.toolName) }; + } +} diff --git a/apps/e2e/demo-e2e-standalone/src/apps/observability-probe/tools/refused-answer.tool.ts b/apps/e2e/demo-e2e-standalone/src/apps/observability-probe/tools/refused-answer.tool.ts new file mode 100644 index 000000000..b187bf3bf --- /dev/null +++ b/apps/e2e/demo-e2e-standalone/src/apps/observability-probe/tools/refused-answer.tool.ts @@ -0,0 +1,18 @@ +import { z } from '@frontmcp/lazy-zod'; +import { Tool, ToolContext } from '@frontmcp/sdk'; + +const outputSchema = z.object({ total: z.number() }); + +type Output = z.infer; + +@Tool({ + name: 'refused-answer', + description: 'Answers with a total its own output schema refuses', + inputSchema: {}, + outputSchema, +}) +export default class RefusedAnswerTool extends ToolContext { + async execute(): Promise { + return { total: 'twelve' } as unknown as Output; + } +} diff --git a/apps/e2e/demo-e2e-standalone/src/main-observability.ts b/apps/e2e/demo-e2e-standalone/src/main-observability.ts index 71abf57f6..3f2c9e944 100644 --- a/apps/e2e/demo-e2e-standalone/src/main-observability.ts +++ b/apps/e2e/demo-e2e-standalone/src/main-observability.ts @@ -1,5 +1,6 @@ import { FrontMcp, LogLevel } from '@frontmcp/sdk'; +import { ObservabilityProbeApp, recordRequestLog } from './apps/observability-probe'; import { ParentApp } from './apps/parent'; const port = parseInt(process.env['PORT'] ?? '3104', 10); @@ -14,11 +15,12 @@ const port = parseInt(process.env['PORT'] ?? '3104', 10); * Telemetry must activate (or, if the module genuinely fails to load, the SDK * must say so accurately rather than claim it isn't installed). * - * Uses the issue's exact config shape. + * Uses the issue's exact config shape, plus a request-log callback and a probe app that reports the spans and + * request logs of a call whose answer its output schema refuses. */ @FrontMcp({ info: { name: 'Demo E2E Observability', version: '0.1.0' }, - apps: [ParentApp], + apps: [ParentApp, ObservabilityProbeApp], logging: { level: LogLevel.Info }, http: { port }, auth: { mode: 'public', sessionTtl: 3600, anonymousScopes: ['anonymous'] }, @@ -26,7 +28,7 @@ const port = parseInt(process.env['PORT'] ?? '3104', 10); observability: { tracing: true, logging: { sinks: [{ type: 'stdout' }] }, - requestLogs: true, + requestLogs: { onRequestComplete: recordRequestLog }, }, }) export default class Server {} diff --git a/libs/observability/src/__tests__/observability-plugin.spec.ts b/libs/observability/src/__tests__/observability-plugin.spec.ts index c2a1f45ee..e58c91433 100644 --- a/libs/observability/src/__tests__/observability-plugin.spec.ts +++ b/libs/observability/src/__tests__/observability-plugin.spec.ts @@ -1,7 +1,9 @@ +import { FrontMcpFlowHookTokens, type HookMetadata } from '@frontmcp/sdk'; + +import { StructuredLogTransport } from '../logging/structured-log-transport'; +import { OTEL_CONFIG, OTEL_TRACER } from '../otel/otel.tokens'; import ObservabilityPlugin from '../plugin/observability.plugin'; -import { OTEL_TRACER, OTEL_CONFIG } from '../otel/otel.tokens'; import { REQUEST_LOG_COLLECTOR } from '../request-log/request-log.tokens'; -import { StructuredLogTransport } from '../logging/structured-log-transport'; describe('ObservabilityPlugin', () => { describe('constructor', () => { @@ -69,7 +71,7 @@ describe('ObservabilityPlugin', () => { it('_httpDidAuth', () => plugin._httpDidAuth(emptyCtx)); it('_httpWillRoute', () => plugin._httpWillRoute(emptyCtx)); it('_httpDidRoute', () => plugin._httpDidRoute(emptyCtx)); - it('_httpDidFinalize', () => plugin._httpDidFinalize(emptyCtx)); + it('_httpFinallyFinalize', () => plugin._httpFinallyFinalize(emptyCtx)); // Tool hooks it('_toolWillParse', () => plugin._toolWillParse(emptyCtx)); @@ -81,28 +83,28 @@ describe('ObservabilityPlugin', () => { it('_toolDidExecute', () => plugin._toolDidExecute(emptyCtx)); it('_toolWillValidateOut', () => plugin._toolWillValidateOut(emptyCtx)); it('_toolWillApplyUI', () => plugin._toolWillApplyUI(emptyCtx)); - it('_toolDidFinalize', () => plugin._toolDidFinalize(emptyCtx)); + it('_toolFinallyFinalize', () => plugin._toolFinallyFinalize(emptyCtx)); // Resource hooks it('_resourceWillParse', () => plugin._resourceWillParse(emptyCtx)); it('_resourceWillFind', () => plugin._resourceWillFind(emptyCtx)); it('_resourceWillExecute', () => plugin._resourceWillExecute(emptyCtx)); it('_resourceDidExecute', () => plugin._resourceDidExecute(emptyCtx)); - it('_resourceDidFinalize', () => plugin._resourceDidFinalize(emptyCtx)); + it('_resourceFinallyFinalize', () => plugin._resourceFinallyFinalize(emptyCtx)); // Prompt hooks it('_promptWillParse', () => plugin._promptWillParse(emptyCtx)); it('_promptWillFind', () => plugin._promptWillFind(emptyCtx)); it('_promptWillExecute', () => plugin._promptWillExecute(emptyCtx)); it('_promptDidExecute', () => plugin._promptDidExecute(emptyCtx)); - it('_promptDidFinalize', () => plugin._promptDidFinalize(emptyCtx)); + it('_promptFinallyFinalize', () => plugin._promptFinallyFinalize(emptyCtx)); // Agent hooks it('_agentWillParse', () => plugin._agentWillParse(emptyCtx)); it('_agentWillFind', () => plugin._agentWillFind(emptyCtx)); it('_agentWillExecute', () => plugin._agentWillExecute(emptyCtx)); it('_agentDidExecute', () => plugin._agentDidExecute(emptyCtx)); - it('_agentDidFinalize', () => plugin._agentDidFinalize(emptyCtx)); + it('_agentFinallyFinalize', () => plugin._agentFinallyFinalize(emptyCtx)); // List hooks it('_listToolsWill', () => plugin._listToolsWill(emptyCtx)); @@ -132,7 +134,7 @@ describe('ObservabilityPlugin', () => { it('_sseDidInit', () => plugin._sseDidInit(emptyCtx)); it('_sseDidMsg', () => plugin._sseDidMsg(emptyCtx)); it('_sseDidElicit', () => plugin._sseDidElicit(emptyCtx)); - it('_sseDidCleanup', () => plugin._sseDidCleanup(emptyCtx)); + it('_sseFinallyCleanup', () => plugin._sseFinallyCleanup(emptyCtx)); // Transport: Streamable HTTP it('_shttpWillParse', () => plugin._shttpWillParse(emptyCtx)); @@ -142,12 +144,12 @@ describe('ObservabilityPlugin', () => { it('_shttpDidElicit', () => plugin._shttpDidElicit(emptyCtx)); it('_shttpDidSse', () => plugin._shttpDidSse(emptyCtx)); it('_shttpDidExtApps', () => plugin._shttpDidExtApps(emptyCtx)); - it('_shttpDidCleanup', () => plugin._shttpDidCleanup(emptyCtx)); + it('_shttpFinallyCleanup', () => plugin._shttpFinallyCleanup(emptyCtx)); // Transport: Stateless HTTP it('_slhttpWillParse', () => plugin._slhttpWillParse(emptyCtx)); it('_slhttpDidHandle', () => plugin._slhttpDidHandle(emptyCtx)); - it('_slhttpDidCleanup', () => plugin._slhttpDidCleanup(emptyCtx)); + it('_slhttpFinallyCleanup', () => plugin._slhttpFinallyCleanup(emptyCtx)); // Auth it('_authVerifyWill', () => plugin._authVerifyWill(emptyCtx)); @@ -232,7 +234,7 @@ describe('ObservabilityPlugin', () => { plugin._httpDidAuth(noop); plugin._httpWillRoute(noop); plugin._httpDidRoute(noop); - plugin._httpDidFinalize(noop); + plugin._httpFinallyFinalize(noop); // Tool plugin._toolWillParse(noop); @@ -244,28 +246,28 @@ describe('ObservabilityPlugin', () => { plugin._toolDidExecute(noop); plugin._toolWillValidateOut(noop); plugin._toolWillApplyUI(noop); - plugin._toolDidFinalize(noop); + plugin._toolFinallyFinalize(noop); // Resource plugin._resourceWillParse(noop); plugin._resourceWillFind(noop); plugin._resourceWillExecute(noop); plugin._resourceDidExecute(noop); - plugin._resourceDidFinalize(noop); + plugin._resourceFinallyFinalize(noop); // Prompt plugin._promptWillParse(noop); plugin._promptWillFind(noop); plugin._promptWillExecute(noop); plugin._promptDidExecute(noop); - plugin._promptDidFinalize(noop); + plugin._promptFinallyFinalize(noop); // Agent plugin._agentWillParse(noop); plugin._agentWillFind(noop); plugin._agentWillExecute(noop); plugin._agentDidExecute(noop); - plugin._agentDidFinalize(noop); + plugin._agentFinallyFinalize(noop); // Lists plugin._listToolsWill(noop); @@ -295,7 +297,7 @@ describe('ObservabilityPlugin', () => { plugin._sseDidInit(noop); plugin._sseDidMsg(noop); plugin._sseDidElicit(noop); - plugin._sseDidCleanup(noop); + plugin._sseFinallyCleanup(noop); // Transport: Streamable HTTP plugin._shttpWillParse(noop); @@ -305,12 +307,12 @@ describe('ObservabilityPlugin', () => { plugin._shttpDidElicit(noop); plugin._shttpDidSse(noop); plugin._shttpDidExtApps(noop); - plugin._shttpDidCleanup(noop); + plugin._shttpFinallyCleanup(noop); // Transport: Stateless HTTP plugin._slhttpWillParse(noop); plugin._slhttpDidHandle(noop); - plugin._slhttpDidCleanup(noop); + plugin._slhttpFinallyCleanup(noop); // Auth plugin._authVerifyWill(noop); @@ -415,4 +417,14 @@ describe('ObservabilityPlugin', () => { expect(providers).toHaveLength(0); }); }); + + describe('hooks on the finalize stages', () => { + it('are Finally hooks, which still run when a stage failed, so the spans they end never stay open', () => { + const hooks = Reflect.getMetadata(FrontMcpFlowHookTokens.hooks, ObservabilityPlugin) as HookMetadata[]; + const finalizeStageHooks = hooks.filter((hook) => hook.stage === 'finalize' || hook.stage === 'cleanup'); + + expect(finalizeStageHooks.length).toBeGreaterThan(0); + expect(finalizeStageHooks.filter((hook) => hook.type !== 'finally').map((hook) => hook.method)).toEqual([]); + }); + }); }); diff --git a/libs/observability/src/__tests__/server-telemetry.spec.ts b/libs/observability/src/__tests__/server-telemetry.spec.ts index a4ad5539d..11b860290 100644 --- a/libs/observability/src/__tests__/server-telemetry.spec.ts +++ b/libs/observability/src/__tests__/server-telemetry.spec.ts @@ -22,6 +22,7 @@ import { Tool, ToolContext, ToolHook, + z, type FlowCtxOf, } from '@frontmcp/sdk'; @@ -59,6 +60,13 @@ class ExportReport extends ToolContext { } } +@Tool({ name: 'total_invoice', inputSchema: {}, outputSchema: { total: z.number() } }) +class TotalInvoice extends ToolContext { + async execute() { + return { total: 'twelve' } as unknown as { total: number }; + } +} + @Plugin({ name: 'audit' }) class AuditPlugin { @ToolHook.Did('execute') @@ -67,7 +75,7 @@ class AuditPlugin { } } -@App({ id: 'desk', name: 'Desk', tools: [CloseTicket, Ping, ExportReport] }) +@App({ id: 'desk', name: 'Desk', tools: [CloseTicket, Ping, ExportReport, TotalInvoice] }) class DeskApp {} function toolCall(name: string): Request { @@ -163,6 +171,26 @@ describe('a call that a hook failed with a plain Error', () => { }); }); +describe('a call whose answer the output schema refuses', () => { + it('ends the tools/call span and logs the refusal with the error ID the client gets', async () => { + const logs: RequestLog[] = []; + const handler = await serve({}, logs); + + const { result } = await (await handler(toolCall('total_invoice'))).json(); + await settle(); + + const { code, errorId } = result._meta; + expect(code).toBe('INVALID_OUTPUT'); + expect(span('tools/call').status.code).toBe(SpanStatusCode.ERROR); + expect(span('tools/call').events.find((event) => event.name === 'exception')?.attributes).toEqual( + expect.objectContaining({ 'exception.type': 'INVALID_OUTPUT' }), + ); + expect(logs[0].error).toEqual( + expect.objectContaining({ type: 'InvalidOutputError', code: 'INVALID_OUTPUT', error_id: errorId }), + ); + }); +}); + describe('the spans of one request', () => { it('nests the tools/call span in the POST / span, and this.fetch() sends the GET span as the parent', async () => { const handler = await serve(); @@ -222,7 +250,7 @@ describe('startupReport', () => { await serve(); expect(span('frontmcp.startup').attributes).toEqual( - expect.objectContaining({ 'frontmcp.startup.tools_count': 3, 'frontmcp.startup.plugins_count': 2 }), + expect.objectContaining({ 'frontmcp.startup.tools_count': 4, 'frontmcp.startup.plugins_count': 2 }), ); }); diff --git a/libs/observability/src/plugin/observability.plugin.ts b/libs/observability/src/plugin/observability.plugin.ts index 5cef9a1bf..4caf07a88 100644 --- a/libs/observability/src/plugin/observability.plugin.ts +++ b/libs/observability/src/plugin/observability.plugin.ts @@ -296,8 +296,8 @@ export default class ObservabilityPlugin extends DynamicPlugin< if (this.tracingEnabled) onHttpDidRoute(ctx); } - @HttpHook.Did('finalize', { priority: 1000 }) - _httpDidFinalize(ctx: unknown): void { + @HttpHook.Finally('finalize', { priority: 1000 }) + _httpFinallyFinalize(ctx: unknown): void { if (this.tracingEnabled) onHttpDidFinalize(ctx); // Delivered off the response path: a slow onRequestComplete must not hold the response if (this.requestLogsEnabled) void completeRequestLog(ctx as never); @@ -367,8 +367,8 @@ export default class ObservabilityPlugin extends DynamicPlugin< if (this.tracingEnabled) onToolWillApplyUI(ctx); } - @ToolHook.Did('finalize', { priority: 1000 }) - _toolDidFinalize(ctx: unknown): void { + @ToolHook.Finally('finalize', { priority: 1000 }) + _toolFinallyFinalize(ctx: unknown): void { if (this.tracingEnabled) onToolDidFinalize(ctx); if (this.requestLogsEnabled) recordRequestLogFailure(ctx as never); } @@ -409,8 +409,8 @@ export default class ObservabilityPlugin extends DynamicPlugin< if (this.tracingEnabled) onResourceDidExecute(ctx); } - @ResourceHook.Did('finalize', { priority: 1000 }) - _resourceDidFinalize(ctx: unknown): void { + @ResourceHook.Finally('finalize', { priority: 1000 }) + _resourceFinallyFinalize(ctx: unknown): void { if (this.tracingEnabled) onResourceDidFinalize(ctx); if (this.requestLogsEnabled) recordRequestLogFailure(ctx as never); } @@ -451,8 +451,8 @@ export default class ObservabilityPlugin extends DynamicPlugin< if (this.tracingEnabled) onPromptDidExecute(ctx); } - @PromptHook.Did('finalize', { priority: 1000 }) - _promptDidFinalize(ctx: unknown): void { + @PromptHook.Finally('finalize', { priority: 1000 }) + _promptFinallyFinalize(ctx: unknown): void { if (this.tracingEnabled) onPromptDidFinalize(ctx); if (this.requestLogsEnabled) recordRequestLogFailure(ctx as never); } @@ -492,8 +492,8 @@ export default class ObservabilityPlugin extends DynamicPlugin< if (this.tracingEnabled) onAgentDidExecute(ctx); } - @AgentCallHook.Did('finalize', { priority: 1000 }) - _agentDidFinalize(ctx: unknown): void { + @AgentCallHook.Finally('finalize', { priority: 1000 }) + _agentFinallyFinalize(ctx: unknown): void { if (this.tracingEnabled) onAgentDidFinalize(ctx); } @@ -575,7 +575,7 @@ export default class ObservabilityPlugin extends DynamicPlugin< if (this.tracingEnabled) onGenericFlowWillStart('skills/search', this.tracingOpts, ctx); } - @SkillSearchHook.Did('finalize', { priority: 1000 }) + @SkillSearchHook.Finally('finalize', { priority: 1000 }) _skillSearchDone(ctx: unknown): void { if (this.tracingEnabled) onGenericFlowDidFinalize(ctx); } @@ -590,7 +590,7 @@ export default class ObservabilityPlugin extends DynamicPlugin< if (this.tracingEnabled) onGenericFlowStage('loadSkills', ctx); } - @SkillLoadHook.Did('finalize', { priority: 1000 }) + @SkillLoadHook.Finally('finalize', { priority: 1000 }) _skillLoadDone(ctx: unknown): void { if (this.tracingEnabled) onGenericFlowDidFinalize(ctx); } @@ -604,7 +604,7 @@ export default class ObservabilityPlugin extends DynamicPlugin< if (this.tracingEnabled) onGenericFlowWillStart('completion/complete', this.tracingOpts, ctx); } - @CompletionHook.Did('finalize', { priority: 1000 }) + @CompletionHook.Finally('finalize', { priority: 1000 }) _completionDone(ctx: unknown): void { if (this.tracingEnabled) onGenericFlowDidFinalize(ctx); } @@ -638,8 +638,8 @@ export default class ObservabilityPlugin extends DynamicPlugin< if (this.tracingEnabled) onTransportStage('onElicitResult', ctx); } - @LegacySseHook.Did('cleanup', { priority: 1000 }) - _sseDidCleanup(ctx: unknown): void { + @LegacySseHook.Finally('cleanup', { priority: 1000 }) + _sseFinallyCleanup(ctx: unknown): void { if (this.tracingEnabled) onTransportDidFinalize(ctx); } @@ -682,8 +682,8 @@ export default class ObservabilityPlugin extends DynamicPlugin< if (this.tracingEnabled) onTransportStage('onExtApps', ctx); } - @StreamableHttpHook.Did('cleanup', { priority: 1000 }) - _shttpDidCleanup(ctx: unknown): void { + @StreamableHttpHook.Finally('cleanup', { priority: 1000 }) + _shttpFinallyCleanup(ctx: unknown): void { if (this.tracingEnabled) onTransportDidFinalize(ctx); } @@ -701,8 +701,8 @@ export default class ObservabilityPlugin extends DynamicPlugin< if (this.tracingEnabled) onTransportStage('handleRequest', ctx); } - @StatelessHttpHook.Did('cleanup', { priority: 1000 }) - _slhttpDidCleanup(ctx: unknown): void { + @StatelessHttpHook.Finally('cleanup', { priority: 1000 }) + _slhttpFinallyCleanup(ctx: unknown): void { if (this.tracingEnabled) onTransportDidFinalize(ctx); } @@ -812,7 +812,7 @@ export default class ObservabilityPlugin extends DynamicPlugin< if (this.traces('elicitationSpans')) onGenericFlowWillStart('elicitation/request', this.tracingOpts, ctx); } - @ElicitRequestHook.Did('finalize', { priority: 1000 }) + @ElicitRequestHook.Finally('finalize', { priority: 1000 }) _elicitReqDone(ctx: unknown): void { if (this.traces('elicitationSpans')) onGenericFlowDidFinalize(ctx); } @@ -822,7 +822,7 @@ export default class ObservabilityPlugin extends DynamicPlugin< if (this.traces('elicitationSpans')) onGenericFlowWillStart('elicitation/result', this.tracingOpts, ctx); } - @ElicitResultHook.Did('finalize', { priority: 1000 }) + @ElicitResultHook.Finally('finalize', { priority: 1000 }) _elicitResDone(ctx: unknown): void { if (this.traces('elicitationSpans')) onGenericFlowDidFinalize(ctx); } @@ -836,7 +836,7 @@ export default class ObservabilityPlugin extends DynamicPlugin< if (this.tracingEnabled) onGenericFlowWillStart('resources/subscribe', this.tracingOpts, ctx); } - @SubscribeResourceHook.Did('finalize', { priority: 1000 }) + @SubscribeResourceHook.Finally('finalize', { priority: 1000 }) _subscribeDone(ctx: unknown): void { if (this.tracingEnabled) onGenericFlowDidFinalize(ctx); } @@ -846,7 +846,7 @@ export default class ObservabilityPlugin extends DynamicPlugin< if (this.tracingEnabled) onGenericFlowWillStart('resources/unsubscribe', this.tracingOpts, ctx); } - @UnsubscribeResourceHook.Did('finalize', { priority: 1000 }) + @UnsubscribeResourceHook.Finally('finalize', { priority: 1000 }) _unsubscribeDone(ctx: unknown): void { if (this.tracingEnabled) onGenericFlowDidFinalize(ctx); } @@ -928,7 +928,7 @@ export default class ObservabilityPlugin extends DynamicPlugin< if (this.tracingEnabled) onGenericFlowWillStart('logging/set-level', this.tracingOpts, ctx); } - @LoggingSetLevelHook.Did('finalize', { priority: 1000 }) + @LoggingSetLevelHook.Finally('finalize', { priority: 1000 }) _setLevelDone(ctx: unknown): void { if (this.tracingEnabled) onGenericFlowDidFinalize(ctx); } diff --git a/libs/sdk/src/common/decorators/hook.decorator.ts b/libs/sdk/src/common/decorators/hook.decorator.ts index 5766dd238..0b529cdea 100644 --- a/libs/sdk/src/common/decorators/hook.decorator.ts +++ b/libs/sdk/src/common/decorators/hook.decorator.ts @@ -151,7 +151,7 @@ export function WillHookOf(flow: Name) { } /** - * Creates a typed Did hook decorator (runs after stage) + * Creates a typed Did hook decorator (runs after the stage succeeds, and not when it fails) */ export function DidHookOf(flow: Name) { type T = ExtendFlows[Name]['stage']; @@ -174,11 +174,23 @@ export function AroundHookOf(name: Name) { }; } +/** + * Creates a typed Finally hook decorator (runs after the stage whatever its outcome; cannot change it) + */ +export function FinallyHookOf(name: Name) { + type T = ExtendFlows[Name]['stage']; + type Ctx = ExtendFlows[Name]['ctx']; + const base = make(name, 'finally'); + return function (stage: T, opts: HookOptions = {}) { + return base(stage, opts); + }; +} + /** * Creates all hook decorators for a specific flow * @example * ```typescript - * const { Stage, Will, Did, Around } = FlowHooksOf('http:request'); + * const { Stage, Will, Did, Around, Finally } = FlowHooksOf('http:request'); * * class HttpRequestFlow { * @Stage('checkAuthorization') @@ -195,5 +207,6 @@ export function FlowHooksOf(name: Name) { Will: WillHookOf(name), Did: DidHookOf(name), Around: AroundHookOf(name), + Finally: FinallyHookOf(name), }; } diff --git a/libs/sdk/src/common/interfaces/internal/flow.utils.ts b/libs/sdk/src/common/interfaces/internal/flow.utils.ts index 037ada969..9df6e5a40 100644 --- a/libs/sdk/src/common/interfaces/internal/flow.utils.ts +++ b/libs/sdk/src/common/interfaces/internal/flow.utils.ts @@ -82,6 +82,9 @@ export class FlowState { (data as any)[prop] = value; return true; }, + deleteProperty(_t, prop: PropertyKey) { + return Reflect.deleteProperty(data as object, prop); + }, has(_t, prop) { return prop === 'required' || methodKeys.has(prop) || prop in (data as object); }, diff --git a/libs/sdk/src/common/metadata/hook.metadata.ts b/libs/sdk/src/common/metadata/hook.metadata.ts index 48517755c..c4af96371 100644 --- a/libs/sdk/src/common/metadata/hook.metadata.ts +++ b/libs/sdk/src/common/metadata/hook.metadata.ts @@ -4,7 +4,8 @@ import { type EntryOwnerRef } from '../entries/base.entry'; import { type ProviderRegistryInterface } from '../interfaces/internal'; import { type FlowName } from './flow.metadata'; -export type HookStageType = 'stage' | 'will' | 'did' | 'around'; +/** A `did` hook runs only when its stage succeeds; a `finally` hook runs on every outcome and cannot change it. */ +export type HookStageType = 'stage' | 'will' | 'did' | 'around' | 'finally'; export type HookPriority = number; /** diff --git a/libs/sdk/src/flows/__tests__/flow-error-state.spec.ts b/libs/sdk/src/flows/__tests__/flow-error-state.spec.ts index b2ff7c5ca..e4624ce94 100644 --- a/libs/sdk/src/flows/__tests__/flow-error-state.spec.ts +++ b/libs/sdk/src/flows/__tests__/flow-error-state.spec.ts @@ -1,15 +1,21 @@ /** * A flow that fails records why in `state.flowError` before its error and finalize stages run, so a * finalize hook can tell a failed call from a successful one (#766: the observability plugin's - * finalize hook ended a failed tool's span as a success and left its execution span open). + * finalize hook ended a failed tool's span as a success and left its execution span open). A failure + * of the finalize stage itself, such as an output schema refusing the answer, is recorded too, for + * the Finally hooks of that stage. */ import 'reflect-metadata'; +import { z } from '@frontmcp/lazy-zod'; + import { App, FlowHooksOf, Plugin, Tool, ToolContext } from '../../common'; +import { InvalidOutputError } from '../../errors'; import { FrontMcpInstance } from '../../front-mcp/front-mcp'; const ToolHook = FlowHooksOf('tools:call-tool'); const seen: unknown[] = []; +const seenFinally: unknown[] = []; @Plugin({ name: 'flow-error-probe' }) class FlowErrorProbe { @@ -17,6 +23,11 @@ class FlowErrorProbe { record(flowCtx: { state: { flowError?: unknown } }) { seen.push(flowCtx.state.flowError); } + + @ToolHook.Finally('finalize') + recordAlways(flowCtx: { state: { flowError?: unknown } }) { + seenFinally.push(flowCtx.state.flowError); + } } @Tool({ name: 'crash', inputSchema: {} }) @@ -33,7 +44,14 @@ class OkTool extends ToolContext { } } -@App({ id: 'desk', name: 'Desk', tools: [CrashTool, OkTool], plugins: [FlowErrorProbe] }) +@Tool({ name: 'refused', inputSchema: {}, outputSchema: { total: z.number() } }) +class RefusedTool extends ToolContext { + async execute() { + return { total: 'twelve' } as unknown as { total: number }; + } +} + +@App({ id: 'desk', name: 'Desk', tools: [CrashTool, OkTool, RefusedTool], plugins: [FlowErrorProbe] }) class DeskApp {} @Plugin({ name: 'zero-thrower' }) @@ -47,7 +65,53 @@ class ZeroThrower { @App({ id: 'zero', name: 'Zero', tools: [OkTool], plugins: [ZeroThrower, FlowErrorProbe] }) class ZeroApp {} +@Plugin({ name: 'unprintable-thrower' }) +class UnprintableThrower { + @ToolHook.Will('execute') + throwUnprintable() { + throw Object.create(null); + } +} + +@App({ id: 'unprintable', name: 'Unprintable', tools: [OkTool], plugins: [UnprintableThrower, FlowErrorProbe] }) +class UnprintableApp {} + +const probeSeen: boolean[] = []; + +@Plugin({ name: 'state-probe' }) +class StateProbe { + @ToolHook.Finally('finalize', { priority: -1 }) + markThenThrow(flowCtx: { state: { set(key: never, value: never): unknown } }) { + flowCtx.state.set('probe' as never, true as never); + throw new Error('the probe store is down'); + } + + @ToolHook.Finally('finalize', { priority: 1 }) + lookForMark(flowCtx: { state: object }) { + probeSeen.push('probe' in flowCtx.state); + } +} + +@App({ id: 'probed', name: 'Probed', tools: [OkTool], plugins: [StateProbe] }) +class ProbedApp {} + +@Plugin({ name: 'finalize-breaker' }) +class FinalizeBreaker { + @ToolHook.Will('finalize') + breakFinalize() { + throw new Error('finalize broke'); + } +} + +@App({ id: 'broken', name: 'Broken', tools: [CrashTool], plugins: [FinalizeBreaker, FlowErrorProbe] }) +class BrokenFinalizeApp {} + describe('state.flowError', () => { + beforeEach(() => { + seen.length = 0; + seenFinally.length = 0; + }); + it('is the error a failed call threw, and unset for a successful one', async () => { const server = await FrontMcpInstance.createDirect({ info: { name: 'desk', version: '1.0.0' }, apps: [DeskApp] }); @@ -61,7 +125,6 @@ describe('state.flowError', () => { }); it('is an Error even when a stage threw a falsy value', async () => { - seen.length = 0; const zeroServer = await FrontMcpInstance.createDirect({ info: { name: 'zero', version: '1.0.0' }, apps: [ZeroApp], @@ -72,4 +135,51 @@ describe('state.flowError', () => { expect(seen).toHaveLength(1); expect(seen[0]).toBeInstanceOf(Error); }); + + it('is an Error, and the Finally hooks still run, when a stage threw a value String() cannot convert', async () => { + const server = await FrontMcpInstance.createDirect({ + info: { name: 'unprintable', version: '1.0.0' }, + apps: [UnprintableApp], + }); + await server.callTool('ok', {}).catch(() => undefined); + await server.dispose(); + + expect(seenFinally).toHaveLength(1); + expect(String(seenFinally[0])).toContain('[object Object]'); + }); + + it('loses a key a Finally hook added before a throw the runner dropped', async () => { + const server = await FrontMcpInstance.createDirect({ + info: { name: 'probed', version: '1.0.0' }, + apps: [ProbedApp], + }); + await server.callTool('ok', {}); + await server.dispose(); + + expect(probeSeen).toEqual([false]); + }); + + it("is the output schema's refusal of the answer for the Finally hooks of finalize, whose Did hooks skip it", async () => { + const server = await FrontMcpInstance.createDirect({ info: { name: 'desk', version: '1.0.0' }, apps: [DeskApp] }); + + await server.callTool('refused', {}).catch(() => undefined); + await server.dispose(); + + expect(seen).toEqual([]); + expect(seenFinally).toEqual([expect.any(InvalidOutputError)]); + }); + + it('keeps the first failure, the one the client gets, when the finalize stage fails after it', async () => { + const server = await FrontMcpInstance.createDirect({ + info: { name: 'broken', version: '1.0.0' }, + apps: [BrokenFinalizeApp], + }); + + const failure = await server.callTool('crash', {}).catch((error: unknown) => error); + await server.dispose(); + + expect(String(failure)).toContain('tool crashed'); + expect(seenFinally).toHaveLength(1); + expect(String(seenFinally[0])).toContain('tool crashed'); + }); }); diff --git a/libs/sdk/src/flows/__tests__/flow-stage-hook-lists.spec.ts b/libs/sdk/src/flows/__tests__/flow-stage-hook-lists.spec.ts index 1e665d80e..cde4ffb04 100644 --- a/libs/sdk/src/flows/__tests__/flow-stage-hook-lists.spec.ts +++ b/libs/sdk/src/flows/__tests__/flow-stage-hook-lists.spec.ts @@ -1,6 +1,6 @@ /** - * A stage runs its will and did hooks only when it has some, and reads each list when the stage starts, so hooks a - * run adds (the tool class's own, joined at `createToolCallContext`) still run on stages that had none before. + * A stage runs its will, did and finally hooks only when it has some, and reads each list when the stage starts, so + * hooks a run adds (the tool class's own, joined at `createToolCallContext`) still run on stages that had none before. */ import 'reflect-metadata'; @@ -25,6 +25,11 @@ class StageTracePlugin { await next(); trace.push('plugin around validateInput: after'); } + + @ToolHook.Finally('validateInput') + finallyValidateInput() { + trace.push('plugin finally validateInput'); + } } @Tool({ name: 'echo', inputSchema: {} }) @@ -44,6 +49,11 @@ class EchoTool extends ToolContext { trace.push('tool did validateOutput'); } + @ToolHook.Finally('validateOutput') + finallyValidateOutput() { + trace.push('tool finally validateOutput'); + } + @ToolHook.Will('finalize') willFinalize() { trace.push('tool will finalize'); @@ -81,8 +91,10 @@ describe('flow stage hook lists', () => { 'tool will checkToolCredentials', 'plugin around validateInput: before', 'plugin around validateInput: after', + 'plugin finally validateInput', 'execute', 'tool did validateOutput', + 'tool finally validateOutput', 'tool will finalize', ]); } diff --git a/libs/sdk/src/flows/__tests__/flow-typed-keys.spec.ts b/libs/sdk/src/flows/__tests__/flow-typed-keys.spec.ts new file mode 100644 index 000000000..06faacc93 --- /dev/null +++ b/libs/sdk/src/flows/__tests__/flow-typed-keys.spec.ts @@ -0,0 +1,26 @@ +import { parseTypedKey, stageBasesOf } from '../flow.instance'; + +describe('parseTypedKey', () => { + it.each([ + ['willExecute', 'will'], + ['didExecute', 'did'], + ['aroundExecute', 'around'], + ['finallyExecute', 'finally'], + ] as const)('reads %s as a %s hook key of the execute stage, never as a stage of its own', (key, type) => { + expect(parseTypedKey(key)).toEqual({ base: 'execute', type }); + }); + + it.each(['execute', 'finalize', 'finally', 'will'])('reads %s as a plain stage name', (key) => { + expect(parseTypedKey(key)).toEqual({ base: key }); + }); +}); + +describe('stageBasesOf', () => { + it('runs a typed key with its base stage, never as a stage of its own', () => { + expect(stageBasesOf(['execute', 'finallyExecute', 'willExecute'])).toEqual(['execute']); + }); + + it('keeps a stage named finally a stage when the group lists no stage, as before Finally hooks', () => { + expect(stageBasesOf(['parse', 'finallyCheck'])).toEqual(['parse', 'finallyCheck']); + }); +}); diff --git a/libs/sdk/src/flows/flow.instance.ts b/libs/sdk/src/flows/flow.instance.ts index 6995b1ecc..3c2c4834a 100644 --- a/libs/sdk/src/flows/flow.instance.ts +++ b/libs/sdk/src/flows/flow.instance.ts @@ -68,6 +68,7 @@ interface StageKeys { will: string; did: string; around: string; + finally: string; } // Stage names come from flow plans, so this stays as small as the set of stages. @@ -76,34 +77,59 @@ const stageKeysByName = new Map(); function stageKeysOf(stage: string): StageKeys { let keys = stageKeysByName.get(stage); if (!keys) { - keys = { will: `will${CAP(stage)}`, did: `did${CAP(stage)}`, around: `around${CAP(stage)}` }; + keys = { + will: `will${CAP(stage)}`, + did: `did${CAP(stage)}`, + around: `around${CAP(stage)}`, + finally: `finally${CAP(stage)}`, + }; stageKeysByName.set(stage, keys); } return keys; } -function parseTypedKey(k: string): { base: string; type?: 'will' | 'did' | 'around' } { +export function parseTypedKey(k: string): { base: string; type?: 'will' | 'did' | 'around' | 'finally' } { const lc = k.toLowerCase(); if (lc.startsWith('will') && k.length > 4) return { base: k.slice(4, 5).toLowerCase() + k.slice(5), type: 'will' }; if (lc.startsWith('did') && k.length > 3) return { base: k.slice(3, 4).toLowerCase() + k.slice(4), type: 'did' }; if (lc.startsWith('around') && k.length > 6) return { base: k.slice(6, 7).toLowerCase() + k.slice(7), type: 'around' }; + if (lc.startsWith('finally') && k.length > 7) + return { base: k.slice(7, 8).toLowerCase() + k.slice(8), type: 'finally' }; return { base: k }; } +/** `String(value)`, or its `Object.prototype.toString` tag for a value that cannot be converted (a null-prototype object). */ +function describeValue(value: unknown): string { + try { + return String(value); + } catch { + return Object.prototype.toString.call(value); + } +} + +/** The error a fail() carried, or an Error naming why the flow was aborted. */ +function failureOf(control: FlowControl): unknown { + const originalError = (control as { originalError?: unknown }).originalError; + if (originalError !== undefined) return originalError; + return control.type === 'abort' ? new InternalMcpError(`Flow aborted: ${String(control.output)}`) : control; +} + const stageBasesByGroup = new WeakMap(); /** The base stages a plan group runs, in order: a typed key runs with its base, and a repeated base runs once. */ -function stageBasesOf(group: readonly string[]): string[] { +export function stageBasesOf(group: readonly string[]): string[] { let bases = stageBasesByGroup.get(group); if (!bases) { const seen = new Set(); bases = []; for (const rawKey of group) { const { base, type } = parseTypedKey(rawKey); - if (type || seen.has(base)) continue; - seen.add(base); - bases.push(base); + // A stage named `finallyCheck` predates Finally hooks: it is `check`'s hook key only when the group lists `check` + const stage = type === 'finally' && !group.includes(base) ? rawKey : base; + if ((type && stage === base) || seen.has(stage)) continue; + seen.add(stage); + bases.push(stage); } stageBasesByGroup.set(group, bases); } @@ -500,8 +526,29 @@ export class FlowInstance extends FlowEntry { // Whether any stage body or hook is registered under `key` right now. const hasEntries = (key: string): boolean => (stages[key]?.length ?? 0) > 0; + // A Finally hook cannot respond or fail its stage: what it throws is logged and dropped. + const ignoreFinallyThrow = (key: string, thrown: unknown) => { + const description = thrown instanceof FlowControl ? `FlowControl '${thrown.type}'` : describeValue(thrown); + this.logger.warn(`Ignored a throw from a Finally hook of '${key}': it cannot change the stage's outcome`, { + flow: name, + thrown: description, + }); + }; + + // The values a Finally hook set on the state before the throw the runner drops, such as a job's answer, are put back + const restoreState = (before: Readonly>) => { + const state = context.state as unknown as Record; + for (const key of Object.keys(context.state.snapshot())) { + if (!(key in before)) delete state[key]; + } + context.state.set(before as never); + }; + // Robust list runner (doesn't skip mid-run insertions) - const runList = async (key: string, opts?: { ignoreRespond?: boolean }): Promise => { + const runList = async ( + key: string, + opts?: { ignoreRespond?: boolean; ignoreThrows?: boolean }, + ): Promise => { const seen = new Set(); while (true) { @@ -516,9 +563,15 @@ export class FlowInstance extends FlowEntry { if (!item) break; seen.add(item); + const stateBefore = opts?.ignoreThrows ? (context.state.snapshot() as Record) : undefined; try { await item.method(context); } catch (e: any) { + if (opts?.ignoreThrows) { + if (stateBefore) restoreState(stateBefore); + ignoreFinallyThrow(key, e); + continue; + } if (e instanceof FlowControl && e.type === 'respond' && opts?.ignoreRespond) continue; return toStageResult(e); } @@ -548,9 +601,20 @@ export class FlowInstance extends FlowEntry { return FAILED_OUTCOMES.has(innerResult.outcome) ? { outcome: 'ok' } : innerResult; }; + // `state.flowError` keeps the run's first failure (a thrown Error, a `fail()` or an abort) for what runs after it + const recordFailure = (control: unknown) => { + if (context.state.get('flowError' as never)) return; + const failure = control instanceof FlowControl ? failureOf(control) : control; + const flowError = + failure instanceof Error + ? failure + : new InternalMcpError(`Flow failed with a non-Error value: ${describeValue(failure)}`); + context.state.set('flowError' as never, flowError as never); + }; + // Run exactly one stage in order: will → around(stage) → did (did runs once) // An empty hook list is skipped without a call: running it would only return 'ok'. - const runOneStage = async (stageName: string, stopOnRespond: boolean): Promise => { + const runStageSteps = async (stageName: string, stopOnRespond: boolean): Promise => { const keys = stageKeysOf(stageName); // 1) willStage if (hasEntries(keys.will)) { @@ -578,6 +642,15 @@ export class FlowInstance extends FlowEntry { return { outcome: 'ok' }; }; + // Then the stage's Finally hooks run, whatever its outcome, with its failure recorded for them. + const runOneStage = async (stageName: string, stopOnRespond: boolean): Promise => { + const result = await runStageSteps(stageName, stopOnRespond); + if (FAILED_OUTCOMES.has(result.outcome)) recordFailure(result.control); + const finallyKey = stageKeysOf(stageName).finally; + if (hasEntries(finallyKey)) await runList(finallyKey, { ignoreThrows: true }); + return result; + }; + // IMPORTANT: ignore typed stage names in plan arrays. // Only base stage names in the plan drive execution; typed hooks run *with* their base. const runStageGroup = async ( @@ -599,15 +672,6 @@ export class FlowInstance extends FlowEntry { return { outcome: 'ok' }; }; - // The error and finalize stages read why the flow failed from `state.flowError`, always an Error - const recordFailure = (control: unknown) => { - const flowError = - control instanceof Error - ? control - : new InternalMcpError(`Flow failed with a non-Error value: ${String(control)}`); - context.state.set('flowError' as never, flowError as never); - }; - const runErrorStage = async () => { await runStageGroup((plan as any).error, false, { ignoreRespond: true }); }; @@ -638,7 +702,6 @@ export class FlowInstance extends FlowEntry { if (pre.outcome === 'respond') { const post = await runStageGroup((plan as any).post, false); if (post.outcome === 'unknown_error' || post.outcome === 'fail') { - recordFailure(post.control); try { await runErrorStage(); } finally { @@ -657,7 +720,6 @@ export class FlowInstance extends FlowEntry { return responded; } if (pre.outcome === 'unknown_error' || pre.outcome === 'fail') { - recordFailure(pre.control); try { await runErrorStage(); } finally { @@ -681,7 +743,6 @@ export class FlowInstance extends FlowEntry { if (exec.outcome === 'respond') { // continue to post + finalize } else if (exec.outcome === 'unknown_error' || exec.outcome === 'fail') { - recordFailure(exec.control); try { await runErrorStage(); } finally { @@ -702,7 +763,6 @@ export class FlowInstance extends FlowEntry { const post = await runStageGroup((plan as any).post, false); this.logger.verbose(`run: POST completed, outcome=${post.outcome}`); if (post.outcome === 'unknown_error' || post.outcome === 'fail') { - recordFailure(post.control); try { await runErrorStage(); } finally { diff --git a/libs/sdk/src/flows/flow.stages.ts b/libs/sdk/src/flows/flow.stages.ts index 1e6f8e9c8..8a46635cf 100644 --- a/libs/sdk/src/flows/flow.stages.ts +++ b/libs/sdk/src/flows/flow.stages.ts @@ -33,13 +33,7 @@ export function cloneStageMap(table: StageMap): StageMap { } export function resolveStageKey(type: HookMetadata['type'], stage: string) { - return type === 'will' - ? `will${cap(stage)}` - : type === 'did' - ? `did${cap(stage)}` - : type === 'around' - ? `around${cap(stage)}` - : stage; + return type === 'stage' ? stage : `${type}${cap(stage)}`; } export function collectFlowHookMap(FlowClass: any): StageMap { diff --git a/libs/sdk/src/hooks/__tests__/flow-hooks.behaviour.spec.ts b/libs/sdk/src/hooks/__tests__/flow-hooks.behaviour.spec.ts index 8e385ac5c..d84abc03b 100644 --- a/libs/sdk/src/hooks/__tests__/flow-hooks.behaviour.spec.ts +++ b/libs/sdk/src/hooks/__tests__/flow-hooks.behaviour.spec.ts @@ -35,6 +35,16 @@ class TracePlugin { trace.push('Did p100'); } + @ToolHook.Finally('execute', { priority: 100 }) + finallyPriorityHundred() { + trace.push('Finally p100'); + } + + @ToolHook.Finally('execute', { priority: 0 }) + finallyPriorityZero() { + trace.push('Finally p0'); + } + @ToolHook.Around('execute') async aroundExecute(_ctx: FlowCtxOf<'tools:call-tool'>, next: () => Promise) { trace.push('Around: before next()'); @@ -184,6 +194,15 @@ describe('tools:call-tool flow hooks', () => { expect(deskTrace.filter((entry) => entry.startsWith('Did p'))).toEqual(['Did p0', 'Did p100']); }); + it('runs Finally hooks after the Did hooks, with a lower priority first', () => { + expect(deskTrace.filter((entry) => /^(Did|Finally) p/.test(entry))).toEqual([ + 'Did p0', + 'Did p100', + 'Finally p0', + 'Finally p100', + ]); + }); + it('runs a hook declared on the @Tool class', () => { expect(deskTrace).toContain('hook on @Tool class'); }); diff --git a/libs/sdk/src/hooks/__tests__/flow-hooks.finally.spec.ts b/libs/sdk/src/hooks/__tests__/flow-hooks.finally.spec.ts new file mode 100644 index 000000000..f09300c35 --- /dev/null +++ b/libs/sdk/src/hooks/__tests__/flow-hooks.finally.spec.ts @@ -0,0 +1,359 @@ +/** + * A stage's Finally hooks run after its Will hooks, its body and its Did hooks whatever the outcome, read why the + * stage failed from `state.flowError`, and never change what the client gets: what one throws or responds is + * logged and dropped. + */ +import 'reflect-metadata'; + +import { z } from '@frontmcp/lazy-zod'; + +import { + createTestFetchServer, + rpc20260728, + type TestFetchServer, +} from '../../__test-utils__/helpers/mcp-20260728.helpers'; +import { + App, + FlowControl, + FlowHooksOf, + LogLevel, + LogTransport, + LogTransportInterface, + Plugin, + Tool, + ToolContext, + type FlowCtxOf, + type LogRecord, +} from '../../common'; +import { PublicMcpError } from '../../errors'; + +const ToolHook = FlowHooksOf('tools:call-tool'); +type CallToolFlow = FlowCtxOf<'tools:call-tool'>; + +const trace: string[] = []; +const warnings: LogRecord[] = []; + +const calling = + (...names: string[]) => + (ctx: CallToolFlow) => + names.includes(String(ctx.state.input?.name)); +const outcomeOf = (ctx: CallToolFlow) => ctx.state.flowError?.message ?? 'ok'; + +@LogTransport({ name: 'FinallyWarningCapture', description: 'Captures the warnings a run logs' }) +class WarningCapture extends LogTransportInterface { + log(record: LogRecord): void { + if (record.level === LogLevel.Warn) warnings.push(record); + } +} + +function postingTool(name: string, answer: unknown = { posted: true }) { + @Tool({ name, inputSchema: {}, outputSchema: { posted: z.boolean() } }) + class PostingTool extends ToolContext { + async execute() { + return answer as { posted: boolean }; + } + } + return PostingTool; +} + +@Tool({ name: 'post_crash', inputSchema: {}, outputSchema: { posted: z.boolean() } }) +class PostCrashTool extends ToolContext { + async execute(): Promise<{ posted: boolean }> { + throw new PublicMcpError('ledger offline'); + } +} + +const PostEntryTool = postingTool('post_entry'); +const PostRefusedTool = postingTool('post_refused', { posted: 'yes' }); + +@Plugin({ name: 'ledger-finally' }) +class LedgerFinallyPlugin { + @ToolHook.Will('execute', { filter: calling('post_blocked') }) + refuse() { + throw new PublicMcpError('blocked by policy'); + } + + @ToolHook.Will('execute', { filter: calling('post_gated') }) + closeGate(ctx: CallToolFlow) { + ctx.fail(new PublicMcpError('gate closed')); + } + + @ToolHook.Will('execute', { filter: calling('post_aborted') }) + abortExecute() { + FlowControl.abort('maintenance window'); + } + + @ToolHook.Will('execute', { filter: calling('post_cached') }) + answerFromCache(ctx: CallToolFlow) { + ctx.respond({ content: [{ type: 'text', text: 'from cache' }] }); + } + + @ToolHook.Around('execute', { filter: calling('post_wrapped') }) + async breakAround() { + throw new PublicMcpError('around broke'); + } + + @ToolHook.Did('execute') + didExecute() { + trace.push('Did execute'); + } + + @ToolHook.Did('execute', { filter: calling('post_did_broke') }) + breakDidExecute() { + throw new PublicMcpError('did hook broke'); + } + + @ToolHook.Finally('execute', { priority: 100 }) + lastFinallyExecute(ctx: CallToolFlow) { + trace.push(`Finally p100 execute: ${outcomeOf(ctx)}`); + } + + @ToolHook.Finally('execute', { priority: 0 }) + firstFinallyExecute(ctx: CallToolFlow) { + trace.push(`Finally p0 execute: ${outcomeOf(ctx)}`); + } + + @ToolHook.Did('finalize') + didFinalize() { + trace.push('Did finalize'); + } + + @ToolHook.Finally('finalize') + finallyFinalize(ctx: CallToolFlow) { + trace.push(`Finally finalize: ${outcomeOf(ctx)}`); + } +} + +@App({ + id: 'ledger', + name: 'Ledger', + plugins: [LedgerFinallyPlugin], + tools: [ + PostEntryTool, + PostCrashTool, + PostRefusedTool, + postingTool('post_blocked'), + postingTool('post_gated'), + postingTool('post_cached'), + postingTool('post_wrapped'), + postingTool('post_did_broke'), + postingTool('post_aborted'), + ], +}) +class LedgerApp {} + +@Plugin({ name: 'unruly-finally' }) +class UnrulyFinallyPlugin { + @ToolHook.Finally('finalize', { priority: -10 }) + hijack(ctx: CallToolFlow) { + ctx.respond({ content: [{ type: 'text', text: 'hijacked' }] }); + } + + @ToolHook.Finally('finalize', { priority: -5 }) + explode() { + throw new Error('finally hook broke'); + } + + @ToolHook.Finally('finalize', { priority: -3 }) + throwUnprintable() { + throw Object.create(null); + } + + @ToolHook.Finally('finalize') + recordAfterUnruly(ctx: CallToolFlow) { + trace.push(`Finally after unruly hooks: ${outcomeOf(ctx)}`); + } +} + +@App({ + id: 'unruly', + name: 'Unruly', + plugins: [UnrulyFinallyPlugin], + tools: [PostEntryTool, PostCrashTool, PostRefusedTool], +}) +class UnrulyApp {} + +async function callTool(server: TestFetchServer, name: string) { + trace.length = 0; + const { message } = await rpc20260728(server.handler, 'tools/call', { name, arguments: {} }); + const result = message.result ?? {}; + const content = (result['content'] as Array<{ text?: string }> | undefined) ?? []; + const resultMeta = result['_meta'] as Record | undefined; + return { + isError: result['isError'] === true, + text: content.map((block) => block.text ?? '').join('\n'), + code: resultMeta?.['code'], + structuredContent: result['structuredContent'], + trace: [...trace], + }; +} + +describe('Finally hooks', () => { + let server: TestFetchServer; + + beforeAll(async () => { + server = await createTestFetchServer({ info: { name: 'finally-hooks', version: '1.0.0' }, apps: [LedgerApp] }); + }); + + it('run after the Did hooks of a stage that succeeded, lower priority first', async () => { + const call = await callTool(server, 'post_entry'); + + expect(call.structuredContent).toEqual({ posted: true }); + expect(call.trace).toEqual([ + 'Did execute', + 'Finally p0 execute: ok', + 'Finally p100 execute: ok', + 'Did finalize', + 'Finally finalize: ok', + ]); + }); + + it('run when the stage body fails, and read the failure from state.flowError', async () => { + const call = await callTool(server, 'post_crash'); + + expect({ isError: call.isError, text: call.text }).toEqual({ isError: true, text: 'ledger offline' }); + expect(call.trace).toEqual([ + 'Finally p0 execute: ledger offline', + 'Finally p100 execute: ledger offline', + 'Did finalize', + 'Finally finalize: ledger offline', + ]); + }); + + it('run when a Will hook fails the stage before its body runs', async () => { + const call = await callTool(server, 'post_blocked'); + + expect({ isError: call.isError, text: call.text }).toEqual({ isError: true, text: 'blocked by policy' }); + expect(call.trace).toEqual([ + 'Finally p0 execute: blocked by policy', + 'Finally p100 execute: blocked by policy', + 'Did finalize', + 'Finally finalize: blocked by policy', + ]); + }); + + it('read the error a Will hook passed to fail(), not the signal that carried it', async () => { + const call = await callTool(server, 'post_gated'); + + expect({ isError: call.isError, text: call.text }).toEqual({ isError: true, text: 'gate closed' }); + expect(call.trace).toEqual([ + 'Finally p0 execute: gate closed', + 'Finally p100 execute: gate closed', + 'Did finalize', + 'Finally finalize: gate closed', + ]); + }); + + it('read an abort as the failure, like a fail()', async () => { + const call = await callTool(server, 'post_aborted'); + + expect(call.trace.slice(0, 2)).toEqual([ + 'Finally p0 execute: Flow aborted: maintenance window', + 'Finally p100 execute: Flow aborted: maintenance window', + ]); + }); + + it('run when a Will hook responds in place of the stage', async () => { + const call = await callTool(server, 'post_cached'); + + expect({ isError: call.isError, text: call.text }).toEqual({ isError: false, text: 'from cache' }); + expect(call.trace).toEqual([ + 'Finally p0 execute: ok', + 'Finally p100 execute: ok', + 'Did finalize', + 'Finally finalize: ok', + ]); + }); + + it('run when an Around hook fails the stage', async () => { + const call = await callTool(server, 'post_wrapped'); + + expect({ isError: call.isError, text: call.text }).toEqual({ isError: true, text: 'around broke' }); + expect(call.trace).toEqual([ + 'Finally p0 execute: around broke', + 'Finally p100 execute: around broke', + 'Did finalize', + 'Finally finalize: around broke', + ]); + }); + + it('run when a Did hook fails a stage whose body succeeded, and read that failure, which the client gets', async () => { + const call = await callTool(server, 'post_did_broke'); + + expect({ isError: call.isError, text: call.text }).toEqual({ isError: true, text: 'did hook broke' }); + expect(call.trace).toEqual([ + 'Did execute', + 'Finally p0 execute: did hook broke', + 'Finally p100 execute: did hook broke', + 'Did finalize', + 'Finally finalize: did hook broke', + ]); + }); + + it('run on finalize when the output schema refuses the answer, while Did on finalize does not', async () => { + const call = await callTool(server, 'post_refused'); + + expect({ isError: call.isError, code: call.code }).toEqual({ isError: true, code: 'INVALID_OUTPUT' }); + expect(call.trace).toEqual([ + 'Did execute', + 'Finally p0 execute: ok', + 'Finally p100 execute: ok', + 'Finally finalize: Tool output validation failed (output does not match outputSchema at posted)', + ]); + }); +}); + +describe('a Finally hook that responds or throws', () => { + let server: TestFetchServer; + + beforeAll(async () => { + server = await createTestFetchServer({ + info: { name: 'unruly-finally-hooks', version: '1.0.0' }, + apps: [UnrulyApp], + logging: { level: LogLevel.Warn, enableConsole: false, transports: [WarningCapture] }, + }); + }); + + beforeEach(() => { + warnings.length = 0; + }); + + it('leaves a successful answer as it was, and the later Finally hooks still run', async () => { + const call = await callTool(server, 'post_entry'); + + expect({ isError: call.isError, structuredContent: call.structuredContent }).toEqual({ + isError: false, + structuredContent: { posted: true }, + }); + expect(call.trace).toEqual(['Finally after unruly hooks: ok']); + }); + + it('leaves the error of a failed call as it was', async () => { + const call = await callTool(server, 'post_crash'); + + expect({ isError: call.isError, text: call.text }).toEqual({ isError: true, text: 'ledger offline' }); + expect(call.trace).toEqual(['Finally after unruly hooks: ledger offline']); + }); + + it('leaves the refusal of an answer the output schema refuses as it was', async () => { + const call = await callTool(server, 'post_refused'); + + expect({ isError: call.isError, code: call.code }).toEqual({ isError: true, code: 'INVALID_OUTPUT' }); + expect(call.trace).toEqual([ + 'Finally after unruly hooks: Tool output validation failed (output does not match outputSchema at posted)', + ]); + }); + + it('logs what each of them threw as a warning naming the stage', async () => { + await callTool(server, 'post_entry'); + + const logged = warnings.map((record) => + [record.message, ...record.args].map((part) => JSON.stringify(part)).join(' '), + ); + expect(logged).toEqual([ + expect.stringMatching(/finallyFinalize.*respond/), + expect.stringMatching(/finallyFinalize.*finally hook broke/), + expect.stringMatching(/finallyFinalize.*\[object Object\]/), + ]); + }); +}); diff --git a/libs/sdk/src/job/__tests__/execute-job.flow.spec.ts b/libs/sdk/src/job/__tests__/execute-job.flow.spec.ts index a278607db..84eab17d5 100644 --- a/libs/sdk/src/job/__tests__/execute-job.flow.spec.ts +++ b/libs/sdk/src/job/__tests__/execute-job.flow.spec.ts @@ -87,6 +87,16 @@ class JobAuditPlugin { await next(); } + @JobHook.Finally('validateOutput') + overrideAnswer(flowCtx: JobFlowCtx) { + // A Finally hook's answer is ignored, so it cannot replace the job's result + if (flowCtx.state.job?.name === 'overridden_job') flowCtx.respond({ result: { count: 999 }, logs: [] }); + if (flowCtx.state.job?.name === 'replaced_job') { + flowCtx.state.set('answer', { result: { count: 999 }, logs: [] }); + throw new Error('the recorder is down'); + } + } + @JobHook.Will('finalize') finalizing(flowCtx: JobFlowCtx) { trace.push(at('will', 'finalize', flowCtx)); @@ -198,6 +208,20 @@ class FailingCompletionStore extends MemoryJobStateStore { } } +@Job({ name: 'overridden_job', inputSchema: {}, outputSchema: { count: z.number() } }) +class OverriddenJob extends JobContext { + async execute() { + return { count: 1 }; + } +} + +@Job({ name: 'replaced_job', inputSchema: {}, outputSchema: { count: z.number() } }) +class ReplacedJob extends JobContext { + async execute() { + return { count: 1 }; + } +} + @Job({ name: 'aborted_job', inputSchema: {}, outputSchema: {} }) class AbortedJob extends JobContext { async execute() { @@ -285,6 +309,8 @@ class WhoAmIFlow {} ThrowerJob, SendJob, AbortedJob, + OverriddenJob, + ReplacedJob, WhoAmIJob, HookedJob, ], @@ -510,18 +536,34 @@ describe('jobs:execute-job flow (#700)', () => { ); }); - it('records an attempt a hook ended without an answer as failed', async () => { + it('records an attempt a hook aborted as failed, with the reason it gave', async () => { await expect(manager.executeJob(jobNamed('aborted_job'), {})).rejects.toBeInstanceOf(FlowControl); const [run] = await manager.listRuns({ jobId: 'aborted_job' }); expect(run).toEqual( expect.objectContaining({ state: 'failed', - error: expect.objectContaining({ message: 'The job attempt ended before it produced a result' }), + error: expect.objectContaining({ message: 'Flow aborted: stopped by a hook' }), }), ); }); + it("keeps the job's result when a Finally hook answers in its place", async () => { + const result = await manager.executeJob(jobNamed('overridden_job'), {}); + + expect(result).toEqual(expect.objectContaining({ state: 'completed', result: { count: 1 } })); + const [run] = await manager.listRuns({ jobId: 'overridden_job' }); + expect(run).toEqual(expect.objectContaining({ state: 'completed', result: { count: 1 } })); + }); + + it("keeps the job's result when a Finally hook replaces it in state and then throws", async () => { + const result = await manager.executeJob(jobNamed('replaced_job'), {}); + + expect(result).toEqual(expect.objectContaining({ state: 'completed', result: { count: 1 } })); + const [run] = await manager.listRuns({ jobId: 'replaced_job' }); + expect(run).toEqual(expect.objectContaining({ state: 'completed', result: { count: 1 } })); + }); + it('builds the job with the providers a caller without a context passes', async () => { const result = await manager.executeJob(jobNamed('count_job'), { n: 7 }, { contextProviders: scope.providers }); diff --git a/libs/sdk/src/tool/flows/__tests__/call-tool.output-schema.spec.ts b/libs/sdk/src/tool/flows/__tests__/call-tool.output-schema.spec.ts index f03f8001d..979d805b4 100644 --- a/libs/sdk/src/tool/flows/__tests__/call-tool.output-schema.spec.ts +++ b/libs/sdk/src/tool/flows/__tests__/call-tool.output-schema.spec.ts @@ -7,7 +7,19 @@ import { rpc20260728, type TestFetchServer, } from '../../../__test-utils__/helpers/mcp-20260728.helpers'; -import { App, Tool, ToolContext } from '../../../common'; +import { App, FlowHooksOf, Plugin, Tool, ToolContext, type FlowCtxOf } from '../../../common'; +import { InvalidOutputError } from '../../../errors'; + +const ToolHook = FlowHooksOf('tools:call-tool'); +const finalizeFailures: unknown[] = []; + +@Plugin({ name: 'refusal-probe' }) +class RefusalProbe { + @ToolHook.Finally('finalize') + record(ctx: FlowCtxOf<'tools:call-tool'>) { + finalizeFailures.push(ctx.state.flowError); + } +} @Tool({ name: 'get_invoice', @@ -37,7 +49,12 @@ class LabelRatioTool extends ToolContext { } } -@App({ id: 'billing', name: 'Billing', tools: [GetInvoiceTool, MeasureRatioTool, LabelRatioTool] }) +@App({ + id: 'billing', + name: 'Billing', + tools: [GetInvoiceTool, MeasureRatioTool, LabelRatioTool], + plugins: [RefusalProbe], +}) class BillingApp {} describe('tools/call output schema enforcement', () => { @@ -73,6 +90,16 @@ describe('tools/call output schema enforcement', () => { expect(content.map((block) => block.text ?? '').join('\n')).not.toContain('CC-7731'); }); + it('records the refusal as state.flowError for the Finally hooks of finalize', async () => { + finalizeFailures.length = 0; + + await callGetInvoice(); + await rpc20260728(server.handler, 'tools/call', { name: 'measure_ratio', arguments: {} }); + + expect(finalizeFailures).toEqual([expect.any(InvalidOutputError), expect.any(InvalidOutputError)]); + expect((finalizeFailures[1] as InvalidOutputError).details?.reason).toBe('non-finite-number'); + }); + describe('non-finite numbers', () => { async function callTool(target: TestFetchServer, name: string) { const { message } = await rpc20260728(target.handler, 'tools/call', { name, arguments: {} }); diff --git a/libs/sdk/src/tool/flows/call-tool.flow.ts b/libs/sdk/src/tool/flows/call-tool.flow.ts index bc971eb50..2b12cecd6 100644 --- a/libs/sdk/src/tool/flows/call-tool.flow.ts +++ b/libs/sdk/src/tool/flows/call-tool.flow.ts @@ -141,6 +141,8 @@ const stateSchema = z.object({ // Store the raw executed output for plugins to see rawOutput: z.any().optional(), output: outputSchema, + // The run's first failure, set by the flow runner for the stages and Finally hooks after it + flowError: z.instanceof(Error).optional(), // UI result from applyUI stage (if UI config exists) uiResult: z.any().optional() as z.ZodType, // UI metadata from rendering (merged into _meta) diff --git a/libs/skills/catalog/frontmcp-development/SKILL.md b/libs/skills/catalog/frontmcp-development/SKILL.md index d1f442dac..5bc8b80eb 100644 --- a/libs/skills/catalog/frontmcp-development/SKILL.md +++ b/libs/skills/catalog/frontmcp-development/SKILL.md @@ -79,7 +79,7 @@ This is a router skill. The "steps" here are how to choose the right reference ( | Use official plugins (caching, remember, feature flags) | `official-plugins` | Built-in plugins for caching, session memory, approval, and feature flags (dashboard is beta) | | Connect to an external data source via a custom adapter | `create-adapter` | Create custom adapters for external data sources | | Configure LLM settings for an agent component | `create-agent-llm-config` | Configure LLM settings for agent components | -| Add will/did/around lifecycle hooks to a plugin | `create-plugin-hooks` | Add lifecycle hooks to plugins (will/did/around) | +| Add will/did/around/finally lifecycle hooks to a plugin | `create-plugin-hooks` | Add lifecycle hooks to plugins (will/did/around/finally) | ## Recommended Reading Order diff --git a/libs/skills/catalog/frontmcp-development/references/create-plugin-hooks.md b/libs/skills/catalog/frontmcp-development/references/create-plugin-hooks.md index cca52d962..a1daad079 100644 --- a/libs/skills/catalog/frontmcp-development/references/create-plugin-hooks.md +++ b/libs/skills/catalog/frontmcp-development/references/create-plugin-hooks.md @@ -1,11 +1,11 @@ --- name: create-plugin-hooks -description: Intercept and extend FrontMCP flows using before, after, around, and stage hook decorators +description: Intercept and extend FrontMCP flows using before, after, around, finally, and stage hook decorators --- # Creating Plugins with Flow Lifecycle Hooks -Plugins intercept and extend FrontMCP flows using lifecycle hook decorators. Every flow (tool calls, resource reads, prompt gets, etc.) is composed of **stages**, and hooks let you run logic before, after, around, or as part of any stage. +Plugins intercept and extend FrontMCP flows using lifecycle hook decorators. Every flow (tool calls, resource reads, prompt gets, etc.) is composed of **stages**, and hooks let you run logic before, after, around, or as part of any stage, or after it whatever its outcome. ## When to Use This Skill @@ -14,6 +14,7 @@ Plugins intercept and extend FrontMCP flows using lifecycle hook decorators. Eve - Adding before/after logic to tool execution (logging, metrics, input enrichment) - Implementing authorization checks that intercept flows before they reach the tool - Wrapping stage execution with caching, retry, or timing logic via `@Around` +- Closing what a hook opened (a span, a timer, a lock) after a stage, whether it succeeded or failed, via `@Finally` ### Recommended @@ -27,28 +28,64 @@ Plugins intercept and extend FrontMCP flows using lifecycle hook decorators. Eve - You want to use an existing official plugin that already provides hooks (see `official-plugins`) - You are building a simple tool with no cross-cutting concerns (see `create-tool`) -> **Decision:** Use this skill when you need to intercept or wrap flow stages with `@Will`, `@Did`, `@Around`, or `@Stage` decorators. +> **Decision:** Use this skill when you need to intercept or wrap flow stages with `@Will`, `@Did`, `@Around`, `@Finally`, or `@Stage` decorators. ## Hook Decorator Types -FrontMCP provides four hook decorators obtained via `FlowHooksOf(flowName)`: +FrontMCP provides five hook decorators obtained via `FlowHooksOf(flowName)`: -| Decorator | Timing | Use Case | -| --------- | ------------------------------------------------ | ---------------------------------------------- | -| `@Will` | **Before** a stage runs | Validate input, inject headers, check auth | -| `@Did` | **After** a stage completes | Log results, emit metrics, transform output | -| `@Stage` | **Joins** a stage, alongside the flow's own step | Extra work in the stage, ending the flow early | -| `@Around` | **Wraps** a stage (before + after) | Caching, timing, retry, skipping the stage | +| Decorator | Timing | Use Case | +| ---------- | -------------------------------------------------------- | ------------------------------------------------ | +| `@Will` | **Before** a stage runs | Validate input, inject headers, check auth | +| `@Did` | **After** a stage succeeds; skipped when it fails | Log results, emit metrics, transform output | +| `@Stage` | **Joins** a stage, alongside the flow's own step | Extra work in the stage, ending the flow early | +| `@Around` | **Wraps** a stage (before + after) | Caching, timing, retry, skipping the stage | +| `@Finally` | **After** a stage, whatever its outcome; can't change it | Close spans, timers or locks; record the failure | ### FlowHooksOf API ```typescript import { FlowHooksOf } from '@frontmcp/sdk'; -const { Stage, Will, Did, Around } = FlowHooksOf('tools:call-tool'); +const { Stage, Will, Did, Around, Finally } = FlowHooksOf('tools:call-tool'); ``` -`FlowHooksOf(flowName)` returns an object with all four decorator factories bound to the specified flow. +`FlowHooksOf(flowName)` returns an object with all five decorator factories bound to the specified flow. + +### `@Did` Runs on Success, `@Finally` Always Runs + +A stage runs its `@Will` hooks, then its body (wrapped by its `@Around` hooks), then its `@Did` hooks, then its `@Finally` hooks. + +- `@Did` runs only when the stage succeeded. When a `@Will` hook, the body or an `@Around` hook fails, the stage's `@Did` hooks are skipped. So a `@Did` hook that closes what a `@Will` hook opened (a span, a timer, a lock) leaks it on every failure. +- `@Finally` runs after the stage on every outcome: when it succeeded or responded, when it failed, when a `@Will` hook failed or responded in its place, when an `@Around` hook failed, and when `finalize` refused an answer the tool's output schema rejects (`InvalidOutputError`). Read the failure from `ctx.state.flowError`: the first error the run failed with (what a stage or hook threw or passed to `ctx.fail()`; a `FlowControl.abort(reason)` reads as `Flow aborted: `), typed on `tools:call-tool`, `resources:read-resource`, `prompts:get-prompt` and `jobs:execute-job`. +- A `@Finally` hook cannot change the outcome. If it calls `ctx.respond()` or `ctx.fail()`, or throws, the flow logs a warning and goes on as if it had not: the client gets the same answer or the same error, the values the hook set on `ctx.state` before it responded, failed or threw are put back (a job's answer, for one; an object it changed in place is not), and the stage's other `@Finally` hooks still run. A `@Finally` hook that returns normally keeps what it set on `ctx.state`, like any other hook: on `jobs:execute-job`, setting `state.answer` before `updateRunState` changes the result the run records and returns. +- `@Finally` hooks of one stage run in `priority` order, like every other hook. A stage the flow never reaches (because an earlier stage failed) runs none of its hooks, `@Finally` included: hook `finalize` to see the end of every call. + +```typescript +import { FlowCtxOf, Plugin, ToolHook } from '@frontmcp/sdk'; + +const { Will, Finally } = ToolHook; + +@Plugin({ name: 'execute-timer' }) +export class ExecuteTimerPlugin { + private readonly startedAt = new WeakMap, number>(); + + @Will('execute') + start(ctx: FlowCtxOf<'tools:call-tool'>) { + this.startedAt.set(ctx, Date.now()); + } + + @Finally('execute') + stop(ctx: FlowCtxOf<'tools:call-tool'>) { + const startedAt = this.startedAt.get(ctx); + if (startedAt === undefined) return; + const outcome = ctx.state.flowError ? `failed: ${ctx.state.flowError.message}` : 'succeeded'; + ctx.logger.info(`execute ${outcome} in ${Date.now() - startedAt}ms`); + } +} +``` + +Up to 1.10.15 there was no `@Finally`: a failure in `finalize` (an output schema refusing the answer) skipped the stage's `@Did` hooks and left `state.flowError` unset. ### What `@Stage` Does @@ -56,7 +93,7 @@ A `@Stage('execute')` hook does not replace the flow's own `execute` step: it ad To keep the flow's own step from running: -- Call `ctx.respond(result)` from the `@Stage` (or a `@Will`) hook. The flow ends with that result: it skips the rest of the stage and the main stages after it, while the stage's `@Did` hooks and the cleanup stages (in `tools:call-tool`: `releaseSemaphore`, `releaseQuota`, `applyUI`, `finalize`) still run. In `tools:call-tool`, `result` is a complete MCP `CallToolResult`; it does not go through the tool's output schema. +- Call `ctx.respond(result)` from the `@Stage` (or a `@Will`) hook. The flow ends with that result: it skips the rest of the stage and the main stages after it, while the stage's `@Finally` hooks (and its `@Did` hooks, when a `@Stage` hook answered) and the cleanup stages (in `tools:call-tool`: `releaseSemaphore`, `releaseQuota`, `applyUI`, `finalize`) still run. In `tools:call-tool`, `result` is a complete MCP `CallToolResult`; it does not go through the tool's output schema. - Or use an `@Around` hook that does not call `next()`. The stage is skipped and the flow goes on; in `tools:call-tool`, set `ctx.state.required.toolContext.output`, and the result is validated and formatted like the tool's own. ## Available Flow Names @@ -189,7 +226,7 @@ import { Usage: ```typescript -const { Will, Did, Around, Stage } = ToolHook; +const { Will, Did, Around, Finally, Stage } = ToolHook; ``` > **Note:** Other flows (e.g., `skills:filter`, transport flows) can be hooked by passing the flow name to `FlowHooksOf('flow:name')`. Prefer the pre-built exports above when one is available: exporting them is also what puts a flow's types in the published package, which is why `FlowHooksOf('prompts:get-prompt')`, `'prompts:list-prompts'` and `'completion:complete'` did not typecheck in consumer projects up to 1.8.7. @@ -217,8 +254,8 @@ A hook method on a plugin or provider receives the running flow as its first arg | `rawInput` | The input the flow was started with; for `tools:call-tool`, the MCP `request` and its `ctx` | | `logger` | The flow's logger (the tool, resource and prompt flows define one; every flow has `scopeLogger`) | | `get(token)` | Resolves a provider registered on the server, or a context-scoped provider of the current call | -| `respond(output)` | Ends the flow with this output | -| `fail(error)` | Ends the flow with this error (an `Error`, such as an MCP error class) | +| `respond(output)` | Ends the flow with this output (ignored in a `@Finally` hook) | +| `fail(error)` | Ends the flow with this error (an `Error`, such as an MCP error class; ignored in a `@Finally` hook) | The flow has no `toolName`, `elapsed` or `tryGet`, and its `input` is protected. In `tools:call-tool`, read the tool name and arguments from `ctx.state.required.input` (`name`, `arguments`), the tool entry from `ctx.state.tool`, and the tool instance from `ctx.state.toolContext` (set from `createToolCallContext` on). The state accepts only the keys the flow declares: `ctx.state.set('startedAt', Date.now())` does not compile. @@ -255,7 +292,7 @@ export class TimingPlugin { ## HookOptions -All four decorators accept an optional options object: +All five decorators accept an optional options object: ```typescript @Will('execute', { @@ -265,7 +302,7 @@ All four decorators accept an optional options object: }) ``` -- **priority** (`number`) - Execution order when multiple hooks target the same stage. Lower values run first, for `@Will`, `@Did`, `@Around` and `@Stage` alike. Default: `0`. +- **priority** (`number`) - Execution order when multiple hooks target the same stage. Lower values run first, for `@Will`, `@Did`, `@Around`, `@Finally` and `@Stage` alike. Default: `0`. - **filter** (`(ctx) => boolean`) - A predicate that receives the flow context. Return `false` to skip this hook for the current invocation. - **appliesTo** (`'own-app' | 'uncovered-apps'`) - A hook of a plugin installed on an app runs, in `tools/call`, `resources/read`, `prompts/get` and `completion/complete`, only for that app's entries (`'own-app'`), unless the plugin has `scope: 'server'`. With `'uncovered-apps'` it also runs for the entries of any app that has no instance of the same hook (same class and method) of its own or from a server-level plugin. Use it for gates an entry's metadata asks for (approval, feature flags), so the entry is not left ungated when the plugin sits on another app. Server-level plugins' hooks, and list-flow hooks, already run for every app. @@ -452,6 +489,7 @@ class ProcessOrderTool extends ToolContext { - `@Will('execute')` on a tool class runs **before** the `execute()` method of that specific tool - `@Did('execute')` runs **after** `execute()` completes successfully +- `@Finally('execute')` runs **after** `execute()` whether it succeeded or failed - `@Will('validateInput')` runs before input validation — useful for input enrichment - `@Did('validateOutput')` runs after output validation — useful for output transformation - The hook has full access to `this` (the tool context) including `this.input`, `this.get()`, `this.fail()` @@ -464,7 +502,7 @@ parseInput → ensureRemoteCapabilities → findTool → checkToolAuthorization → validateInput → execute → validateOutput → releaseSemaphore → releaseQuota → applyUI → finalize ``` -A tool-class hook declared as an instance method runs on the tool instance, which `createToolCallContext` builds. So it can hook `Did`/`Stage` on `createToolCallContext` and any hook on a later stage. The same holds for `@Resource` (`createResourceContext`), `@Prompt` (`createPromptContext`) and `@Agent` (`createAgentContext`) classes. +A tool-class hook declared as an instance method runs on the tool instance, which `createToolCallContext` builds. So it can hook `Did`/`Stage`/`Finally` on `createToolCallContext` and any hook on a later stage. The same holds for `@Resource` (`createResourceContext`), `@Prompt` (`createPromptContext`) and `@Agent` (`createAgentContext`) classes. To hook an earlier stage (`parseInput`, `findTool`, `checkToolAuthorization`, `checkEntryAuthorities`, and `findResource`, `findPrompt`, `findAgent`, `checkAgentAuthorization`), declare the hook as a `static` method. It runs without an instance -- `this` is the class, and the flow context is its argument, as for every hook -- and joins only the calls for its own entry, from their first stage: @@ -493,6 +531,7 @@ An instance method on an earlier stage, or `Will`/`Around` on `createToolCallCon | Hook decorator source | `const { Will, Did } = ToolHook;` or `FlowHooksOf('tools:call-tool')` | Importing `Will` directly from `@frontmcp/sdk` | Decorators must be bound to a specific flow via `FlowHooksOf` or pre-built exports | | Hook priority | `@Will('execute', { priority: -100 })` for early hooks | Relying on array order without priority | Multiple hooks on the same stage need explicit priority; lower runs first | | Around next() | `await next();` | Forgetting to call `next()` in `@Around` | Omitting `next()` skips the wrapped stage; its `@Did` hooks still run | +| Cleanup after a stage | `@Finally('execute')` closes the span or timer `@Will` opened | Closing it in `@Did('execute')` | `@Did` is skipped when the stage fails; `@Finally` runs on every outcome | | Around error recovery | `catch { ctx.state.required.toolContext.output = fallback; }` | Catching a rejected `next()` without setting the output | Returning normally handles the failure: the stage counts as successful | | Filter predicate | `filter: (ctx) => ctx.state.required.input.name !== 'health_check'` | Checking tool name inside the hook body and returning early | A filtered-out hook is skipped cleanly; for `@Around`, the stage still runs | | Tool-level hooks | `@Will('execute')` on a `@Tool` class (scoped to that tool) | `@Will('execute')` on a `@Plugin` class expecting tool-scoped behavior | Plugin hooks fire for every tool of the app; tool-level hooks only for that tool | @@ -508,21 +547,24 @@ An instance method on an earlier stage, or `Will`/`Around` on `createToolCallCon ### Runtime - [ ] `@Will` hook fires before the targeted stage -- [ ] `@Did` hook fires after the targeted stage completes +- [ ] `@Did` hook fires after the targeted stage succeeds +- [ ] `@Finally` hook fires after the targeted stage on success and on failure, and reads the failure from `ctx.state.flowError` - [ ] `@Around` hook calls `next()` and the wrapped stage executes - [ ] A `@Stage` hook meant to stand in for the stage ends the flow with `ctx.respond()` and a valid result for the flow - [ ] Hook `filter` correctly skips invocations for excluded tools ## Troubleshooting -| Problem | Cause | Solution | -| --------------------------------------------- | --------------------------------------------------- | -------------------------------------------------------------------------------------------------------------------------------------------- | -| Hook never fires | Plugin not registered in `plugins` array | Add plugin class to `@App` or `@FrontMcp` `plugins` array | -| `InvalidHookFlowError` at startup | Entry-class hook that could never run | Make early-stage hooks `static`; move list-flow hooks (and a `@Job` hook for a flow other than `jobs:execute-job`) to a plugin or a provider | -| Hook fires for wrong flow | Used wrong flow name in `FlowHooksOf` | Verify flow name matches (e.g., `'tools:call-tool'` not `'tool:call'`) | -| `@Around` skips the stage entirely | `next()` not called inside the around handler | Always `await next()` to execute the wrapped stage | -| Multiple hooks execute in wrong order | Priorities not set or conflicting | Set explicit `priority` values; lower numbers execute first | -| The tool still runs despite a plugin `@Stage` | `@Stage` adds a step; it does not replace the stage | End the flow with `ctx.respond(result)`, or use `@Around` without calling `next()` | +| Problem | Cause | Solution | +| ------------------------------------------------- | --------------------------------------------------- | -------------------------------------------------------------------------------------------------------------------------------------------- | +| Hook never fires | Plugin not registered in `plugins` array | Add plugin class to `@App` or `@FrontMcp` `plugins` array | +| `InvalidHookFlowError` at startup | Entry-class hook that could never run | Make early-stage hooks `static`; move list-flow hooks (and a `@Job` hook for a flow other than `jobs:execute-job`) to a plugin or a provider | +| Hook fires for wrong flow | Used wrong flow name in `FlowHooksOf` | Verify flow name matches (e.g., `'tools:call-tool'` not `'tool:call'`) | +| `@Around` skips the stage entirely | `next()` not called inside the around handler | Always `await next()` to execute the wrapped stage | +| Multiple hooks execute in wrong order | Priorities not set or conflicting | Set explicit `priority` values; lower numbers execute first | +| The tool still runs despite a plugin `@Stage` | `@Stage` adds a step; it does not replace the stage | End the flow with `ctx.respond(result)`, or use `@Around` without calling `next()` | +| A span or timer opened in `@Will` stays open | It is closed in `@Did`, which a failed stage skips | Close it in `@Finally` on the same stage | +| `ctx.respond()` in a `@Finally` hook does nothing | `@Finally` cannot change a stage's outcome | Answer from `@Will`, `@Stage` or `@Around`; the flow logs a warning for each ignored `@Finally` response or throw | ## Examples diff --git a/libs/skills/catalog/frontmcp-development/references/decorators-guide.md b/libs/skills/catalog/frontmcp-development/references/decorators-guide.md index 7d582ade0..ad38d5f01 100644 --- a/libs/skills/catalog/frontmcp-development/references/decorators-guide.md +++ b/libs/skills/catalog/frontmcp-development/references/decorators-guide.md @@ -24,7 +24,7 @@ FrontMCP uses a hierarchical decorator system. The nesting order is: +-- @Job (long-running job) +-- @Workflow (multi-step workflow) +-- @Flow (custom flow) - +-- @Hook (@Will, @Did, @Stage, @Around) + +-- @Hook (@Will, @Did, @Stage, @Around, @Finally) ``` --- @@ -61,34 +61,34 @@ FrontMCP uses a hierarchical decorator system. The nesting order is: **Key fields:** -| Field | Description | -| --------------- | ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | -| `info` | `serverInfo` of every `initialize`: `name`, `version`, optional `title` (else the name), `websiteUrl`, `icons` | -| `instructions?` | Top-level server-level instructions (system prompt) surfaced in the MCP `initialize` response and the 2026-07-28 `server/discover` result. Combined with the channel hint and the skill catalog summary per `skillsConfig.injectInstructions`; sent by every transport, `createFetchHandler()` and `connect()` included | -| `apps` | Array of `@App` classes to mount | -| `serve?` | Auto-start HTTP server (default: `true`). Set `false` for programmatic usage | -| `splitByApp?` | If `true`, each app gets its own scope and basePath. Default: `false` | -| `redis?` | Redis / Vercel KV connection for sessions, transport persistence, auth tokens | -| `plugins?` | Global plugins (instantiated per scope) | -| `providers?` | Global DI providers available to all apps | -| `tools?` | Standalone tools (outside apps, merged with app tools) | -| `resources?` | Standalone resources (merged with app resources) | -| `skills?` | Standalone skills (merged with app skills) | -| `skillsConfig?` | Skills HTTP endpoints (`/llm.txt`, `/skills`), MCP tool config, `injectInstructions` policy, and tamper-evident `audit` log — see `configure-skills-http` | -| `transport?` | Transport preset (`'modern'`, `'legacy'`, `'stateless-api'`, `'full'`) or object | -| `auth?` | Authentication mode: `'public'`, `'transparent'`, `'local'`, `'remote'` | -| `http?` | HTTP server options (port, host, cors, socketPath) | -| `logging?` | Logging configuration (transports and levels); without `level`, the level `FRONTMCP_LOG_LEVEL` names, else `info` (`warn` in a browser); per-request lines are at `verbose` | -| `elicitation?` | Enable interactive user input during tool execution | -| `sqlite?` | SQLite storage for local deployments (sessions, events) | -| `pubsub?` | Redis pub/sub for distributed resource subscriptions across multiple instances (single-server deployments use in-memory subscriptions; falls back to `redis` config) | -| `jobs?` | Background jobs/workflows system (`{ enabled, store? }`) | -| `throttle?` | Server-level guard config (see note below) | -| `pagination?` | List operation pagination (`tools/list` endpoint) | -| `fetch?` | What `this.fetch()` adds upstream: `forwardCallerTokenTo` / `forwardCustomHeadersTo` origin allow-lists (default: none), `autoInjectTracingHeaders`, `requestTimeout` | -| `ui?` | UI rendering config (CDN overrides for widget imports) | -| `extApps?` | MCP Apps widget requests on a session: `ui/open-link`, `ui/request-display-mode`, `ui/update-model-context`, `notifications/message` (or the earlier `ui/openLink`, `ui/setDisplayMode`, `ui/updateModelContext`, `ui/log`). `ui/callServerTool` returns the tool's data, no page; a no-result method, `result: {}` | -| `loader?` | Default npm/ESM package loader for `App.esm()` / `App.remote()` apps | +| Field | Description | +| --------------- | ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ | +| `info` | `serverInfo` of every `initialize`: `name`, `version`, optional `title` (else the name), `websiteUrl`, `icons` | +| `instructions?` | Top-level server-level instructions (system prompt) surfaced in the MCP `initialize` response and the 2026-07-28 `server/discover` result. Combined with the channel hint and the skill catalog summary per `skillsConfig.injectInstructions`; sent by every transport, `createFetchHandler()` and `connect()` included | +| `apps` | Array of `@App` classes to mount | +| `serve?` | Auto-start HTTP server (default: `true`). Set `false` for programmatic usage | +| `splitByApp?` | If `true`, each app gets its own scope and basePath. Default: `false` | +| `redis?` | Redis / Vercel KV connection for sessions, transport persistence, auth tokens | +| `plugins?` | Global plugins (instantiated per scope) | +| `providers?` | Global DI providers available to all apps | +| `tools?` | Standalone tools (outside apps, merged with app tools) | +| `resources?` | Standalone resources (merged with app resources) | +| `skills?` | Standalone skills (merged with app skills) | +| `skillsConfig?` | Skills HTTP endpoints (`/llm.txt`, `/skills`), MCP tool config, `injectInstructions` policy, and tamper-evident `audit` log — see `configure-skills-http` | +| `transport?` | Transport preset (`'modern'`, `'legacy'`, `'stateless-api'`, `'full'`) or object | +| `auth?` | Authentication mode: `'public'`, `'transparent'`, `'local'`, `'remote'` | +| `http?` | HTTP server options (port, host, cors, socketPath) | +| `logging?` | Logging configuration (transports and levels); without `level`, the level `FRONTMCP_LOG_LEVEL` names, else `info` (`warn` in a browser); per-request lines are at `verbose` | +| `elicitation?` | Enable interactive user input during tool execution | +| `sqlite?` | SQLite storage for local deployments (sessions, events) | +| `pubsub?` | Redis pub/sub for distributed resource subscriptions across multiple instances (single-server deployments use in-memory subscriptions; falls back to `redis` config) | +| `jobs?` | Background jobs/workflows system (`{ enabled, store? }`) | +| `throttle?` | Server-level guard config (see note below) | +| `pagination?` | List operation pagination (`tools/list` endpoint) | +| `fetch?` | What `this.fetch()` adds upstream: `forwardCallerTokenTo` / `forwardCustomHeadersTo` origin allow-lists (default: none), `autoInjectTracingHeaders`, `requestTimeout` | +| `ui?` | UI rendering config (CDN overrides for widget imports) | +| `extApps?` | MCP Apps widget requests on a session: `ui/open-link`, `ui/request-display-mode`, `ui/update-model-context`, `notifications/message` (or the earlier `ui/openLink`, `ui/setDisplayMode`, `ui/updateModelContext`, `ui/log`). `ui/callServerTool` returns the tool's data, no page; a no-result method, `result: {}` | +| `loader?` | Default npm/ESM package loader for `App.esm()` / `App.remote()` apps | | `registry?` | MCP Registry listing: `name` (`com.acme/weather`), `description`, `repository`, `publicKey` / `publicKeyEnv`. Serves the domain proof at `/.well-known/mcp-registry-auth`, the SEP-2127 server card at `/server-card` and `/.well-known/ai-catalog.json` — see `frontmcp-deployment`'s `list-in-mcp-registry` | > **Throttle vs per-tool guards:** Server-level `throttle` is a `GuardConfig` object with `global`, `defaultRateLimit`, `defaultConcurrency`, `defaultTimeout` sub-fields that set server-wide defaults. Tool-level `rateLimit`, `concurrency`, `timeout` fields (on `@Tool`) override these defaults per tool. @@ -649,22 +649,23 @@ class DeployPipeline {} --- -## 15. Hook Decorators (@Will, @Did, @Stage, @Around) +## 15. Hook Decorators (@Will, @Did, @Stage, @Around, @Finally) -**Purpose:** Run logic before, after, around, or as part of a stage of a flow, such as a tool call or a resource read. +**Purpose:** Run logic before, after, around, or as part of a stage of a flow, such as a tool call or a resource read, or after it whatever its outcome. **When to use:** When you need cross-cutting logic (logging, timing, authorization, caching) around tool calls, resource reads, prompt gets and the other flows. -`@frontmcp/sdk` does not export `Will`, `Did`, `Stage` or `Around` on their own. Take them from the export for the flow you hook (`ToolHook` for `tools:call-tool`, `ResourceHook` for `resources:read-resource`, `PromptHook` for `prompts:get-prompt`, ...) or from `FlowHooksOf('')`. The flow comes from where you take the decorator; the decorator itself takes a **stage** of that flow, such as `'execute'`. +`@frontmcp/sdk` does not export `Will`, `Did`, `Stage`, `Around` or `Finally` on their own. Take them from the export for the flow you hook (`ToolHook` for `tools:call-tool`, `ResourceHook` for `resources:read-resource`, `PromptHook` for `prompts:get-prompt`, ...) or from `FlowHooksOf('')`. The flow comes from where you take the decorator; the decorator itself takes a **stage** of that flow, such as `'execute'`. **Variants:** -| Decorator | Timing | Description | -| --------- | -------- | --------------------------------------- | -| `@Will` | Before | Runs before the stage | -| `@Did` | After | Runs after the stage completes | -| `@Stage` | During | Runs as part of the stage itself | -| `@Around` | Wrapping | Wraps the stage; `await next()` runs it | +| Decorator | Timing | Description | +| ---------- | ------------- | ------------------------------------------------------------------------------------------------- | +| `@Will` | Before | Runs before the stage | +| `@Did` | After success | Runs after the stage succeeds; skipped when it fails | +| `@Stage` | During | Runs as part of the stage itself | +| `@Around` | Wrapping | Wraps the stage; `await next()` runs it | +| `@Finally` | After, always | Runs after the stage whatever its outcome; reads `ctx.state.flowError`; cannot change the outcome | Declare hooks on a `@Plugin` (or a provider) to run them for every tool, resource or prompt of the app it is registered on: @@ -703,6 +704,7 @@ A hook method receives the running flow, typed `FlowCtxOf<''>`: - `ctx.state` holds the flow's data (for `tools:call-tool`: `input`, `tool`, `toolContext`, ...); `ctx.state.required.` throws when the key is unset. - `ctx.logger` logs, and `ctx.fail(error)` or `ctx.respond(output)` ends the flow. - An `@Around` hook also receives `next`, which runs the stage. +- A `@Finally` hook runs when the stage failed too, so close spans, timers and locks there rather than in `@Did`; its `ctx.respond()`, `ctx.fail()` and throws are logged and ignored. - `this` is the plugin or provider instance. A hook declared on a `@Tool`, `@Resource` or `@Prompt` class runs only for that entry, on its context (`this.input`, `this.get()`). See `create-plugin-hooks` for the stages of each flow, `priority`, `filter` and entry-class hooks. @@ -711,23 +713,23 @@ A hook declared on a `@Tool`, `@Resource` or `@Prompt` class runs only for that ## Quick Reference Table -| Decorator | Extends | Registered In | Purpose | -| --------------------------- | ----------------- | ------------------------------- | ------------------------ | -| `@FrontMcp` | - | Root | Server configuration | -| `@App` | - | `@FrontMcp.apps` | Module grouping | -| `@Tool` | `ToolContext` | `@App.tools` | Executable action | -| `@Prompt` | `PromptContext` | `@App.prompts` | Prompt template | -| `@Resource` | `ResourceContext` | `@App.resources` | Static data | -| `@ResourceTemplate` | `ResourceContext` | `@App.resources` | Parameterized data | -| `@Agent` | `AgentContext` | `@App.agents` | Autonomous AI agent | -| `@Skill` | - | `@App.skills` | Knowledge package | -| `@Plugin` | - | `@App.plugins` | Cross-cutting concern | -| `@Adapter` | - | `@App.adapters` | External integration | -| `@Provider` | - | `@App.providers` | DI binding | -| `@Flow` | - | `@App` | Custom flow | -| `@Job` | `JobContext` | `@App.jobs` | Background task | -| `@Workflow` | - | `@App.workflows` | Multi-step orchestration | -| `@Will/@Did/@Stage/@Around` | - | Plugin, provider or entry class | Flow stage hooks | +| Decorator | Extends | Registered In | Purpose | +| ------------------------------------ | ----------------- | ------------------------------- | ------------------------ | +| `@FrontMcp` | - | Root | Server configuration | +| `@App` | - | `@FrontMcp.apps` | Module grouping | +| `@Tool` | `ToolContext` | `@App.tools` | Executable action | +| `@Prompt` | `PromptContext` | `@App.prompts` | Prompt template | +| `@Resource` | `ResourceContext` | `@App.resources` | Static data | +| `@ResourceTemplate` | `ResourceContext` | `@App.resources` | Parameterized data | +| `@Agent` | `AgentContext` | `@App.agents` | Autonomous AI agent | +| `@Skill` | - | `@App.skills` | Knowledge package | +| `@Plugin` | - | `@App.plugins` | Cross-cutting concern | +| `@Adapter` | - | `@App.adapters` | External integration | +| `@Provider` | - | `@App.providers` | DI binding | +| `@Flow` | - | `@App` | Custom flow | +| `@Job` | `JobContext` | `@App.jobs` | Background task | +| `@Workflow` | - | `@App.workflows` | Multi-step orchestration | +| `@Will/@Did/@Stage/@Around/@Finally` | - | Plugin, provider or entry class | Flow stage hooks | --- diff --git a/libs/skills/catalog/frontmcp-observability/examples/telemetry-api/plugin-telemetry.md b/libs/skills/catalog/frontmcp-observability/examples/telemetry-api/plugin-telemetry.md index 35eb9e369..acbcbc0dd 100644 --- a/libs/skills/catalog/frontmcp-observability/examples/telemetry-api/plugin-telemetry.md +++ b/libs/skills/catalog/frontmcp-observability/examples/telemetry-api/plugin-telemetry.md @@ -7,7 +7,7 @@ tags: [telemetry, plugin, hooks, cache, audit] features: - 'Plugin hooks can access toolCtx.telemetry to add events to the active span' - 'Events from plugins appear in the same trace as the tool execution' - - "One `@ToolHook.Around('execute')` hook records success and failure: the flow state has no `error` key, and a `Did` hook runs only after a successful execute" + - "One `@ToolHook.Around('execute')` hook records success and failure while the execute span is open: a `Did` hook runs only after a successful execute" - 'Graceful degradation when observability is not enabled' --- @@ -94,7 +94,7 @@ tool my_tool - Plugin hooks can access toolCtx.telemetry to add events to the active span - Events from plugins appear in the same trace as the tool execution -- One `@ToolHook.Around('execute')` hook records success and failure: the flow state has no `error` key, and a `Did` hook runs only after a successful execute +- One `@ToolHook.Around('execute')` hook records success and failure while the execute span is open: a `Did` hook runs only after a successful execute - Graceful degradation when observability is not enabled ## Related diff --git a/libs/skills/catalog/skills-manifest.json b/libs/skills/catalog/skills-manifest.json index 65a310d09..0a9a4646c 100644 --- a/libs/skills/catalog/skills-manifest.json +++ b/libs/skills/catalog/skills-manifest.json @@ -1854,7 +1854,7 @@ }, { "name": "create-plugin-hooks", - "description": "Intercept and extend FrontMCP flows using before, after, around, and stage hook decorators", + "description": "Intercept and extend FrontMCP flows using before, after, around, finally, and stage hook decorators", "examples": [ { "name": "basic-logging-plugin", @@ -2692,7 +2692,7 @@ "features": [ "Plugin hooks can access toolCtx.telemetry to add events to the active span", "Events from plugins appear in the same trace as the tool execution", - "One `@ToolHook.Around('execute')` hook records success and failure: the flow state has no `error` key, and a `Did` hook runs only after a successful execute", + "One `@ToolHook.Around('execute')` hook records success and failure while the execute span is open: a `Did` hook runs only after a successful execute", "Graceful degradation when observability is not enabled" ] },