From 1854fc05009d5df594931c2f5800f9881c1fe3d1 Mon Sep 17 00:00:00 2001 From: Ansel-2428 Date: Mon, 19 Oct 2026 18:20:41 -0400 Subject: [PATCH] feat(code-execution): a script's result names the tool calls it ended without seeing answered When a script ends without the answers to some of its tool calls having been seen, its result now says which, so the agent can tell which effects may still come, or came unseen, before it runs anything again. - The runtime sends {"op": "tool_unwaited", "id": ..., "cause": ...} when the code that made a tool call stops waiting for it, at its timeout or because the script cancelled it, as with a shorter wait_for of its own. It sends none when the host asked the script to stop, or for a call it cancelled itself at the script's end. The TimeoutError adds that the call was sent and may still take effect. Only the runtime knows whether an answer was seen: a script that holds its event loop past a call's timeout gets the TimeoutError even when the answer came first. - PyRunner files each tool call under the script running when the host reads it, whatever code made it, a task or a thread an earlier script left running included, keyed by its interpreter's number and the runtime's call id, since call ids start again with each interpreter. A call read while no script runs waits in the runner's own record, and the next script takes it on if its answer hasn't been seen by then. A script's record closes when the host reads its end, so a later answer leaves its call as still running then, and a later call goes to the next script. - ExecResult.calls, when there were any, carries how many were made while the script ran and how many it took on, and, in the order made, each call whose answer wasn't seen while its code waited: still running, timed out or cancelled in the script and still running, or answered after its code stopped waiting, at its timeout, when the script cancelled it, or with its interpreter gone. A call answered after its code stopped waiting carries the start of the answer's text and whether the answer was an error. Each call is named by its tool and its arguments as JSON, cut to 120 characters, each string and array cut first, and each brief is a copy, since on V8 a slice keeps its whole string alive. Past the first 1,000 calls answered after their code stopped waiting, the rest are counted by tool, and the last 1,000 answered while it waited are kept for word that their code stopped waiting, which can come after the answer. - ExecResult.runnerNote carries the runner's own words that end the result, which still end stderr as well: why it stopped the script, the time-limit note, why a script didn't run, or why the interpreter didn't start. scriptStderr gives stderr without them. - The runner's advice after a crash, or after the runtime ended itself over a file descriptor a script took, names what to look for, the traceback that starts "Fatal Python error:" or the runtime's line starting "[pytc-runtime]", since the text now gives it before stderr. - callsLine gives the lines: after an error, a stop or a crash they count the calls and name those whose answers weren't seen; after a script ends on its own, they name those alone, if any. A foreground result's text gives the runner's words and then these lines after its exit code and time-limit note, and its stderr without the runner's words, so they're said once; its structured fields carry the lines first, as tool_calls, and stderr as before. The lines also come in the wake of a background script that dies, before its last output, and first in the result of a cancel. - The tool's description says that how the script ended and a line naming the tool calls that timed out or were cancelled in the script, or were still running when it ended, come back with what it printed, and that a call that times out may still take effect, which a script's retry logic needs before it runs. The earlier changelog fragments that quote the crash advice and describe the text's cut say what holds with this change. Tests: a timed-out call named as still running, with its TimeoutError's words; calls answered after their code stopped waiting, named with their answers' starts in the order made, an error answer as one, and an object result's text as the answer; a call the script cancels, with a shorter wait_for and a retry, and still running at its end; calls a host's stop cuts off, with no word from the runtime; a call answered while the script held its loop past the timeout; a leftover task's call and a script thread's call named in the result of the script running when they're made, and calls made between scripts in the next one's; a call taken on after an idle reclaim kept apart from the new interpreter's call of the same id; an answer that comes once its interpreter has exited, named as unseen; the record closing when the host reads a script's end; both 1,000 bounds; the arguments' cut; a brief keeping no long text alive; a handler resolving null; callsLine's forms; scriptStderr; the runner's words at each place it adds them; the text's heading; and, through the framework, a foreground result's text and structured fields after a stop, an error and a script that ends on its own, the wake of a background script that dies, and a cancel's result. Co-Authored-By: Claude Opus 5.5 --- .../f55-code-execution-text.changed.md | 2 +- ...de-execution-calls-left-uncertain.added.md | 2 + ...-execution-calls-left-uncertain.changed.md | 1 + .../fix-code-execution-signal-advice.fixed.md | 2 +- src/code-execution/index.ts | 6 +- src/code-execution/py-runner.ts | 362 ++++++- src/code-execution/result-text.ts | 19 +- src/code-execution/runtime-py.ts | 35 +- src/code-execution/tool-definition.ts | 11 +- src/framework.ts | 52 +- src/index.ts | 2 + src/types/framework.ts | 4 +- test/code-execution-result-text.test.ts | 28 +- test/code-execution.test.ts | 904 +++++++++++++++++- 14 files changed, 1358 insertions(+), 72 deletions(-) create mode 100644 changelog.d/feat-code-execution-calls-left-uncertain.added.md create mode 100644 changelog.d/feat-code-execution-calls-left-uncertain.changed.md diff --git a/changelog.d/f55-code-execution-text.changed.md b/changelog.d/f55-code-execution-text.changed.md index 7a4f1d7c5..ca1a234a8 100644 --- a/changelog.d/f55-code-execution-text.changed.md +++ b/changelog.d/f55-code-execution-text.changed.md @@ -1 +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. +- `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 how the script ended, or the end of stderr, which holds a traceback's last line, 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 the opening lines and a cut of each stream beside that line, a few hundred characters more than the opening lines, leaves the whole text to the inline cap's usual spill, which keeps its head. diff --git a/changelog.d/feat-code-execution-calls-left-uncertain.added.md b/changelog.d/feat-code-execution-calls-left-uncertain.added.md new file mode 100644 index 000000000..ecc9e60cd --- /dev/null +++ b/changelog.d/feat-code-execution-calls-left-uncertain.added.md @@ -0,0 +1,2 @@ +- When a `code_execution` script ends without the answers to some of its tool calls having been seen, because they were still running, or it timed out on them or cancelled them, its result names them, up to ten, and counts the rest by tool, so the agent can tell which effects may still come or came unseen. A call whose answer came after its code stopped waiting is named with the answer's start, and as answered with an error when the answer was one. The lines come in a foreground result's opening lines, after the exit code and the runner's own words, and also in the wake of a background script that dies and in the result of a `cancel`. After an error, a stop or a crash, the first line also counts the calls made while the script ran and those answered while it waited. A call from code an earlier script left running counts in the result of the script running when it's made, and one made while no script runs in the next one's, if its answer hasn't been seen by then. A tool call that times out in a script now raises a `TimeoutError` that says the call was sent and may still take effect, and the tool's description says so too. +- **Hosts:** `PyRunner`'s `ExecResult` carries `calls`, the tool calls made while the script ran, when there were any, as the host saw them when it read the script's end, and `runnerNote`, the runner's own words that end the result, which end `stderr` too, as they did. A foreground `code_execution` result's `structured` carries those lines first, as `tool_calls`, when the result has them. `PYTHON_RUNTIME_SOURCE` sends `{"op": "tool_unwaited", "id": …, "cause": "timeout"}` when the code that made a tool call stops waiting for it at its timeout, and `"cause": "cancelled"` when the script cancels it, which a host that runs the runtime itself can ignore. The `code_execution` tool's description changes, so each agent's prompt cache misses once after upgrading. diff --git a/changelog.d/feat-code-execution-calls-left-uncertain.changed.md b/changelog.d/feat-code-execution-calls-left-uncertain.changed.md new file mode 100644 index 000000000..9414c6c87 --- /dev/null +++ b/changelog.d/feat-code-execution-calls-left-uncertain.changed.md @@ -0,0 +1 @@ +- A foreground `code_execution` result's opening lines now hold the runner's own words on how the script ended, such as why it stopped the script or why the script didn't run, after the exit code and the time-limit note, and the stderr the model reads goes without them, so they're said once. diff --git a/changelog.d/fix-code-execution-signal-advice.fixed.md b/changelog.d/fix-code-execution-signal-advice.fixed.md index 779fa9ac0..080552eed 100644 --- a/changelog.d/fix-code-execution-signal-advice.fixed.md +++ b/changelog.d/fix-code-execution-signal-advice.fixed.md @@ -1 +1 @@ -- When a crash's signal (SIGSEGV, SIGABRT, SIGBUS, SIGFPE or SIGILL) ends `code_execution`'s Python interpreter while a script runs, the result now says to check the traceback above it for the call that crashed in native code, such as an extension module the script uses, or, when no traceback reached the result, to check whether native code the script calls crashes. It used to say to check whether the script uses too much memory, which now comes only after SIGKILL, the signal the out-of-memory killer sends. Any other signal gets `os.kill()` as its example. +- When a crash's signal (SIGSEGV, SIGABRT, SIGBUS, SIGFPE or SIGILL) ends `code_execution`'s Python interpreter while a script runs, the result now says to check the traceback that starts "Fatal Python error:" for the call that crashed in native code, such as an extension module the script uses, or, when no traceback reached the result, to check whether native code the script calls crashes. It used to say to check whether the script uses too much memory, which now comes only after SIGKILL, the signal the out-of-memory killer sends. Any other signal gets `os.kill()` as its example. diff --git a/src/code-execution/index.ts b/src/code-execution/index.ts index 062fd1f38..69488f47c 100644 --- a/src/code-execution/index.ts +++ b/src/code-execution/index.ts @@ -5,13 +5,17 @@ * (code_execution tool + tools exposed as async python functions), but runs * the interpreter on the host and dispatches inner tool calls in-process * through the framework's own tool routing — intermediate results never - * enter the model's context; the full trace stays on-box. + * enter the model's context, except the start of an answer that came after + * its call's code stopped waiting, which the result's line quotes (callsLine); + * the full trace stays on-box. */ export { PyRunner, buildInjectedTools } from './py-runner.js'; export type { InjectedTool, ExecResult, + ScriptCalls, + UncertainCall, PyRunnerOptions, ScriptToolCallHandler, ScriptToolResult, diff --git a/src/code-execution/py-runner.ts b/src/code-execution/py-runner.ts index 3f112ec3e..41f05501f 100644 --- a/src/code-execution/py-runner.ts +++ b/src/code-execution/py-runner.ts @@ -47,6 +47,57 @@ export interface ExecResult { /** Background execs: rolling tail of interleaved stdout+stderr (for the * crash/finish envelope; the full journal is in the log file). */ tail?: string; + /** + * The runner's own words that end the result, one to a line, which also end + * stderr (a background script's journal too). Set exactly when it adds them: + * - why it stopped the script: at an abort, a dispose, a kill at the time + * limit, or the interpreter's exit under the script, with `aborted`; + * - the time-limit note, after a script it stopped at its limit reports + * (`aborted` unset), or after the reason above; + * - why the script didn't run (another is running, or the runner was + * disposed), with `aborted`; + * - why the interpreter didn't start, with `aborted`. + * Absent when the script ended on its own. + */ + runnerNote?: string; + /** The tool calls made while the script ran, and any it took on from before it started, as the host saw them when the script ended: when it read the script's end, or stopped it. Absent when there were none. */ + calls?: ScriptCalls; +} + +/** + * The tool calls made while a script ran, as the host saw them when the script + * ended: by its own code, or by a task or a thread an earlier script left + * running, since a call named in no result would leave an effect that may + * still come unsaid. + */ +export interface ScriptCalls { + /** How many were made while it ran. */ + made: number; + /** How many it took on from before it started: calls made while no script ran that were still waiting for their answer then, or answered after their code stopped waiting. Absent when none. */ + before?: number; + /** Those whose answer wasn't seen while the script waited, in the order made, but for those `unlisted` counts; the rest were answered while it waited. */ + uncertain: UncertainCall[]; + /** Calls answered after the script stopped waiting for them, past the first CALLS_KEPT of those, which `uncertain` doesn't list: how many, by tool. */ + unlisted?: Record; +} + +/** A tool call whose answer its script didn't see while it waited, so the agent can't tell its effect from the script. */ +export interface UncertainCall { + /** The tool's name, as the framework knows it. */ + tool: string; + /** Its arguments as JSON, cut to CALL_BRIEF_CHARS. */ + args: string; + /** + * - `running`: no answer had come when the script ended, so it may still take effect. + * - `timed-out-running`: the call's code stopped waiting at its tool-call timeout, and no answer had come when the script ended. + * - `cancelled-running`: the script cancelled the call's code, as with a shorter wait_for of its own, and no answer had come when the script ended. + * - `answered-unseen`: the answer came before the script ended, but after the call's code stopped waiting, at its tool-call timeout, when the script cancelled it, or with the interpreter that made the call gone. + */ + state: 'running' | 'timed-out-running' | 'cancelled-running' | 'answered-unseen'; + /** For `answered-unseen`: the answer's start, cut to CALL_BRIEF_CHARS. */ + answer?: string; + /** For `answered-unseen`: set when the answer was an error (ScriptToolResult.isError), which a cut answer's start can leave out of view. */ + isError?: true; } /** Per-exec options for background (daemon) scripts. */ @@ -183,6 +234,131 @@ function onItsOwnLine(text: string, line: string): string { return (text === '' || text.endsWith('\n') ? text : `${text}\n`) + line; } +/** + * A result's stderr without the runner's own words (runnerNote), which end it + * on lines of their own, so a text that shows them elsewhere says them once: + * what the script and the commands it ran wrote, and the line end the runner + * added before its words. The whole stderr when it doesn't end with them. + */ +export function scriptStderr(result: ExecResult): string { + const { stderr, runnerNote } = result; + if (runnerNote === undefined) return stderr; + const start = stderr.endsWith(`${runnerNote}\n`) ? stderr.length - runnerNote.length - 1 + : stderr.endsWith(runnerNote) ? stderr.length - runnerNote.length + : -1; + if (start < 0 || (start > 0 && stderr[start - 1] !== '\n')) return stderr; + return stderr.slice(0, start); +} + +/** Why a script stopped, or didn't run, once its runner was disposed. */ +const DISPOSED = 'code_execution runner disposed'; + +/** How much of a call's arguments, and of its answer, a result that names the call shows. */ +const CALL_BRIEF_CHARS = 120; +/** + * How many calls of two kinds an exec keeps (CallRecords), so that a background + * script that runs for a day doesn't hold every call it made: + * - of those answered while the script waited, the most recent, in case word + * comes that it had stopped waiting for one. Once 1,000 more are answered + * before that word, the call counts as answered while the script waited. + * - of those answered after it stopped waiting, the first, which the result + * lists. It counts the rest by tool. + * A call still waiting for its answer is held until the answer comes, which the + * framework gives within the tool-call timeout and 30 s more. + */ +const CALLS_KEPT = 1000; +/** How many of the calls whose answer a script didn't see its result names; it counts the rest by tool. */ +const CALLS_NAMED = 10; + +/** + * `text` cut to CALL_BRIEF_CHARS with "…", never between a surrogate pair's + * halves. The characters it keeps are copied: on V8 a slice of a string keeps + * the whole string alive, so a kept brief of a long answer would hold the + * answer for as long as the record keeps the call. + */ +export function callBrief(text: string): string { + const cut = text.length > CALL_BRIEF_CHARS; + const end = !cut ? text.length + : /[\uD800-\uDBFF]/.test(text.charAt(CALL_BRIEF_CHARS - 1)) ? CALL_BRIEF_CHARS - 1 : CALL_BRIEF_CHARS; + const kept = text.slice(0, end).split('').join(''); + return cut ? `${kept}…` : kept; +} + +/** + * A call's arguments as JSON, cut as callBrief cuts. Each string and array is + * cut first, to no less than the brief can show, so a long text or list costs + * no more than a short one; an object with many keys, or a long key, is still + * made into JSON whole. + */ +function argsBrief(args: Record): string { + return callBrief(JSON.stringify(args, (_key, value: unknown) => + (typeof value === 'string' || Array.isArray(value)) && value.length > CALL_BRIEF_CHARS ? value.slice(0, CALL_BRIEF_CHARS) : value)); +} + +function newCallRecords(): CallRecords { + return { made: 0, before: 0, ended: false, open: new Map(), answered: new Map(), late: [], lateUnlisted: new Map() }; +} + +/** Keep a call answered after its script stopped waiting for it: listed, up to CALLS_KEPT of them, and past that counted by tool. */ +function keepLate(calls: CallRecords, call: KeptCall): void { + if (calls.late.length < CALLS_KEPT) calls.late.push(call); + else calls.lateUnlisted.set(call.tool, (calls.lateUnlisted.get(call.tool) ?? 0) + 1); +} + +/** The calls made while an exec's script ran, and those it took on, as its result carries them: those whose answers weren't seen, in the order made. */ +function settledCalls(calls: CallRecords): ScriptCalls { + const uncertain: Array = [ + ...[...calls.open.values()].map((c) => ({ + n: c.n, tool: c.tool, args: c.args, + state: c.unwaited === 'timeout' ? 'timed-out-running' as const : c.unwaited === 'cancelled' ? 'cancelled-running' as const : 'running' as const, + })), + ...calls.late.map((c) => ({ ...c, state: 'answered-unseen' as const })), + ].sort((a, b) => a.n - b.n); + return { + made: calls.made, + ...(calls.before > 0 ? { before: calls.before } : {}), + uncertain: uncertain.map(({ n: _n, ...call }) => call), + ...(calls.lateUnlisted.size > 0 ? { unlisted: Object.fromEntries(calls.lateUnlisted) } : {}), + }; +} + +/** + * What a script's result says of its tool calls, so the agent can tell which + * effects took place: after an error, a stop or a crash, how many it made and + * which it didn't see answered; after it ended on its own, only those it + * didn't see answered, if any. Null when there's nothing to say. + */ +export function callsLine(result: ExecResult): string | null { + const calls = result.calls; + const before = calls?.before ?? 0; + const total = (calls?.made ?? 0) + before; + if (!calls || total === 0) return null; + const made = `${calls.made} made while the script ran${before > 0 ? ` and ${before} before it started` : ''}`; + const unseen = calls.uncertain; + const unlisted = Object.entries(calls.unlisted ?? {}); + const others = unseen.length + unlisted.reduce((sum, [, n]) => sum + n, 0); + if (others === 0) { + if (result.aborted !== true && result.returnCode === 0) return null; + return `tool calls: ${made}, ${total === 1 ? '' : 'all '}answered while it waited.`; + } + const lines = [`tool calls: ${made}, ${total - others} answered while it waited; the other ${others === 1 ? 'one' : others}:`]; + for (const call of unseen.slice(0, CALLS_NAMED)) { + const named = `${call.tool} ${call.args}`; + lines.push( + call.state === 'running' ? `- still running when the script ended, so it may still take effect: ${named}` + : call.state === 'timed-out-running' ? `- timed out in the script and still running, so it may still take effect: ${named}` + : call.state === 'cancelled-running' ? `- cancelled in the script and still running, so it may still take effect: ${named}` + : `- answered ${call.isError ? 'with an error ' : ''}after its code stopped waiting: ${named}, answer ${JSON.stringify(call.answer ?? '')}`, + ); + } + const byTool = new Map(); + for (const call of unseen.slice(CALLS_NAMED)) byTool.set(call.tool, (byTool.get(call.tool) ?? 0) + 1); + for (const [tool, n] of unlisted) byTool.set(tool, (byTool.get(tool) ?? 0) + n); + const rest = others - Math.min(unseen.length, CALLS_NAMED); + if (rest > 0) lines.push(`- and ${rest} more: ${[...byTool].map(([tool, n]) => `${tool} ×${n}`).join(', ')}`); + return lines.join('\n'); +} + /** Add a line of the runner's own to a background script's journal, on a line of its own. */ function writeLine(journal: Journal, line: string): void { journal.write(`${journal.tail === '' || journal.tail.endsWith('\n') ? '' : '\n'}${line}\n`); @@ -606,10 +782,10 @@ function interpreterExit(exitCode: number | null, signal: NodeJS.Signals | null, // such as a progress bar's, they follow on that line. SIGKILL is the out-of-memory killer's; any // other signal, the script can send itself. const check = taken - ? `check whether the script closes, shuts down or replaces ${taken}, as the runtime's line above says` + ? `check whether the script closes, shuts down or replaces ${taken}, as the runtime's line starting "[pytc-runtime]" says` : signal && CRASH_SIGNALS.has(signal) ? said.includes(CRASH_TRACEBACK) - ? 'check the traceback above for the call that crashed in native code, such as an extension module the script uses' + ? 'check the traceback that starts "Fatal Python error:" for the call that crashed in native code, such as an extension module the script uses' : 'check whether native code the script calls crashes, such as an extension module it uses' : `check whether the script itself ends the process, for example ${ signal === 'SIGKILL' ? 'by using too much memory' : signal ? 'with os.kill()' : 'with os._exit()'}`; @@ -659,6 +835,59 @@ interface PendingExec { returnCode: number | null; /** Set when the host settled the exec itself (stopPending), rather than its result and marks. */ stopped?: true; + /** The script's tool calls so far. */ + calls: CallRecords; +} + +/** + * The tool calls made while a script runs, each by its interpreter and the + * runtime's call id, which is unique within an interpreter (PyRunner.callKey); + * those made while none runs wait in the runner's own record, which the next + * exec takes on (PyRunner.loose). The runtime alone knows whether a call's + * answer was seen: it says when the code that made a call stopped waiting for + * it, at its timeout or because the script cancelled it (tool_unwaited), which + * can arrive after the answer has gone, as when the script held its event loop + * past the call's timeout with the answer queued behind it. + */ +interface CallRecords { + /** How many were made while the script ran. */ + made: number; + /** How many it took on from before it started (PyRunner.takeLoose). */ + before: number; + /** + * Set once the host reads the script's end (exec_result): the record is + * then the calls as the host saw them when the script ended, so a later + * answer leaves its call as still running then, and a later call goes to + * the next exec's record. + */ + ended: boolean; + /** Calls with no answer yet. */ + open: Map; + /** Calls answered with no word that the script stopped waiting: the last CALLS_KEPT of them. */ + answered: Map; + /** Calls answered after the script stopped waiting for them: the first CALLS_KEPT of them (keepLate). */ + late: KeptCall[]; + /** The rest of those, by tool. */ + lateUnlisted: Map; +} + +interface KeptCall { + /** Its place among the runner's calls, for the order made. */ + n: number; + tool: string; + /** Its arguments, as argsBrief gives them. */ + args: string; + /** The start of its answer, as callBrief gives it. */ + answer: string; + /** Set when the answer was an error (ScriptToolResult.isError). */ + isError?: true; + /** Set on one answered while no script ran, which the next exec keeps only for word that its code had stopped waiting (takeLoose). */ + uncounted?: true; +} + +interface OpenCall extends Omit { + /** Why its code stopped waiting for it, when the runtime says it did (tool_unwaited). */ + unwaited: 'timeout' | 'cancelled' | null; } /** Interpreters started in this process, by every runner: each one's number. */ @@ -699,6 +928,10 @@ export class PyRunner { private err: OutputStream | null = null; private runtimeDir: string | null = null; private pending: PendingExec | null = null; + /** The calls made while no exec is pending, which the next exec takes on (takeLoose). */ + private loose: CallRecords = newCallRecords(); + /** How many calls the runner has kept: each one's place in the order made. */ + private callCounter = 0; private idleTimer: ReturnType | null = null; private execCounter = 0; /** The number of this runner's latest interpreter (interpretersStarted). */ @@ -761,16 +994,12 @@ export class PyRunner { opts?: { deadlineMs?: number; ceilingMs?: number; backgroundCeilingMs?: number }, ): Promise { if (this.disposed) { - return { stdout: '', stderr: 'code_execution runner disposed', returnCode: 1, aborted: true }; + return { stdout: '', stderr: DISPOSED, returnCode: 1, aborted: true, runnerNote: DISPOSED }; } if (this.busy) { - return { - stdout: '', - stderr: "script didn't run: another code_execution script of yours is already running, and they run one at a time. " - + 'Run this one again once that one has finished, or combine the two into one script.', - returnCode: 1, - aborted: true, - }; + const busy = "script didn't run: another code_execution script of yours is already running, and they run one at a time. " + + 'Run this one again once that one has finished, or combine the two into one script.'; + return { stdout: '', stderr: busy, returnCode: 1, aborted: true, runnerNote: busy }; } this.clearIdleTimer(); @@ -794,6 +1023,7 @@ export class PyRunner { sent: false, journal: null, returnCode: null, + calls: this.takeLoose(), }; this.pending = pending; try { @@ -802,12 +1032,8 @@ export class PyRunner { // Settled already when an abort or dispose reclaimed the interpreter // as it started; another exec may have claimed the runner since. if (!pending.settled) { - this.settlePending({ - stdout: '', - stderr: startFailure(this.pythonPath, err), - returnCode: 1, - aborted: true, - }); + const failed = startFailure(this.pythonPath, err); + this.settlePending({ stdout: '', stderr: failed, returnCode: 1, aborted: true, runnerNote: failed }); this.reclaim('spawn-failed'); } return settled; @@ -884,10 +1110,39 @@ export class PyRunner { dispose(): void { if (this.disposed) return; this.disposed = true; - this.stopPending('code_execution runner disposed'); + this.stopPending(DISPOSED); this.reclaim('dispose'); } + /** The record a call read now goes to: the pending exec's while its script runs, else the one the next exec takes on. */ + private callRecords(): CallRecords { + const calls = this.pending?.calls; + return calls && !calls.ended ? calls : this.loose; + } + + /** A call's key in the records: its interpreter's number (interpretersStarted) and the runtime's call id, so a call taken on from an interpreter that has gone doesn't meet the next one's. */ + private callKey(interpreter: number, callId: string): string { + return `${interpreter}:${callId}`; + } + + /** + * A new exec's record of its calls: the runner's record of those made while + * no script ran, so that a call from code an earlier script left running, + * still waiting for its answer when the next script starts or answered after + * its code stopped waiting, is named in that script's result. Those answered + * while their code waited are kept uncounted, since their effect came and was + * seen, unless word comes that their code had stopped waiting after all, as + * a held loop can bring once the next exec has started. + */ + private takeLoose(): CallRecords { + const calls = this.loose; + this.loose = newCallRecords(); + calls.before = calls.open.size + calls.late.length + [...calls.lateUnlisted.values()].reduce((sum, n) => sum + n, 0); + calls.made = 0; + for (const call of calls.answered.values()) call.uncounted = true; + return calls; + } + // ------------------------------------------------------------------------- private async ensureChild(): Promise { @@ -923,6 +1178,7 @@ export class PyRunner { }); this.child = child; this.interpreterNumber = ++interpretersStarted; + const interpreter = this.interpreterNumber; const protoIn = child.stdio[3] as Writable; const protoOut = child.stdio[4] as Readable; this.protoIn = protoIn; @@ -1012,7 +1268,7 @@ export class PyRunner { }); this.reader = createInterface({ input: protoOut }); - this.reader.on('line', (line) => this.handleLine(line, child)); + this.reader.on('line', (line) => this.handleLine(line, child, interpreter)); // readline passes its input's error on to the interface, where with no // listener it would be thrown as an uncaught exception and end the host. // protoOut's own listener above logs it. @@ -1061,8 +1317,9 @@ export class PyRunner { /** Fails the readiness of an interpreter that is still starting (see reclaim). */ private readyFailer: ((err: Error) => void) | null = null; - private handleLine(line: string, child: ChildProcess): void { - let msg: { op?: string; id?: string; name?: string; args?: unknown; return_code?: number }; + /** A line from an interpreter's runtime: `child`, whose number is `interpreter`. */ + private handleLine(line: string, child: ChildProcess, interpreter: number): void { + let msg: { op?: string; id?: string; name?: string; args?: unknown; return_code?: number; cause?: unknown }; try { msg = JSON.parse(line); } catch { @@ -1083,6 +1340,16 @@ export class PyRunner { msg.args && typeof msg.args === 'object' && !Array.isArray(msg.args) ? (msg.args as Record) : {}; + // The exec pending when the call arrives keeps it (CallRecords), + // whatever code made it, a task or a thread an earlier script left + // running included: a call named in no result would leave an effect + // that may still come unsaid. One that arrives while none is pending, + // or once the pending one's script has ended, waits for the next + // (takeLoose). + const calls = this.callRecords(); + const key = this.callKey(interpreter, callId); + calls.made++; + calls.open.set(key, { n: this.callCounter++, tool: toolName, args: argsBrief(args), unwaited: null }); this.onToolCall(toolName, args) .catch((err): ScriptToolResult => ({ text: `Error: ${err instanceof Error ? err.message : String(err)}`, @@ -1092,6 +1359,26 @@ export class PyRunner { // Only an object is a ScriptToolResult. Anything else a handler // resolves with, a string or a value its type rules out, is sent // as it is, so the call is still answered. + const answer = typeof result === 'object' && result !== null ? result.text : result; + const call = calls.ended ? undefined : calls.open.get(key); + if (call) { + calls.open.delete(key); + // A value the handler's type rules out is kept as no text: + // callBrief takes a string, and a throw here would leave the + // call unanswered. + const kept: KeptCall = { + n: call.n, tool: call.tool, args: call.args, answer: callBrief(typeof answer === 'string' ? answer : ''), + ...(typeof result === 'object' && result !== null && result.isError === true ? { isError: true as const } : {}), + }; + // Code whose interpreter has exited or been killed can't see the + // answer either, whether or not the runner has torn it down yet. + if (call.unwaited !== null || !alive(child)) { + keepLate(calls, kept); + } else { + calls.answered.set(key, kept); + if (calls.answered.size > CALLS_KEPT) calls.answered.delete(calls.answered.keys().next().value!); + } + } const reply = typeof result === 'object' && result !== null ? { op: 'tool_result', @@ -1106,6 +1393,29 @@ export class PyRunner { return; } + case 'tool_unwaited': { + // The script stopped waiting for the call, at its timeout or because + // it cancelled it (runtime-py.ts tool_fn), so the result names it, + // with the start of its answer if one comes: the script may call + // again, and that answer tells whether the first call did anything. + // The runtime drops an answer that arrives after this. + const calls = this.callRecords(); + const key = this.callKey(interpreter, String(msg.id)); + const open = calls.open.get(key); + if (open) open.unwaited = msg.cause === 'cancelled' ? 'cancelled' : 'timeout'; + const answered = calls.answered.get(key); + if (answered) { + calls.answered.delete(key); + // One answered while no script ran is counted only now (takeLoose). + if (answered.uncounted) { + delete answered.uncounted; + calls.before++; + } + keepLate(calls, answered); + } + return; + } + case 'wake': { const wakeId = msg.id; if (!wakeId) return; @@ -1128,6 +1438,7 @@ export class PyRunner { const pending = this.pending; if (pending && msg.id === pending.id && pending.returnCode === null) { pending.returnCode = typeof msg.return_code === 'number' ? msg.return_code : 1; + pending.calls.ended = true; this.settleIfComplete(child); } return; @@ -1182,10 +1493,10 @@ export class PyRunner { // own tools, when it has one that hasn't reached its cap or failed a // write, and in its tail, which the result carries. writeLine(journal, why); - this.settlePending({ stdout: '', stderr: why, returnCode, aborted: true, tail: journal.tail }); + this.settlePending({ stdout: '', stderr: why, returnCode, aborted: true, tail: journal.tail, runnerNote: why }); return tail; } - this.settlePending({ stdout, stderr: onItsOwnLine(stderr, why), returnCode, aborted: true }); + this.settlePending({ stdout, stderr: onItsOwnLine(stderr, why), returnCode, aborted: true, runnerNote: why }); return stderr; } @@ -1201,7 +1512,11 @@ export class PyRunner { + `${limitRemedy(pending.deadlineMs, pending.ceilingMs, pending.background, pending.backgroundCeilingMs)}\n`; // On a line of its own: a script's output, and the runner's own texts, such as an // interpreter's exit, can end without a newline. - result = { ...result, stderr: onItsOwnLine(result.stderr, note) }; + result = { + ...result, + stderr: onItsOwnLine(result.stderr, note), + runnerNote: result.runnerNote === undefined ? note.trimEnd() : `${result.runnerNote}\n${note.trimEnd()}`, + }; // A background script's journal says so too: in its file, when it has one, // and in its tail, which is the result's. if (pending.journal) { @@ -1209,6 +1524,7 @@ export class PyRunner { result = { ...result, tail: pending.journal.tail }; } } + if (pending.calls.made + pending.calls.before > 0) result = { ...result, calls: settledCalls(pending.calls) }; // Only now: what the stop wrote above is the journal's last. pending.journal?.close(); if (pending.deadlineTimer) clearTimeout(pending.deadlineTimer); diff --git a/src/code-execution/result-text.ts b/src/code-execution/result-text.ts index 231899070..c1c095a97 100644 --- a/src/code-execution/result-text.ts +++ b/src/code-execution/result-text.ts @@ -1,14 +1,14 @@ /** * 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. + * How the script ended comes first: its exit code, the time-limit note when + * the call's limit was capped, the runner's own words when it has any, such + * as why it stopped the script, and what the script's tool calls left + * uncertain. stderr comes next, ahead of stdout: its end holds a traceback. * 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. + * push how the script ended or stderr's end out of view. */ export interface ScriptEnd { @@ -17,6 +17,10 @@ export interface ScriptEnd { returnCode: number; /** Set when the call's time_limit_ms was capped at the deployment's maximum. */ timeLimitNote?: string; + /** The runner's own words, when it has any (ExecResult.runnerNote); stderr goes without them (scriptStderr). */ + runnerNote?: string; + /** What the script's tool calls left uncertain, when there's something to say (callsLine). */ + toolCalls?: string; } /** The whole text, nothing cut. */ @@ -46,7 +50,10 @@ export function scriptEndTextWithin(end: ScriptEnd, budget: number): string | nu } function heading(end: ScriptEnd): string { - return `exit code: ${end.returnCode}\n` + (end.timeLimitNote ? `time limit: ${end.timeLimitNote}\n` : ''); + return `exit code: ${end.returnCode}\n` + + (end.timeLimitNote ? `time limit: ${end.timeLimitNote}\n` : '') + + (end.runnerNote ? `${end.runnerNote}\n` : '') + + (end.toolCalls ? `${end.toolCalls}\n` : ''); } /** A stream under its label, ending in a newline; nothing for an empty stream. */ diff --git a/src/code-execution/runtime-py.ts b/src/code-execution/runtime-py.ts index 967fc619a..ac7736c34 100644 --- a/src/code-execution/runtime-py.ts +++ b/src/code-execution/runtime-py.ts @@ -9,8 +9,9 @@ * - host tools are injected as async functions taking a single dict and * returning the tool_result text as a str (ToolResult), which also * carries .is_error and .structured - * - a pending tool call that gets no response raises TimeoutError with the - * same message shape the managed runtime produces + * - a pending tool call that gets no response raises TimeoutError, opening + * with the message the managed runtime produces and saying the call may + * still take effect; the runtime tells the host (tool_unwaited) * - interpreter globals persist across execs (container-reuse semantics) * * BACKGROUND MODE (model-authored daemons): when init carries @@ -80,7 +81,18 @@ * can't tell that from a script's own shutdown * of the socket under fd 3. * py -> host : {op:"ready"} - * {op:"tool_call", id, exec_id, name, args} + * {op:"tool_call", id, exec_id, name, args} exec_id + * is the exec running when it was sent, or + * null between scripts; PyRunner files a + * call by when it reads it instead + * {op:"tool_unwaited", id, cause} the code that + * made that call stopped waiting for it, before + * it saw an answer: at call_timeout_s, with + * TimeoutError (cause "timeout"), or because + * the script cancelled it ("cancelled"), not + * when the host stopped the script or the + * runtime cancelled the call at its end; the + * call may still be running * {op:"wake", id, exec_id, line, payload} * {op:"exec_result", id, return_code} * @@ -722,10 +734,25 @@ def _make_tool_fn(tool_name, py_name): try: return await asyncio.wait_for(fut, timeout=CALL_TIMEOUT_S) except asyncio.TimeoutError: + # The host keeps the call as one its code stopped waiting for, + # which the result names, with the answer if one comes in time. + send({"op": "tool_unwaited", "id": call_id, "cause": "timeout"}) raise TimeoutError( "Calling tool ['" + tool_name + "'] timed out (no response after " - + str(int(CALL_TIMEOUT_S)) + "s)." + + str(int(CALL_TIMEOUT_S)) + "s). The call was sent and may still " + "take effect, so check for its effect before calling it again." ) + except asyncio.CancelledError: + # The script's own code stopped waiting, as with a shorter + # wait_for or a TaskGroup whose other task failed, and may call + # again: the host names the call as after a timeout. A call whose + # future the runtime cancelled at the script's end, which it took + # out of the pending calls then, and a stop the host asked for are + # the host's to know: their calls read as still running when the + # script ended. + if call_id in _pending_tool_futures and not (_stop is not None and _stop.state == _DELIVERED): + send({"op": "tool_unwaited", "id": call_id, "cause": "cancelled"}) + raise finally: _pending_tool_futures.pop(call_id, None) tool_fn.__name__ = py_name diff --git a/src/code-execution/tool-definition.ts b/src/code-execution/tool-definition.ts index a42468927..02581f51f 100644 --- a/src/code-execution/tool-definition.ts +++ b/src/code-execution/tool-definition.ts @@ -47,13 +47,14 @@ export function buildCodeExecutionToolDefinition(opts?: { 'JSON object above, or None). ' + "An exact-name lookup dict is also available: tools['mcpl--discord--fetch_history']({...}). " + 'Use top-level await; run independent calls in parallel with asyncio.gather. ' + - 'Only what the script and the commands it runs print (stdout and stderr), and the exit code, come back ' + - 'to you — intermediate tool results stay in the script, so filter or aggregate large data there and ' + - 'print only what you need. Interpreter state (variables, imports) persists across code_execution ' + - `calls but is reclaimed after ~${idleMinutes} minutes idle. Relative paths resolve in a ` + + 'Only how the script ended, what it and the commands it runs print (stdout and stderr), and a line naming ' + + 'the tool calls that timed out or were cancelled in it, or were still running when it ended, come back to you; ' + + 'other tool results stay in the script, so filter or aggregate large data there and print only what you need. ' + + 'Interpreter state (variables, imports) persists ' + + `across code_execution calls but is reclaimed after ~${idleMinutes} minutes idle. Relative paths resolve in a ` + 'scratch directory of the interpreter\'s, which goes whenever it stops or is reclaimed, so a file meant to ' + 'outlast the interpreter needs an absolute path. A tool call that receives no ' + - `response within ~${callTimeoutSeconds}s raises TimeoutError inside the script. ` + + `response within ~${callTimeoutSeconds}s raises TimeoutError inside the script, though the call was sent and may still take effect. ` + `A foreground script is stopped after ${formatLimit(limits.defaultMs)}; pass time_limit_ms to set this call's limit ` + `(at most ${formatLimit(limits.maxMs)}; a background script runs up to ${formatLimit(limits.backgroundMaxMs)}). ` + 'Stopping a script does not stop tools it already called. ' + diff --git a/src/framework.ts b/src/framework.ts index 72c570fe5..b7aa65d54 100644 --- a/src/framework.ts +++ b/src/framework.ts @@ -132,7 +132,7 @@ import { type ShownRanges, } from './tool-image-ledger.js'; import { randomUUID, createHash } from 'node:crypto'; -import { PyRunner, buildInjectedTools, formatLimit, type ScriptToolResult } from './code-execution/py-runner.js'; +import { PyRunner, buildInjectedTools, callsLine, formatLimit, scriptStderr, 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 { @@ -1833,6 +1833,8 @@ interface BackgroundScriptRecord { status: 'running' | 'finished' | 'died' | 'cancelled'; /** Set when cancel/dispose already settled this script (suppresses wakes). */ cancelled: boolean; + /** Its exec, which a cancel waits for to say which tool calls it left running. */ + ended?: Promise; } interface EphemeralRun { @@ -19324,7 +19326,9 @@ export class AgentFramework { * itself). Inner tool calls are dispatched through dispatchToolCall — the * exact model path, including MCPL state/checkpoint handling, channel * routing, and traces — and resolved via scriptToolWaiters, so their - * results reach the running script and never the model context. + * results reach the running script and never the model context, except + * the start of an answer that came after its call's code stopped waiting, + * which the result's line naming the calls quotes (callsLine). */ private async runCodeExecution(agentName: string, call: ToolCall): Promise { // RFC-007: what the script's own tool calls are attributed to. Read @@ -19363,15 +19367,23 @@ export class AgentFramework { if (!record || record.agentName !== agentName) { return { success: false, error: `no background script '${input.script_id}'`, isError: true }; } + // The agent stopped the script, so its result says which tool calls + // the stop left running: they may still take effect. + let toolCalls: string | null = null; if (record.status === 'running') { record.cancelled = true; record.status = 'cancelled'; record.runner.abort('cancelled by agent'); record.runner.dispose(); + // The abort settles the exec at once. + toolCalls = record.ended ? callsLine(await record.ended) : null; } return { success: true, - data: { script_id: record.id, status: record.status, log: record.logPath }, + data: { + ...(toolCalls ? { tool_calls: toolCalls } : {}), + script_id: record.id, status: record.status, log: record.logPath, + }, }; } if (input.action !== undefined && input.action !== 'run') { @@ -19453,15 +19465,25 @@ export class AgentFramework { const earlier = mark?.interpreter === interpreter ? mark.names : []; this.scriptRoutingInterpreters.set(agentName, { interpreter, names: new Set([...earlier, ...reachable]) }); } + const toolCalls = callsLine(exec); // 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`. + // read the fields in `structured`. The runner's own words are in the + // heading, so the text's stderr goes without them (scriptStderr) and says + // them once; `structured` keeps stderr as hosts get it. 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 } : {}) }, + { + stdout: exec.stdout, + stderr: scriptStderr(exec), + returnCode: exec.returnCode, + ...(capNote ? { timeLimitNote: capNote } : {}), + ...(exec.runnerNote !== undefined ? { runnerNote: exec.runnerNote } : {}), + ...(toolCalls ? { toolCalls } : {}), + }, cap, call.id, ); @@ -19469,6 +19491,7 @@ export class AgentFramework { success: true, data: [{ type: 'text', text }], structured: { + ...(toolCalls ? { tool_calls: toolCalls } : {}), stdout: exec.stdout, stderr: exec.stderr, return_code: exec.returnCode, @@ -19616,12 +19639,12 @@ export class AgentFramework { callId: scriptId, input: { lines: code.split('\n').length }, }); - void runner - .exec(code, injected, { - logPath: logAbsPath, - lifetimeMs, - onWake: (line, payload) => this.handleScriptWake(record, line, payload), - }, { ceilingMs: scriptTimeLimits(cfg ?? undefined).backgroundMaxMs }) + record.ended = runner.exec(code, injected, { + logPath: logAbsPath, + lifetimeMs, + onWake: (line, payload) => this.handleScriptWake(record, line, payload), + }, { ceilingMs: scriptTimeLimits(cfg ?? undefined).backgroundMaxMs }); + void record.ended .then((exec) => this.settleBackgroundScript(record, exec)) .catch((err) => { // exec never rejects by contract; this is the belt-and-suspenders. @@ -19739,9 +19762,11 @@ export class AgentFramework { const output = exec.tail ?? exec.stderr ?? ''; const tail = safeSlice(output, Math.max(0, output.length - 2000), output.length); const elapsedMin = Math.round((Date.now() - record.startedAt) / 60_000); + const toolCalls = callsLine(exec); const envelope = `[background script ${record.id}] Your background script DIED ${elapsedMin}m after start ` + `(it did not call wake_agent and is no longer watching).\n` + + (toolCalls ? `${toolCalls}\n` : '') + `Last output:\n${tail || '(none)'}\n` + (record.logPath ? `Full journal: workspace file ${record.logPath}` : ''); this.injectScriptWake(record, envelope); @@ -20077,7 +20102,8 @@ export class AgentFramework { env: cfg?.env, inheritEnv: cfg?.inheritEnv, label: agentName, - // The script that made the call is the one running when it arrives. + // A call is filed with the script running when it arrives, which made + // it unless code an earlier script left running did. onToolCall: (toolName, args) => this.handleScriptToolCall( agentName, toolName, args, @@ -20112,7 +20138,7 @@ export class AgentFramework { toolName: string, args: Record, origin?: ScriptCallOrigin, - /** The foreground script that made the call; none for a background script. */ + /** The foreground script running when the call arrived; none for a background script. */ script?: { endTurn: boolean; turnId?: number; calls: RoundCall[] }, ): Promise { if (toolName === CODE_EXECUTION_TOOL_NAME) { diff --git a/src/index.ts b/src/index.ts index 89f901700..3812f247c 100644 --- a/src/index.ts +++ b/src/index.ts @@ -72,6 +72,8 @@ export { export type { InjectedTool, ExecResult, + ScriptCalls, + UncertainCall, PyRunnerOptions, ScriptToolCallHandler, ScriptToolResult, diff --git a/src/types/framework.ts b/src/types/framework.ts index b547ea89c..28a02a86a 100644 --- a/src/types/framework.ts +++ b/src/types/framework.ts @@ -33,7 +33,9 @@ export interface ProcessLoggingConfig { * Client-side programmatic tool calling: a synthesized `code_execution` tool * that runs model-authored Python on the host, with every framework tool * injected as an async function. Mirrors the trained surface of Anthropic's - * server-side PTC; inner tool results never enter the model context. + * server-side PTC; inner tool results never enter the model context, except + * the start of an answer that came after its call's code stopped waiting, + * which the result's line naming the calls quotes. * * Robustness boundary, not a security sandbox (same doctrine as gate.js — * the agent already has broader host access through its tools). diff --git a/test/code-execution-result-text.test.ts b/test/code-execution-result-text.test.ts index 40b7b9ce4..508515973 100644 --- a/test/code-execution-result-text.test.ts +++ b/test/code-execution-result-text.test.ts @@ -56,6 +56,18 @@ describe('code_execution result text', () => { assert.strictEqual(scriptEndText({ stdout: '', stderr: '', returnCode: 0 }), 'exit code: 0\n'); }); + it("puts the runner's own words and what the tool calls left uncertain in the heading, after the exit code and the time-limit note", () => { + const toolCalls = 'tool calls: 2 made while the script ran, 1 answered while it waited; the other one:\n- still running when the script ended, so it may still take effect: a--b {"i":0}'; + assert.strictEqual( + scriptEndText({ + stdout: 'out\n', stderr: 'Traceback\n', returnCode: 1, timeLimitNote: 'capped', + runnerNote: 'script stopped: it reached its 1s time limit. Run it again.', toolCalls, + }), + `exit code: 1\ntime limit: capped\nscript stopped: it reached its 1s time limit. Run it again.\n${toolCalls}\n--- stderr ---\nTraceback\n--- stdout ---\nout\n`, + ); + assert.strictEqual(scriptEndText({ stdout: '', stderr: '', returnCode: 0, toolCalls }), `exit code: 0\n${toolCalls}\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); @@ -325,17 +337,21 @@ describe('code_execution result text, through the framework (real python3)', () }); }); - it('a stopped script\'s reason stays in view ahead of a long stdout', async () => { + it('a stopped script\'s reason comes in the heading, ahead of a long stdout, and once', 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')); + const { return_code: returnCode, stderr } = r.structured as { return_code: number; stderr: string }; + const reason = /^exit code: \d+\n(script stopped: it reached its 1s time limit\. [^\n]*To give it longer, pass time_limit_ms up to 600000 \(10 min\)\.)\n/.exec(text)?.[1]; + assert.ok(reason, text.slice(0, 400)); + assert.ok(text.startsWith(`exit code: ${returnCode}\n${reason}\n--- stderr ---\n`), text.slice(0, 400)); + // Said once: the text's stderr goes without it, and a host still reads + // it at the end of the stderr it gets. + assert.strictEqual(text.split(reason).length, 2, text.slice(0, 400)); + assert.ok(stderr.endsWith(`\n${reason}\n`), stderr.slice(-300)); + assert.ok(text.indexOf('--- stderr ---') < 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\]$/); }); }); diff --git a/test/code-execution.test.ts b/test/code-execution.test.ts index 0039e6a26..c85092fe9 100644 --- a/test/code-execution.test.ts +++ b/test/code-execution.test.ts @@ -5,7 +5,9 @@ * await, tool-function injection, timeout, and deadline behavior are all * exercised end-to-end. Framework tests drive a full agent turn through the * MockMembrane and assert the load-bearing invariant: inner tool results - * reach the running script but never the model-facing tool_result. + * reach the running script but never the model-facing tool_result, except + * the start of an answer that came after its call's code stopped waiting, + * which the result's line quotes. */ import { describe, it } from 'node:test'; @@ -15,19 +17,24 @@ import { chmodSync, closeSync, existsSync, mkdtempSync, openSync, readdirSync, r import { tmpdir } from 'node:os'; import { join } from 'node:path'; import { PassThrough, type Writable } from 'node:stream'; +import { setFlagsFromString } from 'node:v8'; +import { runInNewContext } from 'node:vm'; import type { EventResponse, + ExecResult, Module, ModuleContext, ProcessEvent, ProcessState, + ScriptCalls, ScriptToolResult, ToolCall, ToolDefinition, ToolResult, + UncertainCall, } from '../src/index.js'; import { AgentFramework, PYTHON_RUNTIME_SOURCE, PyRunner, buildInjectedTools } from '../src/index.js'; -import { OutputStream } from '../src/code-execution/py-runner.js'; +import { callBrief, callsLine, OutputStream, scriptStderr } from '../src/code-execution/py-runner.js'; import { createMockResponse, MockMembrane } from './helpers/mock-membrane.js'; import type { ContentBlock } from '@animalabs/membrane'; import { PYTC_STOP_ROWS_DRIVER } from './helpers/pytc-stop-rows.js'; @@ -76,8 +83,8 @@ const exitedUnder = (how: string, background = false, check?: string): string => how === 'was ended by SIGKILL' ? 'by using too much memory' : how.startsWith('was ended by') ? 'with os.kill()' : 'with os._exit()'}` }; if not, ask whoever runs this host.`; -/** The advice's first step after a crash's signal, with faulthandler's traceback above it, and without. */ -const NATIVE_CRASH = 'check the traceback above for the call that crashed in native code, such as an extension module the script uses'; +/** The advice's first step after a crash's signal, with faulthandler's traceback in the output, and without. */ +const NATIVE_CRASH = 'check the traceback that starts "Fatal Python error:" for the call that crashed in native code, such as an extension module the script uses'; const NATIVE_CRASH_UNSEEN = 'check whether native code the script calls crashes, such as an extension module it uses'; /** @@ -90,7 +97,7 @@ const exitedAfterEnd = (how: string, taken?: string, background = false, check?: `script ended, but the Python interpreter ${how} before all of its output reached the host, so some of it may be missing` + `${background ? '' : ', and variables from earlier scripts are gone'}. If it happens again, ` + (taken - ? `check whether the script closes, shuts down or replaces ${taken}, as the runtime's line above says` + ? `check whether the script closes, shuts down or replaces ${taken}, as the runtime's line starting "[pytc-runtime]" says` : check ?? `check whether the script itself ends the process, for example ${ how === 'was ended by SIGKILL' ? 'by using too much memory' : how.startsWith('was ended by') ? 'with os.kill()' : 'with os._exit()'}`) + '; if not, ask whoever runs this host.'; @@ -99,8 +106,8 @@ const exitedAfterEnd = (how: string, taken?: string, background = false, check?: const runtimeLost = (taken: string): string => "script stopped: the Python interpreter exited with code 70 while it ran, so the rest of the script didn't run, and variables " + 'from earlier scripts are gone. Tool calls it had already made keep their effects, so check them before you run it again in ' - + `a new interpreter. If it stops the same way, check whether the script closes, shuts down or replaces ${taken}, as the runtime's line above ` - + 'says; if not, ask whoever runs this host.'; + + `a new interpreter. If it stops the same way, check whether the script closes, shuts down or replaces ${taken}, as the runtime's line starting ` + + '"[pytc-runtime]" says; if not, ask whoever runs this host.'; describe('buildInjectedTools', () => { it('sanitizes -- to __ and keeps valid identifiers', () => { @@ -312,6 +319,7 @@ describe('PyRunner (real python3)', () => { // A JS handler can resolve with what its type rules out; the call is // still answered, as before this change. if (args.kind === 'nothing') return undefined as unknown as string; + if (args.kind === 'null') return null as unknown as string; return results[String(args.kind)]!; }, }); @@ -320,7 +328,7 @@ describe('PyRunner (real python3)', () => { [ 'import copy, json, pickle', 'out = {}', - 'for kind in ["failed", "textlike", "structured", "oversized", "plain", "rejects", "jsonlike", "nothing"]:', + 'for kind in ["failed", "textlike", "structured", "oversized", "plain", "rejects", "jsonlike", "nothing", "null"]:', ' r = await test__echo({"kind": kind})', ' out[kind] = {"text": str(r), "is_error": r.is_error, "structured": r.structured,', ' "type": type(r).__name__, "is_str": isinstance(r, str)}', @@ -355,6 +363,9 @@ describe('PyRunner (real python3)', () => { assert.deepStrictEqual(out.copies, [[false, { rows: [1, 2] }, true], [false, { rows: [1, 2] }, true]]); assert.deepStrictEqual(out.jsonlike, seen('{"structuredContent": {"a": 1}}', false, null)); assert.deepStrictEqual(out.nothing, seen('', null, null)); + // null isn't a result object either: the reply sends it as it is, which + // the runtime makes the text Python gives it. + assert.deepStrictEqual(out.null, seen('None', null, null)); // A refusal shows a key that is a tool's result as its text, the key the // agent has to write, as it shows any str key. assert.match(String(out.refusal), /\{'a string, nothing said': , 'extra': \}/); @@ -466,17 +477,621 @@ describe('PyRunner (real python3)', () => { } }); - it('raises TimeoutError inside the script when a tool call gets no response', async () => { + it('raises TimeoutError inside the script when a tool call gets no response, saying the call may still take effect, and the result names the call', async () => { const runner = new PyRunner({ toolCallTimeoutMs: 1000, - onToolCall: () => new Promise((resolve) => setTimeout(() => resolve('late'), 5000)), + // No answer comes, so the call is still running when the script ends. + onToolCall: () => new Promise(() => {}), }); try { const result = await runner.exec('await test__echo({})', ECHO_TOOLS); assert.strictEqual(result.returnCode, 1); - assert.match(result.stderr, /TimeoutError: Calling tool \['test--echo'\] timed out/); + assert.match(result.stderr, /TimeoutError: Calling tool \['test--echo'\] timed out \(no response after 1s\)\. The call was sent and may still take effect, so check for its effect before calling it again\.\n/); + assert.deepStrictEqual(result.calls, { made: 1, uncertain: [{ tool: 'test--echo', args: '{}', state: 'timed-out-running' }] }); + } finally { + runner.dispose(); + } + }); + + it("a call the script stopped waiting for and that was answered before it ended is named with its answer's start, in the order the calls were made", async () => { + // The second call is what answers the first, so the first's answer + // reaches the host after the runtime's word that the script stopped + // waiting for it. The third is still running when the script ends. + let answerFirst!: (answer: string) => void; + let answerThird: ((answer: string) => void) | undefined; + // Its 120th character is the first half of a surrogate pair, which the cut leaves out. + const firstAnswer = `first answer, ${'y'.repeat(105)}${'\u{1F600}'.repeat(5)}`; + const runner = new PyRunner({ + toolCallTimeoutMs: 1000, + onToolCall: (_name, args) => { + if (args.n === 1) return new Promise((resolve) => { answerFirst = resolve; }); + if (args.n === 3) return new Promise((resolve) => { answerThird = resolve; }); + answerFirst(firstAnswer); + return new Promise((resolve) => setImmediate(() => resolve('second answer'))); + }, + }); + try { + const result = await within(runner.exec([ + 'import asyncio', + 'try:', + ' await test__echo({"n": 1})', + 'except TimeoutError:', + ' pass', + 'print(await test__echo({"n": 2}))', + 'asyncio.ensure_future(test__echo({"n": 3}))', + 'await asyncio.sleep(0.2)', + ].join('\n'), ECHO_TOOLS), 'the script'); + assert.strictEqual(result.returnCode, 0, result.stderr); + assert.strictEqual(result.stdout, 'second answer\n'); + assert.deepStrictEqual(result.calls, { + made: 3, + uncertain: [ + { tool: 'test--echo', args: '{"n":1}', state: 'answered-unseen', answer: `first answer, ${'y'.repeat(105)}\u2026` }, + { tool: 'test--echo', args: '{"n":3}', state: 'running' }, + ], + }); + } finally { + answerThird?.(''); + runner.dispose(); + } + }); + + it('a call answered with an error after its code stopped waiting is named as one, and an answer is the start of the text a script gets', async () => { + // Each answer comes once the script has stopped waiting for its call: the + // last call is what answers the others. The failed one's JSON, as a + // structured result reaches a script, holds isError past the cut. + const failedText = JSON.stringify({ content: [{ type: 'text', text: `rate limited: ${'x'.repeat(150)}` }], structuredContent: null, isError: true }); + const answers: Record = { + failed: { text: failedText, isError: true, structuredJson: true }, + sent: { text: 'Message sent', isError: false }, + plain: 'a plain string', + }; + const held: Array<() => void> = []; + const runner = new PyRunner({ + toolCallTimeoutMs: 1000, + onToolCall: (_name, args) => { + if (args.kind === 'release') { + for (const answer of held.splice(0)) answer(); + return new Promise((resolve) => setImmediate(() => resolve('released'))); + } + return new Promise((resolve, reject) => { + held.push(args.kind === 'rejects' ? () => reject(new Error('handler broke')) : () => resolve(answers[String(args.kind)]!)); + }); + }, + }); + try { + const result = await within(runner.exec([ + 'import asyncio', + 'async def call(kind):', + ' try:', + ' await test__echo({"kind": kind})', + ' except TimeoutError:', + ' pass', + 'await asyncio.gather(*(call(kind) for kind in ["failed", "sent", "plain", "rejects"]))', + 'print(await test__echo({"kind": "release"}))', + ].join('\n'), ECHO_TOOLS), 'the script'); + assert.strictEqual(result.returnCode, 0, result.stderr); + assert.strictEqual(result.stdout, 'released\n'); + assert.deepStrictEqual(result.calls, { + made: 5, + uncertain: [ + { tool: 'test--echo', args: '{"kind":"failed"}', state: 'answered-unseen', answer: `${failedText.slice(0, 120)}\u2026`, isError: true }, + { tool: 'test--echo', args: '{"kind":"sent"}', state: 'answered-unseen', answer: 'Message sent' }, + { tool: 'test--echo', args: '{"kind":"plain"}', state: 'answered-unseen', answer: 'a plain string' }, + { tool: 'test--echo', args: '{"kind":"rejects"}', state: 'answered-unseen', answer: 'Error: handler broke', isError: true }, + ], + }); + const lines = callsLine(result)!.split('\n'); + assert.strictEqual(lines[1], `- answered with an error after its code stopped waiting: test--echo {"kind":"failed"}, answer ${JSON.stringify(`${failedText.slice(0, 120)}\u2026`)}`); + assert.strictEqual(lines[2], '- answered after its code stopped waiting: test--echo {"kind":"sent"}, answer "Message sent"'); + } finally { + for (const answer of held.splice(0)) answer(); + runner.dispose(); + } + }); + + it('a call the script stops waiting for with a shorter wait_for of its own is named with its answer, beside the retry', async () => { + // The retry is what answers the first call, so that answer comes after + // the runtime's word that the script cancelled it. + let answerFirst!: (answer: string) => void; + const runner = new PyRunner({ + onToolCall: (_name, args) => { + if (args.n === 1) return new Promise((resolve) => { answerFirst = resolve; }); + answerFirst('sent message 41'); + return new Promise((resolve) => setImmediate(() => resolve('sent message 42'))); + }, + }); + try { + const result = await within(runner.exec([ + 'import asyncio', + 'try:', + ' await asyncio.wait_for(test__echo({"n": 1}), 0.3)', + 'except asyncio.TimeoutError:', + ' pass', + 'print(await test__echo({"n": 2}))', + ].join('\n'), ECHO_TOOLS), 'the script'); + assert.strictEqual(result.returnCode, 0, result.stderr); + assert.strictEqual(result.stdout, 'sent message 42\n'); + assert.deepStrictEqual(result.calls, { + made: 2, + uncertain: [{ tool: 'test--echo', args: '{"n":1}', state: 'answered-unseen', answer: 'sent message 41' }], + }); + } finally { + runner.dispose(); + } + }); + + it('a call the script cancels and that is still running when it ends is named as cancelled in the script', async () => { + const runner = new PyRunner({ onToolCall: () => new Promise(() => {}) }); + try { + const result = await within(runner.exec([ + 'import asyncio, __main__', + 't = asyncio.ensure_future(test__echo({"n": 1}))', + 'while not __main__._pending_tool_futures:', + ' await asyncio.sleep(0.01)', + 't.cancel()', + 'try:', + ' await t', + 'except asyncio.CancelledError:', + ' pass', + ].join('\n'), ECHO_TOOLS), 'the script'); + assert.strictEqual(result.returnCode, 0, result.stderr); + assert.deepStrictEqual(result.calls, { + made: 1, + uncertain: [{ tool: 'test--echo', args: '{"n":1}', state: 'cancelled-running' }], + }); + } finally { + runner.dispose(); + } + }); + + it("calls a host's stop cuts off, and those the runtime cancels at a script's end, read as still running, with no word that the script stopped waiting", async () => { + const runner = new PyRunner({ onToolCall: () => new Promise(() => {}) }); + const internals = runner as unknown as { handleLine(line: string, child: ChildProcess, interpreter: number): void }; + const handle = internals.handleLine.bind(runner); + const ops: string[] = []; + internals.handleLine = (line, child, interpreter) => { + try { ops.push(String((JSON.parse(line) as { op?: unknown }).op)); } catch { /* not the protocol's */ } + handle(line, child, interpreter); + }; + try { + // One call the script awaits, which the time limit's stop cuts off, and + // one a task it started has pending when the script ends. The awaited + // call runs at once, and the task's at the loop's next turn. + const result = await within(runner.exec([ + 'import asyncio', + 'asyncio.ensure_future(test__echo({"n": "left"}))', + 'await test__echo({"n": "awaited"})', + ].join('\n'), ECHO_TOOLS, undefined, { deadlineMs: 1000 }), 'the script'); + assert.match(result.runnerNote ?? '', /^script stopped: it reached its 1s time limit\./); + assert.deepStrictEqual(result.calls, { + made: 2, + uncertain: [ + { tool: 'test--echo', args: '{"n":"awaited"}', state: 'running' }, + { tool: 'test--echo', args: '{"n":"left"}', state: 'running' }, + ], + }); + await new Promise((resolve) => setTimeout(resolve, 200)); + assert.ok(!ops.includes('tool_unwaited'), ops.join(', ')); + } finally { + runner.dispose(); + } + }); + + it("a call answered while the script held its event loop past the call's timeout is named with that answer when the script got a TimeoutError", async () => { + const dir = mkdtempSync(join(tmpdir(), 'pytc-held-')); + const holding = join(dir, 'holding'); + const answered = join(dir, 'answered'); + const runner = new PyRunner({ + toolCallTimeoutMs: 1000, + // The answer goes once the script holds its loop, and its mark after it has gone. + onToolCall: async () => { + await until(() => existsSync(holding), 'the script to hold its loop'); + setImmediate(() => writeFileSync(answered, '')); + return 'answered while the loop was held'; + }, + }); + try { + const result = await within(runner.exec([ + 'import asyncio, os, sys, time', + 't = asyncio.ensure_future(test__echo({"n": 1}))', + 'await asyncio.sleep(0)', + `open(${JSON.stringify(holding)}, "w").close()`, + 'start = time.monotonic()', + // Held until the answer has gone, and past the call's 1 s timeout. + `while not os.path.exists(${JSON.stringify(answered)}) or time.monotonic() - start < 1.5:`, + ' time.sleep(0.01)', + 'try:', + ' await t', + ' print("saw the answer")', + 'except TimeoutError:', + ' print("timed out")', + 'print(sys.version_info >= (3, 12))', + ].join('\n'), ECHO_TOOLS), 'the script'); + assert.strictEqual(result.returnCode, 0, result.stderr); + const timedOut = result.stdout.startsWith('timed out\n'); + // From Python 3.12, the timeout fires before the answer queued behind it is read. + if (result.stdout.endsWith('True\n')) assert.ok(timedOut, result.stdout); + // Either way, the result says what the script saw. + assert.deepStrictEqual(result.calls, { + made: 1, + uncertain: timedOut + ? [{ tool: 'test--echo', args: '{"n":1}', state: 'answered-unseen', answer: 'answered while the loop was held' }] + : [], + }); + } finally { + runner.dispose(); + rmSync(dir, { recursive: true, force: true }); + } + }); + + it("a call from a task an earlier script left running is named in the result of the script running when it's made, and one made while none runs in the next script's", async () => { + const dir = mkdtempSync(join(tmpdir(), 'pytc-left-')); + const between = join(dir, 'between-scripts'); + const started = join(dir, 'second-started'); + let sawBetween!: () => void; + const madeBetween = new Promise((resolve) => { sawBetween = resolve; }); + const runner = new PyRunner({ + // Only the first call between the scripts is answered, so the others are + // still running when the second script ends. + onToolCall: (_name, args) => { + if (args.when === 'answered between scripts') return Promise.resolve('ok'); + if (args.when === 'between scripts') sawBetween(); + return new Promise(() => {}); + }, + }); + try { + // The first script leaves a task that calls a tool twice once the host + // has the first script's result, and again once the second has started. + const first = await within(runner.exec([ + 'import asyncio, os, __main__', + 'async def later():', + ' global answered', + ` while not os.path.exists(${JSON.stringify(between)}):`, + ' await asyncio.sleep(0.01)', + ' await test__echo({"when": "answered between scripts"})', + ' answered = "t" + str(__main__._next_tool_call_id)', + ' asyncio.ensure_future(test__echo({"when": "between scripts"}))', + ` while not os.path.exists(${JSON.stringify(started)}):`, + ' await asyncio.sleep(0.01)', + ' asyncio.ensure_future(test__echo({"when": "during the second"}))', + 'left = asyncio.ensure_future(later())', + ].join('\n'), ECHO_TOOLS), 'the first script'); + assert.strictEqual(first.calls, undefined); + writeFileSync(between, ''); + await within(madeBetween, 'the call made between scripts'); + const second = await within(runner.exec([ + 'import asyncio, __main__', + // Word, once the second script has started, that the code waiting for + // the call answered between the scripts had stopped waiting, as a held + // loop brings it: that call's answer went unseen after all. + '__main__.send({"op": "tool_unwaited", "id": answered, "cause": "timeout"})', + `open(${JSON.stringify(started)}, "w").close()`, + // The runtime keeps each call's future just before it sends the call. + 'while len(__main__._pending_tool_futures) < 2:', + ' await asyncio.sleep(0.01)', + ].join('\n'), ECHO_TOOLS), 'the second script'); + assert.strictEqual(second.returnCode, 0, second.stderr); + assert.deepStrictEqual(second.calls, { + made: 1, + before: 2, + uncertain: [ + { tool: 'test--echo', args: '{"when":"answered between scripts"}', state: 'answered-unseen', answer: 'ok' }, + { tool: 'test--echo', args: '{"when":"between scripts"}', state: 'running' }, + { tool: 'test--echo', args: '{"when":"during the second"}', state: 'running' }, + ], + }); + } finally { + runner.dispose(); + rmSync(dir, { recursive: true, force: true }); + } + }); + + it("a call taken on from an interpreter that has gone is kept apart from the next interpreter's, whose call ids start again", async () => { + let answerLeftover!: (text: string) => void; + let sawLeftover!: () => void; + const leftoverMade = new Promise((resolve) => { sawLeftover = resolve; }); + const dir = mkdtempSync(join(tmpdir(), 'pytc-reclaim-')); + const between = join(dir, 'between-scripts'); + const filed = join(dir, 'leftover-answer-filed'); + const runner = new PyRunner({ + // Off, so the test reclaims the interpreter itself once the leftover's + // call is in, as the idle timer does, rather than racing a timer. + idleReclaimMs: 0, + onToolCall: (_name, args) => { + if (args.who === 'leftover') { + sawLeftover(); + return new Promise((resolve) => { answerLeftover = resolve; }); + } + // The leftover's answer comes once the second interpreter's own first + // call is in, and the second script ends only once the host has filed + // it, which the answer's microtasks do before setImmediate's turn. + answerLeftover('the leftover\'s answer'); + setImmediate(() => writeFileSync(filed, '')); + return new Promise(() => {}); + }, + }); + const internals = runner as unknown as { child: ChildProcess | null; reclaim(reason: string): void }; + try { + // The first script leaves a task whose call, its interpreter's first, is + // made once the host has the script's result. + await within(runner.exec([ + 'import asyncio, os', + 'async def later():', + ` while not os.path.exists(${JSON.stringify(between)}):`, + ' await asyncio.sleep(0.01)', + ' await test__echo({"who": "leftover"})', + 'left = asyncio.ensure_future(later())', + ].join('\n'), ECHO_TOOLS), 'the first script'); + writeFileSync(between, ''); + await within(leftoverMade, 'the leftover call'); + internals.reclaim('idle'); + assert.strictEqual(internals.child, null); + // In a new interpreter, whose first call has the same id as the leftover's. + const second = await within(runner.exec([ + 'import asyncio, os', + 't = asyncio.ensure_future(test__echo({"who": "the second script"}))', + `while not os.path.exists(${JSON.stringify(filed)}):`, + ' await asyncio.sleep(0.01)', + ].join('\n'), ECHO_TOOLS), 'the second script'); + assert.strictEqual(second.returnCode, 0, second.stderr); + // The leftover's answer came once its interpreter had gone, so its code never saw it. + assert.deepStrictEqual(second.calls, { + made: 1, + before: 1, + uncertain: [ + { tool: 'test--echo', args: '{"who":"leftover"}', state: 'answered-unseen', answer: "the leftover's answer" }, + { tool: 'test--echo', args: '{"who":"the second script"}', state: 'running' }, + ], + }); } finally { runner.dispose(); + rmSync(dir, { recursive: true, force: true }); + } + }); + + it('an answer that comes once the interpreter that made the call has exited, before its script settles, is named as unseen', async () => { + let answer!: (text: string) => void; + let sawCall!: () => void; + const made = new Promise((resolve) => { sawCall = resolve; }); + const runner = new PyRunner({ + onToolCall: () => { + sawCall(); + return new Promise((resolve) => { answer = resolve; }); + }, + }); + const internals = runner as unknown as { child: ChildProcess | null }; + let command = 0; + try { + // A command holding the output pipes keeps the host waiting for them + // after the interpreter exits, so its script settles only later. + const running = runner.exec([ + 'import asyncio, os, subprocess, __main__', + 'print(subprocess.Popen(["sleep", "30"]).pid, flush=True)', + 't = asyncio.ensure_future(test__echo({"x": 1}))', + 'while not __main__._pending_tool_futures:', + ' await asyncio.sleep(0.01)', + 'os._exit(3)', + ].join('\n'), ECHO_TOOLS); + await within(made, 'the call'); + const child = internals.child!; + await within(new Promise((resolve) => { + if (child.exitCode !== null) resolve(); + else child.once('exit', () => resolve()); + }), 'the exit'); + answer('late answer'); + const result = await within(running, 'the script to settle'); + command = Number(result.stdout.trim()); + assert.deepStrictEqual(result.calls, { + made: 1, + uncertain: [{ tool: 'test--echo', args: '{"x":1}', state: 'answered-unseen', answer: 'late answer' }], + }); + } finally { + if (command && alive(command)) process.kill(command, 'SIGKILL'); + runner.dispose(); + } + }); + + it('a call made while no script runs, whose code stops waiting and whose answer then comes, is taken on by the next script', async () => { + const dir = mkdtempSync(join(tmpdir(), 'pytc-gap-')); + const between = join(dir, 'between-scripts'); + let answer!: (text: string) => void; + let sawCall!: () => void; + const made = new Promise((resolve) => { sawCall = resolve; }); + const runner = new PyRunner({ + onToolCall: () => { + sawCall(); + return new Promise((resolve) => { answer = resolve; }); + }, + }); + try { + // The first script leaves a task that calls a tool once the host has the + // first script's result, then sends the runtime's own word that it + // stopped waiting (runtime-py.ts tool_fn), as its timeout would. + await within(runner.exec([ + 'import asyncio, os, __main__', + 'async def later():', + ` while not os.path.exists(${JSON.stringify(between)}):`, + ' await asyncio.sleep(0.01)', + ' t = asyncio.ensure_future(test__echo({"when": "between scripts"}))', + ' while not __main__._pending_tool_futures:', + ' await asyncio.sleep(0.01)', + ' __main__.send({"op": "tool_unwaited", "id": "t" + str(__main__._next_tool_call_id), "cause": "timeout"})', + 'left = asyncio.ensure_future(later())', + ].join('\n'), ECHO_TOOLS), 'the first script'); + writeFileSync(between, ''); + await within(made, 'the call made between scripts'); + // Once the host has read that word, in its record of calls made while no + // script runs, the answer comes. + const internals = runner as unknown as { loose: { open: Map } }; + await until(() => [...internals.loose.open.values()].some((call) => call.unwaited !== null), 'the word that its code stopped waiting'); + answer('answered while no script ran'); + await new Promise((resolve) => setImmediate(resolve)); + const second = await within(runner.exec('pass', ECHO_TOOLS), 'the second script'); + assert.deepStrictEqual(second.calls, { + made: 0, + before: 1, + uncertain: [{ tool: 'test--echo', args: '{"when":"between scripts"}', state: 'answered-unseen', answer: 'answered while no script ran' }], + }); + } finally { + runner.dispose(); + rmSync(dir, { recursive: true, force: true }); + } + }); + + it('a call from a thread the script started, through run_coroutine_threadsafe, is named in its result', async () => { + // The answer never comes, so the call is still running when the script ends. + const runner = new PyRunner({ onToolCall: () => new Promise(() => {}) }); + try { + const result = await within(runner.exec([ + 'import asyncio, threading, __main__', + 'loop = asyncio.get_running_loop()', + 'def in_thread():', + ' try:', + ' asyncio.run_coroutine_threadsafe(test__echo({"from": "a thread"}), loop).result()', + ' except BaseException:', + ' pass', + 'threading.Thread(target=in_thread, daemon=True).start()', + // The runtime keeps the call's future just before it sends the call. + 'while not __main__._pending_tool_futures:', + ' await asyncio.sleep(0.01)', + ].join('\n'), ECHO_TOOLS), 'the script'); + assert.strictEqual(result.returnCode, 0, result.stderr); + assert.deepStrictEqual(result.calls, { + made: 1, + uncertain: [{ tool: 'test--echo', args: '{"from":"a thread"}', state: 'running' }], + }); + } finally { + runner.dispose(); + } + }); + + it("the host's record of a script's calls closes when it reads the script's end: a later answer leaves its call running, and a later call goes to the next script's", async () => { + const answers = new Map void>(); + const runner = new PyRunner({ + onToolCall: (_name, args) => new Promise((resolve) => { answers.set(String(args.when), resolve); }), + }); + const internals = runner as unknown as { + settleIfComplete(child: ChildProcess): void; + handleLine(line: string, child: ChildProcess, interpreter: number): void; + interpreterNumber: number; + pending: { returnCode: number | null } | null; + }; + const settle = internals.settleIfComplete.bind(runner); + let held = false; + // Once the host has read the script's end, before it settles: the call's + // answer comes, and another call arrives. + internals.settleIfComplete = (child) => { + if (held || internals.pending?.returnCode == null) { + settle(child); + return; + } + held = true; + answers.get('during')!('answered after the end'); + internals.handleLine(JSON.stringify({ op: 'tool_call', id: 't9999', exec_id: null, name: 'test--echo', args: { when: 'after the end' } }), child, internals.interpreterNumber); + setTimeout(() => settle(child), 50); + }; + try { + const first = await within(runner.exec([ + 'import asyncio, __main__', + 't = asyncio.ensure_future(test__echo({"when": "during"}))', + 'while not __main__._pending_tool_futures:', + ' await asyncio.sleep(0.01)', + ].join('\n'), ECHO_TOOLS), 'the first script'); + assert.ok(held); + assert.deepStrictEqual(first.calls, { made: 1, uncertain: [{ tool: 'test--echo', args: '{"when":"during"}', state: 'running' }] }); + const second = await within(runner.exec('pass', ECHO_TOOLS), 'the second script'); + assert.deepStrictEqual(second.calls, { + made: 0, + before: 1, + uncertain: [{ tool: 'test--echo', args: '{"when":"after the end"}', state: 'running' }], + }); + } finally { + runner.dispose(); + } + }); + + it('an exec lists the first 1,000 calls answered after its script stopped waiting for them, and counts the rest by tool', async () => { + const held: Array<(answer: string) => void> = []; + const runner = new PyRunner({ + onToolCall: (_name, args) => { + if (!args.go) return new Promise((resolve) => { held.push(resolve); }); + // The script's word that it stopped waiting for each has come first, as it was sent first. + for (const answer of held.splice(0)) answer('late'); + return Promise.resolve('go'); + }, + }); + try { + // The script sends the runtime's own word itself (runtime-py.ts tool_fn) + // for 1,001 calls still waiting for their answers. + const result = await within(runner.exec([ + 'import asyncio, __main__', + 'first = __main__._next_tool_call_id + 1', + 'waiting = [asyncio.ensure_future(test__echo({"n": i})) for i in range(1001)]', + 'await asyncio.sleep(0)', + 'for i in range(first, first + 1001):', + ' __main__.send({"op": "tool_unwaited", "id": "t" + str(i), "cause": "timeout"})', + 'await test__echo({"go": True})', + // And word for one answered while the script waited, once the list is full. + '__main__.send({"op": "tool_unwaited", "id": "t" + str(__main__._next_tool_call_id), "cause": "timeout"})', + ].join('\n'), ECHO_TOOLS), 'the script'); + assert.strictEqual(result.returnCode, 0, result.stderr); + const calls = result.calls!; + assert.strictEqual(calls.made, 1002); + assert.strictEqual(calls.uncertain.length, 1000); + assert.deepStrictEqual(calls.uncertain[999], { tool: 'test--echo', args: '{"n":999}', state: 'answered-unseen', answer: 'late' }); + assert.deepStrictEqual(calls.unlisted, { 'test--echo': 2 }); + const lines = callsLine(result)!.split('\n'); + assert.strictEqual(lines[0], 'tool calls: 1002 made while the script ran, 0 answered while it waited; the other 1002:'); + assert.strictEqual(lines.at(-1), '- and 992 more: test--echo \u00d7992'); + } finally { + runner.dispose(); + } + }); + + it('an exec keeps the last 1,000 calls answered while its script waited, so word that the script stopped waiting for an older one finds it answered', async () => { + const runner = new PyRunner({ onToolCall: async () => 'ok' }); + try { + // The script sends the runtime's own word itself (runtime-py.ts tool_fn), + // after 1,001 answers, which put the first out of what the exec keeps. + const result = await within(runner.exec([ + 'import asyncio, __main__', + 'await test__echo({"n": 0})', + 'first = "t" + str(__main__._next_tool_call_id)', + 'await test__echo({"n": 1})', + 'second = "t" + str(__main__._next_tool_call_id)', + 'await asyncio.gather(*(test__echo({"n": i}) for i in range(2, 1001)))', + '__main__.send({"op": "tool_unwaited", "id": first, "cause": "timeout"})', + '__main__.send({"op": "tool_unwaited", "id": second, "cause": "timeout"})', + // A round trip after them, so both have reached the host before the end. + 'await test__echo({"n": "last"})', + ].join('\n'), ECHO_TOOLS), 'the script'); + assert.strictEqual(result.returnCode, 0, result.stderr); + assert.deepStrictEqual(result.calls, { + made: 1002, + uncertain: [{ tool: 'test--echo', args: '{"n":1}', state: 'answered-unseen', answer: 'ok' }], + }); + } finally { + runner.dispose(); + } + }); + + it('a call is named by its arguments as JSON, cut to 120 characters with each string cut first, never inside a surrogate pair', async () => { + let answer: ((answer: string) => void) | undefined; + const runner = new PyRunner({ onToolCall: () => new Promise((resolve) => { answer = resolve; }) }); + try { + // '{"text":"' and 110 x's take 119 characters, so the cut at 120 falls inside the first pair. + const pending = runner.exec('await test__echo({"text": "x" * 110 + "\\U0001F600" * 5 + "z" * 1_000_000})', ECHO_TOOLS); + await until(() => answer !== undefined, 'the call'); + runner.abort('the test is done with it'); + const result = await pending; + assert.deepStrictEqual(result.calls, { + made: 1, + uncertain: [{ tool: 'test--echo', args: `{"text":"${'x'.repeat(110)}\u2026`, state: 'running' }], + }); + } finally { + answer?.(''); + runner.dispose(); } }); @@ -491,6 +1106,10 @@ describe('PyRunner (real python3)', () => { assert.strictEqual(result.returnCode, 1); assert.match(result.stderr, /cancelled by host/); assert.ok(Date.now() - started < 15_000, 'deadline cancel took too long'); + // The runner's note on the limit ends the result, and it alone is the runner's. + assert.match(result.runnerNote ?? '', /^script stopped: it reached its 1s time limit\. [^\n]*$/); + assert.ok(result.stderr.endsWith(`\n${result.runnerNote}\n`), result.stderr); + assert.strictEqual(result.aborted, undefined); } finally { runner.dispose(); } @@ -523,6 +1142,8 @@ describe('PyRunner (real python3)', () => { const result = await pending; assert.strictEqual(result.aborted, true); assert.match(result.stderr, /aborted by host: test abort/); + assert.strictEqual(result.runnerNote, 'script aborted by host: test abort'); + assert.deepStrictEqual(result.calls, { made: 1, uncertain: [] }); // Runner remains usable after reclaim, in a fresh interpreter: the // aborted script's state is gone. const after = await runner.exec('try:\n marker\n print("kept")\nexcept NameError:\n print("fresh")', []); @@ -542,6 +1163,8 @@ describe('PyRunner (real python3)', () => { assert.strictEqual(second.returnCode, 1); assert.strictEqual(second.stderr, "script didn't run: another code_execution script of yours is already running, and they run one at a time. " + 'Run this one again once that one has finished, or combine the two into one script.'); + assert.strictEqual(second.runnerNote, second.stderr); + assert.strictEqual(second.calls, undefined); runner.abort('cleanup'); await first; } finally { @@ -582,6 +1205,12 @@ describe('PyRunner (real python3)', () => { assert.strictEqual(result.returnCode, 1); assert.strictEqual(result.stderr, "script didn't run: this host can't start its Python interpreter, /definitely/not/a/python (ENOENT), " + "so code_execution can't run scripts here until whoever runs this host installs it or points this host at one. Calling it again before then fails the same way."); + assert.strictEqual(result.runnerNote, result.stderr); + // The runner disposed, a script given to it doesn't run either, and says why. + runner.dispose(); + assert.deepStrictEqual(await runner.exec('print(1)', []), { + stdout: '', stderr: 'code_execution runner disposed', returnCode: 1, aborted: true, runnerNote: 'code_execution runner disposed', + }); } finally { runner.dispose(); } @@ -4483,6 +5112,7 @@ describe('PyRunner background mode (real python3)', () => { assert.strictEqual(result.returnCode, 1, result.tail ?? ''); const note = 'script stopped: it reached its 2s time limit. Tool calls it had already made keep their effects, so check them before running it again.\n'; assert.strictEqual(result.tail, `watching\n\nKeyboardInterrupt: script cancelled by host\n${note}`); + assert.strictEqual(result.runnerNote, note.trimEnd()); assert.strictEqual(readFileSync(logPath, 'utf8'), result.tail); } finally { runner.dispose(); @@ -4509,6 +5139,9 @@ describe('PyRunner background mode (real python3)', () => { const result = await within(runner.exec(code, [], { logPath: null, lifetimeMs: 30_000, onWake: async () => null }), what); assert.strictEqual(result.aborted, true, what); assert.match(result.tail ?? '', says, what); + // The runner's line on the exit ends the journal's tail, and is its own. + assert.strictEqual(result.runnerNote, result.stderr, what); + assert.ok(result.tail?.endsWith(`${result.runnerNote}\n`), what); } finally { runner.dispose(); } @@ -5310,6 +5943,8 @@ describe('code_execution per-call time limit (time_limit_ms)', () => { await withFramework({ scriptTimeoutMs: 300_000, maxScriptTimeoutMs: 1_800_000 }, async (framework) => { const tool = framework.getAllTools().find((t) => t.name === 'code_execution')!; assert.match(tool.description, /A foreground script is stopped after 5 min; pass time_limit_ms to set this call's limit \(at most 30 min; a background script runs up to 24 h\)/); + assert.match(tool.description, /raises TimeoutError inside the script, though the call was sent and may still take effect\. /); + assert.match(tool.description, /Only how the script ended, what it and the commands it runs print \(stdout and stderr\), and a line naming the tool calls that timed out or were cancelled in it, or were still running when it ended, come back to you; other tool results stay in the script, so filter or aggregate large data there and print only what you need\. Interpreter state /); const props = (tool.inputSchema as { properties: Record }).properties; assert.match(props.time_limit_ms.description, /Default 300000, at most 1800000/); }); @@ -5720,8 +6355,255 @@ describe('code_execution time limit vs blocking code (real python3)', { skip: pr + 'if not, ask whoever runs this host.\n' + 'script stopped: it reached its 1s time limit. Tool calls it had already made keep their effects, so check them before running it again.\n', ); + // Both lines are the runner's own. + assert.strictEqual(result.runnerNote, result.stderr.trimEnd()); } finally { runner.dispose(); } }); }); + +describe("callsLine: what a script's result says of its tool calls", () => { + const ended = (calls: ScriptCalls, how: Partial = {}): ExecResult => ({ stdout: '', stderr: '', returnCode: 0, calls, ...how }); + const running = (i: number, tool = 'a--b'): UncertainCall => ({ tool, args: `{"i":${i}}`, state: 'running' }); + const STILL_RUNNING = '- still running when the script ended, so it may still take effect:'; + + it('says nothing of a script that ended on its own with every call answered, or that made none', () => { + assert.strictEqual(callsLine(ended({ made: 3, uncertain: [] })), null); + assert.strictEqual(callsLine(ended({ made: 0, uncertain: [] }, { aborted: true, returnCode: 1 })), null); + assert.strictEqual(callsLine({ stdout: '', stderr: '', returnCode: 1, aborted: true }), null); + }); + + it('after an error or a stop, counts the calls even when the script saw every answer', () => { + assert.strictEqual(callsLine(ended({ made: 1, uncertain: [] }, { returnCode: 1 })), 'tool calls: 1 made while the script ran, answered while it waited.'); + assert.strictEqual(callsLine(ended({ made: 5, uncertain: [] }, { aborted: true, returnCode: 1 })), 'tool calls: 5 made while the script ran, all answered while it waited.'); + // A stop after the script had reported 0 still counts them. + assert.strictEqual(callsLine(ended({ made: 2, uncertain: [] }, { aborted: true, returnCode: 0 })), 'tool calls: 2 made while the script ran, all answered while it waited.'); + }); + + it("names each call whose answer the script didn't see, by how it stood, after a clean finish too", () => { + assert.strictEqual(callsLine(ended({ made: 6, uncertain: [ + { tool: 'x--send', args: '{"to":"a"}', state: 'running' }, + { tool: 'x--write', args: '{"p":"b"}', state: 'timed-out-running' }, + { tool: 'x--send', args: '{"to":"c"}', state: 'answered-unseen', answer: 'sent "c"\nok' }, + { tool: 'x--send', args: '{"to":"d"}', state: 'answered-unseen', answer: '{"content":[{"type":"text","text":"rate…', isError: true }, + { tool: 'x--write', args: '{"p":"e"}', state: 'cancelled-running' }, + ] })), [ + 'tool calls: 6 made while the script ran, 1 answered while it waited; the other 5:', + `${STILL_RUNNING} x--send {"to":"a"}`, + '- timed out in the script and still running, so it may still take effect: x--write {"p":"b"}', + '- answered after its code stopped waiting: x--send {"to":"c"}, answer "sent \\"c\\"\\nok"', + '- answered with an error after its code stopped waiting: x--send {"to":"d"}, answer "{\\"content\\":[{\\"type\\":\\"text\\",\\"text\\":\\"rate…"', + '- cancelled in the script and still running, so it may still take effect: x--write {"p":"e"}', + ].join('\n')); + assert.strictEqual(callsLine(ended({ made: 1, uncertain: [running(0)] }, { returnCode: 1 })), + `tool calls: 1 made while the script ran, 0 answered while it waited; the other one:\n${STILL_RUNNING} a--b {"i":0}`); + }); + + it('counts apart the calls made before the script started that it took on', () => { + assert.strictEqual(callsLine(ended({ made: 1, before: 1, uncertain: [running(0), running(1)] })), [ + 'tool calls: 1 made while the script ran and 1 before it started, 0 answered while it waited; the other 2:', + `${STILL_RUNNING} a--b {"i":0}`, + `${STILL_RUNNING} a--b {"i":1}`, + ].join('\n')); + assert.strictEqual(callsLine(ended({ made: 2, before: 1, uncertain: [] }, { returnCode: 1 })), + 'tool calls: 2 made while the script ran and 1 before it started, all answered while it waited.'); + assert.strictEqual(callsLine(ended({ made: 0, before: 1, uncertain: [] }, { returnCode: 1 })), + 'tool calls: 0 made while the script ran and 1 before it started, answered while it waited.'); + }); + + it('names ten, and counts the rest by tool, those past what the record lists included', () => { + const uncertain = [...Array(10).keys()].map((i) => running(i)).concat([running(10, 'c--d'), running(11), running(12, 'c--d')]); + const lines = callsLine(ended({ made: 13, uncertain }, { aborted: true, returnCode: 1 }))!.split('\n'); + assert.strictEqual(lines.length, 12); + assert.strictEqual(lines[10], `${STILL_RUNNING} a--b {"i":9}`); + assert.strictEqual(lines[11], '- and 3 more: c--d \u00d72, a--b \u00d71'); + const past = callsLine(ended({ made: 20, uncertain: [running(0)], unlisted: { 'a--b': 2, 'e--f': 3 } }))!.split('\n'); + assert.deepStrictEqual(past, [ + 'tool calls: 20 made while the script ran, 14 answered while it waited; the other 6:', + `${STILL_RUNNING} a--b {"i":0}`, + '- and 5 more: a--b \u00d72, e--f \u00d73', + ]); + }); +}); + +describe("callBrief: what a call's record keeps of its arguments or its answer", () => { + it('keeps a copy of what it shows, so a kept brief holds no long text alive', () => { + setFlagsFromString('--expose-gc'); + const gc = runInNewContext('gc') as () => void; + gc(); + const before = process.memoryUsage().heapUsed; + // Briefs of answers as long as the framework gives a script: a slice of + // each would keep its whole answer, 100 MB for the twenty. + const kept = Array.from({ length: 20 }, (_, i) => callBrief(`${i}:`.padEnd(5_000_000, 'x'))); + gc(); + const grown = process.memoryUsage().heapUsed - before; + assert.ok(grown < 20_000_000, `twenty briefs of 5,000,000-character texts kept ${grown} bytes`); + assert.strictEqual(kept[0], `0:${'x'.repeat(118)}\u2026`); + }); +}); + +describe("scriptStderr: a result's stderr without the runner's own words", () => { + const result = (stderr: string, runnerNote?: string): ExecResult => + ({ stdout: '', stderr, returnCode: 1, ...(runnerNote === undefined ? {} : { aborted: true, runnerNote }) }); + + it('takes off the words that end it, with or without the line end after them', () => { + const why = 'script aborted by host: test abort'; + const note = 'script stopped: it reached its 1s time limit. Tool calls it had already made keep their effects.'; + // As the runner ends stderr: the reason after the script's own line, the time-limit note after both. + assert.strictEqual(scriptStderr(result(`Traceback\nValueError: x\n${why}`, why)), 'Traceback\nValueError: x\n'); + assert.strictEqual(scriptStderr(result(`partial\n${why}\n${note}\n`, `${why}\n${note}`)), 'partial\n'); + assert.strictEqual(scriptStderr(result(`Traceback\n${note}\n`, note)), 'Traceback\n'); + // A script that didn't run wrote nothing. + assert.strictEqual(scriptStderr(result(why, why)), ''); + }); + + it("is the whole stderr when the runner added no words, or the stderr doesn't end with them on a line of their own", () => { + assert.strictEqual(scriptStderr(result('Traceback\n')), 'Traceback\n'); + assert.strictEqual(scriptStderr(result('the script wrote: done', 'done')), 'the script wrote: done'); + assert.strictEqual(scriptStderr(result('something else\n', 'done')), 'something else\n'); + }); +}); + +/** A module whose one tool, hold--wait, answers only once the test releases it, or the module stops. */ +class HoldToolModule implements Module { + readonly name = 'hold'; + readonly calls: ToolCall[] = []; + private readonly answers: Array<(result: ToolResult) => void> = []; + + async start(_ctx: ModuleContext): Promise {} + async stop(): Promise { + this.release(); + } + + getTools(): ToolDefinition[] { + return [{ name: 'wait', description: 'Answers once released.', inputSchema: { type: 'object', properties: { what: { type: 'string' } } } }]; + } + + handleToolCall(call: ToolCall): Promise { + this.calls.push(call); + return new Promise((resolve) => this.answers.push(resolve)); + } + + async onProcess(): Promise { + return {}; + } + + release(): void { + for (const answer of this.answers.splice(0)) answer({ success: true, data: { released: true } }); + } +} + +describe("framework code_execution: the result names the calls a script didn't see answered (real python3)", () => { + const STILL_RUNNING = '- still running when the script ended, so it may still take effect:'; + + async function withHold(body: (framework: AgentFramework, hold: HoldToolModule) => Promise): Promise { + const { tempDir, storePath } = tempStorePath('pytc-calls-'); + const membrane = new MockMembrane(); + // The answer to a background script's wake. + membrane.pushResponse(createMockResponse([{ type: 'text', text: 'noted' }])); + const hold = new HoldToolModule(); + const framework = await AgentFramework.create({ + storePath, + membrane: membrane.asMembrane(), + agents: [{ name: 'prime', model: 'test-model', systemPrompt: 'You are prime.', allowedTools: 'all' }], + modules: [new ScriptToolModule(), hold], + syncIntervalMs: 0, + codeExecution: { enabled: true, wakeMinIntervalMs: 0 }, + }); + try { + // A script's calls come back through the framework's event loop. + framework.start(); + await body(framework, hold); + } finally { + hold.release(); + await framework.stop(); + rmSync(tempDir, { recursive: true, force: true }); + } + } + + const run = (framework: AgentFramework, input: Record) => + framework.executeToolCall({ id: `ce-${Math.random()}`, name: 'code_execution', input, callerAgentName: 'prime' }); + const dataOf = (result: ToolResult) => result.data as Record; + // A foreground script's result: the text the model reads, and the fields a host reads. + const textOf = (result: ToolResult) => (result.data as Array<{ type: string; text: string }>)[0]!.text; + const structuredOf = (result: ToolResult) => result.structured as Record; + + it("a script stopped at its time limit names the calls it left running after the runner's words, ahead of its output, and one that fails counts its calls", async () => { + await withHold(async (framework) => { + const result = await run(framework, { + code: 'import asyncio\nawait test__echo({"message": "a"})\nasyncio.ensure_future(hold__wait({"what": "x"}))\nawait asyncio.sleep(60)', + // Room for both calls before the limit, on a loaded host too. + time_limit_ms: 3000, + }); + const line = `tool calls: 2 made while the script ran, 1 answered while it waited; the other one:\n${STILL_RUNNING} hold--wait {"what":"x"}`; + const stopped = structuredOf(result); + assert.strictEqual(Object.keys(stopped)[0], 'tool_calls', JSON.stringify(stopped)); + assert.strictEqual(stopped.tool_calls, line); + // How it ended comes first: the exit code, the runner's words and the + // line, then stderr without the runner's words, which a host still reads + // at the end of the stderr it gets. + const text = textOf(result); + const note = /^exit code: \d+\n(script stopped: it reached its 3s time limit\. [^\n]*)\n/.exec(text)?.[1]; + assert.ok(note !== undefined, text); + assert.ok(text.startsWith(`exit code: ${stopped.return_code}\n${note}\n${line}\n--- stderr ---\n`), text); + assert.strictEqual(text.split(note).length, 2, text); + assert.ok(String(stopped.stderr).endsWith(`\n${note}\n`), String(stopped.stderr)); + const failedResult = await run(framework, { code: 'await test__echo({"message": "b"})\nraise ValueError("no")' }); + const failed = structuredOf(failedResult); + assert.strictEqual(failed.tool_calls, 'tool calls: 1 made while the script ran, answered while it waited.'); + // A script that fails on its own has no words of the runner's: the line + // follows the exit code, ahead of the traceback. + assert.ok(textOf(failedResult).startsWith(`exit code: 1\n${failed.tool_calls}\n--- stderr ---\nTraceback`), textOf(failedResult)); + }); + }); + + it('a script that finishes on its own says nothing of its calls, unless it left one running', async () => { + await withHold(async (framework) => { + const quietResult = await run(framework, { code: 'print(await test__echo({"message": "c"}))' }); + const quiet = structuredOf(quietResult); + assert.strictEqual(quiet.return_code, 0, String(quiet.stderr)); + assert.ok(!('tool_calls' in quiet), JSON.stringify(quiet)); + assert.ok(!textOf(quietResult).includes('tool calls'), textOf(quietResult)); + const leftResult = await run(framework, { code: 'import asyncio\nasyncio.ensure_future(hold__wait({"what": "y"}))\nawait asyncio.sleep(0.2)' }); + const left = structuredOf(leftResult); + const line = `tool calls: 1 made while the script ran, 0 answered while it waited; the other one:\n${STILL_RUNNING} hold--wait {"what":"y"}`; + assert.strictEqual(left.return_code, 0, String(left.stderr)); + assert.strictEqual(left.tool_calls, line); + assert.ok(textOf(leftResult).startsWith(`exit code: 0\n${line}\n`), textOf(leftResult)); + }); + }); + + it('a background script that dies names the calls it left running in the wake, before its last output', async () => { + await withHold(async (framework) => { + const started = await run(framework, { + code: 'import asyncio\nasyncio.ensure_future(hold__wait({"what": "z"}))\nawait asyncio.sleep(0.2)\nraise ValueError("watcher exploded")', + background: true, + }); + assert.strictEqual(started.success, true, JSON.stringify(started)); + let text = ''; + await until(() => { + const messages = (framework.getAgent('prime')?.getContextManager().queryMessages({}).messages ?? []) as unknown as + Array<{ content: Array<{ text?: string }>; metadata?: { source?: string } }>; + text = messages.find((m) => m.metadata?.source === 'background-script')?.content[0]?.text ?? ''; + return text !== ''; + }, 'the wake'); + assert.ok(text.includes(`(it did not call wake_agent and is no longer watching).\ntool calls: 1 made while the script ran, 0 answered while it waited; the other one:\n${STILL_RUNNING} hold--wait {"what":"z"}\nLast output:\n`), text); + }); + }); + + it("a cancel's result names, first, the calls the cancelled script left running", async () => { + await withHold(async (framework, hold) => { + const started = await run(framework, { + code: 'import asyncio\nasyncio.ensure_future(hold__wait({"what": "w"}))\nawait asyncio.sleep(60)', + background: true, + }); + const scriptId = (started.data as { script_id: string }).script_id; + await until(() => hold.calls.length === 1, 'the call'); + const cancelled = dataOf(await run(framework, { action: 'cancel', script_id: scriptId })); + assert.strictEqual(Object.keys(cancelled)[0], 'tool_calls', JSON.stringify(cancelled)); + assert.strictEqual(cancelled.tool_calls, `tool calls: 1 made while the script ran, 0 answered while it waited; the other one:\n${STILL_RUNNING} hold--wait {"what":"w"}`); + assert.strictEqual(cancelled.status, 'cancelled'); + }); + }); +});