Skip to content

Commit 733898f

Browse files
authored
Add launcher, parse, tool, workflow, and engine debug logging (#290)
1 parent 7e4ce77 commit 733898f

7 files changed

Lines changed: 121 additions & 10 deletions

File tree

skills/rig/engines/anthropic.ts

Lines changed: 16 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,8 +1,15 @@
11
import Anthropic from "@anthropic-ai/sdk";
22
import type { ClientOptions } from "@anthropic-ai/sdk";
33
import { betaTool } from "@anthropic-ai/sdk/helpers/beta/json-schema";
4+
import { debug } from "../rig.ts";
45
import type { AgentFactory, Tool } from "../rig.ts";
56

7+
const debugCreate = debug("engine:anthropic:create");
8+
const debugAsk = debug("engine:anthropic:ask");
9+
const debugResponse = debug("engine:anthropic:response");
10+
const debugTool = debug("engine:anthropic:tool");
11+
const debugClose = debug("engine:anthropic:close");
12+
613
export type AnthropicEngineOptions = ClientOptions & {
714
maxTokens?: number;
815
maxIterations?: number;
@@ -11,12 +18,14 @@ export type AnthropicEngineOptions = ClientOptions & {
1118
export function anthropicEngine(options: AnthropicEngineOptions = {}): AgentFactory {
1219
const { maxTokens = 8192, maxIterations, ...clientOptions } = options;
1320
return (agentOptions) => {
21+
debugCreate({ model: agentOptions.model, tools: agentOptions.tools?.map((tool) => tool.name) ?? [] });
1422
const client = new Anthropic(clientOptions);
1523
let messages: any[] = [];
1624
const tools = agentOptions.tools?.map(toAnthropicTool) ?? [];
1725

1826
return {
1927
async ask(prompt, askOptions = {}) {
28+
debugAsk({ model: agentOptions.model, prompt });
2029
const requestMessages = [...messages, { role: "user" as const, content: prompt }];
2130
const runner = client.beta.messages.toolRunner({
2231
model: agentOptions.model,
@@ -28,9 +37,13 @@ export function anthropicEngine(options: AnthropicEngineOptions = {}): AgentFact
2837
}, askOptions.signal ? { signal: askOptions.signal } : undefined);
2938
const response = await runner.runUntilDone();
3039
messages = [...runner.params.messages];
31-
return contentText(response.content);
40+
const text = contentText(response.content);
41+
debugResponse({ model: agentOptions.model, response: text });
42+
return text;
43+
},
44+
async close() {
45+
debugClose({ model: agentOptions.model });
3246
},
33-
async close() {},
3447
};
3548
};
3649
}
@@ -44,6 +57,7 @@ function toAnthropicTool(tool: Tool<any>) {
4457
if (!tool.handler) {
4558
throw new Error(`${tool.name} tool has no handler`);
4659
}
60+
debugTool({ tool: tool.name, args });
4761
return toolResultText(await tool.handler(args));
4862
},
4963
});

skills/rig/engines/codex.ts

Lines changed: 12 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,13 @@
11
import { Codex } from "@openai/codex-sdk";
22
import type { CodexOptions, ThreadOptions } from "@openai/codex-sdk";
3+
import { debug } from "../rig.ts";
34
import type { AgentFactory } from "../rig.ts";
45

6+
const debugCreate = debug("engine:codex:create");
7+
const debugAsk = debug("engine:codex:ask");
8+
const debugResponse = debug("engine:codex:response");
9+
const debugClose = debug("engine:codex:close");
10+
511
export type CodexEngineOptions = CodexOptions & {
612
thread?: Omit<ThreadOptions, "model">;
713
};
@@ -12,6 +18,7 @@ export function codexEngine(options: CodexEngineOptions = {}): AgentFactory {
1218
if (agentOptions.tools && agentOptions.tools.length > 0) {
1319
throw new Error("codexEngine does not support Rig tools");
1420
}
21+
debugCreate({ model: agentOptions.model });
1522
const systemMessage = stringSystemMessage(agentOptions.systemMessage);
1623
const codex = new Codex({
1724
...clientOptions,
@@ -31,6 +38,7 @@ export function codexEngine(options: CodexEngineOptions = {}): AgentFactory {
3138

3239
return {
3340
async ask(prompt, askOptions = {}) {
41+
debugAsk({ model: agentOptions.model, prompt, structured: askOptions.outputSchema !== undefined });
3442
throwIfAborted(closeController.signal);
3543
const signal = askOptions.signal
3644
? AbortSignal.any([askOptions.signal, closeController.signal])
@@ -42,15 +50,15 @@ export function codexEngine(options: CodexEngineOptions = {}): AgentFactory {
4250
activeTurns.add(activeTurn);
4351
try {
4452
const turn = await activeTurn;
45-
if (typeof turn.finalResponse === "string") {
46-
return turn.finalResponse;
47-
}
48-
return JSON.stringify(turn.finalResponse);
53+
const text = typeof turn.finalResponse === "string" ? turn.finalResponse : JSON.stringify(turn.finalResponse);
54+
debugResponse({ model: agentOptions.model, response: text });
55+
return text;
4956
} finally {
5057
activeTurns.delete(activeTurn);
5158
}
5259
},
5360
async close() {
61+
debugClose({ model: agentOptions.model });
5462
closeController.abort(new DOMException("Agent closed", "AbortError"));
5563
await Promise.allSettled(activeTurns);
5664
},

skills/rig/engines/gemini.ts

Lines changed: 12 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,8 +1,14 @@
11
import { randomUUID } from "node:crypto";
22
import { spawn } from "node:child_process";
33
import type { ChildProcessWithoutNullStreams } from "node:child_process";
4+
import { debug } from "../rig.ts";
45
import type { AgentFactory } from "../rig.ts";
56

7+
const debugCreate = debug("engine:gemini:create");
8+
const debugAsk = debug("engine:gemini:ask");
9+
const debugResponse = debug("engine:gemini:response");
10+
const debugClose = debug("engine:gemini:close");
11+
612
export type GeminiEngineOptions = {
713
command?: string;
814
cwd?: string;
@@ -32,6 +38,7 @@ export function geminiEngine(options: GeminiEngineOptions = {}): AgentFactory {
3238
if (agentOptions.tools && agentOptions.tools.length > 0) {
3339
throw new Error("geminiEngine does not support Rig tools");
3440
}
41+
debugCreate({ model: agentOptions.model, command, ...(cwd !== undefined && { cwd }) });
3542
const systemMessage = stringSystemMessage(agentOptions.systemMessage);
3643
const closeController = new AbortController();
3744
const activeTurns = new Set<Promise<unknown>>();
@@ -40,6 +47,7 @@ export function geminiEngine(options: GeminiEngineOptions = {}): AgentFactory {
4047

4148
return {
4249
async ask(prompt, askOptions = {}) {
50+
debugAsk({ model: agentOptions.model, prompt, resumed: sessionId !== undefined });
4351
throwIfAborted(closeController.signal);
4452
if (activeProcess) {
4553
throw new Error("geminiEngine does not support concurrent turns");
@@ -78,13 +86,16 @@ export function geminiEngine(options: GeminiEngineOptions = {}): AgentFactory {
7886
if (output.error) {
7987
throw new Error(output.error.message ?? "Gemini CLI request failed");
8088
}
81-
return output.response ?? "";
89+
const text = output.response ?? "";
90+
debugResponse({ model: agentOptions.model, session: sessionId, response: text });
91+
return text;
8292
} finally {
8393
activeProcess = undefined;
8494
activeTurns.delete(activeTurn);
8595
}
8696
},
8797
async close() {
98+
debugClose({ model: agentOptions.model, session: sessionId });
8899
closeController.abort(new DOMException("Agent closed", "AbortError"));
89100
await Promise.allSettled(activeTurns);
90101
},

skills/rig/engines/pi.ts

Lines changed: 14 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -3,8 +3,15 @@ import type { AgentTool as PiAgentTool } from "@earendil-works/pi-agent-core";
33
import { Type } from "@earendil-works/pi-ai";
44
import type { Models } from "@earendil-works/pi-ai";
55
import { builtinModels } from "@earendil-works/pi-ai/providers/all";
6+
import { debug } from "../rig.ts";
67
import type { AgentFactory, Tool } from "../rig.ts";
78

9+
const debugCreate = debug("engine:pi:create");
10+
const debugAsk = debug("engine:pi:ask");
11+
const debugResponse = debug("engine:pi:response");
12+
const debugTool = debug("engine:pi:tool");
13+
const debugClose = debug("engine:pi:close");
14+
815
export type PiEngineOptions = {
916
provider: string;
1017
models?: Models;
@@ -17,6 +24,7 @@ export function piEngine(options: PiEngineOptions): AgentFactory {
1724
if (!model) {
1825
throw new Error(`Unknown pi-agent model: ${options.provider}/${agentOptions.model}`);
1926
}
27+
debugCreate({ provider: options.provider, model: agentOptions.model, tools: agentOptions.tools?.map((tool) => tool.name) ?? [] });
2028
const piAgent = new PiAgent({
2129
streamFn: models.streamSimple.bind(models),
2230
initialState: {
@@ -28,6 +36,7 @@ export function piEngine(options: PiEngineOptions): AgentFactory {
2836

2937
return {
3038
async ask(prompt, askOptions = {}) {
39+
debugAsk({ model: agentOptions.model, prompt });
3140
throwIfAborted(askOptions.signal);
3241
const abort = () => piAgent.abort();
3342
askOptions.signal?.addEventListener("abort", abort, { once: true });
@@ -37,12 +46,15 @@ export function piEngine(options: PiEngineOptions): AgentFactory {
3746
if (piAgent.state.errorMessage) {
3847
throw new Error(piAgent.state.errorMessage);
3948
}
40-
return piResponseText(piAgent.state.messages);
49+
const text = piResponseText(piAgent.state.messages);
50+
debugResponse({ model: agentOptions.model, response: text });
51+
return text;
4152
} finally {
4253
askOptions.signal?.removeEventListener("abort", abort);
4354
}
4455
},
4556
async close() {
57+
debugClose({ model: agentOptions.model });
4658
piAgent.abort();
4759
await piAgent.waitForIdle();
4860
},
@@ -70,6 +82,7 @@ function toPiTool(tool: Tool<any>): PiAgentTool {
7082
if (!tool.handler) {
7183
throw new Error(`${tool.name} tool has no handler`);
7284
}
85+
debugTool({ tool: tool.name, args: params });
7386
const result = await tool.handler(params);
7487
return {
7588
content: [{ type: "text", text: toolResultText(result) }],

skills/rig/references/runtime.md

Lines changed: 16 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -131,6 +131,22 @@ RIG_DEBUG="engine,agent:turn,-engine:copilot:event" node skills/rig/rig.ts src/p
131131

132132
Debug records are `rig.*` JSONL events on stderr and never replace the final stdout result.
133133

134+
| Category | Emitted when |
135+
|---|---|
136+
| `launcher:start` | CLI starts, with script name and argv |
137+
| `launcher:program` | Root program is resolved (file, stdin, or import mode) |
138+
| `launcher:typecheck` | Typecheck starts, passes, or fails |
139+
| `launcher:result` | Root result is rendered to stdout |
140+
| `agent:invoke` / `agent:turn` / `agent:response` | Agent call starts, each turn prompt, each raw response |
141+
| `agent:parse` | Response parse/validation outcome (`parse`, `validation`, `ok`) |
142+
| `agent:tools` | Tools registered on an agent spec |
143+
| `agent:complete` / `agent:retry` / `agent:error` / `agent:failure` / `agent:close` | Agent lifecycle outcomes |
144+
| `workflow:event` | Every workflow event (`run_start`, `phase_start`, `agent_start`, `log`, …) |
145+
| `engine:select` | Default engine selection |
146+
| `engine:copilot:*` | Copilot session create, event, ask, response, close |
147+
| `engine:anthropic:*` / `engine:pi:*` | Engine create, ask, response, tool call, close |
148+
| `engine:codex:*` / `engine:gemini:*` | Engine create, ask, response, close |
149+
134150
## Operational conventions
135151

136152
- Assume Node.js 24.

skills/rig/rig.ts

Lines changed: 25 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -694,6 +694,13 @@ const debugAgentComplete = debug("agent:complete");
694694
const debugAgentRetry = debug("agent:retry");
695695
const debugAgentFailure = debug("agent:failure");
696696
const debugAgentClose = debug("agent:close");
697+
const debugAgentTools = debug("agent:tools");
698+
const debugAgentParse = debug("agent:parse");
699+
const debugLauncherStart = debug("launcher:start");
700+
const debugLauncherProgram = debug("launcher:program");
701+
const debugLauncherTypecheck = debug("launcher:typecheck");
702+
const debugLauncherResult = debug("launcher:result");
703+
const debugWorkflowEvent = debug("workflow:event");
697704

698705
export type AgentAddonContext = {
699706
spec: NormalizedAgentSpec<any, any>;
@@ -1453,6 +1460,7 @@ export async function launchRigProgram(programPath: string, options: LaunchOptio
14531460
const cwd = options.cwd ?? process.cwd();
14541461
const resolvedPath = isAbsolute(programPath) ? programPath : resolve(cwd, programPath);
14551462

1463+
debugLauncherProgram({ mode: "import", program: resolvedPath, cwd, server: options.startServer === true });
14561464
configureAgent(defaultAgentFactory({ cwd, ...(options.startServer ? { startServer: true } : {}) }));
14571465
await import(pathToFileURL(resolvedPath).href);
14581466
}
@@ -1626,6 +1634,7 @@ async function hasEsmPackageContext(filePath: string): Promise<boolean> {
16261634
}
16271635

16281636
async function typecheckProgram(programPath: string, cwd: string, displayPath = programPath): Promise<void> {
1637+
debugLauncherTypecheck({ phase: "start", program: displayPath, cwd });
16291638
const execFileAsync = promisify(execFile);
16301639
const skillTsconfigPath = resolve(dirname(fileURLToPath(import.meta.url)), "tsconfig.json");
16311640
const candidateTsconfigPaths = [resolve(cwd, "tsconfig.json"), skillTsconfigPath];
@@ -1672,6 +1681,7 @@ async function typecheckProgram(programPath: string, cwd: string, displayPath =
16721681
env: { ...process.env, npm_config_ignore_scripts: "true" },
16731682
},
16741683
);
1684+
debugLauncherTypecheck({ phase: "passed", program: displayPath });
16751685
} catch (error) {
16761686
const execError = error as NodeJS.ErrnoException & { stdout?: string; stderr?: string };
16771687
if (execError.code === "ENOENT") {
@@ -1691,6 +1701,7 @@ async function typecheckProgram(programPath: string, cwd: string, displayPath =
16911701
.replaceAll(relativeShadowPath, displayPath);
16921702
const detail = diagnostics ? `\n${diagnostics}` : "";
16931703
const hasCjsEsmMismatch = diagnostics.includes("TS1295") || diagnostics.includes("TS1479");
1704+
debugLauncherTypecheck({ phase: "failed", program: displayPath, diagnostics });
16941705
const hint = hasCjsEsmMismatch
16951706
? "\nHint: add {\"type\":\"module\"} to a package.json in the same directory as your rig program."
16961707
: "";
@@ -1725,9 +1736,12 @@ async function runRootAgentFromStdin(
17251736
if (!rootAgent) {
17261737
throw new Error("Expected program to export a root value (agent, workflow, string, or prompt builder) as default export.");
17271738
}
1739+
debugLauncherProgram({ mode: "file", program: resolvedPath, root: rootAgent.agentName, promptLength: prompt.length });
17281740

17291741
const result = await rootAgent(coerceStdinInput(rootAgent, prompt));
1730-
io.stdout.write(renderStdout(result));
1742+
const rendered = renderStdout(result);
1743+
debugLauncherResult({ mode: "file", root: rootAgent.agentName, bytes: Buffer.byteLength(rendered) });
1744+
io.stdout.write(rendered);
17311745
}
17321746

17331747
async function runProgramCodeFromStdin(
@@ -1759,12 +1773,15 @@ async function runProgramCodeFromStdin(
17591773
if (!rootAgent) {
17601774
throw new Error("Expected program to export a root value (agent, workflow, string, or prompt builder) as default export.");
17611775
}
1776+
debugLauncherProgram({ mode: "stdin", program: tempProgramPath, root: rootAgent.agentName, codeLength: programCode.length });
17621777
const input = noInputInvocation(rootAgent);
17631778
if (input === undefined) {
17641779
throw new Error("Expected stdin program root agent to have no input (omit input or use input: s.object({})).");
17651780
}
17661781
const result = await rootAgent(input);
1767-
io.stdout.write(renderStdout(result));
1782+
const rendered = renderStdout(result);
1783+
debugLauncherResult({ mode: "stdin", root: rootAgent.agentName, bytes: Buffer.byteLength(rendered) });
1784+
io.stdout.write(rendered);
17681785
} finally {
17691786
await rm(tempDir, { recursive: true, force: true });
17701787
}
@@ -1825,6 +1842,7 @@ export async function runLauncherCli(
18251842
io: LauncherIo = process,
18261843
): Promise<void> {
18271844
const scriptName = process.argv[1] ? basename(process.argv[1]) : "launcher";
1845+
debugLauncherStart({ script: scriptName, argv });
18281846
if (argv.some(isLauncherHelpArg)) {
18291847
io.stdout.write(`${renderLauncherUsage(scriptName)}\n`);
18301848
return;
@@ -2230,6 +2248,7 @@ export async function runWorkflow<Input, Output>(
22302248
timer?.unref();
22312249

22322250
const emit = (event: WorkflowEvent): void => {
2251+
debugWorkflowEvent(() => ({ workflow: definition.meta.name, event }));
22332252
try {
22342253
options.onEvent?.(event);
22352254
} catch {
@@ -2374,6 +2393,7 @@ function normalizeToolConfig<T extends { skipPermission?: boolean }>(tool: T): T
23742393
}
23752394

23762395
function normalizeTools(tools: Tool<any>[], agentName: string): Tool<any>[] {
2396+
debugAgentTools(() => ({ agent: agentName, tools: tools.map((tool) => tool?.name) }));
23772397
return tools.map((tool, index) => {
23782398
if (!tool || typeof tool !== "object") {
23792399
throw new Error(`Invalid tool for agent "${agentName}" at tools[${index}]. Expected a tool definition object.`);
@@ -2714,6 +2734,7 @@ export type ResponseAnalysisResult = { ok: true; output: unknown } | { ok: false
27142734
export function analyzeResponse(response: string, outputSchema: Schema, agentName: string, turn: number): ResponseAnalysisResult {
27152735
const parsed = parseJson(response);
27162736
if (!parsed.ok) {
2737+
debugAgentParse({ agent: agentName, turn, kind: "parse", error: parsed.error });
27172738
return {
27182739
ok: false,
27192740
error: new AgentError({
@@ -2729,6 +2750,7 @@ export function analyzeResponse(response: string, outputSchema: Schema, agentNam
27292750

27302751
const result = validate(parsed.value, outputSchema);
27312752
if (!result.ok) {
2753+
debugAgentParse({ agent: agentName, turn, kind: "validation", error: result.error });
27322754
return {
27332755
ok: false,
27342756
error: new AgentError({
@@ -2742,6 +2764,7 @@ export function analyzeResponse(response: string, outputSchema: Schema, agentNam
27422764
};
27432765
}
27442766

2767+
debugAgentParse({ agent: agentName, turn, kind: "ok" });
27452768
return { ok: true, output: parsed.value };
27462769
}
27472770

src/rig.test.ts

Lines changed: 26 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -156,10 +156,36 @@ describe("debug logging", () => {
156156
"rig.agent:invoke",
157157
"rig.agent:turn",
158158
"rig.agent:response",
159+
"rig.agent:parse",
159160
"rig.agent:complete",
160161
"rig.agent:close",
161162
]);
162163
});
164+
165+
it("logs response parse failures with their kind", () => {
166+
process.env["RIG_DEBUG"] = "agent:parse";
167+
168+
analyzeResponse("not json", s.string, "parse-debug", 1);
169+
analyzeResponse(JSON.stringify(1), s.string, "parse-debug", 2);
170+
171+
const events = fsMocks.writeSync.mock.calls.map(([, line]) => JSON.parse(String(line)));
172+
expect(events.map((event) => event.data.kind)).toEqual(["parse", "validation"]);
173+
expect(events[0].type).toBe("rig.agent:parse");
174+
});
175+
176+
it("logs registered tool names for an agent", () => {
177+
process.env["RIG_DEBUG"] = "agent:tools";
178+
179+
agent({
180+
name: "tool-debug",
181+
tools: [defineTool("lookup", { description: "Lookup", parameters: s.object({ id: s.string }), handler: () => "ok" })],
182+
});
183+
184+
expect(JSON.parse(String(fsMocks.writeSync.mock.calls[0]?.[1]))).toEqual({
185+
type: "rig.agent:tools",
186+
data: { agent: "tool-debug", tools: ["lookup"] },
187+
});
188+
});
163189
});
164190

165191
describe("agent", () => {

0 commit comments

Comments
 (0)