From 064c34b25a62fd4916f88ce7eb5bd14aba4fa7e7 Mon Sep 17 00:00:00 2001 From: Aiden Cline Date: Wed, 1 Jul 2026 11:36:37 -0500 Subject: [PATCH] feat(opencode): capture console output and surface it to the model MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - console.log/warn/error/info/debug are now a real Rune interpreter builtin: a seeded global that formats its args (strings verbatim, objects/arrays as JSON, space-joined) and appends a line to a per-run LogCollector. It is not a tool call (spends no tool-call budget), returns undefined, and any other member throws. Formatting is charged to maxOperations and total captured output is bounded by maxAuditBytes so a logging loop can't exhaust memory. - The collector is shared by reference with parallel interpreter forks (like the operation budget) and lives in execute()'s outer scope, so logs are surfaced on every ExecuteResult path — success, thrown error, and timeout. - ExecuteResult (and its schema) gain a logs field; code mode appends captured logs to the model-facing output as a trailing '[level] message' section on both the success and error paths (withLogs). Logs go to the model only. - Documents console in rune.md; drops the now-satisfied 'not done yet' entry. --- packages/opencode/src/session/code-mode.ts | 18 ++- packages/opencode/src/session/rune/rune.md | 39 +++++-- packages/opencode/src/session/rune/rune.ts | 104 +++++++++++++++++- .../session/code-mode-integration.test.ts | 34 ++++++ .../opencode/test/session/code-mode.test.ts | 12 ++ 5 files changed, 187 insertions(+), 20 deletions(-) diff --git a/packages/opencode/src/session/code-mode.ts b/packages/opencode/src/session/code-mode.ts index 880a4f013a..0f5c459397 100644 --- a/packages/opencode/src/session/code-mode.ts +++ b/packages/opencode/src/session/code-mode.ts @@ -3,7 +3,7 @@ import { asSchema, type Tool as AITool, type JSONSchema7 } from "ai" import type { Tool as MCPToolDef } from "@modelcontextprotocol/sdk/types.js" import { Effect, Schema } from "effect" import { Rune } from "./rune/rune" -import type { ExecutionLimits } from "./rune/rune" +import type { ExecutionLimits, LogEntry } from "./rune/rune" import type { HostTools } from "./rune/tool-runtime" export const CODE_MODE_TOOL = "execute" @@ -544,6 +544,18 @@ export function toEnvelope(result: unknown, seal: AttachmentTable["seal"]): Enve return attachments.length > 0 ? { result: value, attachments } : { result: value } } +/** + * Append captured `console.*` output to the model-facing text as a trailing `Logs:` section, + * so a program's diagnostics ride back alongside its result (and errors). Each line is + * `[level] message`; returns the text unchanged when nothing was logged. This is the sandbox's + * only stdout-like channel — it goes to the model, not the user. + */ +export function withLogs(output: string, logs: ReadonlyArray): string { + if (logs.length === 0) return output + const section = "Logs:\n" + logs.map((entry) => `[${entry.level}] ${entry.message}`).join("\n") + return output.length > 0 ? `${output}\n\n${section}` : section +} + /** Coerce the program's return value to model-facing text without ever failing on shape. */ export function formatValue(value: unknown): string { if (typeof value === "string") return value @@ -800,7 +812,7 @@ export function define( return { title: "execute", metadata: { toolCalls: calls }, - output, + output: withLogs(output, result.logs), ...(attachments && attachments.length > 0 ? { attachments } : {}), } satisfies Tool.ExecuteResult } @@ -812,7 +824,7 @@ export function define( return { title: "execute", metadata: { toolCalls: calls, error: true }, - output: result.error.message + hint, + output: withLogs(result.error.message + hint, result.logs), } satisfies Tool.ExecuteResult }), }), diff --git a/packages/opencode/src/session/rune/rune.md b/packages/opencode/src/session/rune/rune.md index a25dc84f25..f352989099 100644 --- a/packages/opencode/src/session/rune/rune.md +++ b/packages/opencode/src/session/rune/rune.md @@ -31,9 +31,10 @@ implemented throws. errors. ### Result -`{ ok: true, value, toolCalls }` or `{ ok: false, error: { kind, message, location?, -suggestions? }, toolCalls }`. `value` is the program's `return`. Uncaught `throw` -becomes `ok: false`. +`{ ok: true, value, toolCalls, logs }` or `{ ok: false, error: { kind, message, location?, +suggestions? }, toolCalls, logs }`. `value` is the program's `return`. Uncaught `throw` +becomes `ok: false`. `logs` is the captured `console.*` output (see below), present on +every path — including timeout and failure — so logs emitted before a crash survive. ### Limits (`ExecutionLimits`, enforced; defaults) | Limit | Default | Bounds | @@ -53,8 +54,12 @@ not cumulative. (Code mode overrides `maxDataBytes`→10MB, `timeoutMs`→30s.) ## Standard library (allowlist — everything else throws) -- **Globals**: `tools`, `Promise`, `Object`, `Math`, `JSON`, `Number`, `String`, +- **Globals**: `tools`, `console`, `Promise`, `Object`, `Math`, `JSON`, `Number`, `String`, `Boolean`, `Array`, `parseInt`, `parseFloat`, `undefined`. +- **console**: `log`/`warn`/`error`/`info`/`debug`. Each formats its args (strings verbatim, + objects/arrays as JSON, space-joined) and appends a line to `logs`; it returns `undefined`, + is **not** a tool call (spends no tool-call budget), and any other member throws. Formatting + is charged to `maxOperations`, and total captured output is bounded by `maxAuditBytes`. - **String**: case/trim, split, slice/substring/substr, includes/startsWith/endsWith, indexOf/lastIndexOf, replace/replaceAll, repeat, padStart/padEnd, charAt/at, charCodeAt/codePointAt, concat. **String args only.** @@ -76,7 +81,6 @@ not cumulative. (Code mode overrides `maxDataBytes`→10MB, `timeoutMs`→30s.) - **`Date`** — no dates or time. - **`RegExp` / regex literals** — none. `replace`/`split` take plain strings only. - **`Map` / `Set` / `WeakMap` / `WeakSet`** — none. -- **`console`** — no logging/output. - **`Promise`** — only `Promise.all`. No `new Promise`, `race`, `allSettled`, `resolve`, `reject`. - **`new`** — only the `Error` family (`Error`, `TypeError`, `RangeError`, `SyntaxError`, @@ -167,6 +171,25 @@ impossible rather than merely discouraged. The trade-off: a program can no longe bytes to route them into another tool's input; if that need arises it would be an explicit host call (e.g. a `readAttachment(handle)`), not the always-on default. Not implemented yet. +## console output is surfaced to the model as a trailing `Logs:` section + +The sandbox has no stdout, but `console.log`/`warn`/`error`/`info`/`debug` are available (an +interpreter builtin, not a tool). Code mode reads the run's `logs` and, when non-empty, appends +them to the model-facing text as a trailing section — one `[level] message` line each: + +``` + + +Logs: +[log] resolved 3 candidates +[warn] falling back to first match +``` + +This holds on the error path too, so a program's diagnostics ride back with the failure that +followed them. Logs go to the **model only** (not the user) — they are the program's scratch +channel for narrating what it did, distinct from the `return` value (the answer) and returned +`attachments` (media for the model + user). A program that logs nothing gets no section. + ## Path handling — separator-tolerant The flat catalog key is `server_tool`, but the model is never required to guess the @@ -197,9 +220,3 @@ returning real callable paths (e.g. `context7/resolve-library` → suggests branches on `result.error` and retries with a suggestion. (Tool *calls* on a genuinely unknown path still surface as a catchable in-program error via Rune's `UnknownCapability`; only the discovery helpers return soft errors.) - -## Not done yet - -- **`console` capture** — a program has no way to surface `console.log` output. Rune has no - `console` (see "What is missing") and the interpreter is frozen, so buffering log output into - the result envelope is deferred to separate interpreter work rather than faked here. diff --git a/packages/opencode/src/session/rune/rune.ts b/packages/opencode/src/session/rune/rune.ts index 530fa9e49a..414e389ade 100644 --- a/packages/opencode/src/session/rune/rune.ts +++ b/packages/opencode/src/session/rune/rune.ts @@ -57,11 +57,18 @@ export type ExecuteOptions = {}> = { limits?: ExecutionLimits } +/** One captured `console.*` line: the method used and the formatted message. */ +export type LogEntry = { + readonly level: "log" | "warn" | "error" | "info" | "debug" + readonly message: string +} + export type ExecuteResult = | { ok: true value: unknown toolCalls: ReadonlyArray + logs: ReadonlyArray } | { ok: false @@ -72,6 +79,7 @@ export type ExecuteResult = suggestions?: ReadonlyArray } toolCalls: ReadonlyArray + logs: ReadonlyArray } export type RuneOptions = {}> = Omit, "code"> @@ -91,6 +99,7 @@ export const ExecuteResultSchema = Schema.Union([ ok: Schema.Literal(true), value: Schema.Unknown, toolCalls: Schema.Array(Schema.Struct({ name: Schema.String })), + logs: Schema.Array(Schema.Struct({ level: Schema.String, message: Schema.String })), }), Schema.Struct({ ok: Schema.Literal(false), @@ -101,6 +110,7 @@ export const ExecuteResultSchema = Schema.Union([ suggestions: Schema.optional(Schema.Array(Schema.String)), }), toolCalls: Schema.Array(Schema.Struct({ name: Schema.String })), + logs: Schema.Array(Schema.Struct({ level: Schema.String, message: Schema.String })), }), ]) @@ -203,6 +213,56 @@ class CoercionFunction { constructor(readonly name: "Number" | "String" | "Boolean" | "parseInt" | "parseFloat") {} } +// The `console` builtin. `console.` resolves to a ConsoleMethodReference; calling it +// formats its arguments and appends a line to the run's shared LogCollector. Logging is a pure +// side effect on the host — it never dispatches a tool, spends the tool-call budget, or returns +// a value the program can branch on (every method returns undefined, like JS `console`). +class ConsoleReference {} + +const consoleLevels = new Set(["log", "warn", "error", "info", "debug"] as const) + +class ConsoleMethodReference { + constructor(readonly level: LogEntry["level"]) {} +} + +/** + * Collects `console.*` output for one execution. Shared by reference across parallel + * interpreter forks (like the operation budget), so logs emitted inside `Promise.all` + * / `.map` callbacks are captured too. Bounded by a total character budget — once spent, + * further lines are dropped (the last accepted line is truncated to fit) so a logging loop + * can't grow memory without also spending the operation budget. + */ +class LogCollector { + readonly entries: LogEntry[] = [] + private used = 0 + constructor(private readonly maxChars: number) {} + push(level: LogEntry["level"], message: string): void { + if (this.used >= this.maxChars) return + const remaining = this.maxChars - this.used + const text = message.length > remaining ? message.slice(0, remaining) : message + this.used += text.length + this.entries.push({ level, message: text }) + } +} + +/** Format one `console.*` argument the way `console` roughly does: strings verbatim, + * objects/arrays as JSON, opaque runtime references as a placeholder (never leaking their + * internals), everything else via String(). Never throws. */ +const formatLogArg = (value: unknown): string => { + if (typeof value === "string") return value + if (value === null) return "null" + if (value === undefined) return "undefined" + if (isRuntimeReference(value)) return "[runtime reference]" + if (typeof value === "object") { + try { + return JSON.stringify(value) ?? coerceToString(value) + } catch { + return coerceToString(value) + } + } + return String(value) +} + class ProgramThrow { constructor(readonly value: unknown) {} } @@ -479,7 +539,8 @@ const boundedData = (value: unknown, label: string, node: AstNode, limits: Resol const isRuntimeReference = (value: unknown): boolean => value instanceof RuneFunction || value instanceof ToolReference || value instanceof IntrinsicReference || value instanceof GlobalNamespace || value instanceof GlobalMethodReference || value instanceof PromiseNamespace || - value instanceof PromiseAllReference || value instanceof CoercionFunction + value instanceof PromiseAllReference || value instanceof CoercionFunction || + value instanceof ConsoleReference || value instanceof ConsoleMethodReference const containsRuntimeReference = (value: unknown, seen = new Set()): boolean => { if (isRuntimeReference(value)) return true @@ -904,6 +965,9 @@ class Interpreter { private readonly limits: ResolvedExecutionLimits private readonly invokeTool: (path: ReadonlyArray, args: Array) => Effect.Effect private readonly budget: { operations: number } + // Shared by reference with any parallel forks (see forkForParallelCallback) so every + // console.* line lands in one ordered collection regardless of which fork emitted it. + private readonly logs: LogCollector private lastValue: unknown // Cached byte size (and, for objects, key count) of each live container, maintained incrementally // by the mutation helpers so appending in a loop is O(1)/op rather than re-walking the whole @@ -916,14 +980,17 @@ class Interpreter { limits: ResolvedExecutionLimits, invokeTool: (path: ReadonlyArray, args: Array) => Effect.Effect, budget: { operations: number } = { operations: 0 }, + logs: LogCollector = new LogCollector(limits.maxAuditBytes), ) { const globalScope = new Map() this.scopes = [globalScope] this.limits = limits this.invokeTool = invokeTool this.budget = budget + this.logs = logs this.lastValue = undefined globalScope.set("tools", { mutable: false, value: new ToolReference([]) }) + globalScope.set("console", { mutable: false, value: new ConsoleReference() }) globalScope.set("Promise", { mutable: false, value: new PromiseNamespace() }) globalScope.set("undefined", { mutable: false, value: undefined }) globalScope.set("Object", { mutable: false, value: new GlobalNamespace("Object") }) @@ -1740,6 +1807,14 @@ class Interpreter { self.recordWork(workUnits(coercionResult), node) return boundedData(coercionResult, `${callable.name} result`, node, self.limits) } + if (callable instanceof ConsoleMethodReference) { + const message = args.map(formatLogArg).join(" ") + // Charge formatting to the operation budget so a console.log loop is bounded by + // maxOperations, not just the wall-clock timeout. + self.recordWork(message.length, node) + self.logs.push(callable.level, message) + return undefined + } throw new InterpreterRuntimeError("Only tool capabilities are callable in Rune.", callee) }) } @@ -2310,7 +2385,7 @@ class Interpreter { } } - private getMemberReference(node: AstNode): Effect.Effect { + private getMemberReference(node: AstNode): Effect.Effect { const objectNode = getNode(node, "object") const propertyNode = getNode(node, "property") const computed = getBoolean(node, "computed") @@ -2339,6 +2414,13 @@ class Interpreter { throw new InterpreterRuntimeError(`Promise.${String(key)} is not available in Rune. Use Promise.all(...) for parallel Tool Capabilities.`, propertyNode) } + if (objectValue instanceof ConsoleReference) { + if (typeof key === "string" && consoleLevels.has(key as LogEntry["level"])) { + return new ConsoleMethodReference(key as LogEntry["level"]) + } + throw new InterpreterRuntimeError(`console.${String(key)} is not available in Rune. Use log, warn, error, info, or debug.`, propertyNode) + } + if (objectValue instanceof GlobalNamespace) { if (typeof key !== "string" || isBlockedMember(key)) { throw new InterpreterRuntimeError(`${objectValue.name}.${String(key)} is not available in Rune.`, propertyNode) @@ -2411,7 +2493,8 @@ class Interpreter { reference instanceof ToolReference || reference instanceof PromiseAllReference || reference instanceof IntrinsicReference || - reference instanceof GlobalMethodReference + reference instanceof GlobalMethodReference || + reference instanceof ConsoleMethodReference ) return reference if (Array.isArray(reference.target)) { if (typeof reference.key === "string" && arrayMethods.has(reference.key)) { @@ -2444,7 +2527,8 @@ class Interpreter { reference instanceof ToolReference || reference instanceof PromiseAllReference || reference instanceof IntrinsicReference || - reference instanceof GlobalMethodReference + reference instanceof GlobalMethodReference || + reference instanceof ConsoleMethodReference ) { throw new InterpreterRuntimeError("Only data fields may be assigned in Rune.", node) } @@ -2643,7 +2727,7 @@ class Interpreter { } private forkForParallelCallback(): Interpreter { - const fork = new Interpreter(this.limits, this.invokeTool, this.budget) + const fork = new Interpreter(this.limits, this.invokeTool, this.budget, this.logs) fork.scopes.splice( 0, fork.scopes.length, @@ -2682,12 +2766,16 @@ export const execute = >(options: Ex const limits = resolveExecutionLimits(options.limits) ToolRuntime.assertValidTools((options.tools ?? {}) as HostTools>) const tools = ToolRuntime.make((options.tools ?? {}) as HostTools>, limits.maxToolCalls, limits) + // Lives in the outer scope (not the interpreter) so console output is surfaced on every + // result path, including timeout and failure where the interpreter instance is unreachable. + const logs = new LogCollector(limits.maxAuditBytes) if (new TextEncoder().encode(options.code).byteLength > limits.maxSourceBytes) { return Effect.succeed({ ok: false, error: { kind: "InvalidDataValue", message: `Code exceeds the maximum source size of ${limits.maxSourceBytes} bytes.` }, toolCalls: tools.calls, + logs: logs.entries, }) } @@ -2696,12 +2784,13 @@ export const execute = >(options: Ex ok: false, error: { kind: "ParseError", message: "Code cannot be empty." }, toolCalls: tools.calls, + logs: logs.entries, }) } const operation = Effect.gen(function*() { const program = parseProgram(options.code) - const interpreter = new Interpreter>(limits, tools.invoke) + const interpreter = new Interpreter>(limits, tools.invoke, undefined, logs) const value = yield* interpreter.run(program) const copied = copyIn(value, "Execution result", limits) if (dataByteLength(copied) > limits.maxDataBytes) { @@ -2711,6 +2800,7 @@ export const execute = >(options: Ex ok: true, value: copyOut(copied), toolCalls: tools.calls, + logs: logs.entries, } satisfies ExecuteResult }).pipe( Effect.timeoutOrElse({ @@ -2719,6 +2809,7 @@ export const execute = >(options: Ex ok: false, error: { kind: "TimeoutExceeded", message: `Execution timed out after ${limits.timeoutMs}ms.` }, toolCalls: tools.calls, + logs: logs.entries, } satisfies ExecuteResult), }), ) @@ -2729,6 +2820,7 @@ export const execute = >(options: Ex ok: false, error: normalizeError(Cause.squash(cause)), toolCalls: tools.calls, + logs: logs.entries, }), onSuccess: (result): ExecuteResult => result, }), diff --git a/packages/opencode/test/session/code-mode-integration.test.ts b/packages/opencode/test/session/code-mode-integration.test.ts index d23ab1ab58..0d8adf32c7 100644 --- a/packages/opencode/test/session/code-mode-integration.test.ts +++ b/packages/opencode/test/session/code-mode-integration.test.ts @@ -216,6 +216,40 @@ describe("code mode integration (real MCP server)", () => { expect(out.output).toContain("kaboom") }) + test("console output is captured and appended as a Logs section after the result", async () => { + const out = await run(` + console.log("looking up", { name: "world" }) + const r = await tools.fixtures.get_text({ name: "world" }) + console.warn("got", r.result) + return r.result + `) + expect(out.output).toBe('hello world\n\nLogs:\n[log] looking up {"name":"world"}\n[warn] got hello world') + expect(out.metadata.error).toBeUndefined() + }) + + test("console output is preserved on the error path", async () => { + const out = await run(` + console.log("before the throw") + await tools.fixtures.boom({}) + return "unreachable" + `) + expect(out.metadata.error).toBe(true) + expect(out.output).toContain("kaboom") + expect(out.output).toContain("Logs:\n[log] before the throw") + }) + + test("a program that logs nothing gets no Logs section", async () => { + const out = await run("return 'quiet'") + expect(out.output).toBe("quiet") + expect(out.output).not.toContain("Logs:") + }) + + test("console does not consume the tool-call metadata (logging is not a tool call)", async () => { + const out = await run("console.log('hi'); console.error('bye'); return 'ok'") + expect(out.output).toBe("ok\n\nLogs:\n[log] hi\n[error] bye") + expect(out.metadata.toolCalls).toEqual([]) + }) + test("asks permission for each MCP call but not for discovery helpers", async () => { const asked: string[] = [] const permCtx: Tool.Context = { ...ctx, ask: (req: any) => Effect.sync(() => void asked.push(req.permission)) } diff --git a/packages/opencode/test/session/code-mode.test.ts b/packages/opencode/test/session/code-mode.test.ts index 9b0e449edd..fac8e9e5d0 100644 --- a/packages/opencode/test/session/code-mode.test.ts +++ b/packages/opencode/test/session/code-mode.test.ts @@ -9,6 +9,7 @@ import { rankTools, renderType, toEnvelope, + withLogs, type SearchEntry, } from "@/session/code-mode" import type { Tool as MCPToolDef } from "@modelcontextprotocol/sdk/types.js" @@ -406,6 +407,17 @@ describe("code mode execute", () => { expect(formatValue(undefined)).toBe("undefined") }) + test("unit: withLogs", () => { + // No logs: output is returned untouched. + expect(withLogs("result", [])).toBe("result") + // Logs are appended as a trailing section, one `[level] message` line each. + expect(withLogs("result", [{ level: "log", message: "a" }, { level: "warn", message: "b" }])).toBe( + "result\n\nLogs:\n[log] a\n[warn] b", + ) + // Empty output still gets the section (no leading blank lines). + expect(withLogs("", [{ level: "error", message: "boom" }])).toBe("Logs:\n[error] boom") + }) + test("terminates a runaway loop via the operation limit instead of hanging", async () => { const tool = await build({}) const output = await Effect.runPromise(tool.execute({ code: "while (true) {}" }, ctx))