diff --git a/changelog.d/f55-code-execution-text.breaking.md b/changelog.d/f55-code-execution-text.breaking.md new file mode 100644 index 000000000..db183989a --- /dev/null +++ b/changelog.d/f55-code-execution-text.breaking.md @@ -0,0 +1 @@ +- **Hosts:** a foreground `code_execution` result's `data` is now the text the model reads, as a list of one text block, and its fields, `stdout`, `stderr`, `return_code` and `time_limit_note`, are in `structured`. A host that reads those fields from `data` reads them from `structured`. We found no host that reads them. A background script's results are unchanged. diff --git a/changelog.d/f55-code-execution-text.changed.md b/changelog.d/f55-code-execution-text.changed.md new file mode 100644 index 000000000..7a4f1d7c5 --- /dev/null +++ b/changelog.d/f55-code-execution-text.changed.md @@ -0,0 +1 @@ +- `code_execution`'s result now reaches the model as text, where it was one line of JSON with the script's output escaped inside it. How the script ended comes first, as `exit code: N` and, when the call's `time_limit_ms` was capped, the time-limit note; then the script's stderr, then its stdout, each under a label. A result past the agent's inline cap (`tool_result_inline_max_chars`, 24,000 characters by default) is cut a stream at a time to each one's head and tail, around a count of what was cut, at a line's end where one is near: stderr keeps up to a third of the room, or more when stdout needs less, and its tail keeps its last line whole when that line fits. So at any cap that holds a cut of each stream, however long stdout runs, it no longer pushes the exit code and the end of stderr, which holds a traceback's last line and the reason a stopped script gives, past the cut. With a writable workspace mount that has no include list, the whole output goes to a file of its own in the folder a long result spills to, and the result's last line says where; without one, or when writing it fails, that line says what was cut wasn't kept. A cap too small to hold a cut of each stream beside that line, a few hundred characters, leaves the whole text to the inline cap's usual spill, which keeps its head. diff --git a/changelog.d/fix-code-execution-output-to-host.fixed.md b/changelog.d/fix-code-execution-output-to-host.fixed.md index d17320f3a..7e7ce60ff 100644 --- a/changelog.d/fix-code-execution-output-to-host.fixed.md +++ b/changelog.d/fix-code-execution-output-to-host.fixed.md @@ -1,4 +1,4 @@ -- What the commands a `code_execution` script runs write to stdout and stderr now comes back in the script's result, beside the script's own prints, line by line in the order written on each stream: `subprocess` without `capture_output`, `os.system`, and C code writing to file descriptors 1 and 2. It used to reach only the host's log, and a line a command wrote without a newline ran into the runtime's own reply, so the script waited out its time limit. A command with a lot of output now fills the result as the script's own prints do: each stream keeps up to 2,000,000 characters, counted as UTF-16 code units, so a character outside the Basic Multilingual Plane, such as an emoji, counts as two, and a long result spills to a workspace file, as any result does. Output belongs to the script running when it arrives: a command a script left running writes into the result of a later script running then, and into the host's log between scripts or once its interpreter has been replaced. The tool's description now says that what the script and the commands it runs print comes back, and that a background script's output streams to a log file when the agent has a writable workspace. That changes the tool definitions every request carries, and by [Anthropic's prompt-caching documentation](https://platform.claude.com/docs/en/build-with-claude/prompt-caching#what-invalidates-the-cache), a prompt cache written before the upgrade isn't reused. +- What the commands a `code_execution` script runs write to stdout and stderr now comes back in the script's result, beside the script's own prints, line by line in the order written on each stream: `subprocess` without `capture_output`, `os.system`, and C code writing to file descriptors 1 and 2. It used to reach only the host's log, and a line a command wrote without a newline ran into the runtime's own reply, so the script waited out its time limit. A command with a lot of output now fills the result as the script's own prints do: each stream keeps up to 2,000,000 characters, counted as UTF-16 code units, so a character outside the Basic Multilingual Plane, such as an emoji, counts as two, and a result past the agent's inline cap is cut to fit it, with a note naming the workspace file that holds the whole of it or saying that it wasn't kept. Output belongs to the script running when it arrives: a command a script left running writes into the result of a later script running then, and into the host's log between scripts or once its interpreter has been replaced. The tool's description now says that what the script and the commands it runs print comes back, and that a background script's output streams to a log file when the agent has a writable workspace. That changes the tool definitions every request carries, and by [Anthropic's prompt-caching documentation](https://platform.claude.com/docs/en/build-with-claude/prompt-caching#what-invalidates-the-cache), a prompt cache written before the upgrade isn't reused. - A command a `code_execution` script runs now reads the end of its input at once: its standard input is `/dev/null`. It used to read the runtime's channel from the host, so a command that reads its input, such as `cat`, or `ssh` without `-n`, took the host's messages, and the script failed or waited out its time limit. - A script that closes or redirects its file descriptors 0, 1 or 2 leaves the next script its output: the runtime's channel to the host has file descriptors of its own, 3 and 4, which no command a script runs is given, and each script starts with 0, 1 and 2 as the host set them, blocking even after a command set one non-blocking. A script that points 1 or 2 at the runtime's channel gets it put back at its end, so a partial line it left there reaches its result; what a script or its commands write onto that channel, or read from it, can still garble the runtime's messages: the script's own, and, from a command started holding the channel, a later script's for as long as that command runs. A script whose result is garbled that way waits out its time limit and the grace, and the interpreter restarts, so the next script's variables are gone. A script's `os.close(1)` used to leave it waiting out its time limit, and its `os.close(0)` sometimes left the next script doing so. A script that closes or replaces one of the runtime's own file descriptors, 3, 4, or its copies of 0 to 2, now ends the interpreter by the end of that script at the latest, and the result says which and what to check, as does one that shuts down the socket under file descriptor 1, 3 or 4. That line is lost when the script also closed or replaced both the runtime's copy of file descriptor 2 and file descriptor 2 itself, or shut down the socket under them, and the result leaves it out once the script's stderr has passed its 2,000,000-character cap. - What a script and its commands wrote before it was stopped, as far as it had reached the host, now comes back ahead of the message saying why, when it's killed at its time limit, aborted, or its interpreter crashes; it used to be lost. A partial line still in the script's writer when the interpreter is killed or crashes is lost with it. A crash's own text comes back too, and goes to the host's log: a fatal error's, which goes to the script's file descriptor 2 wherever the script pointed it, and now a traceback for a segfault or an abort, which faulthandler writes where CPython alone wrote nothing. diff --git a/src/code-execution/result-text.ts b/src/code-execution/result-text.ts new file mode 100644 index 000000000..231899070 --- /dev/null +++ b/src/code-execution/result-text.ts @@ -0,0 +1,111 @@ +/** + * What the model reads when a foreground `code_execution` script ends. + * + * How the script ended comes first: its exit code, and the time-limit note + * when the call's limit was capped. stderr comes next, ahead of stdout: its + * end holds a traceback, and for a script the runner stopped, why it stopped, + * which the runner writes on a line of its own after the script's own stderr. + * Within a budget, each stream is cut to its head and its tail around a count + * of what was cut, and stderr keeps a share of the room of its own, so in any + * budget that holds a cut of each stream, however long stdout runs, it can't + * push the exit code or stderr's end out of view. + */ + +export interface ScriptEnd { + stdout: string; + stderr: string; + returnCode: number; + /** Set when the call's time_limit_ms was capped at the deployment's maximum. */ + timeLimitNote?: string; +} + +/** The whole text, nothing cut. */ +export function scriptEndText(end: ScriptEnd): string { + return heading(end) + section('stderr', end.stderr) + section('stdout', end.stdout); +} + +/** + * The text within `budget` characters. When the whole text is longer, stderr + * keeps up to a third of the room the streams have, or more when stdout needs + * less, and stdout takes the rest, each cut to its head and tail. stderr's + * tail keeps its last line whole when the line fits its room. Returns null + * when the streams' room is three cut markers or less, so that stderr's share, + * when stderr is cut, keeps some of its own text beside its count. + */ +export function scriptEndTextWithin(end: ScriptEnd, budget: number): string | null { + const whole = scriptEndText(end); + if (whole.length <= budget) return whole; + const { stderr, stdout } = end; + const marker = cutMarker(Math.max(stderr.length, stdout.length)).length; + const room = budget - heading(end).length - labelLength('stderr', stderr) - labelLength('stdout', stdout); + if (room <= 3 * marker) return null; + const stderrRoom = Math.min(stderr.length, Math.max(Math.ceil(room / 3), room - stdout.length)); + return heading(end) + + section('stderr', cutMiddle(stderr, stderrRoom, true)) + + section('stdout', cutMiddle(stdout, room - stderrRoom)); +} + +function heading(end: ScriptEnd): string { + return `exit code: ${end.returnCode}\n` + (end.timeLimitNote ? `time limit: ${end.timeLimitNote}\n` : ''); +} + +/** A stream under its label, ending in a newline; nothing for an empty stream. */ +function section(name: string, body: string): string { + if (body === '') return ''; + return `--- ${name} ---\n${body}${body.endsWith('\n') ? '' : '\n'}`; +} + +/** What a stream's section adds besides the stream itself, at most: its label and a closing newline. */ +function labelLength(name: string, body: string): number { + return body === '' ? 0 : `--- ${name} ---\n`.length + 1; +} + +/** The count of what was cut, on a line of its own. */ +function cutMarker(cut: number, afterLineEnd = false): string { + return `${afterLineEnd ? '' : '\n'}[… ${cut} characters cut …]\n`; +} + +/** + * `text` in at most `keep` characters: its head and its tail around a count of + * what was cut. Each cut falls at a line's end when one is near, within a + * quarter of the part it ends, so a part line doesn't read as a whole one; + * otherwise it falls mid-line, never inside a surrogate pair. With + * `keepLastLine`, the tail is at least the last line when that line fits. + * `keep` must hold the marker for a cut of `text.length`. + */ +function cutMiddle(text: string, keep: number, keepLastLine = false): string { + if (text.length <= keep) return text; + const left = keep - cutMarker(text.length).length; + let headLength = Math.floor(left / 2); + let tailLength = left - headLength; + if (keepLastLine) { + // The tail keeps the last line whole, taking from the head, when the + // line fits; a longer one keeps its end. Blank lines at the end, LF or + // CRLF, go with the line before them. + let contentEnd = text.length; + while (contentEnd > 0 && (text[contentEnd - 1] === '\n' || text[contentEnd - 1] === '\r')) contentEnd--; + const lastLine = text.length - (text.lastIndexOf('\n', contentEnd - 1) + 1); + if (lastLine > tailLength && lastLine <= left) { + tailLength = lastLine; + headLength = left - lastLine; + } + } + let headEnd = headLength; + const lineEnd = headEnd > 0 ? text.lastIndexOf('\n', headEnd - 1) : -1; + if (lineEnd >= 0 && headEnd - (lineEnd + 1) <= headLength / 4) headEnd = lineEnd + 1; + else if (headEnd > 0 && isHighSurrogate(text.charCodeAt(headEnd - 1))) headEnd--; + let tailStart = text.length - tailLength; + const lineStart = text.indexOf('\n', tailStart - 1) + 1; + if (lineStart > 0 && lineStart - tailStart <= tailLength / 4) tailStart = lineStart; + else if (tailStart < text.length && isLowSurrogate(text.charCodeAt(tailStart))) tailStart++; + const head = text.slice(0, headEnd); + return head + cutMarker(tailStart - headEnd, head === '' || head.endsWith('\n')) + text.slice(tailStart); +} + +function isHighSurrogate(code: number): boolean { + return code >= 0xd800 && code <= 0xdbff; +} + +function isLowSurrogate(code: number): boolean { + return code >= 0xdc00 && code <= 0xdfff; +} diff --git a/src/framework.ts b/src/framework.ts index 07eb7e8f8..aa2fbe7c6 100644 --- a/src/framework.ts +++ b/src/framework.ts @@ -134,6 +134,7 @@ import { import { randomUUID, createHash } from 'node:crypto'; import { PyRunner, buildInjectedTools, formatLimit, type ScriptToolResult } from './code-execution/py-runner.js'; import { scriptToolNames } from './code-execution/script-tool-names.js'; +import { scriptEndText, scriptEndTextWithin, type ScriptEnd } from './code-execution/result-text.js'; import { buildCodeExecutionToolDefinition, CODE_EXECUTION_TOOL_NAME, @@ -19444,9 +19445,21 @@ export class AgentFramework { this.scriptRoutingInterpreters.set(agentName, { interpreter, names: new Set([...earlier, ...reachable]) }); } + // The model reads how the script ended as text, its ending first, within + // the bound its caller reads whole: the one the call carries, as an + // in-process caller may set it, or else the one the framework gives the + // calls it dispatches (resultMaxCharsFor), the agent's inline cap. Hosts + // read the fields in `structured`. + const cap = call.resultMaxChars ?? this.resultMaxCharsFor(agentName, call.id); + const text = await this.scriptEndResultText( + { stdout: exec.stdout, stderr: exec.stderr, returnCode: exec.returnCode, ...(capNote ? { timeLimitNote: capNote } : {}) }, + cap, + call.id, + ); return { success: true, - data: { + data: [{ type: 'text', text }], + structured: { stdout: exec.stdout, stderr: exec.stderr, return_code: exec.returnCode, @@ -19457,6 +19470,39 @@ export class AgentFramework { }; } + /** + * A foreground script's ending as the model reads it: whole when it fits + * `cap`, or else cut to fit beside a notice, with the whole text written + * to a file of its own in the tool results folder. Its name differs from + * the one the inline cap's spill gives the result before the call id, + * which a long id can cut short, so a later spill of the cut text, as at a + * cap lowered before the result is stored, can't write over it. The cut + * leaves room for the longest notice it could end with, so it's decided + * before anything is written. When the cap can't hold a cut of each stream + * beside that notice, the whole text comes back, unwritten. On a model's + * call, the inline cap's spill then keeps its head as the result is stored; + * an in-process caller that set so small a bound gets the whole text. + */ + private async scriptEndResultText(end: ScriptEnd, cap: number, callId: string): Promise { + const whole = scriptEndText(end); + if (whole.length <= cap) return whole; + const label = `${new Date().toISOString().slice(0, 10)}-output-${callId}`; + const keptIn = (path: string) => + `[cut to fit; the whole output (${whole.length} chars): workspace file ${path}. ${this.spillPageAdvice(path, cap)}]`; + const writeFailed = (path: string, error: string) => + `[cut to fit; writing the whole output (${whole.length} chars) to workspace file ${path} FAILED (${error.slice(0, 200)}); what was cut was not retained]`; + const noWorkspace = `[cut to fit; the whole output was ${whole.length} chars, and with no writable workspace mount without an include, what was cut was not retained]`; + const place = this.toolResultFilePlace(label); + const reserve = place + ? Math.max(keptIn(place.path).length, writeFailed(place.path, 'x'.repeat(200)).length, noWorkspace.length) + : noWorkspace.length; + const within = scriptEndTextWithin(end, cap - reserve); + if (within === null) return whole; + const written = place ? await this.writeToolResultFile(label, whole) : null; + if (!written) return within + noWorkspace; + return within + (written.error === undefined ? keptIn(written.path) : writeFailed(written.path, written.error)); + } + // --------------------------------------------------------------------------- // Background (daemon) scripts — model-authored watchers that outlive the turn // --------------------------------------------------------------------------- @@ -19946,6 +19992,19 @@ export class AgentFramework { return { path, error: failure }; } + /** How to read a tool result's file back a page at a time, with each page + * sized to come back within `cap`. */ + private spillPageAdvice(path: string, cap: number): string { + // JSON serialization can expand each read-back code unit to six + // chars (\\u0000). Leave room for the page's metadata and a possible + // extra code unit at a surrogate-pair boundary. + const pageOverhead = JSON.stringify(path).length + 256; + const readLimit = Math.max(1, Math.min(2000, Math.floor((cap - pageOverhead) / 6) - 1)); + return `Page with workspace--read ${JSON.stringify({ path, offsetChars: 0, limitChars: readLimit })}; ` + + 'use nextOffsetChars as offsetChars until null, keeping limitChars. Or raise the inline cap via ' + + 'agent_settings update tool_result_inline_max_chars.'; + } + private async spillOrTruncate( content: string, cap: number | undefined, @@ -19969,17 +20028,10 @@ export class AgentFramework { const written = await this.writeToolResultFile(label, content); if (written && written.error === undefined) { const path = written.path; - // JSON serialization can expand each read-back code unit to six - // chars (\\u0000). Leave room for the page's metadata and a possible - // extra code unit at a surrogate-pair boundary. - const pageOverhead = JSON.stringify(path).length + 256; - const readLimit = Math.max(1, Math.min(2000, Math.floor((cap - pageOverhead) / 6) - 1)); return { text: head + `\n\n[truncated — showing ${head.length} of ${content.length} chars; full content: workspace file ${path}` - + `. Page with workspace--read ${JSON.stringify({ path, offsetChars: 0, limitChars: readLimit })}; ` - + 'use nextOffsetChars as offsetChars until null, keeping limitChars. Or raise the inline cap via ' - + 'agent_settings update tool_result_inline_max_chars.]' + + `. ${this.spillPageAdvice(path, cap)}]` + kept, filePath: path, }; diff --git a/src/types/events.ts b/src/types/events.ts index 4f6139ed8..1c32e9fd0 100644 --- a/src/types/events.ts +++ b/src/types/events.ts @@ -193,11 +193,14 @@ export interface ToolResult { /** Whether this was an error (for LLM) */ isError?: boolean; /** - * An MCP tool's `structuredContent`: its machine-readable result, beside - * `data`, which is the content view. Present exactly when the server sent - * one, so `false`, `0` and `null` are values here, not absence. Programs - * read it (scripts get it in their result object); the model sees content, - * and sees this rendered as JSON only when the content carries no text. + * The result's machine-readable form, beside `data`. Programs read it: a + * script gets it in its result object, and a host in the tool result + * event. The model never reads this field: it sees the value only where an + * MCP conversion put it in the content as JSON, which happens only when the + * server sent no text. An MCP tool's is its `structuredContent`, present + * exactly when the server sent one, so `false`, `0` and `null` are values + * here, not absence. Any other tool can set one too, as `code_execution` + * does with its script's stdout, stderr, exit code and any time-limit note. */ structured?: unknown; /** diff --git a/test/agent-allowed-tools.test.ts b/test/agent-allowed-tools.test.ts index 76d032b06..f352dd11a 100644 --- a/test/agent-allowed-tools.test.ts +++ b/test/agent-allowed-tools.test.ts @@ -183,9 +183,9 @@ test('model-issued Python cannot forge unlisted inner generic or builtin calls', }]); assert.equal(result.toolUseId, 'script'); assert.ok(!result.isError); - const execution = JSON.parse(result.content) as { stdout: string; stderr: string; return_code: number }; - assert.equal(execution.return_code, 0, execution.stderr); - assert.equal((execution.stdout.match(/not permitted.*allowedTools/g) ?? []).length, 2); + // The model reads the script's ending first, then its output, as text. + assert.match(result.content, /^exit code: 0\n/, result.content); + assert.equal((result.content.match(/not permitted.*allowedTools/g) ?? []).length, 2); assert.deepEqual(h.effects.map((c) => c.name), ['allowed']); assert.deepEqual(h.framework.getAgentRuntimeSettings('assistant'), before); assert.deepEqual(h.lifecycle.filter(event => ['probe--denied', 'agent_settings'].includes(event.tool)), []); @@ -210,7 +210,7 @@ test('unregistered programmatic ephemeral script callers retain their full surfa try { const result = await pending; assert.equal(result.success, true); - assert.equal((result.data as { return_code: number }).return_code, 0); + assert.equal((result.structured as { return_code: number }).return_code, 0); assert.equal(h.effects.length, 1); } finally { clearInterval(processing); } } finally { await h.close(); } @@ -638,7 +638,7 @@ test('script in flight cannot gain legacy permissions when its ephemeral run dis assert.equal(h.framework.getAgent(created.agent.name), null); release(); const result = await script; assert.equal(result.success, true); - assert.match((result.data as { stdout: string }).stdout, /not a running agent.*only while registered/); + assert.match((result.structured as { stdout: string }).stdout, /not a running agent.*only while registered/); assert.deepEqual(h.effects.map(call => call.input), [{phase: 'barrier'}]); assert.equal(h.emitter.openCount, 0); assert.equal((h.framework as unknown as { scriptToolWaiters: Map }).scriptToolWaiters.size, 0); diff --git a/test/code-execution-result-text.test.ts b/test/code-execution-result-text.test.ts new file mode 100644 index 000000000..40b7b9ce4 --- /dev/null +++ b/test/code-execution-result-text.test.ts @@ -0,0 +1,411 @@ +/** + * What the model reads when a foreground code_execution script ends: how it + * ended first, then stderr, then stdout, kept within the agent's inline cap + * by cutting each stream to its head and tail, with the whole text in the + * tool result's file. + */ + +import { describe, it } from 'node:test'; +import assert from 'node:assert'; +import { mkdirSync, mkdtempSync, rmSync } from 'node:fs'; +import { tmpdir } from 'node:os'; +import { join } from 'node:path'; +import type { Module, ToolResult } from '../src/index.js'; +import { AgentFramework, PassthroughStrategy } from '../src/index.js'; +import { scriptEndText, scriptEndTextWithin } from '../src/code-execution/result-text.js'; +import { MockMembrane, createMockResponse } from './helpers/mock-membrane.js'; + +const CUT = /\[… (\d+) characters cut …\]\n/; +const LONE_SURROGATE = /[\uD800-\uDBFF](?![\uDC00-\uDFFF])|(?= 0 ? text.slice(from, next + 1) : text.slice(from); +} + +/** + * A cut body's head, the count it says was cut, and its tail. The marker + * starts a line: after a head that ends a line, or after a newline of its own. + */ +function cutOf(body: string, original?: string): { head: string; cut: number; tail: string } { + const m = CUT.exec(body); + assert.ok(m, `no cut in ${JSON.stringify(body.slice(0, 80))}`); + assert.ok(m.index === 0 || body[m.index - 1] === '\n', 'the marker starts a line'); + const cut = Number(m[1]); + const tail = body.slice(m.index + m[0].length); + const before = body.slice(0, m.index); + const endsALine = original !== undefined && original.startsWith(before) + && before.length + cut + tail.length === original.length; + return { head: endsALine || before === '' ? before : before.slice(0, -1), cut, tail }; +} + +const numbered = (n: number, prefix: string) => + Array.from({ length: n }, (_, i) => `${prefix} ${String(i).padStart(5, '0')}\n`).join(''); + +describe('code_execution result text', () => { + it('says how the script ended first, then stderr, then stdout, each under its label', () => { + assert.strictEqual(scriptEndText({ stdout: 'hi\n', stderr: '', returnCode: 0 }), 'exit code: 0\n--- stdout ---\nhi\n'); + assert.strictEqual( + scriptEndText({ stdout: 'out', stderr: 'warn', returnCode: 2, timeLimitNote: "time_limit_ms 60000 was capped at 1000, this deployment's maximum" }), + "exit code: 2\ntime limit: time_limit_ms 60000 was capped at 1000, this deployment's maximum\n--- stderr ---\nwarn\n--- stdout ---\nout\n", + ); + assert.strictEqual(scriptEndText({ stdout: '', stderr: '', returnCode: 0 }), 'exit code: 0\n'); + }); + + it('is whole when it fits the budget', () => { + const end = { stdout: 'a\n'.repeat(100), stderr: 'b\n', returnCode: 0 }; + const whole = scriptEndText(end); + assert.strictEqual(scriptEndTextWithin(end, whole.length), whole); + }); + + it('keeps stderr whole ahead of a long stdout, and stdout\'s head and tail around the count cut', () => { + // A script that prints 33,000 characters of numbered lines to stdout, + // then an error line to stderr, then exits 5: stderr after stdout would + // fall in the cut. + const stdout = numbered(3000, 'line'); + const end = { stdout, stderr: 'an error line\n', returnCode: 5 }; + const text = scriptEndTextWithin(end, 24_000)!; + assert.ok(text.length <= 24_000, String(text.length)); + assert.ok(text.startsWith('exit code: 5\n--- stderr ---\nan error line\n--- stdout ---\n'), text.slice(0, 120)); + const { head, cut, tail } = cutOf(bodyOf(text, 'stdout')!, stdout); + assert.ok(head.startsWith('line 00000\nline 00001\n'), head.slice(0, 40)); + assert.ok(tail.endsWith('line 02998\nline 02999\n'), tail.slice(-40)); + assert.strictEqual(head.length + cut + tail.length, stdout.length, 'the count is what was cut'); + assert.strictEqual(stdout.slice(0, head.length), head); + assert.strictEqual(stdout.slice(stdout.length - tail.length), tail); + // Each cut falls at a line's end, so no part line reads as a whole one, + // and the count follows on the next line, with no blank line between. + assert.ok(head.endsWith('\n'), JSON.stringify(head.slice(-20))); + assert.match(tail, /^line \d{5}\n/); + assert.ok(!text.includes('\n\n['), 'a blank line before the count'); + // stderr needs 14 characters, so stdout has the rest of the room: all of + // it but its label, the count and less than a line on each side. + assert.ok(head.length + tail.length > 23_850, String(head.length + tail.length)); + }); + + it('falls at a line\'s end on each side of a cut, across eleven budgets in a row', () => { + const stdout = numbered(3000, 'line'); + // Eleven budgets in a row: cut at the length each side is given, most of + // them would fall mid-line, since each line is 11 characters. + for (let budget = 24_000; budget <= 24_010; budget++) { + const text = scriptEndTextWithin({ stdout, stderr: '', returnCode: 0 }, budget)!; + const { head, tail } = cutOf(bodyOf(text, 'stdout')!, stdout); + assert.ok(head.endsWith('\n'), `the head at budget ${budget}: ${JSON.stringify(head.slice(-12))}`); + assert.match(tail, /^line \d{5}\n/, `the tail at budget ${budget}`); + } + }); + + it('cuts mid-line when no line ends near the cut, and the count still says what was cut', () => { + // The only line ends are far from both cuts: near the start, in the + // middle, and near the end. A cut moves at most a quarter of its part. + const stdout = 's\n' + 'a'.repeat(20_000) + '\n' + 'b'.repeat(20_000) + '\ne'; + const text = scriptEndTextWithin({ stdout, stderr: '', returnCode: 0 }, 4000)!; + const { head, cut, tail } = cutOf(bodyOf(text, 'stdout')!.replace(/\n$/, ''), stdout); + assert.ok(/^s\na+$/.test(head) && /^b+\ne$/.test(tail), `${head.slice(-5)} | ${tail.slice(0, 5)}`); + assert.ok(head.length > 1500 && tail.length > 1500, `${head.length} and ${tail.length}`); + assert.strictEqual(head.length + cut + tail.length, stdout.length); + }); + + it('gives stderr a third of the room when both streams are long, and keeps the end of each', () => { + const stderr = numbered(2000, 'err'); + const stdout = numbered(2000, 'out'); + const end = { stdout, stderr, returnCode: 1 }; + const budget = 9000; + const text = scriptEndTextWithin(end, budget)!; + assert.ok(text.length <= budget, String(text.length)); + const room = budget - 'exit code: 1\n'.length - 2 * ('--- stderr ---\n'.length + 1); + const err = bodyOf(text, 'stderr')!; + const out = bodyOf(text, 'stdout')!; + // A third of the room, less what falling at a line's end left out: under + // a 10-character line on each side of the cut. + assert.ok(err.length <= Math.ceil(room / 3) && err.length > Math.ceil(room / 3) - 20, `${err.length} of ${room}`); + // A short last line leaves the tail its half: many lines, not just that one. + const errTail = cutOf(err).tail; + assert.ok(errTail.endsWith('err 01999\n') && errTail.length > 1300, `${errTail.length}`); + assert.ok(cutOf(out).tail.endsWith('out 01999\n')); + assert.ok(out.length > err.length); + }); + + it('keeps stderr\'s last line whole in its tail when the line fits, and the end of a longer one', () => { + const stdout = numbered(2000, 'out'); + const budget = 9000; + // Its default tail would be about 1,480 characters, shorter than this line. + const lastLine = `ValueError: ${'v'.repeat(1500)}\n`; + const stderr = numbered(2000, 'tb') + lastLine; + const text = scriptEndTextWithin({ stdout, stderr, returnCode: 1 }, budget)!; + assert.ok(text.length <= budget, String(text.length)); + assert.strictEqual(cutOf(bodyOf(text, 'stderr')!, stderr).tail, lastLine); + // A last line longer than stderr's room keeps its end. + const longest = `ValueError: ${'w'.repeat(4000)}\n`; + const over = scriptEndTextWithin({ stdout, stderr: numbered(2000, 'tb') + longest, returnCode: 1 }, budget)!; + assert.ok(over.length <= budget, String(over.length)); + const { tail } = cutOf(bodyOf(over, 'stderr')!); + assert.ok(/^w+\n$/.test(tail) && longest.endsWith(tail), tail.slice(0, 20)); + // Blank lines at the end go with the line before them, LF or CRLF. + const blanks = numbered(2000, 'tb') + lastLine + '\n\n'; + const ended = scriptEndTextWithin({ stdout, stderr: blanks, returnCode: 1 }, budget)!; + assert.strictEqual(cutOf(bodyOf(ended, 'stderr')!, blanks).tail, `${lastLine}\n\n`); + const crlfLine = `ValueError: ${'v'.repeat(1500)}\r\n`; + const crlf = numbered(2000, 'tb') + crlfLine + '\r\n'; + const crlfEnded = scriptEndTextWithin({ stdout, stderr: crlf, returnCode: 1 }, budget)!; + assert.strictEqual(cutOf(bodyOf(crlfEnded, 'stderr')!, crlf).tail, `${crlfLine}\r\n`); + }); + + it('gives stderr the room stdout leaves, and all of it when stdout is empty', () => { + const stderr = numbered(2000, 'err'); + const short = scriptEndTextWithin({ stdout: 'done\n', stderr, returnCode: 1 }, 5000)!; + assert.ok(short.length <= 5000); + assert.ok(short.endsWith('--- stdout ---\ndone\n'), 'a short stdout stays whole'); + assert.ok(cutOf(bodyOf(short, 'stderr')!).tail.endsWith('err 01999\n')); + // stderr has all the room but stdout's 5 characters, not a third of it. + assert.ok(bodyOf(short, 'stderr')!.length > 4900, String(bodyOf(short, 'stderr')!.length)); + const alone = scriptEndTextWithin({ stdout: '', stderr, returnCode: 1 }, 5000)!; + assert.strictEqual(bodyOf(alone, 'stdout'), null); + assert.ok(alone.length <= 5000 && alone.length >= 4990, String(alone.length)); + }); + + it('never splits a surrogate pair at a cut', () => { + const stdout = '🌱'.repeat(10_000); + const stderr = 'é🌱'.repeat(5_000); + for (let budget = 3001; budget <= 3012; budget++) { + const text = scriptEndTextWithin({ stdout, stderr, returnCode: 0 }, budget)!; + assert.ok(text.length <= budget, `${text.length} > ${budget}`); + assert.ok(!LONE_SURROGATE.test(text), `a lone surrogate at budget ${budget}`); + } + }); + + it('is null when the streams\' room is three cut markers or less', () => { + assert.strictEqual(scriptEndTextWithin({ stdout: 'x'.repeat(1000), stderr: '', returnCode: 0 }, 60), null); + // Both streams cut. With three markers' room, stderr's third would hold + // its count and nothing of its own; one more, and it keeps its end. + const both = { stdout: 'o'.repeat(20_000), stderr: `${'e'.repeat(19_999)}E`, returnCode: 0 }; + const fixed = 'exit code: 0\n'.length + 2 * ('--- stderr ---\n'.length + 1); + const marker = '\n[… 20000 characters cut …]\n'.length; + assert.strictEqual(scriptEndTextWithin(both, fixed + 3 * marker), null); + const text = scriptEndTextWithin(both, fixed + 3 * marker + 1); + assert.ok(text !== null); + assert.ok(text.length <= fixed + 3 * marker + 1, String(text.length)); + assert.strictEqual(cutOf(bodyOf(text, 'stderr')!).tail, 'E\n'); + }); +}); + +describe('code_execution result text, through the framework (real python3)', () => { + /** An agent whose strategy bounds its inline cap at 4 characters a token. */ + const agentWithTokenBound = (maxMessageTokens: number) => { + class Bounded extends PassthroughStrategy { readonly maxMessageTokens = maxMessageTokens; } + return { name: 'prime', model: 'test-model', systemPrompt: 'You are prime.', allowedTools: 'all' as const, strategy: new Bounded() as never }; + }; + + async function withFramework( + opts: { + workspace: boolean; + codeExecution?: Record; + agents?: Parameters[0]['agents']; + toolResultInlineMaxChars?: number; + membrane?: MockMembrane; + }, + body: ( + framework: AgentFramework, + readSpill: (path: string) => Promise, + failWrites: (answer?: { success: false; error: string; isError: true; data?: unknown }) => void, + wroteFor: (callId: string, days: string[]) => Promise, + ) => Promise, + ): Promise { + const tempDir = mkdtempSync(join(tmpdir(), 'pytc-text-')); + const mountDir = join(tempDir, 'mount'); + mkdirSync(mountDir, { recursive: true }); + const { WorkspaceModule } = await import('../src/modules/workspace/index.js'); + const workspace = opts.workspace + ? new WorkspaceModule({ mounts: [{ name: 'files', path: mountDir, mode: 'read-write', watch: 'never' }] }) + : null; + const framework = await AgentFramework.create({ + storePath: join(tempDir, 'store.chronicle'), + membrane: (opts.membrane ?? new MockMembrane()).asMembrane(), + agents: opts.agents ?? [], + modules: workspace ? [workspace as unknown as Module] : [], + syncIntervalMs: 0, + codeExecution: { enabled: true, ...opts.codeExecution }, + ...(opts.toolResultInlineMaxChars !== undefined ? { toolResultInlineMaxChars: opts.toolResultInlineMaxChars } : {}), + }); + workspace?.initStore(framework.getStore()); + try { + await body( + framework, + async (path) => { + const read = await workspace!.readBinary(path); + assert.ok('data' in read, JSON.stringify(read)); + return (read as { data: Buffer }).data.toString('utf8'); + }, + (answer = { success: false, error: 'disk full', isError: true }) => { workspace!.writeBinary = async () => answer; }, + async (callId, days) => { + // The name this path gives the whole output's file. These calls are + // made in process, so nothing stores their results, and the inline + // cap's spill never runs here. + for (const day of new Set(days)) { + if ('data' in await workspace!.readBinary(`files/tool-results/${day}-output-${callId}.txt`)) return true; + } + return false; + }, + ); + } finally { + await framework.stop(); + rmSync(tempDir, { recursive: true, force: true }); + } + } + + const run = (framework: AgentFramework, id: string, input: Record, callerAgentName?: string) => + framework.executeToolCall({ id, name: 'code_execution', input, ...(callerAgentName ? { callerAgentName } : {}) }); + const today = () => new Date().toISOString().slice(0, 10); + const textOf = (r: ToolResult) => { + assert.ok(Array.isArray(r.data), JSON.stringify(r.data).slice(0, 200)); + const blocks = r.data as Array<{ type: string; text: string }>; + assert.strictEqual(blocks.length, 1); + assert.strictEqual(blocks[0].type, 'text'); + return blocks[0].text; + }; + + // 30,000 characters to stdout, then an error line to stderr, then + // SystemExit(5). The runtime reports a script's SystemExit as an + // exception: exit code 1, and its traceback after the error line. + const outputTail = 'import sys\nsys.stdout.write("x" * 30000)\nsys.stderr.write("an error line\\n")\nraise SystemExit(5)'; + + it('a long stdout keeps stderr and the exit code in view, and the whole output goes to a file of its own', async () => { + await withFramework({ workspace: true }, async (framework, readSpill) => { + const r = await run(framework, 'ce-output-tail', { code: outputTail }); + assert.strictEqual(r.success, true, JSON.stringify(r).slice(0, 300)); + const text = textOf(r); + // The house default cap for a caller with no agent, filled by the cut. + assert.ok(text.length <= 24_000 && text.length > 23_000, `${text.length} characters against the default inline cap`); + const { stderr } = r.structured as { stderr: string }; + assert.match(stderr, /^an error line\nTraceback \(most recent call last\):\n[\s\S]*SystemExit: 5\n$/); + assert.ok(text.startsWith(`exit code: 1\n--- stderr ---\n${stderr}--- stdout ---\nxxx`), text.slice(0, 400)); + const notice = /\n\[cut to fit; the whole output \((\d+) chars\): workspace file (files\/tool-results\/\d{4}-\d{2}-\d{2}-output-ce-output-tail\.txt)\. Page with workspace--read \{"path":"files\/tool-results\/\S+","offsetChars":0,"limitChars":\d+\}; use nextOffsetChars as offsetChars until null, keeping limitChars\. Or raise the inline cap via agent_settings update tool_result_inline_max_chars\.\]$/.exec(text); + assert.ok(notice, text.slice(-400)); + const whole = await readSpill(notice[2]); + assert.strictEqual(whole, `exit code: 1\n--- stderr ---\n${stderr}--- stdout ---\n${'x'.repeat(30_000)}\n`); + assert.strictEqual(Number(notice[1]), whole.length); + // Hosts read the fields, whole, in structured. + assert.deepStrictEqual(r.structured, { stdout: 'x'.repeat(30_000), stderr, return_code: 1 }); + }); + }); + + it('through a model\'s own call, the model reads and the history keeps the ending first and the end of each stream', async () => { + // The calls above are made in process, so nothing stores their results. + // Here the model makes the call: what it reads on the wire and what its + // history stores go through the framework's storing too, whose own spill + // would keep only a head if the text were past the cap. + const membrane = new MockMembrane(); + const code = 'import sys\nsys.stdout.write("x" * 30000 + "\\nstdout ends here\\n")\nsys.stderr.write("an error line\\n")\nraise SystemExit(5)'; + membrane.pushResponse(createMockResponse([{ type: 'tool_use', id: 'call_long', name: 'code_execution', input: { code } }], 'tool_use')); + membrane.pushResponse(createMockResponse([{ type: 'text', text: 'Done.' }])); + await withFramework({ workspace: true, membrane }, async (framework, readSpill) => { + const created = await framework.createEphemeralAgent({ name: 'worker', model: 'test-model', systemPrompt: 'Do the task.', allowedTools: 'all' }); + created.contextManager.addMessage('user', [{ type: 'text', text: 'Go.' }]); + const running = framework.runEphemeralToCompletion(created.agent, created.contextManager); + framework.start(); + await running; + const wire = (membrane.lastStream!.receivedToolResults.flat() as Array<{ toolUseId: string; content: string }>) + .find((r) => r.toolUseId === 'call_long')!.content; + assert.ok(wire.length <= 24_000 && wire.length > 23_000, `${wire.length} characters against the default inline cap`); + assert.ok(wire.startsWith('exit code: 1\n--- stderr ---\nan error line\nTraceback'), wire.slice(0, 120)); + assert.ok(wire.includes('SystemExit: 5\n--- stdout ---\nxxx'), 'stderr whole, ending in the exit, ahead of stdout'); + const notice = /\nstdout ends here\n\[cut to fit; the whole output \(\d+ chars\): workspace file (files\/tool-results\/\d{4}-\d{2}-\d{2}-output-call_long\.txt)\. [^\n]*\]$/.exec(wire); + assert.ok(notice, wire.slice(-300)); + assert.ok((await readSpill(notice[1])).endsWith('stdout ends here\n')); + // The history holds the very text the model read. + const stored = created.contextManager.getAllMessages().flatMap((m) => m.content) + .find((b) => b.type === 'tool_result' && (b as { toolUseId?: string }).toolUseId === 'call_long') as unknown as { content: unknown }; + const storedText = typeof stored.content === 'string' ? stored.content + : (stored.content as Array<{ type: string; text?: string }>).filter((b) => b.type === 'text').map((b) => b.text).join(''); + assert.strictEqual(storedText, wire); + }); + }); + + it('a stopped script\'s reason stays in view ahead of a long stdout', async () => { + await withFramework({ workspace: false, codeExecution: { scriptTimeoutMs: 600_000 } }, async (framework) => { + const code = 'import sys, asyncio\nsys.stdout.write("y" * 30000)\nsys.stdout.flush()\nawait asyncio.sleep(60)'; + const r = await run(framework, 'ce-stopped', { code, time_limit_ms: 1000 }); + const text = textOf(r); + assert.ok(text.length <= 24_000, String(text.length)); + const stderr = bodyOf(text, 'stderr'); + assert.ok(stderr, text.slice(0, 300)); + assert.match(stderr, /\nscript stopped: it reached its 1s time limit\. [^\n]*To give it longer, pass time_limit_ms up to 600000 \(10 min\)\.\n$/); + assert.ok(text.startsWith(`exit code: ${(r.structured as { return_code: number }).return_code}\n--- stderr ---\n`), text.slice(0, 120)); + assert.ok(text.indexOf('script stopped') < text.indexOf('--- stdout ---\nyyy')); + assert.match(text, /\n\[cut to fit; the whole output was \d+ chars, and with no writable workspace mount without an include, what was cut was not retained\]$/); + }); + }); + + it('a failed write of the whole output says so', async () => { + await withFramework({ workspace: true }, async (framework, _readSpill, failWrites) => { + failWrites(); + const text = textOf(await run(framework, 'ce-write-fails', { code: outputTail })); + assert.ok(text.length <= 24_000, String(text.length)); + assert.ok(text.startsWith('exit code: 1\n--- stderr ---\nan error line\nTraceback'), text.slice(0, 80)); + assert.match(text, /\n\[cut to fit; writing the whole output \(\d+ chars\) to workspace file files\/tool-results\/\S+-ce-write-fails\.txt FAILED \(disk full\); what was cut was not retained\]$/); + // writeToolResultFile cuts a failed write's error at 200 characters, + // and passes a store's own words on whole only for a write on a branch, + // which this path never asks for. Answered so all the same, the notice + // cuts them at 200, as the room it left assumes. + const said = `${'w'.repeat(200)}${'z'.repeat(100)}`; + failWrites({ success: false, error: said, isError: true, data: { branchLeft: true } }); + const long = textOf(await run(framework, 'ce-write-left', { code: outputTail })); + assert.ok(long.length <= 24_000, String(long.length)); + assert.ok(long.endsWith(`FAILED (${'w'.repeat(200)}); what was cut was not retained]`), long.slice(-80)); + }); + }); + + it('the inline cap resolved for the calling agent bounds the text', async () => { + await withFramework({ workspace: true, toolResultInlineMaxChars: 5000, agents: [agentWithTokenBound(0)] }, async (framework) => { + const text = textOf(await run(framework, 'ce-agent-cap', { code: outputTail }, 'prime')); + assert.ok(text.length <= 5000 && text.length > 4500, String(text.length)); + assert.ok(text.startsWith('exit code: 1\n--- stderr ---\nan error line\n'), text.slice(0, 80)); + assert.match(text, /\n\[cut to fit; the whole output \(\d+ chars\): workspace file files\/tool-results\/\S+-ce-agent-cap\.txt\. /); + }); + }); + + it('a bound the call carries, as an in-process caller may set it, bounds the text', async () => { + await withFramework({ workspace: true }, async (framework) => { + const r = await framework.executeToolCall({ id: 'ce-call-bound', name: 'code_execution', input: { code: outputTail }, resultMaxChars: 5000 }); + const text = textOf(r); + assert.ok(text.length <= 5000 && text.length > 4500, String(text.length)); + assert.ok(text.startsWith('exit code: 1\n--- stderr ---\nan error line\n'), text.slice(0, 80)); + assert.match(text, /\n\[cut to fit; the whole output \(\d+ chars\): workspace file files\/tool-results\/\S+-ce-call-bound\.txt\. /); + }); + }); + + it('a cap too small for a cut of each stream returns the whole text and writes nothing', async () => { + // 50 tokens bound the cap at 200 characters, less than the notice alone. + await withFramework({ workspace: true, agents: [agentWithTokenBound(50)] }, async (framework, _readSpill, _failWrites, wroteFor) => { + const days = [today()]; + const r = await run(framework, 'ce-tiny-cap', { code: outputTail }, 'prime'); + days.push(today()); + const { stderr } = r.structured as { stderr: string }; + assert.strictEqual(textOf(r), `exit code: 1\n--- stderr ---\n${stderr}--- stdout ---\n${'x'.repeat(30_000)}\n`); + assert.strictEqual(await wroteFor('ce-tiny-cap', days), false, 'nothing is written here: a model\'s call is then cut by the inline cap\'s spill, which writes its own file as the result is stored'); + }); + }); + + it('a capped time limit is said in the heading', async () => { + await withFramework({ workspace: true, codeExecution: { scriptTimeoutMs: 1000 } }, async (framework) => { + const r = await run(framework, 'ce-capped', { code: 'print("ok")', time_limit_ms: 60_000 }); + assert.strictEqual(textOf(r), "exit code: 0\ntime limit: time_limit_ms 60000 was capped at 1000, this deployment's maximum\n--- stdout ---\nok\n"); + assert.strictEqual((r.structured as { time_limit_note: string }).time_limit_note, "time_limit_ms 60000 was capped at 1000, this deployment's maximum"); + }); + }); + + it('a short run reads as its text, whole, with nothing written', async () => { + await withFramework({ workspace: true }, async (framework, _readSpill, _failWrites, wroteFor) => { + const days = [today()]; + const r = await run(framework, 'ce-short', { code: 'print("hello")' }); + days.push(today()); + assert.strictEqual(textOf(r), 'exit code: 0\n--- stdout ---\nhello\n'); + assert.deepStrictEqual(r.structured, { stdout: 'hello\n', stderr: '', return_code: 0 }); + assert.strictEqual(await wroteFor('ce-short', days), false); + }); + }); +}); diff --git a/test/code-execution-structured-results.test.ts b/test/code-execution-structured-results.test.ts index c80d710c6..b3ee47b2e 100644 --- a/test/code-execution-structured-results.test.ts +++ b/test/code-execution-structured-results.test.ts @@ -154,10 +154,7 @@ test("a script reads a structured result whole, the model's calls and history ke // structured JSON only when the content has none. assert.equal(resultOf('model-direct'), JSON.stringify(transcript)); assert.match(resultOf('model-only'), /\\"runId\\":\\"r41\\"/); - const python = JSON.parse(resultOf('model-python')); - assert.equal(python.stderr, ''); - assert.equal(python.return_code, 0); - assert.equal(python.stdout.trim(), 'r41 running café 🌱'); + assert.equal(resultOf('model-python'), 'exit code: 0\n--- stdout ---\nr41 running café 🌱\n'); assert.deepEqual(calls, ['dual', 'dual', 'only', 'dual', 'empty', 'only', 'plain', 'absent', 'error', 'large']); // The stored history holds what the model read: the readable direct diff --git a/test/code-execution.test.ts b/test/code-execution.test.ts index 23b1cf6ca..ed4dc737b 100644 --- a/test/code-execution.test.ts +++ b/test/code-execution.test.ts @@ -3006,7 +3006,7 @@ describe('framework code_execution integration (real python3)', () => { // Through the framework, each result says it isn't an error (a // handler that passed on only the string would make it None). assert.match(wireResult.content, /is_error: \[False, False\]/); - assert.match(wireResult.content, /"return_code":\s*0/); + assert.match(wireResult.content, /^exit code: 0\n/); // ...and NOT the intermediate tool results. assert.ok( !wireResult.content.includes('"echoed"'), @@ -3127,7 +3127,7 @@ describe('framework code_execution integration (real python3)', () => { // The first script is stopped at its time limit while its call that ends the turn is running. const stopped = await run({ code: 'await test__finish({})', time_limit_ms: 1000 }); assert.ok(finishStarted); - assert.match((stopped.data as { stderr: string }).stderr, /reached its 1s time limit/); + assert.match((stopped.structured as { stderr: string }).stderr, /reached its 1s time limit/); assert.ok(!stopped.endTurn); // The call finishes while the next script runs; its request belonged to the stopped script. @@ -3135,7 +3135,7 @@ describe('framework code_execution integration (real python3)', () => { await new Promise((r) => setTimeout(r, 300)); releaseFinish(); const result = await next; - assert.strictEqual((result.data as { stdout: string }).stdout, 'next done\n'); + assert.strictEqual((result.structured as { stdout: string }).stdout, 'next done\n'); assert.ok(!result.endTurn, "the stopped script's request ended the next script's turn"); } finally { await framework.stop(); @@ -5263,7 +5263,7 @@ describe('code_execution per-call time limit (time_limit_ms)', () => { const run = (framework: AgentFramework, input: Record) => framework.executeToolCall({ id: `ce-${Math.random()}`, name: 'code_execution', input }); - const dataOf = (r: ToolResult) => r.data as { stdout: string; stderr: string; return_code: number; time_limit_note?: string }; + const dataOf = (r: ToolResult) => r.structured as { stdout: string; stderr: string; return_code: number; time_limit_note?: string }; it('the tool tells the agent its time limit and offers time_limit_ms', async () => { await withFramework({ scriptTimeoutMs: 300_000, maxScriptTimeoutMs: 1_800_000 }, async (framework) => {