diff --git a/packages/cli/src/commands/replay.ts b/packages/cli/src/commands/replay.ts index c8037f3..139bee5 100644 --- a/packages/cli/src/commands/replay.ts +++ b/packages/cli/src/commands/replay.ts @@ -682,7 +682,14 @@ async function replayRestored( const mcp = trace === undefined ? undefined - : await mcpForReplay(args, ctx.events, trace, out, join(ctx.runDir, 'mcp-frames.jsonl')); + : await mcpForReplay( + args, + ctx.events, + trace, + out, + join(ctx.runDir, 'mcp-frames.jsonl'), + ctx.runDir, + ); const adapter = defaultAdapters().get(ctx.manifest.adapter.id); const launch = await adapter.prepare({ @@ -1009,7 +1016,9 @@ async function replayFork( // A fork continues the run live past the checkpoint, so its MCP traffic is new and belongs in the // fork's own trace. Without this the layer simply stopped at the fork point. - const mcp = await mcpForReplay(args, ctx.events, writer, out).catch(abandon); + const mcp = await mcpForReplay(args, ctx.events, writer, out, undefined, ctx.runDir).catch( + abandon, + ); const proxy = await createProxy({ mode: 'hybrid', diff --git a/packages/cli/src/mcp.ts b/packages/cli/src/mcp.ts index d48935f..dc1c2d5 100644 --- a/packages/cli/src/mcp.ts +++ b/packages/cli/src/mcp.ts @@ -29,6 +29,28 @@ export interface McpCapture { */ export type { McpFrameRecord }; +/** + * The recording's own copy of the config it was given, kept beside the frames it produced. + * + * A replay used to find the source by reading the path out of the `mcp_instrumented` note, and a + * path is a poor thing to depend on. It has to survive the trace's redactor — `mkdtemp` and every + * CI workspace end in a random segment, and `orca-int-mcp-stdio-feH8gJ` is 25 characters of + * mixed-case base62, so roughly one in seven cleared the entropy sweep's threshold and reached the + * trace as ``. `stat` then failed, MCP was dropped for the replay, and the + * agent was launched with no `MCP_CONFIG_PATH`: `KeyError` from a recording that was perfectly + * good, intermittently, according to what `mkdtemp` picked. + * + * It also has to still be there, and mean the same thing. Deleting the config, moving it, or + * editing a server's command between the recording and the replay all changed what the replay ran + * — for a file the operator has no reason to think of as part of the run. + * + * Keeping the bytes removes both. Nothing has to survive redaction, because this is not in the + * trace; nothing outside the run directory has to still exist. It carries the same material as the + * rewritten `mcp-config.json` written next to it — same directory, same `0600` — so it is not a + * new kind of thing to protect. + */ +export const MCP_SOURCE_FILENAME = 'mcp-source.json'; + /** * The MCP config a *replay* should instrument: the flag if one was given, else whatever the * recording itself used. @@ -43,6 +65,7 @@ export type { McpFrameRecord }; * the *rewritten* config in the parent run directory: its servers already point at the parent's * frames file, so reusing it would append this replay's traffic to the recording it is replaying. */ + export function mcpSourceFrom( flagValue: string | undefined, events: { type: string; attrs?: Record }[], @@ -76,7 +99,21 @@ export async function mcpForReplay( out: Output, /** The recording's own frames, so the servers are answered from rather than started. */ recordedFrames?: string, + /** The recording's directory, which holds its own copy of the config it was given. */ + recordedRunDir?: string, ): Promise { + // The recording's copy first, and only then the path it wrote down. The copy cannot have been + // redacted, moved or edited since; the path can have been all three. + const kept = recordedRunDir === undefined ? undefined : join(recordedRunDir, MCP_SOURCE_FILENAME); + if (kept !== undefined && (await stat(kept).catch(() => null))) { + return setupMcpCapture({ + sourceConfigPath: kept, + runDir: writer.runDir, + out, + ...(recordedFrames === undefined ? {} : { replayFrames: recordedFrames }), + }); + } + const source = mcpSourceFrom(args.str('mcp-config'), events); if (source === undefined) { if (usedMcp(events)) { @@ -205,6 +242,11 @@ export async function setupMcpCapture(opts: { opts.out.warn('mcp.config_unreadable', { path: opts.sourceConfigPath }); return undefined; } + // Kept before it is parsed, so a later run reads back what this run was handed — byte for byte, + // key order and all. See {@link MCP_SOURCE_FILENAME} for why a path was not good enough. + await writeFile(join(opts.runDir, MCP_SOURCE_FILENAME), raw, { mode: 0o600 }).catch( + () => undefined, + ); let parsed: unknown; try { diff --git a/packages/cli/test/mcp-capture.test.ts b/packages/cli/test/mcp-capture.test.ts index 5f3ba41..ada440e 100644 --- a/packages/cli/test/mcp-capture.test.ts +++ b/packages/cli/test/mcp-capture.test.ts @@ -1,5 +1,5 @@ import { execFile } from 'node:child_process'; -import { mkdtemp, readFile, rm, writeFile } from 'node:fs/promises'; +import { mkdtemp, readFile, rm, stat, writeFile } from 'node:fs/promises'; import { tmpdir } from 'node:os'; import { dirname, join } from 'node:path'; import { fileURLToPath } from 'node:url'; @@ -9,7 +9,13 @@ import { TraceReader, deriveCheckpoints, resolveRunSelector } from '@orcareplay/ import { validateEvent } from '@orcareplay/schema'; import { parseArgs } from '../src/args.js'; import { Output } from '../src/out.js'; -import { mcpSourceFrom, setupMcpCapture, usedMcp } from '../src/mcp.js'; +import { + MCP_SOURCE_FILENAME, + mcpForReplay, + mcpSourceFrom, + setupMcpCapture, + usedMcp, +} from '../src/mcp.js'; import { recordCommand } from '../src/commands/record.js'; import { replayCommand } from '../src/commands/replay.js'; import { startFakeModel } from './fixtures/fake-model.mjs'; @@ -204,7 +210,13 @@ describe('mcp capture', () => { for (const event of mcp) expect(validateEvent(event).valid).toBe(true); }); - it('says so rather than silently dropping the layer when the config has moved', async () => { + it('replays a moved config, because the recording kept the bytes', async () => { + // This used to warn `mcp.source_missing` and drop the layer, and that was the best it could + // do: the replay found the config by reading a path out of the trace, so a config the + // operator moved was a config the replay could not open. The recording now keeps its own + // copy, which also removes the reason the path had to survive redaction — see + // `MCP_SOURCE_FILENAME`. + // // The config lives *outside* the workspace here, because exact replay restores the recorded // tree over the working directory — deleting a file that was in the snapshot just brings it // back, which is the restore working correctly and would make this test pass for the wrong @@ -220,6 +232,25 @@ describe('mcp capture', () => { await replayCommand(parseArgs(['replay', 'last']), out, workspace); + const printed = lines.join(''); + expect(printed).toContain('mcp.instrumented'); + expect(printed).not.toContain('mcp.source_missing'); + }); + + it('still says so for a recording made before the copy was kept', async () => { + // The warning is not gone, and must not be: a trace recorded by an older orca has only the + // path, and a dropped capture layer must never read as a quiet success. Same run as above + // with the kept copy removed, which is exactly what those traces look like. + const elsewhere = await mkdtemp(join(tmpdir(), 'orca-mcp-cfg-')); + const configPath = join(elsewhere, 'mcp.json'); + await writeFile(configPath, await readFile(join(workspace, 'mcp.json'), 'utf8')); + const { runDir } = await record(configPath); + await rm(elsewhere, { recursive: true, force: true }); + await rm(join(runDir, MCP_SOURCE_FILENAME)); + lines.length = 0; + + await replayCommand(parseArgs(['replay', 'last']), out, workspace); + const printed = lines.join(''); expect(printed).toContain('mcp.source_missing'); expect(printed, 'a dropped capture layer must not read as a quiet success').not.toContain( @@ -280,6 +311,98 @@ describe('mcpSourceFrom', () => { }); }); +/** + * The recording keeps the config it was given, so a replay does not depend on a path. + * + * Found by an integration check that failed about one run in seven. The path was read back out of + * the `mcp_instrumented` note, and a path in the trace has to survive the redactor: + * `orca-int-mcp-stdio-feH8gJ` is 25 characters of mixed-case base62, over `MIN_ENTROPY_LENGTH`, so + * often enough the entropy sweep replaced the directory with ``. `stat` + * then failed, MCP was dropped for the replay, and the agent was launched with no + * `MCP_CONFIG_PATH` — `KeyError` from a recording that was perfectly good. + * + * Widening the redactor was the wrong fix and was tried first: an exemption keyed on `cwd`/`source` + * containing a separator also shelters a URL with a token in its query, a database DSN, and a + * `data:image/png;base64,…` forgery — which bypasses the raster validation that + * `data-uri-redaction.test.ts` exists to enforce. Measured before it was reverted: a forged image + * under `source` survived with **zero** redaction records, so the miss was invisible in + * `redactions.json` too. The file's own comment says an exemption granted on the label was a hole + * every time it was tried; this was that hole again. + */ +describe('the config the recording kept', () => { + /** An Output that says nothing, because these assert on files rather than on what was printed. */ + const quiet = () => new Output({ write: () => {}, isTTY: false }); + + let runDir: string; + let source: string; + + beforeEach(async () => { + runDir = await mkdtemp(join(tmpdir(), 'orca-mcp-src-')); + source = join(runDir, 'given.json'); + await writeFile(source, CONFIG_TEXT); + }); + + afterEach(async () => { + await rm(runDir, { recursive: true, force: true }); + }); + + const CONFIG_TEXT = `{\n "mcpServers": {\n "probe": { "command": "python", "args": ["s.py"] }\n }\n}\n`; + + it('keeps the bytes it was handed, not a re-serialisation of them', async () => { + // Byte for byte, so key order and whitespace a later reader might depend on survive. + await setupMcpCapture({ sourceConfigPath: source, runDir, out: quiet() }); + expect(await readFile(join(runDir, MCP_SOURCE_FILENAME), 'utf8')).toBe(CONFIG_TEXT); + }); + + it('keeps it beside the rewritten one, at the same mode', async () => { + await setupMcpCapture({ sourceConfigPath: source, runDir, out: quiet() }); + const mode = (await stat(join(runDir, MCP_SOURCE_FILENAME))).mode & 0o777; + const rewritten = (await stat(join(runDir, 'mcp-config.json'))).mode & 0o777; + expect(mode).toBe(rewritten); + }); + + it('is what a replay reads, even after the original is gone', async () => { + await setupMcpCapture({ sourceConfigPath: source, runDir, out: quiet() }); + // The case the note could never survive: the operator moved or deleted their config, or the + // path in the trace was redacted into something `stat` cannot find. + await rm(source); + + const replayDir = await mkdtemp(join(tmpdir(), 'orca-mcp-replay-')); + try { + const capture = await mcpForReplay( + { str: () => undefined }, + [{ type: 'note', attrs: { rule: 'mcp_instrumented', source: '/gone//c.json' } }], + { runDir: replayDir } as never, + quiet(), + undefined, + runDir, + ); + expect(capture, 'the replay found nothing to instrument').toBeTruthy(); + expect(capture?.rewritten).toEqual(['probe']); + } finally { + await rm(replayDir, { recursive: true, force: true }); + } + }); + + it('still falls back to the note, for a run recorded before this', async () => { + const replayDir = await mkdtemp(join(tmpdir(), 'orca-mcp-replay-')); + try { + const capture = await mcpForReplay( + { str: () => undefined }, + [{ type: 'note', attrs: { rule: 'mcp_instrumented', source } }], + { runDir: replayDir } as never, + quiet(), + undefined, + // A directory with no kept copy in it, which is every run recorded before this change. + replayDir, + ); + expect(capture?.rewritten).toEqual(['probe']); + } finally { + await rm(replayDir, { recursive: true, force: true }); + } + }); +}); + describe('a capture line that parsed is not yet a frame', () => { /** * The same rule the shell frames reader has, one file over, and for the same reason: several diff --git a/test/integrations/agents/mcp_agent.py b/test/integrations/agents/mcp_agent.py new file mode 100644 index 0000000..1b8e730 --- /dev/null +++ b/test/integrations/agents/mcp_agent.py @@ -0,0 +1,44 @@ +"""An agent that talks to a model *and* to an MCP server it launches from a config file. + +Both halves on purpose. The model call is what every other check asserts and what makes the +exchange counts comparable; the MCP session is the half no other check covers at all. + +It reads the config rather than building `StdioServerParameters` in code, because that is the shape +orca can instrument — it rewrites the config to put its shim between client and server. A client +that constructs the parameters itself leaves orca nothing to rewrite, and the session is then +invisible to every capture layer: the transport is OS pipes, so the proxy never sees it, and +`mcp.client.stdio` spawns in list form rather than through a shell, so the PATH shim never fires. +That gap is real and is not what this check covers. +""" + +import asyncio +import json +import os + +from mcp import ClientSession, StdioServerParameters, stdio_client +from openai import OpenAI + + +async def main() -> None: + with open(os.environ["MCP_CONFIG_PATH"], encoding="utf8") as fh: + config = json.load(fh) + name, entry = next(iter(config["mcpServers"].items())) + params = StdioServerParameters( + command=entry["command"], args=entry.get("args", []), env=entry.get("env") + ) + + async with stdio_client(params) as (read, write): + async with ClientSession(read, write) as session: + await session.initialize() + tools = await session.list_tools() + print("TOOLS:", [t.name for t in tools.tools]) + result = await session.call_tool("lookup", {"key": "alpha"}) + print("MCP:", result.content[0].text) + + reply = OpenAI().chat.completions.create( + model="stub-1", messages=[{"role": "user", "content": "hello"}] + ) + print("GOT:", reply.choices[0].message.content) + + +asyncio.run(main()) diff --git a/test/integrations/agents/mcp_server.py b/test/integrations/agents/mcp_server.py new file mode 100644 index 0000000..bbf4280 --- /dev/null +++ b/test/integrations/agents/mcp_server.py @@ -0,0 +1,20 @@ +"""An MCP server over stdio, for the check that records one and then takes it away. + +Deliberately trivial and deliberately deterministic: the point of the check is the transport and +the replay, not the tool. `lookup` answers from its argument so a replay that served the wrong +recorded frame is visible in the output rather than only in a count. +""" + +from mcp.server.fastmcp import FastMCP + +app = FastMCP("orca-check") + + +@app.tool() +def lookup(key: str) -> str: + """Return a canned value for a key.""" + return f"VALUE-FOR-{key}" + + +if __name__ == "__main__": + app.run() diff --git a/test/integrations/run.mjs b/test/integrations/run.mjs index d2e11aa..ddd9ded 100644 --- a/test/integrations/run.mjs +++ b/test/integrations/run.mjs @@ -13,7 +13,8 @@ */ import { execFile, spawn } from 'node:child_process'; import { createRequire } from 'node:module'; -import { cp, mkdtemp, readFile, readdir, rm } from 'node:fs/promises'; +import { cp, mkdtemp, readFile, readdir, rename, rm, writeFile } from 'node:fs/promises'; +import { existsSync } from 'node:fs'; import { tmpdir } from 'node:os'; import { dirname, join } from 'node:path'; import { fileURLToPath } from 'node:url'; @@ -161,6 +162,23 @@ const CHECKS = [ needs: 'llama_index.llms.openai', exchanges: 1, }, + { + id: 'mcp-stdio', + what: 'an MCP server launched from a config, recorded and then taken away', + run: ['python', 'agents/mcp_agent.py'], + needs: ['mcp', 'openai'], + exchanges: 1, + /** + * The layer with the most code behind it and, until this, no end-to-end check at all: + * `mcp-shim` and `cli/src/mcp.ts` are ~1900 lines including their unit tests, and nothing + * asserted that a recorded MCP session comes back. + * + * Named here rather than inferred, because the whole point is what the shim puts in the trace + * that the proxy never saw: MCP rides OS pipes, so no base-URL variable reaches it. + */ + mcp: 'agents/mcp_server.py', + expectEvents: ['mcp.request', 'mcp.response'], + }, { id: 'fetch-hook', what: 'a JS agent with its origin compiled in', @@ -284,10 +302,50 @@ async function orca(argv, cwd, extraEnv = {}) { }); return { code: 0, out: `${stdout}${stderr}` }; } catch (e) { - return { code: e.status ?? -1, out: `${e.stdout ?? ''}${e.stderr ?? ''}`, killed: e.killed }; + // `e.status` is `spawnSync`'s field and is always undefined here, so every failure reported + // `-1` whatever the command actually did. `execFile` rejects with `code` — the exit status, or + // a string like `ENOENT` when the process never started — plus `signal` when it was killed. + // + // `e.message` matters as much: a spawn that fails, a timeout, or a `maxBuffer` overrun all + // reject with empty `stdout`/`stderr`, so without it the check reports a number and nothing + // else, which is the one case where there is no other evidence to go on. + const how = e.signal ? `${e.code ?? 'killed'} (${e.signal})` : (e.code ?? 'failed'); + // Not just the first line. `execFile`'s message is `Command failed: ` followed by the + // child's stderr — so taking one line keeps the part naming the command and drops the part + // saying what went wrong, which is the whole reason for reading it. + // And the *last* lines rather than the first. A Python traceback puts the exception at the + // bottom and the frames above it; keeping the top means keeping `asyncio.run(main())` and + // dropping the sentence that says what went wrong. + const why = String(e.message ?? '') + .split('\n') + .map((line) => line.trim()) + .filter((line) => line !== '' && !line.startsWith('Command failed:')) + .slice(-4) + .join(' | '); + return { + code: typeof e.code === 'number' ? e.code : -1, + out: `${e.stdout ?? ''}${e.stderr ?? ''}`, + killed: e.killed === true, + how: why === '' ? String(how) : `${how}: ${why}`, + }; } } +/** + * The last few lines of what a command said, for an error message that has to survive CI. + * + * `exited -1` on its own is unactionable: nobody can re-run the failing check by hand from a log, + * and -1 is what `orca()` reports when the process was killed rather than exiting — a timeout, or + * a signal — which is exactly the case where the output is the only evidence there is. + */ +function tail(out, lines = 6) { + const kept = String(out ?? '') + .split(/\r?\n/) + .filter((line) => line.trim() !== '') + .slice(-lines); + return kept.length === 0 ? '' : `\n ${kept.join('\n ')}`; +} + async function runCheck(check) { const absent = await installed(check.needs); if (absent !== undefined) return { skipped: `${absent} is not installed` }; @@ -303,6 +361,22 @@ async function runCheck(check) { await cp(join(here, 'agents'), join(dir, 'agents'), { recursive: true }); const adapter = check.adapter ?? 'generic-openai'; + /** + * The config an MCP-config-reading agent loads, and the file orca rewrites. + * + * `orca record --mcp-config` swaps each server's command for ` --out -- + * `, so the shim sits in the pipe and tees every JSON-RPC frame both ways. Written + * here pointing at the copy under `dir`, because the copy is what gets taken away before the + * replay. + */ + const mcpServer = check.mcp ? join(dir, ...check.mcp.split('/')) : undefined; + const mcpConfig = join(dir, 'mcp.json'); + if (mcpServer !== undefined) { + await writeFile( + mcpConfig, + `${JSON.stringify({ mcpServers: { probe: { command: check.run[0], args: [mcpServer] } } }, null, 2)}\n`, + ); + } // The variable that names the second origin is redirected by name, which is what an adapter // for a known harness does for itself. const splitEnv = second @@ -319,6 +393,7 @@ async function runCheck(check) { `http://127.0.0.1:${origin.port}`, '--upstream-anthropic', `http://127.0.0.1:${origin.port}`, + ...(mcpServer === undefined ? [] : ['--mcp-config', mcpConfig]), '--', ...(check.fromRepo ? [check.run[0], join(here, ...check.run.slice(1).join('/').split('/'))] @@ -327,7 +402,10 @@ async function runCheck(check) { dir, splitEnv, ); - if (recorded.code !== 0) throw new Error(`record exited ${recorded.code}`); + if (recorded.code !== 0) + throw new Error( + `record exited ${recorded.code} — ${recorded.how ?? 'no detail'}${tail(recorded.out)}`, + ); if (!recorded.out.includes('GOT:')) throw new Error('the agent did not produce its answer'); if (/capture\.empty/.test(recorded.out)) { throw new Error('recorded nothing — the traffic never reached the proxy'); @@ -353,7 +431,10 @@ async function runCheck(check) { ], dir, ); - if (forked.code !== 0) throw new Error(`fork exited ${forked.code}`); + if (forked.code !== 0) + throw new Error( + `fork exited ${forked.code} — ${forked.how ?? 'no detail'}${tail(forked.out)}`, + ); const f = /fork\.done .*live=(\d+) divergences=(\d+)/.exec(forked.out); if (f === null) throw new Error('fork printed no verdict'); if (Number(f[1]) === 0) throw new Error('the fork answered nothing live'); @@ -420,12 +501,19 @@ async function runCheck(check) { // From here the recording is on its own. Anything that reaches out now fails. origin.stop(); second?.stop(); + // The MCP server is an origin too, and taking it away is the only way to tell a replay that + // served the recorded frames from one that quietly started the server again. Renamed rather + // than deleted so a failure says what is missing. + if (mcpServer !== undefined) await rename(mcpServer, `${mcpServer}.gone`); const replayed = await orca(['replay', runId, '--in-place'], dir, { ...splitEnv, ...(check.repaint ? { ORCA_CHECK_REPAINT: '1' } : {}), }); - if (replayed.code !== 0) throw new Error(`replay exited ${replayed.code}`); + if (replayed.code !== 0) + throw new Error( + `replay exited ${replayed.code} — ${replayed.how ?? 'no detail'}${tail(replayed.out)}`, + ); const m = /reused=(\d+)\/(\d+) exact=(\d+) divergences=(\d+) unmatched=(\d+)/.exec( replayed.out, @@ -456,6 +544,26 @@ async function runCheck(check) { if (exact !== total) throw new Error(`${exact}/${total} matched byte for byte`); if (divergences !== 0) throw new Error(`${divergences} divergence(s)`); + /** + * The claim this check exists for: the session reproduces with the server gone. + * + * Asserted on the agent's own output rather than on a count, because a count cannot tell a + * served frame from a wrong one. The tool answers from its argument, so `VALUE-FOR-alpha` is + * the recorded reply to the recorded call and nothing else. + * + * `replay.done`'s numbers say nothing here — they count model exchanges — so a broken MCP + * replay would leave that line reading exactly as it does on success. + */ + if (mcpServer !== undefined) { + if (existsSync(mcpServer)) throw new Error('the MCP server was still there for the replay'); + if (!/MCP: VALUE-FOR-alpha/.test(replayed.out)) { + throw new Error('the MCP session did not reproduce from the recording'); + } + if (!/mode=replay/.test(replayed.out)) { + throw new Error('the shim was not put in replay mode'); + } + } + // Event types a check insists on. Counting exchanges says the traffic was captured; it says // nothing about a layer whose whole purpose is what the traffic does not contain. if (check.expectEvents) { @@ -484,7 +592,7 @@ async function runCheck(check) { const retrievalNote = check.retrieval === undefined ? '' : `, ${check.retrieval} retrieval`; return { - ok: `${total} exchanges${retrievalNote}, replayed exact with the origin down${check.forks ? ', forked live' : ''}${check.expectEvents ? `, ${check.expectEvents.length} agent events` : ''}`, + ok: `${total} exchanges${retrievalNote}, replayed exact with the origin down${check.forks ? ', forked live' : ''}${check.expectEvents ? `, ${check.expectEvents.length} of ${check.expectEvents[0].split('.')[0]}.* asserted` : ''}`, }; } finally { origin.stop();