From 271ea1b317da2b6eee35a20a99e47632b3bdadfc Mon Sep 17 00:00:00 2001 From: Fini Date: Wed, 22 Apr 2026 10:05:00 +0800 Subject: [PATCH] =?UTF-8?q?feat(mcp):=20dispatcher=20metrics=20=E2=80=94?= =?UTF-8?q?=20per-tool=20call/error=20counters?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit In-memory counters for the element-tool dispatcher, exposed via \`getElementToolMetric(name)\` / \`getAllElementToolMetrics()\` / \`getTopElementToolCalls(n)\` / \`resetElementToolMetrics()\` in packages/pen-mcp/src/metrics/. \`handleElementToolCall\` now wraps the existing switch in a try/record — every dispatch increments \`calls\`, thrown handlers additionally bump \`errors\` and stash the last error message. Unknown tool names still fire a counter (useful signal: "the AI picked a tool we don't have"). Process-local / in-memory by design: - Test determinism: resetElementToolMetrics() in beforeEach - Matches stdio MCP server's one-client-one-server model - No persistence backend choice baked in — if we need cross-restart persistence later, a thin serializer drops on top without touching this API Unlocks #92 Local A/B harness: feed a corpus through the MCP server, read back getAllElementToolMetrics() to see which tools the model actually picked vs what the corpus expected. Core observability for non-Claude regression detection. --- .../__tests__/element-tool-metrics.test.ts | 164 ++++++++++++++++++ .../src/metrics/element-tool-metrics.ts | 95 ++++++++++ .../pen-mcp/src/routes/element-tool-defs.ts | 13 ++ 3 files changed, 272 insertions(+) create mode 100644 packages/pen-mcp/src/__tests__/element-tool-metrics.test.ts create mode 100644 packages/pen-mcp/src/metrics/element-tool-metrics.ts diff --git a/packages/pen-mcp/src/__tests__/element-tool-metrics.test.ts b/packages/pen-mcp/src/__tests__/element-tool-metrics.test.ts new file mode 100644 index 000000000..9be3d80cc --- /dev/null +++ b/packages/pen-mcp/src/__tests__/element-tool-metrics.test.ts @@ -0,0 +1,164 @@ +import { describe, it, expect, beforeEach, afterEach } from 'vitest'; +import { writeFile, unlink, mkdir } from 'node:fs/promises'; +import { tmpdir } from 'node:os'; +import { join } from 'node:path'; +import { + getAllElementToolMetrics, + getElementToolMetric, + getTopElementToolCalls, + recordElementToolCall, + resetElementToolMetrics, +} from '../metrics/element-tool-metrics'; +import { handleElementToolCall } from '../routes/element-tool-defs'; +import { invalidateCache } from '../document-manager'; + +const TMP = join(tmpdir(), 'openpencil-element-tool-metrics'); +const EMPTY = JSON.stringify({ version: '1.0.0', children: [] }); + +async function fresh(name: string): Promise { + const fp = join(TMP, name); + await writeFile(fp, EMPTY, 'utf-8'); + return fp; +} + +beforeEach(async () => { + await mkdir(TMP, { recursive: true }); + resetElementToolMetrics(); +}); +afterEach(async () => { + for (const f of ['m.op']) { + try { + const fp = join(TMP, f); + invalidateCache(fp); + await unlink(fp); + } catch {} + } +}); + +describe('element-tool metrics module', () => { + describe('direct counter API', () => { + it('increments on first record', () => { + recordElementToolCall('add_heading_v0', true); + const m = getElementToolMetric('add_heading_v0'); + expect(m?.calls).toBe(1); + expect(m?.errors).toBe(0); + }); + + it('counts successive calls', () => { + recordElementToolCall('add_heading_v0', true); + recordElementToolCall('add_heading_v0', true); + recordElementToolCall('add_heading_v0', true); + expect(getElementToolMetric('add_heading_v0')?.calls).toBe(3); + }); + + it('counts errors separately', () => { + recordElementToolCall('add_badge_v0', true); + recordElementToolCall('add_badge_v0', false, 'missing label'); + recordElementToolCall('add_badge_v0', false, 'bad color'); + const m = getElementToolMetric('add_badge_v0'); + expect(m?.calls).toBe(3); + expect(m?.errors).toBe(2); + expect(m?.lastError).toBe('bad color'); + }); + + it('returns undefined for never-called tool', () => { + expect(getElementToolMetric('add_never_called_v0')).toBeUndefined(); + }); + + it('reset clears all counters', () => { + recordElementToolCall('add_foo_v0', true); + recordElementToolCall('add_bar_v0', false, 'oops'); + resetElementToolMetrics(); + expect(getElementToolMetric('add_foo_v0')).toBeUndefined(); + expect(getElementToolMetric('add_bar_v0')).toBeUndefined(); + expect(Object.keys(getAllElementToolMetrics()).length).toBe(0); + }); + + it('snapshot is alphabetical by name', () => { + recordElementToolCall('add_zebra_v0', true); + recordElementToolCall('add_apple_v0', true); + recordElementToolCall('add_mango_v0', true); + const keys = Object.keys(getAllElementToolMetrics()); + expect(keys).toEqual(['add_apple_v0', 'add_mango_v0', 'add_zebra_v0']); + }); + + it('top-N ranks by call count, ties broken by name', () => { + recordElementToolCall('add_a_v0', true); + recordElementToolCall('add_b_v0', true); + recordElementToolCall('add_b_v0', true); + recordElementToolCall('add_c_v0', true); + recordElementToolCall('add_c_v0', true); + recordElementToolCall('add_d_v0', true); + + const top = getTopElementToolCalls(3); + expect(top[0].calls).toBe(2); + expect(top[1].calls).toBe(2); + // Tie breaker: names in sorted order + expect(top[0].name).toBe('add_b_v0'); + expect(top[1].name).toBe('add_c_v0'); + expect(top[2].calls).toBe(1); + }); + + it('top-N with N=0 returns empty; N larger than set returns all', () => { + recordElementToolCall('add_a_v0', true); + recordElementToolCall('add_b_v0', true); + expect(getTopElementToolCalls(0)).toEqual([]); + expect(getTopElementToolCalls(100).length).toBe(2); + }); + + it('readers return copies — cannot mutate counter by reference', () => { + recordElementToolCall('add_x_v0', true); + const snap = getElementToolMetric('add_x_v0')!; + snap.calls = 999; // local mutation + // Internal counter must be unchanged + expect(getElementToolMetric('add_x_v0')?.calls).toBe(1); + }); + }); + + describe('dispatcher instrumentation', () => { + it('increments on successful element-tool call', async () => { + const fp = await fresh('m.op'); + await handleElementToolCall('add_heading_v0', { + filePath: fp, + content: 'Hello', + }); + expect(getElementToolMetric('add_heading_v0')?.calls).toBe(1); + expect(getElementToolMetric('add_heading_v0')?.errors).toBe(0); + }); + + it('increments AND counts errors on failed call (missing required field)', async () => { + const fp = await fresh('m.op'); + // Pass intentionally-bad parent_id to trigger the ensureParentExists throw + await expect( + handleElementToolCall('add_heading_v0', { + filePath: fp, + content: 'Hello', + parent_id: 'nonexistent_id', + }), + ).rejects.toThrow(/parent_id.*not found/); + const m = getElementToolMetric('add_heading_v0'); + expect(m?.calls).toBe(1); + expect(m?.errors).toBe(1); + expect(m?.lastError).toMatch(/parent_id/); + }); + + it('3 different tools in one session → 3 counters, each =1', async () => { + const fp = await fresh('m.op'); + await handleElementToolCall('add_heading_v0', { filePath: fp, content: 'A' }); + await handleElementToolCall('add_body_text_v0', { filePath: fp, content: 'B' }); + await handleElementToolCall('add_badge_v0', { filePath: fp, label: 'NEW' }); + const snap = getAllElementToolMetrics(); + expect(Object.keys(snap).length).toBe(3); + expect(snap.add_heading_v0.calls).toBe(1); + expect(snap.add_body_text_v0.calls).toBe(1); + expect(snap.add_badge_v0.calls).toBe(1); + }); + + it('unknown tool name in dispatcher still records a call (returns empty string)', async () => { + const result = await handleElementToolCall('add_never_existed_v0', {}); + expect(result).toBe(''); // dispatcher fallthrough + // Counter still fires — useful for detecting "AI called a tool we don't have" + expect(getElementToolMetric('add_never_existed_v0')?.calls).toBe(1); + }); + }); +}); diff --git a/packages/pen-mcp/src/metrics/element-tool-metrics.ts b/packages/pen-mcp/src/metrics/element-tool-metrics.ts new file mode 100644 index 000000000..c15237524 --- /dev/null +++ b/packages/pen-mcp/src/metrics/element-tool-metrics.ts @@ -0,0 +1,95 @@ +/** + * In-memory metrics for the element-tool dispatcher. + * + * Records how often each `add_X_v0` tool is called, plus the last + * error message per tool if any. The counters are process-local + * (no persistence, no networking) — meant to be queried by tests + * and local A/B harnesses, not exposed to end users. + * + * Why in-memory: + * - We don't want to bake in a choice of persistence backend + * (file / sqlite / redis) at this stage + * - Tests can assert call counts deterministically by resetting + * between runs + * - Per-process state is the right default for a stdio MCP + * server (each spawned instance has its own counter, which + * matches the "one client, one server" model) + * + * If we later want persistent metrics (across server restarts), + * add a thin serializer on top without touching this module's + * API. + */ + +export interface ElementToolMetrics { + /** Total number of dispatches for this tool (successful or failed). */ + calls: number; + /** Total failures (thrown from the handler). */ + errors: number; + /** Last error message for this tool, if any. */ + lastError?: string; + /** When the counter last fired (epoch ms). */ + lastCalledAt?: number; +} + +const METRICS = new Map(); + +/** + * Record one dispatch. Called by the element-tool dispatcher + * exactly once per incoming request. `ok` distinguishes success + * from a thrown handler (either path counts for `calls`). + */ +export function recordElementToolCall(name: string, ok: boolean, errorMessage?: string): void { + const existing = METRICS.get(name) ?? { calls: 0, errors: 0 }; + existing.calls += 1; + if (!ok) { + existing.errors += 1; + if (errorMessage) existing.lastError = errorMessage; + } + existing.lastCalledAt = Date.now(); + METRICS.set(name, existing); +} + +/** Read the current counter for one tool (undefined if never called). */ +export function getElementToolMetric(name: string): ElementToolMetrics | undefined { + const m = METRICS.get(name); + // Return a copy so callers can't mutate our state by reference. + return m ? { ...m } : undefined; +} + +/** Snapshot of every tool ever called, sorted alphabetically by name. */ +export function getAllElementToolMetrics(): Record { + const out: Record = {}; + const names = Array.from(METRICS.keys()).sort(); + for (const n of names) { + out[n] = { ...(METRICS.get(n) as ElementToolMetrics) }; + } + return out; +} + +/** + * Top-N most-called tools. Ties broken by name (stable). Useful + * for A/B harnesses that want to eyeball "what did this model + * actually pick most often on this corpus?" + */ +export function getTopElementToolCalls( + n: number, +): Array<{ name: string; calls: number; errors: number }> { + const entries = Array.from(METRICS.entries()).map(([name, m]) => ({ + name, + calls: m.calls, + errors: m.errors, + })); + entries.sort((a, b) => { + if (b.calls !== a.calls) return b.calls - a.calls; + return a.name.localeCompare(b.name); + }); + return entries.slice(0, Math.max(0, Math.floor(n))); +} + +/** + * Reset all counters. Tests MUST call this in `beforeEach` to + * stay deterministic under shared process state. + */ +export function resetElementToolMetrics(): void { + METRICS.clear(); +} diff --git a/packages/pen-mcp/src/routes/element-tool-defs.ts b/packages/pen-mcp/src/routes/element-tool-defs.ts index d429ea260..36206445b 100644 --- a/packages/pen-mcp/src/routes/element-tool-defs.ts +++ b/packages/pen-mcp/src/routes/element-tool-defs.ts @@ -77,6 +77,7 @@ import { handleAddChipInputV0 } from '../tools/add-chip-input-v0'; import { handleAddEmptyChartV0 } from '../tools/add-empty-chart-v0'; import { handleAddActionMenuV0 } from '../tools/add-action-menu-v0'; import { handleAddDatePickerV0 } from '../tools/add-date-picker-v0'; +import { recordElementToolCall } from '../metrics/element-tool-metrics'; import { ELEMENT_TOOL_DEFINITIONS_BASE } from './element-tool-defs-base'; import { ELEMENT_TOOL_DEFINITIONS_EXT } from './element-tool-defs-ext'; @@ -91,6 +92,18 @@ export const ELEMENT_TOOL_NAMES: ReadonlySet = new Set( // eslint-disable-next-line @typescript-eslint/no-explicit-any export async function handleElementToolCall(name: string, a: any): Promise { + try { + const out = await dispatchElementToolCall(name, a); + recordElementToolCall(name, true); + return out; + } catch (err) { + recordElementToolCall(name, false, err instanceof Error ? err.message : String(err)); + throw err; + } +} + +// eslint-disable-next-line @typescript-eslint/no-explicit-any +async function dispatchElementToolCall(name: string, a: any): Promise { switch (name) { case 'add_card_row_v0': return JSON.stringify(await handleAddCardRowV0(a), null, 2);