Add trace logging and tighten daemon log defaults (#933)

* Add trace logging and tighten daemon log defaults

* Clean up daemon trace logging shape

* Clean up daemon trace logging

* Route provider turn-id checks through shared helper

* Fix supervisor log config test paths on Windows

* Expect resolved supervisor log path on Windows
This commit is contained in:
Mohamed Boudra
2026-05-12 12:58:46 +08:00
committed by GitHub
parent a5c2b97e1d
commit 95f45e4e2b
22 changed files with 982 additions and 350 deletions
+8 -1
View File
@@ -39,7 +39,14 @@ In any worktree-style or portless setup, never assume default ports.
### Daemon logs ### Daemon logs
Check `$PASEO_HOME/daemon.log` for trace-level logs. Check `$PASEO_HOME/daemon.log` for daemon logs. The default level is `info`; set
`PASEO_LOG_LEVEL=trace` before launching the daemon when you need full provider,
session, and agent-manager traces for stuck-state debugging.
The supervisor rotates `daemon.log`. Persisted `log.file.rotate` settings in
`$PASEO_HOME/config.json` win first. Without persisted config, the optional
`PASEO_LOG_ROTATE_SIZE` and `PASEO_LOG_ROTATE_COUNT` env vars override the
defaults. The default rotation is `10m` x `3` files everywhere.
## paseo.json service scripts ## paseo.json service scripts
@@ -10,12 +10,9 @@ import {
import { resolvePaseoHome } from "../src/server/paseo-home.js"; import { resolvePaseoHome } from "../src/server/paseo-home.js";
import { loadPersistedConfig } from "../src/server/persisted-config.js"; import { loadPersistedConfig } from "../src/server/persisted-config.js";
import { runSupervisor } from "./supervisor.js"; import { runSupervisor } from "./supervisor.js";
import { resolveSupervisorLogFile } from "./supervisor-log-config.js";
import { applySherpaLoaderEnv } from "../src/server/speech/providers/local/sherpa/sherpa-runtime-env.js"; import { applySherpaLoaderEnv } from "../src/server/speech/providers/local/sherpa/sherpa-runtime-env.js";
const DEFAULT_DAEMON_LOG_FILENAME = "daemon.log";
const DEFAULT_LOG_ROTATE_SIZE = "10m";
const DEFAULT_LOG_ROTATE_MAX_FILES = 2;
interface DaemonRunnerConfig { interface DaemonRunnerConfig {
devMode: boolean; devMode: boolean;
workerArgs: string[]; workerArgs: string[];
@@ -77,28 +74,6 @@ function resolvePackagedNodeEntrypointRunnerPath(currentScriptPath: string): str
return existsSync(runnerPath) ? runnerPath : null; return existsSync(runnerPath) ? runnerPath : null;
} }
function resolveSupervisorLogFile(
paseoHome: string,
persistedConfig: ReturnType<typeof loadPersistedConfig>,
) {
const configuredFile = persistedConfig.log?.file;
const configuredPath = configuredFile?.path;
let logPath = path.join(paseoHome, DEFAULT_DAEMON_LOG_FILENAME);
if (configuredPath) {
logPath = path.isAbsolute(configuredPath)
? configuredPath
: path.resolve(paseoHome, configuredPath);
}
return {
path: logPath,
rotate: {
maxSize: configuredFile?.rotate?.maxSize ?? DEFAULT_LOG_ROTATE_SIZE,
maxFiles: configuredFile?.rotate?.maxFiles ?? DEFAULT_LOG_ROTATE_MAX_FILES,
},
};
}
async function main(): Promise<void> { async function main(): Promise<void> {
const config = parseConfig(process.argv.slice(2)); const config = parseConfig(process.argv.slice(2));
const workerEntry = config.devMode ? resolveDevWorkerEntry() : resolveWorkerEntry(); const workerEntry = config.devMode ? resolveDevWorkerEntry() : resolveWorkerEntry();
@@ -113,7 +88,7 @@ async function main(): Promise<void> {
const paseoHome = resolvePaseoHome(workerEnv); const paseoHome = resolvePaseoHome(workerEnv);
const persistedConfig = loadPersistedConfig(paseoHome); const persistedConfig = loadPersistedConfig(paseoHome);
const supervisorLogFile = resolveSupervisorLogFile(paseoHome, persistedConfig); const supervisorLogFile = resolveSupervisorLogFile(paseoHome, persistedConfig, workerEnv);
try { try {
await acquirePidLock(paseoHome, null, { await acquirePidLock(paseoHome, null, {
@@ -0,0 +1,42 @@
import path from "node:path";
import type { loadPersistedConfig } from "../src/server/persisted-config.js";
const DEFAULT_DAEMON_LOG_FILENAME = "daemon.log";
const DEFAULT_LOG_ROTATE_SIZE = "10m";
const DEFAULT_LOG_ROTATE_MAX_FILES = 3;
export function resolveSupervisorLogFile(
paseoHome: string,
persistedConfig: ReturnType<typeof loadPersistedConfig>,
env: NodeJS.ProcessEnv = process.env,
) {
const configuredFile = persistedConfig.log?.file;
const configuredPath = configuredFile?.path;
const envRotateSize = env.PASEO_LOG_ROTATE_SIZE?.trim();
const envRotateMaxFiles = parseOptionalPositiveInteger(env.PASEO_LOG_ROTATE_COUNT);
let logPath = path.join(paseoHome, DEFAULT_DAEMON_LOG_FILENAME);
if (configuredPath) {
logPath = path.isAbsolute(configuredPath)
? configuredPath
: path.resolve(paseoHome, configuredPath);
}
return {
path: logPath,
rotate: {
maxSize: configuredFile?.rotate?.maxSize ?? envRotateSize ?? DEFAULT_LOG_ROTATE_SIZE,
maxFiles:
configuredFile?.rotate?.maxFiles ?? envRotateMaxFiles ?? DEFAULT_LOG_ROTATE_MAX_FILES,
},
};
}
function parseOptionalPositiveInteger(value: string | undefined): number | undefined {
if (value === undefined) {
return undefined;
}
const parsed = Number.parseInt(value.trim(), 10);
return Number.isInteger(parsed) && parsed > 0 ? parsed : undefined;
}
@@ -5,6 +5,7 @@ import { fileURLToPath, pathToFileURL } from "node:url";
import { spawn } from "node:child_process"; import { spawn } from "node:child_process";
import { describe, expect, test } from "vitest"; import { describe, expect, test } from "vitest";
import { isPlatform } from "../src/test-utils/platform.js"; import { isPlatform } from "../src/test-utils/platform.js";
import { resolveSupervisorLogFile } from "./supervisor-log-config.js";
const repoRoot = path.resolve(fileURLToPath(new URL("../../..", import.meta.url))); const repoRoot = path.resolve(fileURLToPath(new URL("../../..", import.meta.url)));
const supervisorPath = fileURLToPath(new URL("./supervisor.ts", import.meta.url)); const supervisorPath = fileURLToPath(new URL("./supervisor.ts", import.meta.url));
@@ -87,6 +88,57 @@ async function runSupervisorFixture(options: {
} }
describe("supervisor durable logging", () => { describe("supervisor durable logging", () => {
test("resolves rotation defaults", () => {
const paseoHome = path.join(path.sep, "tmp", "paseo-home");
const logFile = resolveSupervisorLogFile(paseoHome, {}, {});
expect(logFile).toEqual({
path: path.join(paseoHome, "daemon.log"),
rotate: { maxSize: "10m", maxFiles: 3 },
});
});
test("lets persisted rotation override env rotation defaults", () => {
const paseoHome = path.join(path.sep, "tmp", "paseo-home");
const logFile = resolveSupervisorLogFile(
paseoHome,
{
log: {
file: {
path: "logs/daemon.log",
rotate: { maxSize: "25m", maxFiles: 4 },
},
},
},
{
PASEO_LOG_ROTATE_SIZE: "200m",
PASEO_LOG_ROTATE_COUNT: "12",
},
);
expect(logFile).toEqual({
path: path.resolve(paseoHome, "logs", "daemon.log"),
rotate: { maxSize: "25m", maxFiles: 4 },
});
});
test("uses env rotation when persisted rotation is absent", () => {
const paseoHome = path.join(path.sep, "tmp", "paseo-home");
const logFile = resolveSupervisorLogFile(
paseoHome,
{},
{
PASEO_LOG_ROTATE_SIZE: "50m",
PASEO_LOG_ROTATE_COUNT: "8",
},
);
expect(logFile).toEqual({
path: path.join(paseoHome, "daemon.log"),
rotate: { maxSize: "50m", maxFiles: 8 },
});
});
test("writes supervised worker stdout and stderr to daemon.log", async () => { test("writes supervised worker stdout and stderr to daemon.log", async () => {
const result = await runSupervisorFixture({ const result = await runSupervisorFixture({
workerSource: ` workerSource: `
@@ -716,6 +716,7 @@ test("createAgent passes daemon launch env through the provider launch context",
modeId: "auto", modeId: "auto",
}); });
expect(client.lastLaunchContext).toEqual({ expect(client.lastLaunchContext).toEqual({
agentId: snapshot.id,
env: { env: {
PASEO_AGENT_ID: snapshot.id, PASEO_AGENT_ID: snapshot.id,
}, },
@@ -1179,6 +1180,7 @@ test("resumeAgentFromPersistence keeps metadata config, applies overrides, and p
}, },
}); });
expect(client.lastResumeLaunchContext).toEqual({ expect(client.lastResumeLaunchContext).toEqual({
agentId: resumed.id,
env: { env: {
PASEO_AGENT_ID: resumed.id, PASEO_AGENT_ID: resumed.id,
}, },
@@ -1283,6 +1285,7 @@ test("reloadAgentSession passes daemon launch env through the provider launch co
}); });
expect(client.lastCreateLaunchContext).toEqual({ expect(client.lastCreateLaunchContext).toEqual({
agentId: snapshot.id,
env: { env: {
PASEO_AGENT_ID: snapshot.id, PASEO_AGENT_ID: snapshot.id,
}, },
@@ -1293,6 +1296,7 @@ test("reloadAgentSession passes daemon launch env through the provider launch co
}); });
expect(client.lastResumeLaunchContext).toEqual({ expect(client.lastResumeLaunchContext).toEqual({
agentId: snapshot.id,
env: { env: {
PASEO_AGENT_ID: snapshot.id, PASEO_AGENT_ID: snapshot.id,
}, },
+215 -38
View File
@@ -10,30 +10,31 @@ import type { Logger } from "pino";
import { z } from "zod"; import { z } from "zod";
import type { TerminalManager } from "../../terminal/terminal-manager.js"; import type { TerminalManager } from "../../terminal/terminal-manager.js";
import type { import {
AgentCapabilityFlags, getAgentStreamEventTurnId,
AgentClient, type AgentCapabilityFlags,
AgentCreateSessionOptions, type AgentClient,
AgentFeature, type AgentCreateSessionOptions,
AgentLaunchContext, type AgentFeature,
AgentSlashCommand, type AgentLaunchContext,
AgentMode, type AgentSlashCommand,
AgentPermissionRequest, type AgentMode,
AgentPermissionResponse, type AgentPermissionRequest,
AgentPermissionResult, type AgentPermissionResponse,
AgentPersistenceHandle, type AgentPermissionResult,
AgentPromptInput, type AgentPersistenceHandle,
AgentProvider, type AgentPromptInput,
AgentRunOptions, type AgentProvider,
AgentRunResult, type AgentRunOptions,
AgentSession, type AgentRunResult,
AgentSessionConfig, type AgentSession,
AgentStreamEvent, type AgentSessionConfig,
AgentTimelineItem, type AgentStreamEvent,
AgentUsage, type AgentTimelineItem,
AgentRuntimeInfo, type AgentUsage,
ListPersistedAgentsOptions, type AgentRuntimeInfo,
PersistedAgentDescriptor, type ListPersistedAgentsOptions,
type PersistedAgentDescriptor,
} from "./agent-sdk-types.js"; } from "./agent-sdk-types.js";
import { buildArchivedAgentRecord, type ArchivedStoredAgentRecord } from "./agent-archive.js"; import { buildArchivedAgentRecord, type ArchivedStoredAgentRecord } from "./agent-archive.js";
import type { StoredAgentRecord, AgentStorage } from "./agent-storage.js"; import type { StoredAgentRecord, AgentStorage } from "./agent-storage.js";
@@ -1005,18 +1006,28 @@ export class AgentManager {
this.logger.trace( this.logger.trace(
{ {
agentId, agentId,
provider: agent.provider,
sessionId: agent.persistence?.sessionId ?? undefined,
turnId: agent.activeForegroundTurnId ?? undefined,
lifecycle: agent.lifecycle, lifecycle: agent.lifecycle,
activeForegroundTurnId: agent.activeForegroundTurnId, activeForegroundTurnId: agent.activeForegroundTurnId,
pendingPermissions: agent.pendingPermissions.size, pendingPermissions: agent.pendingPermissions.size,
}, },
"closeAgent: start", "agent.manager.close.start",
); );
const closedAgent = this.prepareAgentForClosure(agent, "agent closed"); const closedAgent = this.prepareAgentForClosure(agent, "agent closed");
await agent.session.close(); await agent.session.close();
this.timelineStore.delete(agentId); this.timelineStore.delete(agentId);
await this.persistSnapshot(closedAgent); await this.persistSnapshot(closedAgent);
this.emitClosedAgent(closedAgent, { persist: false }); this.emitClosedAgent(closedAgent, { persist: false });
this.logger.trace({ agentId }, "closeAgent: completed"); this.logger.trace(
{
agentId,
provider: closedAgent.provider,
sessionId: closedAgent.persistence?.sessionId ?? undefined,
},
"agent.manager.close.complete",
);
} }
async archiveAgent(agentId: string): Promise<{ archivedAt: string }> { async archiveAgent(agentId: string): Promise<{ archivedAt: string }> {
@@ -1470,22 +1481,28 @@ export class AgentManager {
this.logger.trace( this.logger.trace(
{ {
agentId, agentId,
provider: existingAgent.provider,
sessionId: existingAgent.persistence?.sessionId ?? undefined,
turnId: existingAgent.activeForegroundTurnId ?? undefined,
lifecycle: existingAgent.lifecycle, lifecycle: existingAgent.lifecycle,
activeForegroundTurnId: existingAgent.activeForegroundTurnId, activeForegroundTurnId: existingAgent.activeForegroundTurnId,
hasPendingForegroundRun: this.foregroundRuns.hasPendingRun(agentId), hasPendingForegroundRun: this.foregroundRuns.hasPendingRun(agentId),
promptType: typeof prompt === "string" ? "string" : "structured", promptType: typeof prompt === "string" ? "string" : "structured",
hasRunOptions: Boolean(options), hasRunOptions: Boolean(options),
}, },
"streamAgent: requested", "agent.manager.stream.request",
); );
if (existingAgent.activeForegroundTurnId || this.foregroundRuns.hasPendingRun(agentId)) { if (existingAgent.activeForegroundTurnId || this.foregroundRuns.hasPendingRun(agentId)) {
this.logger.trace( this.logger.trace(
{ {
agentId, agentId,
provider: existingAgent.provider,
sessionId: existingAgent.persistence?.sessionId ?? undefined,
turnId: existingAgent.activeForegroundTurnId ?? undefined,
lifecycle: existingAgent.lifecycle, lifecycle: existingAgent.lifecycle,
hasPendingForegroundRun: this.foregroundRuns.hasPendingRun(agentId), hasPendingForegroundRun: this.foregroundRuns.hasPendingRun(agentId),
}, },
"streamAgent: rejected because a foreground run is already in flight", "agent.manager.stream.reject",
); );
throw new Error(`Agent ${agentId} already has an active run`); throw new Error(`Agent ${agentId} already has an active run`);
} }
@@ -1522,10 +1539,13 @@ export class AgentManager {
this.logger.trace( this.logger.trace(
{ {
agentId, agentId,
provider: agent.provider,
sessionId: agent.persistence?.sessionId ?? undefined,
turnId,
lifecycle: agent.lifecycle, lifecycle: agent.lifecycle,
activeForegroundTurnId: agent.activeForegroundTurnId, activeForegroundTurnId: agent.activeForegroundTurnId,
}, },
"streamAgent: started", "agent.manager.stream.start",
); );
turnStream = this.foregroundRuns.createTurnStream(turnId); turnStream = this.foregroundRuns.createTurnStream(turnId);
@@ -1577,11 +1597,14 @@ export class AgentManager {
this.logger.trace( this.logger.trace(
{ {
agentId: agent.id, agentId: agent.id,
provider: agent.provider,
sessionId: mutableAgent.persistence?.sessionId ?? undefined,
turnId,
lifecycle: mutableAgent.lifecycle, lifecycle: mutableAgent.lifecycle,
terminalError, terminalError,
pendingReplacement: mutableAgent.pendingReplacement, pendingReplacement: mutableAgent.pendingReplacement,
}, },
"finalizeForegroundTurn: applying terminal state", "agent.manager.finalize",
); );
if (!shouldHoldBusyForReplacement) { if (!shouldHoldBusyForReplacement) {
this.touchUpdatedAt(mutableAgent); this.touchUpdatedAt(mutableAgent);
@@ -2371,6 +2394,16 @@ export class AgentManager {
} }
private enqueueSessionEvent(agentId: string, event: AgentStreamEvent): void { private enqueueSessionEvent(agentId: string, event: AgentStreamEvent): void {
this.logger.trace(
{
agentId,
provider: event.provider,
sessionId: this.agents.get(agentId)?.persistence?.sessionId ?? undefined,
turnId: getAgentStreamEventTurnId(event),
event,
},
"agent.manager.enqueue",
);
const previous = this.sessionEventTails.get(agentId) ?? Promise.resolve(); const previous = this.sessionEventTails.get(agentId) ?? Promise.resolve();
const next = previous const next = previous
.catch(() => undefined) .catch(() => undefined)
@@ -2382,6 +2415,16 @@ export class AgentManager {
if (current.session == null) { if (current.session == null) {
return; return;
} }
this.logger.trace(
{
agentId,
provider: event.provider,
sessionId: current.persistence?.sessionId ?? undefined,
turnId: getAgentStreamEventTurnId(event),
event,
},
"agent.manager.dequeue",
);
await this.dispatchSessionEvent(current, event); await this.dispatchSessionEvent(current, event);
return; return;
}) })
@@ -2405,8 +2448,19 @@ export class AgentManager {
agent: ActiveManagedAgent, agent: ActiveManagedAgent,
event: AgentStreamEvent, event: AgentStreamEvent,
): Promise<void> { ): Promise<void> {
const turnId = (event as { turnId?: string }).turnId; const turnId = getAgentStreamEventTurnId(event);
const matchingWaiters = this.foregroundRuns.getMatchingWaiters(agent, turnId); const matchingWaiters = this.foregroundRuns.getMatchingWaiters(agent, turnId);
this.logger.trace(
{
agentId: agent.id,
provider: event.provider,
sessionId: agent.persistence?.sessionId ?? undefined,
turnId,
matchingWaiterCount: matchingWaiters.length,
event,
},
"agent.manager.dispatch_session_event",
);
const shouldNotifyWaiters = await this.handleStreamEvent(agent, event); const shouldNotifyWaiters = await this.handleStreamEvent(agent, event);
@@ -2417,6 +2471,18 @@ export class AgentManager {
this.foregroundRuns.notifyWaiters(matchingWaiters, event, { this.foregroundRuns.notifyWaiters(matchingWaiters, event, {
terminal: isTurnTerminalEvent(event), terminal: isTurnTerminalEvent(event),
}); });
this.logger.trace(
{
agentId: agent.id,
provider: event.provider,
sessionId: agent.persistence?.sessionId ?? undefined,
turnId,
notifiedWaiterCount: matchingWaiters.length,
terminal: isTurnTerminalEvent(event),
event,
},
"agent.manager.notify_waiters",
);
} }
private async resolveInitialPersistedTitle( private async resolveInitialPersistedTitle(
@@ -2529,7 +2595,7 @@ export class AgentManager {
} }
private notifyForegroundTurnWaiters(agentId: string, event: AgentStreamEvent): void { private notifyForegroundTurnWaiters(agentId: string, event: AgentStreamEvent): void {
const turnId = (event as { turnId?: string }).turnId; const turnId = getAgentStreamEventTurnId(event);
if (turnId == null) { if (turnId == null) {
return; return;
} }
@@ -2540,6 +2606,16 @@ export class AgentManager {
} }
this.foregroundRuns.notifyAgentWaiters(agent, event); this.foregroundRuns.notifyAgentWaiters(agent, event);
this.logger.trace(
{
agentId,
provider: event.provider,
sessionId: agent.persistence?.sessionId ?? undefined,
turnId,
event,
},
"agent.manager.notify_waiters.coalesced",
);
} }
private async handleStreamEvent( private async handleStreamEvent(
@@ -2547,8 +2623,9 @@ export class AgentManager {
event: AgentStreamEvent, event: AgentStreamEvent,
options?: HandleStreamEventOptions, options?: HandleStreamEventOptions,
): Promise<boolean> { ): Promise<boolean> {
const eventTurnId = (event as { turnId?: string }).turnId; const eventTurnId = getAgentStreamEventTurnId(event);
const isForegroundEvent = Boolean(eventTurnId && agent.activeForegroundTurnId === eventTurnId); const isForegroundEvent = Boolean(eventTurnId && agent.activeForegroundTurnId === eventTurnId);
this.traceHandleStreamEventStart(agent, event, eventTurnId, isForegroundEvent);
if ( if (
eventTurnId && eventTurnId &&
isTurnTerminalEvent(event) && isTurnTerminalEvent(event) &&
@@ -2561,6 +2638,7 @@ export class AgentManager {
if (!options?.fromHistory) { if (!options?.fromHistory) {
this.touchUpdatedAt(agent); this.touchUpdatedAt(agent);
if (this.agentStreamCoalescer.handle(agent.id, event)) { if (this.agentStreamCoalescer.handle(agent.id, event)) {
this.traceCoalescerBuffered(agent, event, eventTurnId);
return false; return false;
} }
this.agentStreamCoalescer.flushFor(agent.id); this.agentStreamCoalescer.flushFor(agent.id);
@@ -2588,9 +2666,71 @@ export class AgentManager {
this.dispatchStream(agent.id, event); this.dispatchStream(agent.id, event);
} }
this.traceHandleStreamEventEnd(agent, event, eventTurnId, flags);
return flags.shouldNotifyWaiters; return flags.shouldNotifyWaiters;
} }
private traceHandleStreamEventStart(
agent: ActiveManagedAgent,
event: AgentStreamEvent,
turnId: string | undefined,
isForegroundEvent: boolean,
): void {
this.logger.trace(
{
agentId: agent.id,
provider: event.provider,
sessionId: agent.persistence?.sessionId ?? undefined,
turnId,
lifecycle: agent.lifecycle,
activeForegroundTurnId: agent.activeForegroundTurnId,
isForegroundEvent,
event,
},
"agent.manager.handle_stream_event.start",
);
}
private traceCoalescerBuffered(
agent: ActiveManagedAgent,
event: AgentStreamEvent,
turnId: string | undefined,
): void {
this.logger.trace(
{
agentId: agent.id,
provider: event.provider,
sessionId: agent.persistence?.sessionId ?? undefined,
turnId,
event,
},
"agent.manager.coalescer.buffer",
);
}
private traceHandleStreamEventEnd(
agent: ActiveManagedAgent,
event: AgentStreamEvent,
turnId: string | undefined,
flags: StreamEventFlags,
): void {
this.logger.trace(
{
agentId: agent.id,
provider: event.provider,
sessionId: agent.persistence?.sessionId ?? undefined,
turnId,
lifecycle: agent.lifecycle,
activeForegroundTurnId: agent.activeForegroundTurnId,
shouldDispatchEvent: flags.shouldDispatchEvent,
shouldNotifyWaiters: flags.shouldNotifyWaiters,
event,
},
"agent.manager.handle_stream_event.end",
);
}
private dispatchStreamEventByType(params: { private dispatchStreamEventByType(params: {
agent: ActiveManagedAgent; agent: ActiveManagedAgent;
event: AgentStreamEvent; event: AgentStreamEvent;
@@ -2747,11 +2887,13 @@ export class AgentManager {
this.logger.trace( this.logger.trace(
{ {
agentId: agent.id, agentId: agent.id,
provider: agent.provider,
sessionId: agent.persistence?.sessionId ?? undefined,
turnId: eventTurnId,
lifecycle: agent.lifecycle, lifecycle: agent.lifecycle,
activeForegroundTurnId: agent.activeForegroundTurnId, activeForegroundTurnId: agent.activeForegroundTurnId,
eventTurnId,
}, },
"handleStreamEvent: turn_completed", "agent.manager.turn.completed",
); );
agent.lastUsage = event.usage; agent.lastUsage = event.usage;
agent.lastError = undefined; agent.lastError = undefined;
@@ -2778,6 +2920,9 @@ export class AgentManager {
this.logger.warn( this.logger.warn(
{ {
agentId: agent.id, agentId: agent.id,
provider: agent.provider,
sessionId: agent.persistence?.sessionId ?? undefined,
turnId: eventTurnId,
lifecycle: agent.lifecycle, lifecycle: agent.lifecycle,
activeForegroundTurnId: agent.activeForegroundTurnId, activeForegroundTurnId: agent.activeForegroundTurnId,
eventTurnId, eventTurnId,
@@ -2818,11 +2963,14 @@ export class AgentManager {
this.logger.trace( this.logger.trace(
{ {
agentId: agent.id, agentId: agent.id,
provider: agent.provider,
sessionId: agent.persistence?.sessionId ?? undefined,
turnId: eventTurnId,
lifecycle: agent.lifecycle, lifecycle: agent.lifecycle,
activeForegroundTurnId: agent.activeForegroundTurnId, activeForegroundTurnId: agent.activeForegroundTurnId,
eventTurnId, eventTurnId,
}, },
"handleStreamEvent: turn_canceled", "agent.manager.turn.canceled",
); );
if (!isForegroundEvent && !agent.pendingReplacement) { if (!isForegroundEvent && !agent.pendingReplacement) {
agent.lifecycle = "idle"; agent.lifecycle = "idle";
@@ -2843,11 +2991,13 @@ export class AgentManager {
this.logger.trace( this.logger.trace(
{ {
agentId: agent.id, agentId: agent.id,
provider: agent.provider,
sessionId: agent.persistence?.sessionId ?? undefined,
turnId: eventTurnId,
lifecycle: agent.lifecycle, lifecycle: agent.lifecycle,
activeForegroundTurnId: agent.activeForegroundTurnId, activeForegroundTurnId: agent.activeForegroundTurnId,
eventTurnId,
}, },
"handleStreamEvent: turn_started", "agent.manager.turn.started",
); );
if (!isForegroundEvent) { if (!isForegroundEvent) {
agent.lifecycle = "running"; agent.lifecycle = "running";
@@ -2993,6 +3143,20 @@ export class AgentManager {
this.syncFeaturesFromSession(agent); this.syncFeaturesFromSession(agent);
this.logger.trace(
{
agentId: agent.id,
provider: agent.provider,
sessionId: agent.persistence?.sessionId ?? undefined,
turnId: agent.activeForegroundTurnId ?? undefined,
lifecycle: agent.lifecycle,
activeForegroundTurnId: agent.activeForegroundTurnId,
pendingPermissions: agent.pendingPermissions.size,
persist: options?.persist !== false,
},
"agent.manager.emit_state",
);
this.dispatch({ this.dispatch({
type: "agent_state", type: "agent_state",
agent: { ...agent }, agent: { ...agent },
@@ -3120,6 +3284,18 @@ export class AgentManager {
event: AgentStreamEvent, event: AgentStreamEvent,
metadata?: { seq?: number; epoch?: string }, metadata?: { seq?: number; epoch?: string },
): void { ): void {
const agent = this.agents.get(agentId);
this.logger.trace(
{
agentId,
provider: event.provider,
sessionId: agent?.persistence?.sessionId ?? undefined,
turnId: getAgentStreamEventTurnId(event),
metadata,
event,
},
"agent.manager.dispatch_stream",
);
this.dispatch({ type: "agent_stream", agentId, event, ...metadata }); this.dispatch({ type: "agent_stream", agentId, event, ...metadata });
} }
@@ -3215,6 +3391,7 @@ export class AgentManager {
private buildLaunchContext(agentId: string): AgentLaunchContext { private buildLaunchContext(agentId: string): AgentLaunchContext {
return { return {
agentId,
env: { env: {
PASEO_AGENT_ID: agentId, PASEO_AGENT_ID: agentId,
}, },
@@ -17,6 +17,19 @@ export function startAgentRun(
logger: Logger, logger: Logger,
options?: StartAgentRunOptions, options?: StartAgentRunOptions,
): { outOfBand: boolean } { ): { outOfBand: boolean } {
const snapshot = agentManager.getAgent(agentId);
logger.trace(
{
agentId,
provider: snapshot?.provider,
providerSessionId: snapshot?.persistence?.sessionId ?? undefined,
turnId: snapshot?.activeForegroundTurnId ?? undefined,
promptType: typeof prompt === "string" ? "string" : "structured",
hasRunOptions: Boolean(options?.runOptions),
replaceRunning: Boolean(options?.replaceRunning),
},
"agent.session.start_stream.request",
);
// Out-of-band commands (e.g. /goal pause) must run WITHOUT canceling an // Out-of-band commands (e.g. /goal pause) must run WITHOUT canceling an
// in-flight turn — replaceAgentRun would interrupt the running turn. The // in-flight turn — replaceAgentRun would interrupt the running turn. The
// intercept lives at this layer so it covers every prompt entrypoint. // intercept lives at this layer so it covers every prompt entrypoint.
@@ -28,12 +41,38 @@ export function startAgentRun(
const iterator = shouldReplace const iterator = shouldReplace
? agentManager.replaceAgentRun(agentId, prompt, runOptions) ? agentManager.replaceAgentRun(agentId, prompt, runOptions)
: agentManager.streamAgent(agentId, prompt, runOptions); : agentManager.streamAgent(agentId, prompt, runOptions);
logger.trace(
{
agentId,
provider: snapshot?.provider,
providerSessionId: snapshot?.persistence?.sessionId ?? undefined,
shouldReplace,
},
"agent.session.start_stream.iterator_returned",
);
void (async () => { void (async () => {
try { try {
for await (const _ of iterator) { for await (const _ of iterator) {
// Events are broadcast via AgentManager subscribers. // Events are broadcast via AgentManager subscribers.
} }
logger.trace(
{
agentId,
provider: snapshot?.provider,
providerSessionId: snapshot?.persistence?.sessionId ?? undefined,
},
"agent.session.iterator.drained",
);
} catch (error) { } catch (error) {
logger.trace(
{
agentId,
provider: snapshot?.provider,
providerSessionId: snapshot?.persistence?.sessionId ?? undefined,
err: error,
},
"agent.session.iterator.error",
);
logger.error({ err: error, agentId }, "Agent stream failed"); logger.error({ err: error, agentId }, "Agent stream failed");
} }
})(); })();
@@ -358,6 +358,10 @@ export type AgentStreamEvent =
timestamp: string; timestamp: string;
}; };
export function getAgentStreamEventTurnId(event: AgentStreamEvent): string | undefined {
return "turnId" in event ? event.turnId : undefined;
}
export type AgentPermissionRequestKind = "tool" | "plan" | "question" | "mode" | "other"; export type AgentPermissionRequestKind = "tool" | "plan" | "question" | "mode" | "other";
export type AgentPermissionUpdate = AgentMetadata; export type AgentPermissionUpdate = AgentMetadata;
@@ -476,6 +480,7 @@ export interface AgentSessionConfig {
} }
export interface AgentLaunchContext { export interface AgentLaunchContext {
agentId?: string;
env?: Record<string, string>; env?: Record<string, string>;
} }
@@ -1,6 +1,6 @@
import { randomUUID } from "node:crypto"; import { randomUUID } from "node:crypto";
import type { AgentStreamEvent } from "./agent-sdk-types.js"; import { getAgentStreamEventTurnId, type AgentStreamEvent } from "./agent-sdk-types.js";
export interface ForegroundTurnWaiter { export interface ForegroundTurnWaiter {
turnId: string; turnId: string;
@@ -105,7 +105,7 @@ export class ForegroundRunState {
event: AgentStreamEvent, event: AgentStreamEvent,
options?: { terminal?: boolean }, options?: { terminal?: boolean },
): void { ): void {
const waiters = this.getMatchingWaiters(agent, eventTurnId(event)); const waiters = this.getMatchingWaiters(agent, getAgentStreamEventTurnId(event));
this.notifyWaiters(waiters, event, { terminal: options?.terminal ?? false }); this.notifyWaiters(waiters, event, { terminal: options?.terminal ?? false });
} }
@@ -226,7 +226,3 @@ function settlePendingForegroundRun(pendingRun: PendingForegroundRun): void {
pendingRun.settled = true; pendingRun.settled = true;
pendingRun.resolveSettled(); pendingRun.resolveSettled();
} }
function eventTurnId(event: AgentStreamEvent): string | undefined {
return (event as { turnId?: string }).turnId;
}
@@ -266,7 +266,7 @@ function prepareConfiguredOverrideSession(
test("ACP setModel only uses config-option fallback when the matching select choice contains the model", async () => { test("ACP setModel only uses config-option fallback when the matching select choice contains the model", async () => {
const logger = createTestLogger(); const logger = createTestLogger();
const childLogger = { warn: vi.fn() }; const childLogger = { trace: vi.fn(), warn: vi.fn() };
vi.spyOn(logger, "child").mockReturnValue(asInternals<typeof logger>(childLogger)); vi.spyOn(logger, "child").mockReturnValue(asInternals<typeof logger>(childLogger));
const session = createSessionWithConfig({}, logger); const session = createSessionWithConfig({}, logger);
const setSessionConfigOption = vi.fn(async () => ({ const setSessionConfigOption = vi.fn(async () => ({
@@ -653,7 +653,7 @@ describe("ACPAgentSession Zed parity", () => {
expect(await validSession.getCurrentMode()).toBe("default"); expect(await validSession.getCurrentMode()).toBe("default");
const logger = createTestLogger(); const logger = createTestLogger();
const childLogger = { warn: vi.fn() }; const childLogger = { trace: vi.fn(), warn: vi.fn() };
vi.spyOn(logger, "child").mockReturnValue(asInternals<typeof logger>(childLogger)); vi.spyOn(logger, "child").mockReturnValue(asInternals<typeof logger>(childLogger));
const invalidSession = createSessionWithConfig( const invalidSession = createSessionWithConfig(
{ modeId: "acceptEdits", model: "opus" }, { modeId: "acceptEdits", model: "opus" },
@@ -54,35 +54,36 @@ import {
} from "@agentclientprotocol/sdk"; } from "@agentclientprotocol/sdk";
import type { Logger } from "pino"; import type { Logger } from "pino";
import type { import {
AgentCapabilityFlags, getAgentStreamEventTurnId,
AgentClient, type AgentCapabilityFlags,
AgentLaunchContext, type AgentClient,
AgentMetadata, type AgentLaunchContext,
AgentMode, type AgentMetadata,
AgentModelDefinition, type AgentMode,
AgentPermissionRequest, type AgentModelDefinition,
AgentPermissionRequestKind, type AgentPermissionRequest,
AgentPermissionResponse, type AgentPermissionRequestKind,
AgentPersistenceHandle, type AgentPermissionResponse,
AgentPromptContentBlock, type AgentPersistenceHandle,
AgentPromptInput, type AgentPromptContentBlock,
AgentRunOptions, type AgentPromptInput,
AgentRunResult, type AgentRunOptions,
AgentRuntimeInfo, type AgentRunResult,
AgentSession, type AgentRuntimeInfo,
AgentSessionConfig, type AgentSession,
AgentSlashCommand, type AgentSessionConfig,
AgentStreamEvent, type AgentSlashCommand,
AgentTimelineItem, type AgentStreamEvent,
AgentUsage, type AgentTimelineItem,
ListModesOptions, type AgentUsage,
ListModelsOptions, type ListModesOptions,
ListPersistedAgentsOptions, type ListModelsOptions,
McpServerConfig, type ListPersistedAgentsOptions,
PersistedAgentDescriptor, type McpServerConfig,
ToolCallDetail, type PersistedAgentDescriptor,
ToolCallTimelineItem, type ToolCallDetail,
type ToolCallTimelineItem,
} from "../agent-sdk-types.js"; } from "../agent-sdk-types.js";
import { import {
createProviderEnvSpec, createProviderEnvSpec,
@@ -265,6 +266,7 @@ interface ACPAgentSessionOptions {
) => Promise<void>; ) => Promise<void>;
capabilities: AgentCapabilityFlags; capabilities: AgentCapabilityFlags;
handle?: AgentPersistenceHandle; handle?: AgentPersistenceHandle;
agentId?: string;
launchEnv?: Record<string, string>; launchEnv?: Record<string, string>;
waitForInitialCommands?: boolean; waitForInitialCommands?: boolean;
initialCommandsWaitTimeoutMs?: number; initialCommandsWaitTimeoutMs?: number;
@@ -519,7 +521,10 @@ export class ACPAgentClient implements AgentClient {
constructor(options: ACPAgentClientOptions) { constructor(options: ACPAgentClientOptions) {
this.provider = options.provider; this.provider = options.provider;
this.capabilities = options.capabilities ?? DEFAULT_ACP_CAPABILITIES; this.capabilities = options.capabilities ?? DEFAULT_ACP_CAPABILITIES;
this.logger = options.logger.child({ module: "agent", provider: options.provider }); this.logger = options.logger.child({
module: "agent",
provider: options.provider,
});
this.runtimeSettings = options.runtimeSettings; this.runtimeSettings = options.runtimeSettings;
this.defaultCommand = options.defaultCommand; this.defaultCommand = options.defaultCommand;
this.defaultModes = options.defaultModes ?? []; this.defaultModes = options.defaultModes ?? [];
@@ -557,6 +562,7 @@ export class ACPAgentClient implements AgentClient {
beforeModeWriter: this.beforeModeWriter, beforeModeWriter: this.beforeModeWriter,
thinkingOptionWriter: this.thinkingOptionWriter, thinkingOptionWriter: this.thinkingOptionWriter,
capabilities: this.capabilities, capabilities: this.capabilities,
agentId: launchContext?.agentId,
launchEnv: launchContext?.env, launchEnv: launchContext?.env,
waitForInitialCommands: this.waitForInitialCommands, waitForInitialCommands: this.waitForInitialCommands,
initialCommandsWaitTimeoutMs: this.initialCommandsWaitTimeoutMs, initialCommandsWaitTimeoutMs: this.initialCommandsWaitTimeoutMs,
@@ -603,6 +609,7 @@ export class ACPAgentClient implements AgentClient {
thinkingOptionWriter: this.thinkingOptionWriter, thinkingOptionWriter: this.thinkingOptionWriter,
capabilities: this.capabilities, capabilities: this.capabilities,
handle, handle,
agentId: launchContext?.agentId,
launchEnv: launchContext?.env, launchEnv: launchContext?.env,
waitForInitialCommands: this.waitForInitialCommands, waitForInitialCommands: this.waitForInitialCommands,
initialCommandsWaitTimeoutMs: this.initialCommandsWaitTimeoutMs, initialCommandsWaitTimeoutMs: this.initialCommandsWaitTimeoutMs,
@@ -842,6 +849,7 @@ export class ACPAgentSession implements AgentSession, ACPClient {
sessionId: string, sessionId: string,
thinkingOptionId: string, thinkingOptionId: string,
) => Promise<void>; ) => Promise<void>;
private readonly agentId?: string;
private readonly launchEnv?: Record<string, string>; private readonly launchEnv?: Record<string, string>;
private readonly subscribers = new Set<(event: AgentStreamEvent) => void>(); private readonly subscribers = new Set<(event: AgentStreamEvent) => void>();
private readonly pendingPermissions = new Map<string, PendingPermission>(); private readonly pendingPermissions = new Map<string, PendingPermission>();
@@ -894,6 +902,7 @@ export class ACPAgentSession implements AgentSession, ACPClient {
this.beforeModeWriter = options.beforeModeWriter; this.beforeModeWriter = options.beforeModeWriter;
this.thinkingOptionWriter = options.thinkingOptionWriter; this.thinkingOptionWriter = options.thinkingOptionWriter;
this.availableModes = options.defaultModes; this.availableModes = options.defaultModes;
this.agentId = options.agentId;
this.launchEnv = options.launchEnv; this.launchEnv = options.launchEnv;
this.initialHandle = options.handle; this.initialHandle = options.handle;
this.config = { ...config, provider: options.provider }; this.config = { ...config, provider: options.provider };
@@ -1567,11 +1576,31 @@ export class ACPAgentSession implements AgentSession, ACPClient {
} }
async sessionUpdate(params: SessionNotification): Promise<void> { async sessionUpdate(params: SessionNotification): Promise<void> {
this.logger.trace(
{
agentId: this.agentId,
provider: this.provider,
sessionId: params.sessionId,
rawEvent: params,
},
"provider.acp.raw_event",
);
if (params.sessionId !== this.sessionId) { if (params.sessionId !== this.sessionId) {
return; return;
} }
const events = this.translateSessionUpdate(params.update); const events = this.translateSessionUpdate(params.update);
this.logger.trace(
{
agentId: this.agentId,
provider: this.provider,
sessionId: this.sessionId,
turnId: this.activeForegroundTurnId ?? undefined,
rawEvent: params,
events,
},
"provider.acp.parsed_event",
);
if (this.replayingHistory) { if (this.replayingHistory) {
for (const event of events) { for (const event of events) {
if (event.type === "timeline") { if (event.type === "timeline") {
@@ -2002,6 +2031,16 @@ export class ACPAgentSession implements AgentSession, ACPClient {
} }
private pushEvent(event: AgentStreamEvent): void { private pushEvent(event: AgentStreamEvent): void {
this.logger.trace(
{
agentId: this.agentId,
provider: this.provider,
sessionId: this.sessionId,
turnId: getAgentStreamEventTurnId(event) ?? this.activeForegroundTurnId ?? undefined,
event,
},
"provider.acp.event_emit",
);
for (const subscriber of this.subscribers) { for (const subscriber of this.subscribers) {
subscriber(event); subscriber(event);
} }
@@ -14,7 +14,11 @@ import { tmpdir } from "node:os";
import path from "node:path"; import path from "node:path";
import pino from "pino"; import pino from "pino";
import type { AgentSession, AgentStreamEvent } from "../../agent-sdk-types.js"; import {
getAgentStreamEventTurnId,
type AgentSession,
type AgentStreamEvent,
} from "../../agent-sdk-types.js";
import { isProviderAvailable } from "../../../daemon-e2e/agent-configs.js"; import { isProviderAvailable } from "../../../daemon-e2e/agent-configs.js";
import { ClaudeAgentClient } from "./agent.js"; import { ClaudeAgentClient } from "./agent.js";
@@ -37,15 +41,14 @@ function isTerminalEvent(event: AgentStreamEvent): boolean {
); );
} }
// turnId is optional on AgentStreamEvent — this narrows to events where it's present.
type EventWithTurnId = AgentStreamEvent & { turnId: string }; type EventWithTurnId = AgentStreamEvent & { turnId: string };
function hasTurnId(event: AgentStreamEvent): event is EventWithTurnId { function hasTurnId(event: AgentStreamEvent): event is EventWithTurnId {
return "turnId" in event && typeof (event as Record<string, unknown>).turnId === "string"; return getAgentStreamEventTurnId(event) !== undefined;
} }
function eventsForTurn(events: AgentStreamEvent[], turnId: string): AgentStreamEvent[] { function eventsForTurn(events: AgentStreamEvent[], turnId: string): AgentStreamEvent[] {
return events.filter((e) => hasTurnId(e) && e.turnId === turnId); return events.filter((e) => getAgentStreamEventTurnId(e) === turnId);
} }
function userMessagesWithText(events: AgentStreamEvent[], text: string): AgentStreamEvent[] { function userMessagesWithText(events: AgentStreamEvent[], text: string): AgentStreamEvent[] {
@@ -157,7 +160,7 @@ function assertInvariants(events: AgentStreamEvent[], foregroundTurnIds: string[
// Invariant 2: Every turn_started has exactly one matching terminal // Invariant 2: Every turn_started has exactly one matching terminal
const turnStartedIds = events const turnStartedIds = events
.filter((e) => e.type === "turn_started" && hasTurnId(e)) .filter((e) => e.type === "turn_started" && hasTurnId(e))
.map((e) => (e as EventWithTurnId).turnId); .map((e) => e.turnId);
for (const turnId of turnStartedIds) { for (const turnId of turnStartedIds) {
const terminals = eventsForTurn(events, turnId).filter(isTerminalEvent); const terminals = eventsForTurn(events, turnId).filter(isTerminalEvent);
@@ -277,7 +280,7 @@ test("Test 3: Lifecycle doesn't get stuck in running", async () => {
// Any turn_started after terminal must have a different turnId // Any turn_started after terminal must have a different turnId
for (const ts of afterTerminal.filter((e) => e.type === "turn_started" && hasTurnId(e))) { for (const ts of afterTerminal.filter((e) => e.type === "turn_started" && hasTurnId(e))) {
expect((ts as EventWithTurnId).turnId).not.toBe(turnId); expect(ts.turnId).not.toBe(turnId);
} }
assertInvariants(events, [turnId]); assertInvariants(events, [turnId]);
@@ -313,8 +316,9 @@ test("Test 4: Autonomous run", async () => {
// Autonomous turn_started with a different turnId // Autonomous turn_started with a different turnId
const autoStarts = afterForeground.filter( const autoStarts = afterForeground.filter(
(e) => e.type === "turn_started" && hasTurnId(e) && e.turnId !== fgTurnId, (e): e is EventWithTurnId =>
) as EventWithTurnId[]; e.type === "turn_started" && hasTurnId(e) && e.turnId !== fgTurnId,
);
if (autoStarts.length === 0) { if (autoStarts.length === 0) {
assertInvariants(events, [fgTurnId]); assertInvariants(events, [fgTurnId]);
return; return;
@@ -42,34 +42,35 @@ import { appendOrReplaceGrowingAssistantMessage, runProviderTurn } from "../prov
import { renderPromptAttachmentAsText } from "../../prompt-attachments.js"; import { renderPromptAttachmentAsText } from "../../prompt-attachments.js";
import { claudeQuery, type ClaudeOptions, type ClaudeQueryFactory } from "./query.js"; import { claudeQuery, type ClaudeOptions, type ClaudeQueryFactory } from "./query.js";
import type { import {
AgentPermissionAction, getAgentStreamEventTurnId,
AgentCapabilityFlags, type AgentPermissionAction,
AgentClient, type AgentCapabilityFlags,
AgentCreateSessionOptions, type AgentClient,
AgentLaunchContext, type AgentCreateSessionOptions,
AgentMetadata, type AgentLaunchContext,
AgentMode, type AgentMetadata,
AgentModelDefinition, type AgentMode,
AgentPermissionRequest, type AgentModelDefinition,
AgentPermissionRequestKind, type AgentPermissionRequest,
AgentPermissionResponse, type AgentPermissionRequestKind,
AgentPermissionUpdate, type AgentPermissionResponse,
AgentPersistenceHandle, type AgentPermissionUpdate,
AgentPromptInput, type AgentPersistenceHandle,
AgentRunOptions, type AgentPromptInput,
AgentRunResult, type AgentRunOptions,
AgentSession, type AgentRunResult,
AgentSessionConfig, type AgentSession,
AgentSlashCommand, type AgentSessionConfig,
AgentStreamEvent, type AgentSlashCommand,
AgentTimelineItem, type AgentStreamEvent,
AgentUsage, type AgentTimelineItem,
AgentRuntimeInfo, type AgentUsage,
ListModelsOptions, type AgentRuntimeInfo,
ListPersistedAgentsOptions, type ListModelsOptions,
McpServerConfig, type ListPersistedAgentsOptions,
PersistedAgentDescriptor, type McpServerConfig,
type PersistedAgentDescriptor,
} from "../../agent-sdk-types.js"; } from "../../agent-sdk-types.js";
import { import {
createProviderEnv, createProviderEnv,
@@ -250,6 +251,7 @@ interface ClaudeAgentSessionOptions {
defaults?: { agents?: Record<string, AgentDefinition> }; defaults?: { agents?: Record<string, AgentDefinition> };
runtimeSettings?: ProviderRuntimeSettings; runtimeSettings?: ProviderRuntimeSettings;
handle?: AgentPersistenceHandle; handle?: AgentPersistenceHandle;
agentId?: string;
launchEnv?: Record<string, string>; launchEnv?: Record<string, string>;
persistSession?: boolean; persistSession?: boolean;
logger: Logger; logger: Logger;
@@ -1152,8 +1154,6 @@ export function readEventIdentifiers(message: SDKMessage): EventIdentifiers {
}; };
} }
const claudeDebug = process.env.PASEO_CLAUDE_DEBUG === "1";
export class ClaudeAgentClient implements AgentClient { export class ClaudeAgentClient implements AgentClient {
readonly provider = "claude" as const; readonly provider = "claude" as const;
readonly capabilities = CLAUDE_CAPABILITIES; readonly capabilities = CLAUDE_CAPABILITIES;
@@ -1181,6 +1181,7 @@ export class ClaudeAgentClient implements AgentClient {
return new ClaudeAgentSession(claudeConfig, { return new ClaudeAgentSession(claudeConfig, {
defaults: this.defaults, defaults: this.defaults,
runtimeSettings: this.runtimeSettings, runtimeSettings: this.runtimeSettings,
agentId: launchContext?.agentId,
launchEnv: launchContext?.env, launchEnv: launchContext?.env,
persistSession: options?.persistSession, persistSession: options?.persistSession,
logger: this.logger, logger: this.logger,
@@ -1209,6 +1210,7 @@ export class ClaudeAgentClient implements AgentClient {
defaults: this.defaults, defaults: this.defaults,
runtimeSettings: this.runtimeSettings, runtimeSettings: this.runtimeSettings,
handle, handle,
agentId: launchContext?.agentId,
launchEnv: launchContext?.env, launchEnv: launchContext?.env,
logger: this.logger, logger: this.logger,
queryFactory: this.queryFactory, queryFactory: this.queryFactory,
@@ -1477,6 +1479,7 @@ class ClaudeAgentSession implements AgentSession {
private readonly config: ClaudeAgentConfig; private readonly config: ClaudeAgentConfig;
private readonly launchEnv?: Record<string, string>; private readonly launchEnv?: Record<string, string>;
private readonly agentId?: string;
private readonly defaults?: { agents?: Record<string, AgentDefinition> }; private readonly defaults?: { agents?: Record<string, AgentDefinition> };
private readonly runtimeSettings?: ProviderRuntimeSettings; private readonly runtimeSettings?: ProviderRuntimeSettings;
private readonly persistSession?: boolean; private readonly persistSession?: boolean;
@@ -1526,10 +1529,11 @@ class ClaudeAgentSession implements AgentSession {
constructor(config: ClaudeAgentConfig, options: ClaudeAgentSessionOptions) { constructor(config: ClaudeAgentConfig, options: ClaudeAgentSessionOptions) {
this.config = config; this.config = config;
this.launchEnv = options.launchEnv; this.launchEnv = options.launchEnv;
this.agentId = options.agentId;
this.defaults = options.defaults; this.defaults = options.defaults;
this.runtimeSettings = options.runtimeSettings; this.runtimeSettings = options.runtimeSettings;
this.persistSession = options.persistSession; this.persistSession = options.persistSession;
this.logger = options.logger; this.logger = options.logger.child({ agentId: this.agentId });
this.queryFactory = options.queryFactory; this.queryFactory = options.queryFactory;
this.resolveBinary = options.resolveBinary; this.resolveBinary = options.resolveBinary;
const handle = options.handle; const handle = options.handle;
@@ -1869,13 +1873,16 @@ class ClaudeAgentSession implements AgentSession {
async close(): Promise<void> { async close(): Promise<void> {
this.logger.trace( this.logger.trace(
{ {
claudeSessionId: this.claudeSessionId, agentId: this.agentId,
provider: "claude",
sessionId: this.claudeSessionId,
turnId: this.activeForegroundTurnId ?? this.autonomousTurn?.id ?? undefined,
turnState: this.turnState, turnState: this.turnState,
hasQuery: Boolean(this.query), hasQuery: Boolean(this.query),
hasInput: Boolean(this.input), hasInput: Boolean(this.input),
hasActiveForegroundTurnId: Boolean(this.activeForegroundTurnId), hasActiveForegroundTurnId: Boolean(this.activeForegroundTurnId),
}, },
"Claude session close: start", "provider.claude.session_close.start",
); );
this.closed = true; this.closed = true;
this.rejectAllPendingPermissions(new Error("Claude session closed")); this.rejectAllPendingPermissions(new Error("Claude session closed"));
@@ -1910,8 +1917,13 @@ class ClaudeAgentSession implements AgentSession {
} }
} }
this.logger.trace( this.logger.trace(
{ claudeSessionId: this.claudeSessionId, turnState: this.turnState }, {
"Claude session close: completed", agentId: this.agentId,
provider: "claude",
sessionId: this.claudeSessionId,
turnState: this.turnState,
},
"provider.claude.session_close.complete",
); );
} }
@@ -2188,16 +2200,41 @@ class ClaudeAgentSession implements AgentSession {
label: string, label: string,
): Promise<void> { ): Promise<void> {
if (!promise) { if (!promise) {
this.logger.trace({ label }, "Claude query operation skipped (no promise)"); this.logger.trace(
{
agentId: this.agentId,
provider: "claude",
sessionId: this.claudeSessionId,
turnId: this.activeForegroundTurnId ?? this.autonomousTurn?.id ?? undefined,
label,
},
"provider.claude.query_operation.skip",
);
return; return;
} }
const startedAt = Date.now(); const startedAt = Date.now();
this.logger.trace({ label }, "Claude query operation wait start"); this.logger.trace(
{
agentId: this.agentId,
provider: "claude",
sessionId: this.claudeSessionId,
turnId: this.activeForegroundTurnId ?? this.autonomousTurn?.id ?? undefined,
label,
},
"provider.claude.query_operation.start",
);
try { try {
await withTimeout(promise, 3_000, "timeout"); await withTimeout(promise, 3_000, "timeout");
this.logger.trace( this.logger.trace(
{ label, durationMs: Date.now() - startedAt }, {
"Claude query operation settled", agentId: this.agentId,
provider: "claude",
sessionId: this.claudeSessionId,
turnId: this.activeForegroundTurnId ?? this.autonomousTurn?.id ?? undefined,
label,
durationMs: Date.now() - startedAt,
},
"provider.claude.query_operation.settled",
); );
} catch (error) { } catch (error) {
this.logger.warn({ err: error, label }, "Claude query operation did not settle cleanly"); this.logger.warn({ err: error, label }, "Claude query operation did not settle cleanly");
@@ -2593,7 +2630,16 @@ class ClaudeAgentSession implements AgentSession {
} }
const pump = this.runQueryPump().catch((error) => { const pump = this.runQueryPump().catch((error) => {
this.logger.trace({ err: error }, "Claude query pump exited unexpectedly"); this.logger.trace(
{
agentId: this.agentId,
provider: "claude",
sessionId: this.claudeSessionId,
turnId: this.activeForegroundTurnId ?? this.autonomousTurn?.id ?? undefined,
err: error,
},
"provider.claude.query_pump.exit_unexpected",
);
}); });
this.queryPumpPromise = pump; this.queryPumpPromise = pump;
@@ -2609,24 +2655,34 @@ class ClaudeAgentSession implements AgentSession {
try { try {
activeQuery = await this.ensureQuery(); activeQuery = await this.ensureQuery();
} catch (error) { } catch (error) {
this.logger.trace({ err: error }, "Failed to initialize Claude query pump"); this.logger.trace(
{
agentId: this.agentId,
provider: "claude",
sessionId: this.claudeSessionId,
turnId: this.activeForegroundTurnId ?? this.autonomousTurn?.id ?? undefined,
err: error,
},
"provider.claude.query_pump.init_failed",
);
this.failActiveTurns(error instanceof Error ? error.message : "Claude stream failed"); this.failActiveTurns(error instanceof Error ? error.message : "Claude stream failed");
return; return;
} }
let consecutiveInterruptAbortRecoveries = 0; let consecutiveInterruptAbortRecoveries = 0;
const logRawMessage = (message: SDKMessage): void => { const logRawMessage = (message: SDKMessage): void => {
if (!claudeDebug) {
return;
}
this.logger.trace( this.logger.trace(
{ {
claudeSessionId: this.claudeSessionId, agentId: this.agentId,
provider: "claude",
sessionId: this.claudeSessionId,
turnId: this.activeForegroundTurnId ?? this.autonomousTurn?.id ?? undefined,
messageType: message.type, messageType: message.type,
messageSubtype: "subtype" in message ? message.subtype : undefined, messageSubtype: "subtype" in message ? message.subtype : undefined,
messageUuid: "uuid" in message ? message.uuid : undefined, messageUuid: "uuid" in message ? message.uuid : undefined,
rawEvent: message,
}, },
"Claude query pump: raw SDK message", "provider.claude.raw_event",
); );
}; };
const handlePumpedMessage = async (message: SDKMessage): Promise<boolean> => { const handlePumpedMessage = async (message: SDKMessage): Promise<boolean> => {
@@ -2739,16 +2795,18 @@ class ClaudeAgentSession implements AgentSession {
const turnId = this.activeForegroundTurnId ?? this.autonomousTurn?.id ?? null; const turnId = this.activeForegroundTurnId ?? this.autonomousTurn?.id ?? null;
const identifiers = readEventIdentifiers(message); const identifiers = readEventIdentifiers(message);
if (claudeDebug) { this.logger.trace(
this.logger.trace( {
{ agentId: this.agentId,
claudeSessionId: this.claudeSessionId, provider: "claude",
messageType: message.type, sessionId: this.claudeSessionId,
turnId, turnId: turnId ?? undefined,
}, messageType: message.type,
"Claude query pump: SDK message", identifiers,
); rawEvent: message,
} },
"provider.claude.parsed_event",
);
const messageEvents = this.translateMessageToEvents(message, { const messageEvents = this.translateMessageToEvents(message, {
suppressAssistantText: true, suppressAssistantText: true,
@@ -2816,7 +2874,6 @@ class ClaudeAgentSession implements AgentSession {
this.logger.warn( this.logger.warn(
{ {
claudeSessionId: this.claudeSessionId,
error: staleResumeError, error: staleResumeError,
}, },
"Claude resumed session no longer exists; invalidating persisted session", "Claude resumed session no longer exists; invalidating persisted session",
@@ -2846,7 +2903,15 @@ class ClaudeAgentSession implements AgentSession {
private async interruptActiveTurn(): Promise<void> { private async interruptActiveTurn(): Promise<void> {
const queryToInterrupt = this.query; const queryToInterrupt = this.query;
if (!queryToInterrupt || typeof queryToInterrupt.interrupt !== "function") { if (!queryToInterrupt || typeof queryToInterrupt.interrupt !== "function") {
this.logger.trace("interruptActiveTurn: no query to interrupt"); this.logger.trace(
{
agentId: this.agentId,
provider: "claude",
sessionId: this.claudeSessionId,
turnId: this.activeForegroundTurnId ?? this.autonomousTurn?.id ?? undefined,
},
"provider.claude.interrupt.no_query",
);
return; return;
} }
this.pendingInterruptAbort = true; this.pendingInterruptAbort = true;
@@ -3455,6 +3520,16 @@ class ClaudeAgentSession implements AgentSession {
private notifySubscribers(event: AgentStreamEvent): void { private notifySubscribers(event: AgentStreamEvent): void {
const turnId = this.activeForegroundTurnId ?? this.autonomousTurn?.id; const turnId = this.activeForegroundTurnId ?? this.autonomousTurn?.id;
const tagged = turnId ? { ...event, turnId } : event; const tagged = turnId ? { ...event, turnId } : event;
this.logger.trace(
{
agentId: this.agentId,
provider: "claude",
sessionId: this.claudeSessionId,
turnId: getAgentStreamEventTurnId(tagged),
event: tagged,
},
"provider.claude.event_emit",
);
for (const callback of this.subscribers) { for (const callback of this.subscribers) {
try { try {
callback(tagged); callback(tagged);
@@ -1,32 +1,33 @@
import type { import {
AgentPermissionAction, getAgentStreamEventTurnId,
AgentCapabilityFlags, type AgentPermissionAction,
AgentClient, type AgentCapabilityFlags,
AgentCreateSessionOptions, type AgentClient,
AgentFeature, type AgentCreateSessionOptions,
AgentLaunchContext, type AgentFeature,
AgentMode, type AgentLaunchContext,
AgentModelDefinition, type AgentMode,
McpServerConfig, type AgentModelDefinition,
AgentPersistenceHandle, type McpServerConfig,
AgentPermissionRequest, type AgentPersistenceHandle,
AgentPermissionResponse, type AgentPermissionRequest,
AgentPermissionResult, type AgentPermissionResponse,
AgentPromptContentBlock, type AgentPermissionResult,
AgentPromptInput, type AgentPromptContentBlock,
AgentRunOptions, type AgentPromptInput,
AgentRunResult, type AgentRunOptions,
AgentRuntimeInfo, type AgentRunResult,
AgentSession, type AgentRuntimeInfo,
AgentSessionConfig, type AgentSession,
AgentSlashCommand, type AgentSessionConfig,
AgentStreamEvent, type AgentSlashCommand,
AgentTimelineItem, type AgentStreamEvent,
ToolCallTimelineItem, type AgentTimelineItem,
AgentUsage, type ToolCallTimelineItem,
ListModelsOptions, type AgentUsage,
ListPersistedAgentsOptions, type ListModelsOptions,
PersistedAgentDescriptor, type ListPersistedAgentsOptions,
type PersistedAgentDescriptor,
} from "../agent-sdk-types.js"; } from "../agent-sdk-types.js";
import type { Logger } from "pino"; import type { Logger } from "pino";
import { homedir } from "node:os"; import { homedir } from "node:os";
@@ -55,7 +56,10 @@ import { findExecutable, isCommandAvailable } from "../../../utils/executable.js
import { spawnProcess } from "../../../utils/spawn.js"; import { spawnProcess } from "../../../utils/spawn.js";
import { extractCodexTerminalSessionId, nonEmptyString } from "./tool-call-mapper-utils.js"; import { extractCodexTerminalSessionId, nonEmptyString } from "./tool-call-mapper-utils.js";
import { buildCodexFeatures, codexModelSupportsFastMode } from "./codex-feature-definitions.js"; import { buildCodexFeatures, codexModelSupportsFastMode } from "./codex-feature-definitions.js";
import { CodexAppServerClient } from "./codex/app-server-transport.js"; import {
CodexAppServerClient,
type CodexAppServerTraceContext,
} from "./codex/app-server-transport.js";
import { import {
renderProviderImageOutputAsAssistantMarkdown, renderProviderImageOutputAsAssistantMarkdown,
type ProviderImageOutput, type ProviderImageOutput,
@@ -183,6 +187,7 @@ interface CodexAppServerAgentDeps {
_createCodexClient?: ( _createCodexClient?: (
child: ChildProcessWithoutNullStreams, child: ChildProcessWithoutNullStreams,
logger: Logger, logger: Logger,
getTraceContext: () => CodexAppServerTraceContext,
) => CodexAppServerClientLike; ) => CodexAppServerClientLike;
} }
@@ -2653,8 +2658,13 @@ class CodexAppServerAgentSession implements AgentSession {
private readonly deps: CodexAppServerAgentDeps = {}, private readonly deps: CodexAppServerAgentDeps = {},
private readonly ephemeral: boolean = false, private readonly ephemeral: boolean = false,
private readonly goalsEnabled: boolean = false, private readonly goalsEnabled: boolean = false,
private readonly agentId?: string,
) { ) {
this.logger = logger.child({ module: "agent", provider: CODEX_PROVIDER }); this.logger = logger.child({
module: "agent",
provider: CODEX_PROVIDER,
agentId: this.agentId,
});
if (config.modeId === undefined) { if (config.modeId === undefined) {
throw new Error("Codex agent requires modeId to be specified"); throw new Error("Codex agent requires modeId to be specified");
} }
@@ -2691,7 +2701,7 @@ class CodexAppServerAgentSession implements AgentSession {
async connect(): Promise<void> { async connect(): Promise<void> {
if (this.connected) return; if (this.connected) return;
const child = await this.spawnAppServer(); const child = await this.spawnAppServer();
this.client = new CodexAppServerClient(child, this.logger); this.client = new CodexAppServerClient(child, this.logger, () => this.traceContext());
this.client.setNotificationHandler((method, params) => this.handleNotification(method, params)); this.client.setNotificationHandler((method, params) => this.handleNotification(method, params));
this.registerRequestHandlers(); this.registerRequestHandlers();
@@ -2709,6 +2719,14 @@ class CodexAppServerAgentSession implements AgentSession {
this.connected = true; this.connected = true;
} }
private traceContext(): CodexAppServerTraceContext {
return {
agentId: this.agentId,
sessionId: this.currentThreadId ?? undefined,
turnId: this.activeForegroundTurnId ?? undefined,
};
}
private async loadCollaborationModes(): Promise<void> { private async loadCollaborationModes(): Promise<void> {
if (!this.client) return; if (!this.client) return;
try { try {
@@ -2729,7 +2747,16 @@ class CodexAppServerAgentSession implements AgentSession {
}; };
}); });
} catch (error) { } catch (error) {
this.logger.trace({ error }, "Failed to load collaboration modes"); this.logger.trace(
{
agentId: this.agentId,
provider: CODEX_PROVIDER,
sessionId: this.currentThreadId,
turnId: this.activeForegroundTurnId ?? undefined,
error,
},
"provider.codex.metadata.collaboration_modes_failed",
);
this.collaborationModes = []; this.collaborationModes = [];
} }
this.refreshResolvedCollaborationMode(); this.refreshResolvedCollaborationMode();
@@ -2761,7 +2788,16 @@ class CodexAppServerAgentSession implements AgentSession {
} }
this.cachedSkills = skills; this.cachedSkills = skills;
} catch (error) { } catch (error) {
this.logger.trace({ error }, "Failed to load skills list"); this.logger.trace(
{
agentId: this.agentId,
provider: CODEX_PROVIDER,
sessionId: this.currentThreadId,
turnId: this.activeForegroundTurnId ?? undefined,
error,
},
"provider.codex.metadata.skills_failed",
);
this.cachedSkills = []; this.cachedSkills = [];
} }
} }
@@ -3657,6 +3693,16 @@ class CodexAppServerAgentSession implements AgentSession {
private notifySubscribers(event: AgentStreamEvent): void { private notifySubscribers(event: AgentStreamEvent): void {
const turnId = this.activeForegroundTurnId; const turnId = this.activeForegroundTurnId;
const tagged = turnId ? { ...event, turnId } : event; const tagged = turnId ? { ...event, turnId } : event;
this.logger.trace(
{
agentId: this.agentId,
provider: CODEX_PROVIDER,
sessionId: this.currentThreadId,
turnId: getAgentStreamEventTurnId(tagged),
event: tagged,
},
"provider.codex.event_emit",
);
for (const callback of this.subscribers) { for (const callback of this.subscribers) {
try { try {
callback(tagged); callback(tagged);
@@ -3672,6 +3718,7 @@ class CodexAppServerAgentSession implements AgentSession {
private handleNotification(method: string, params: unknown): void { private handleNotification(method: string, params: unknown): void {
const parsed = CodexNotificationSchema.parse({ method, params }); const parsed = CodexNotificationSchema.parse({ method, params });
this.traceParsedNotification(method, params, parsed);
switch (parsed.kind) { switch (parsed.kind) {
case "thread_started": case "thread_started":
this.handleThreadStartedNotification(parsed); this.handleThreadStartedNotification(parsed);
@@ -3728,6 +3775,25 @@ class CodexAppServerAgentSession implements AgentSession {
} }
} }
private traceParsedNotification(
method: string,
params: unknown,
parsed: z.infer<typeof CodexNotificationSchema>,
): void {
this.logger.trace(
{
agentId: this.agentId,
provider: CODEX_PROVIDER,
sessionId: this.currentThreadId,
turnId: this.activeForegroundTurnId ?? undefined,
method,
params,
parsed,
},
"provider.codex.parsed_event",
);
}
private getSubAgentCallIdForThread(threadId: string | null | undefined): string | null { private getSubAgentCallIdForThread(threadId: string | null | undefined): string | null {
if (!threadId || threadId === this.currentThreadId) { if (!threadId || threadId === this.currentThreadId) {
return null; return null;
@@ -4320,7 +4386,17 @@ class CodexAppServerAgentSession implements AgentSession {
return; return;
} }
this.warnedUnknownNotificationMethods.add(method); this.warnedUnknownNotificationMethods.add(method);
this.logger.trace({ method, params }, "Unhandled Codex app-server notification method"); this.logger.trace(
{
agentId: this.agentId,
provider: CODEX_PROVIDER,
sessionId: this.currentThreadId,
turnId: this.activeForegroundTurnId ?? undefined,
method,
params,
},
"provider.codex.event_unhandled",
);
} }
private warnInvalidNotificationPayload(method: string, params: unknown): void { private warnInvalidNotificationPayload(method: string, params: unknown): void {
@@ -4598,7 +4674,14 @@ export class CodexAppServerAgentClient implements AgentClient {
const launchPrefix = await resolveCodexLaunchPrefix(this.runtimeSettings); const launchPrefix = await resolveCodexLaunchPrefix(this.runtimeSettings);
const versionOutput = await resolveBinaryVersion(launchPrefix.command); const versionOutput = await resolveBinaryVersion(launchPrefix.command);
const enabled = codexVersionAtLeast(versionOutput, CODEX_GOALS_MIN_VERSION); const enabled = codexVersionAtLeast(versionOutput, CODEX_GOALS_MIN_VERSION);
this.logger.trace({ versionOutput, enabled }, "Resolved codex goals feature gate"); this.logger.trace(
{
provider: CODEX_PROVIDER,
versionOutput,
enabled,
},
"provider.codex.config.goals_resolved",
);
return enabled; return enabled;
} catch (error) { } catch (error) {
this.logger.warn({ err: error }, "Failed to probe codex version for goals gate"); this.logger.warn({ err: error }, "Failed to probe codex version for goals gate");
@@ -4611,7 +4694,7 @@ export class CodexAppServerAgentClient implements AgentClient {
private async spawnAppServer( private async spawnAppServer(
launchEnv?: Record<string, string>, launchEnv?: Record<string, string>,
options?: { goalsEnabled?: boolean }, options?: { goalsEnabled?: boolean; agentId?: string },
): Promise<ChildProcessWithoutNullStreams> { ): Promise<ChildProcessWithoutNullStreams> {
const launchPrefix = await resolveCodexLaunchPrefix(this.runtimeSettings); const launchPrefix = await resolveCodexLaunchPrefix(this.runtimeSettings);
const args = [...launchPrefix.args, "app-server"]; const args = [...launchPrefix.args, "app-server"];
@@ -4620,10 +4703,12 @@ export class CodexAppServerAgentClient implements AgentClient {
} }
this.logger.trace( this.logger.trace(
{ {
agentId: options?.agentId,
provider: CODEX_PROVIDER,
launchPrefix, launchPrefix,
goalsEnabled: options?.goalsEnabled === true, goalsEnabled: options?.goalsEnabled === true,
}, },
"Spawning Codex app server", "provider.codex.spawn",
); );
const child = spawnProcess(launchPrefix.command, args, { const child = spawnProcess(launchPrefix.command, args, {
detached: process.platform !== "win32", detached: process.platform !== "win32",
@@ -4655,10 +4740,12 @@ export class CodexAppServerAgentClient implements AgentClient {
sessionConfig, sessionConfig,
null, null,
this.logger, this.logger,
() => this.spawnAppServer(launchContext?.env, { goalsEnabled }), () =>
this.spawnAppServer(launchContext?.env, { goalsEnabled, agentId: launchContext?.agentId }),
this.sessionDeps(), this.sessionDeps(),
options?.persistSession === false, options?.persistSession === false,
goalsEnabled, goalsEnabled,
launchContext?.agentId,
); );
await session.connect(); await session.connect();
return session; return session;
@@ -4681,10 +4768,12 @@ export class CodexAppServerAgentClient implements AgentClient {
merged, merged,
handle, handle,
this.logger, this.logger,
() => this.spawnAppServer(launchContext?.env, { goalsEnabled }), () =>
this.spawnAppServer(launchContext?.env, { goalsEnabled, agentId: launchContext?.agentId }),
this.sessionDeps(), this.sessionDeps(),
false, false,
goalsEnabled, goalsEnabled,
launchContext?.agentId,
); );
await session.connect(); await session.connect();
return session; return session;
@@ -4695,7 +4784,7 @@ export class CodexAppServerAgentClient implements AgentClient {
): Promise<PersistedAgentDescriptor[]> { ): Promise<PersistedAgentDescriptor[]> {
const child = await this.spawnAppServer(); const child = await this.spawnAppServer();
const client = const client =
this.deps._createCodexClient?.(child, this.logger) ?? this.deps._createCodexClient?.(child, this.logger, () => ({})) ??
new CodexAppServerClient(child, this.logger); new CodexAppServerClient(child, this.logger);
try { try {
@@ -35,6 +35,12 @@ interface PendingRequest {
type RequestHandler = (params: unknown) => unknown; type RequestHandler = (params: unknown) => unknown;
type NotificationHandler = (method: string, params: unknown) => void; type NotificationHandler = (method: string, params: unknown) => void;
export interface CodexAppServerTraceContext {
agentId?: string;
sessionId?: string;
turnId?: string;
}
function isRecord(value: unknown): value is Record<string, unknown> { function isRecord(value: unknown): value is Record<string, unknown> {
return value != null && typeof value === "object" && !Array.isArray(value); return value != null && typeof value === "object" && !Array.isArray(value);
} }
@@ -54,6 +60,24 @@ function isJsonRpcNotification(msg: unknown): msg is JsonRpcNotification {
return typeof msg.method === "string" && msg.id === undefined; return typeof msg.method === "string" && msg.id === undefined;
} }
function readProviderSessionId(params: unknown): string | undefined {
if (!isRecord(params)) {
return undefined;
}
return typeof params.threadId === "string" ? params.threadId : undefined;
}
function readProviderTurnId(params: unknown): string | undefined {
if (!isRecord(params)) {
return undefined;
}
if (typeof params.turnId === "string") {
return params.turnId;
}
const turn = params.turn;
return isRecord(turn) && typeof turn.id === "string" ? turn.id : undefined;
}
export class CodexAppServerClient { export class CodexAppServerClient {
private readonly rl: readline.Interface; private readonly rl: readline.Interface;
private readonly pending = new Map<number, PendingRequest>(); private readonly pending = new Map<number, PendingRequest>();
@@ -66,6 +90,7 @@ export class CodexAppServerClient {
constructor( constructor(
private readonly child: ChildProcessWithoutNullStreams, private readonly child: ChildProcessWithoutNullStreams,
private readonly logger: Logger, private readonly logger: Logger,
private readonly getTraceContext: () => CodexAppServerTraceContext = () => ({}),
) { ) {
this.rl = readline.createInterface({ input: child.stdout }); this.rl = readline.createInterface({ input: child.stdout });
this.rl.on("line", (line) => { this.rl.on("line", (line) => {
@@ -224,6 +249,19 @@ export class CodexAppServerClient {
} }
if (isJsonRpcNotification(raw)) { if (isJsonRpcNotification(raw)) {
const traceContext = this.getTraceContext();
this.logger.trace(
{
provider: "codex",
agentId: traceContext.agentId,
sessionId: traceContext.sessionId ?? readProviderSessionId(raw.params),
turnId: traceContext.turnId ?? readProviderTurnId(raw.params),
method: raw.method,
params: raw.params,
rawEvent: raw,
},
"provider.codex.raw_event",
);
this.notificationHandler?.(raw.method, raw.params); this.notificationHandler?.(raw.method, raw.params);
} }
} }
@@ -13,33 +13,34 @@ import { findExecutable, isCommandAvailable } from "../../../utils/executable.js
import type { Logger } from "pino"; import type { Logger } from "pino";
import { z } from "zod"; import { z } from "zod";
import type { import {
AgentCapabilityFlags, getAgentStreamEventTurnId,
AgentClient, type AgentCapabilityFlags,
AgentCreateSessionOptions, type AgentClient,
AgentLaunchContext, type AgentCreateSessionOptions,
AgentMode, type AgentLaunchContext,
AgentModelDefinition, type AgentMode,
AgentPermissionRequest, type AgentModelDefinition,
AgentPermissionResponse, type AgentPermissionRequest,
AgentPersistenceHandle, type AgentPermissionResponse,
AgentPromptInput, type AgentPersistenceHandle,
AgentRunOptions, type AgentPromptInput,
AgentRunResult, type AgentRunOptions,
AgentRuntimeInfo, type AgentRunResult,
AgentSession, type AgentRuntimeInfo,
AgentSessionConfig, type AgentSession,
AgentSlashCommand, type AgentSessionConfig,
AgentStreamEvent, type AgentSlashCommand,
AgentTimelineItem, type AgentStreamEvent,
AgentUsage, type AgentTimelineItem,
ListModelsOptions, type AgentUsage,
ListModesOptions, type ListModelsOptions,
ListPersistedAgentsOptions, type ListModesOptions,
McpServerConfig, type ListPersistedAgentsOptions,
PersistedAgentDescriptor, type McpServerConfig,
ToolCallDetail, type PersistedAgentDescriptor,
ToolCallTimelineItem, type ToolCallDetail,
type ToolCallTimelineItem,
} from "../agent-sdk-types.js"; } from "../agent-sdk-types.js";
import { createProviderEnvSpec, type ProviderRuntimeSettings } from "../provider-launch-config.js"; import { createProviderEnvSpec, type ProviderRuntimeSettings } from "../provider-launch-config.js";
import { withTimeout } from "../../../utils/promise-timeout.js"; import { withTimeout } from "../../../utils/promise-timeout.js";
@@ -966,7 +967,7 @@ export class OpenCodeAgentClient implements AgentClient {
async createSession( async createSession(
config: AgentSessionConfig, config: AgentSessionConfig,
_launchContext?: AgentLaunchContext, launchContext?: AgentLaunchContext,
options?: AgentCreateSessionOptions, options?: AgentCreateSessionOptions,
): Promise<AgentSession> { ): Promise<AgentSession> {
const openCodeConfig = this.assertConfig(config); const openCodeConfig = this.assertConfig(config);
@@ -1004,6 +1005,7 @@ export class OpenCodeAgentClient implements AgentClient {
new Map(this.modelContextWindows), new Map(this.modelContextWindows),
acquisition.release, acquisition.release,
options?.persistSession, options?.persistSession,
launchContext?.agentId,
); );
} catch (error) { } catch (error) {
acquisition.release(); acquisition.release();
@@ -1014,7 +1016,7 @@ export class OpenCodeAgentClient implements AgentClient {
async resumeSession( async resumeSession(
handle: AgentPersistenceHandle, handle: AgentPersistenceHandle,
overrides?: Partial<AgentSessionConfig>, overrides?: Partial<AgentSessionConfig>,
_launchContext?: AgentLaunchContext, launchContext?: AgentLaunchContext,
): Promise<AgentSession> { ): Promise<AgentSession> {
const cwd = overrides?.cwd ?? (handle.metadata?.cwd as string); const cwd = overrides?.cwd ?? (handle.metadata?.cwd as string);
if (!cwd) { if (!cwd) {
@@ -1046,6 +1048,7 @@ export class OpenCodeAgentClient implements AgentClient {
new Map(this.modelContextWindows), new Map(this.modelContextWindows),
acquisition.release, acquisition.release,
undefined, undefined,
launchContext?.agentId,
); );
} catch (error) { } catch (error) {
acquisition.release(); acquisition.release();
@@ -1277,6 +1280,28 @@ export interface OpenCodeEventTranslationState {
onAssistantModelContextWindowResolved?: (contextWindowMaxTokens: number) => void; onAssistantModelContextWindowResolved?: (contextWindowMaxTokens: number) => void;
} }
interface OpenCodeTraceData {
turnId?: string;
[key: string]: unknown;
}
type OpenCodeTraceMessage =
| "provider.opencode.prompt_async.start"
| "provider.opencode.prompt_async.response"
| "provider.opencode.prompt_async.throw"
| "provider.opencode.subscribe.start"
| "provider.opencode.subscribe.ready"
| "provider.opencode.stream.eof"
| "provider.opencode.turn.fail_eof"
| "provider.opencode.subscribe.error"
| "provider.opencode.raw_event"
| "provider.opencode.event.skip"
| "provider.opencode.parsed_event"
| "provider.opencode.parsed_event.skip_active"
| "provider.opencode.event.terminal"
| "provider.opencode.finish_foreground_turn"
| "provider.opencode.event_emit";
type OpenCodeToolPartEventPart = Extract< type OpenCodeToolPartEventPart = Extract<
Extract<OpenCodeEvent, { type: "message.part.updated" }>["properties"]["part"], Extract<OpenCodeEvent, { type: "message.part.updated" }>["properties"]["part"],
{ type: "tool" } { type: "tool" }
@@ -2141,18 +2166,6 @@ function createDeferred<T>(): Deferred<T> {
return { promise, resolve, reject }; return { promise, resolve, reject };
} }
const OPENCODE_TRACE_ENABLED = process.env.PASEO_OPENCODE_TRACE === "1";
function traceOpenCode(tag: string, data: Record<string, unknown> = {}): void {
if (!OPENCODE_TRACE_ENABLED) return;
const line = JSON.stringify({ ts: new Date().toISOString(), tag, ...data }, (_k, v) => {
if (v instanceof Error) return { name: v.name, message: v.message, stack: v.stack };
if (typeof v === "bigint") return v.toString();
return v;
});
process.stderr.write(`[opencode-trace] ${line}\n`);
}
function unwrapOpenCodeGlobalEvent(event: unknown): OpenCodeEvent | null { function unwrapOpenCodeGlobalEvent(event: unknown): OpenCodeEvent | null {
const record = readOpenCodeRecord(event); const record = readOpenCodeRecord(event);
if (!record) { if (!record) {
@@ -2217,11 +2230,12 @@ class OpenCodeAgentSession implements AgentSession {
modelContextWindowsByModelKey: ReadonlyMap<string, number> = new Map(), modelContextWindowsByModelKey: ReadonlyMap<string, number> = new Map(),
releaseServer?: () => void, releaseServer?: () => void,
persistSession = true, persistSession = true,
private readonly agentId?: string,
) { ) {
this.config = config; this.config = config;
this.client = client; this.client = client;
this.sessionId = sessionId; this.sessionId = sessionId;
this.logger = logger; this.logger = logger.child({ agentId: this.agentId });
this.modelContextWindowsByModelKey = modelContextWindowsByModelKey; this.modelContextWindowsByModelKey = modelContextWindowsByModelKey;
this.currentMode = normalizeOpenCodeModeId(config.modeId); this.currentMode = normalizeOpenCodeModeId(config.modeId);
this.releaseServer = releaseServer ?? null; this.releaseServer = releaseServer ?? null;
@@ -2483,7 +2497,7 @@ class OpenCodeAgentSession implements AgentSession {
// SDK input validation) is caught alongside async rejections. A plain // SDK input validation) is caught alongside async rejections. A plain
// `.then().catch()` chain would let a sync throw escape unhandled. // `.then().catch()` chain would let a sync throw escape unhandled.
void (async () => { void (async () => {
traceOpenCode("promptAsync.start", { this.traceOpenCode("provider.opencode.prompt_async.start", {
turnId, turnId,
sessionId: this.sessionId, sessionId: this.sessionId,
model, model,
@@ -2509,7 +2523,7 @@ class OpenCodeAgentSession implements AgentSession {
...(effectiveMode ? { agent: effectiveMode } : {}), ...(effectiveMode ? { agent: effectiveMode } : {}),
...(effectiveVariant ? { variant: effectiveVariant } : {}), ...(effectiveVariant ? { variant: effectiveVariant } : {}),
}); });
traceOpenCode("promptAsync.response", { this.traceOpenCode("provider.opencode.prompt_async.response", {
turnId, turnId,
hasError: promptResponse.error !== undefined, hasError: promptResponse.error !== undefined,
error: promptResponse.error, error: promptResponse.error,
@@ -2526,7 +2540,7 @@ class OpenCodeAgentSession implements AgentSession {
); );
} }
} catch (error) { } catch (error) {
traceOpenCode("promptAsync.throw", { this.traceOpenCode("provider.opencode.prompt_async.throw", {
turnId, turnId,
error: error:
error instanceof Error error instanceof Error
@@ -2560,7 +2574,11 @@ class OpenCodeAgentSession implements AgentSession {
turnAbortController: AbortController, turnAbortController: AbortController,
subscriptionReady: Deferred<void>, subscriptionReady: Deferred<void>,
): Promise<void> { ): Promise<void> {
traceOpenCode("subscribe.start", { turnId, sessionId: this.sessionId, cwd: this.config.cwd }); this.traceOpenCode("provider.opencode.subscribe.start", {
turnId,
sessionId: this.sessionId,
cwd: this.config.cwd,
});
try { try {
const result = await this.client.global.event({ const result = await this.client.global.event({
signal: turnAbortController.signal, signal: turnAbortController.signal,
@@ -2572,7 +2590,10 @@ class OpenCodeAgentSession implements AgentSession {
eventCount += 1; eventCount += 1;
if (!subscriptionReadyResolved) { if (!subscriptionReadyResolved) {
subscriptionReadyResolved = true; subscriptionReadyResolved = true;
traceOpenCode("subscribe.ready", { turnId, sessionId: this.sessionId }); this.traceOpenCode("provider.opencode.subscribe.ready", {
turnId,
sessionId: this.sessionId,
});
subscriptionReady.resolve(); subscriptionReady.resolve();
} }
const shouldContinue = await this.consumeOpenCodeStreamEvent({ const shouldContinue = await this.consumeOpenCodeStreamEvent({
@@ -2586,7 +2607,7 @@ class OpenCodeAgentSession implements AgentSession {
} }
} }
traceOpenCode("stream.eof", { this.traceOpenCode("provider.opencode.stream.eof", {
turnId, turnId,
eventCount, eventCount,
aborted: turnAbortController.signal.aborted, aborted: turnAbortController.signal.aborted,
@@ -2594,7 +2615,7 @@ class OpenCodeAgentSession implements AgentSession {
}); });
if (!turnAbortController.signal.aborted && this.activeForegroundTurnId === turnId) { if (!turnAbortController.signal.aborted && this.activeForegroundTurnId === turnId) {
traceOpenCode("turn.fail.eof", { turnId, eventCount }); this.traceOpenCode("provider.opencode.turn.fail_eof", { turnId, eventCount });
if (!subscriptionReadyResolved) { if (!subscriptionReadyResolved) {
subscriptionReady.reject(new Error("OpenCode event stream ended before it became ready")); subscriptionReady.reject(new Error("OpenCode event stream ended before it became ready"));
} }
@@ -2608,7 +2629,7 @@ class OpenCodeAgentSession implements AgentSession {
); );
} }
} catch (error) { } catch (error) {
traceOpenCode("subscribe.error", { this.traceOpenCode("provider.opencode.subscribe.error", {
turnId, turnId,
error: error:
error instanceof Error ? { name: error.name, message: error.message } : String(error), error instanceof Error ? { name: error.name, message: error.message } : String(error),
@@ -2649,19 +2670,20 @@ class OpenCodeAgentSession implements AgentSession {
}): Promise<boolean> { }): Promise<boolean> {
const { rawEvent, eventCount, turnId, turnAbortController } = params; const { rawEvent, eventCount, turnId, turnAbortController } = params;
const event = unwrapOpenCodeGlobalEvent(rawEvent); const event = unwrapOpenCodeGlobalEvent(rawEvent);
traceOpenCode("event.raw", { this.traceOpenCode("provider.opencode.raw_event", {
turnId, turnId,
n: eventCount, n: eventCount,
type: event?.type, type: event?.type,
rawType: readOpenCodeRecord(rawEvent)?.type, rawType: readOpenCodeRecord(rawEvent)?.type,
directory: readOpenCodeRecord(rawEvent)?.directory, directory: readOpenCodeRecord(rawEvent)?.directory,
properties: event ? (event as { properties?: unknown }).properties : undefined, rawEvent,
properties: event?.properties,
}); });
if (!event) { if (!event) {
return true; return true;
} }
if (turnAbortController.signal.aborted || this.activeForegroundTurnId !== turnId) { if (turnAbortController.signal.aborted || this.activeForegroundTurnId !== turnId) {
traceOpenCode("event.skip", { this.traceOpenCode("provider.opencode.event.skip", {
turnId, turnId,
n: eventCount, n: eventCount,
aborted: turnAbortController.signal.aborted, aborted: turnAbortController.signal.aborted,
@@ -2672,16 +2694,17 @@ class OpenCodeAgentSession implements AgentSession {
this.armRetryFailureTimerForStatus(event, turnId); this.armRetryFailureTimerForStatus(event, turnId);
const translated = await this.translateEvent(event); const translated = await this.translateEvent(event);
traceOpenCode("event.translated", { this.traceOpenCode("provider.opencode.parsed_event", {
turnId, turnId,
n: eventCount, n: eventCount,
count: translated.length, count: translated.length,
types: translated.map((t) => t.type), types: translated.map((t) => t.type),
events: translated,
}); });
for (const e of translated) { for (const e of translated) {
if (this.activeForegroundTurnId !== turnId) { if (this.activeForegroundTurnId !== turnId) {
traceOpenCode("event.translated.skip-active", { turnId, type: e.type }); this.traceOpenCode("provider.opencode.parsed_event.skip_active", { turnId, type: e.type });
return false; return false;
} }
if (e.type === "timeline" && e.item.type === "tool_call") { if (e.type === "timeline" && e.item.type === "tool_call") {
@@ -2689,7 +2712,10 @@ class OpenCodeAgentSession implements AgentSession {
} }
const terminalEvent = toTerminalTurnEvent(e); const terminalEvent = toTerminalTurnEvent(e);
if (terminalEvent) { if (terminalEvent) {
traceOpenCode("event.terminal", { turnId, type: terminalEvent.type }); this.traceOpenCode("provider.opencode.event.terminal", {
turnId,
type: terminalEvent.type,
});
this.finishForegroundTurn(terminalEvent, turnId); this.finishForegroundTurn(terminalEvent, turnId);
return false; return false;
} }
@@ -2703,7 +2729,7 @@ class OpenCodeAgentSession implements AgentSession {
event: Extract<AgentStreamEvent, { type: "turn_completed" | "turn_failed" | "turn_canceled" }>, event: Extract<AgentStreamEvent, { type: "turn_completed" | "turn_failed" | "turn_canceled" }>,
turnId: string, turnId: string,
): void { ): void {
traceOpenCode("finishForegroundTurn", { this.traceOpenCode("provider.opencode.finish_foreground_turn", {
turnId, turnId,
activeTurnId: this.activeForegroundTurnId, activeTurnId: this.activeForegroundTurnId,
type: event.type, type: event.type,
@@ -2803,6 +2829,10 @@ class OpenCodeAgentSession implements AgentSession {
private notifySubscribers(event: AgentStreamEvent, turnIdOverride?: string): void { private notifySubscribers(event: AgentStreamEvent, turnIdOverride?: string): void {
const turnId = turnIdOverride ?? this.activeForegroundTurnId; const turnId = turnIdOverride ?? this.activeForegroundTurnId;
const tagged = turnId ? { ...event, turnId } : event; const tagged = turnId ? { ...event, turnId } : event;
this.traceOpenCode("provider.opencode.event_emit", {
turnId: getAgentStreamEventTurnId(tagged),
event: tagged,
});
for (const callback of this.subscribers) { for (const callback of this.subscribers) {
try { try {
callback(tagged); callback(tagged);
@@ -2816,6 +2846,19 @@ class OpenCodeAgentSession implements AgentSession {
return `opencode-turn-${this.nextTurnOrdinal++}`; return `opencode-turn-${this.nextTurnOrdinal++}`;
} }
private traceOpenCode(msg: OpenCodeTraceMessage, data: OpenCodeTraceData = {}): void {
this.logger.trace(
{
agentId: this.agentId,
provider: "opencode",
sessionId: this.sessionId,
turnId: data.turnId ?? this.activeForegroundTurnId ?? undefined,
...data,
},
msg,
);
}
async *streamHistory(): AsyncGenerator<AgentStreamEvent> { async *streamHistory(): AsyncGenerator<AgentStreamEvent> {
const response = await this.client.session.messages({ const response = await this.client.session.messages({
sessionID: this.sessionId, sessionID: this.sessionId,
@@ -30,29 +30,30 @@ import type { ThinkingLevel } from "@mariozechner/pi-agent-core";
import type { Api, ImageContent, Model, TextContent } from "@mariozechner/pi-ai"; import type { Api, ImageContent, Model, TextContent } from "@mariozechner/pi-ai";
import { z } from "zod"; import { z } from "zod";
import type { import {
AgentCapabilityFlags, getAgentStreamEventTurnId,
AgentClient, type AgentCapabilityFlags,
AgentLaunchContext, type AgentClient,
AgentMetadata, type AgentLaunchContext,
AgentMode, type AgentMetadata,
AgentModelDefinition, type AgentMode,
AgentPermissionRequest, type AgentModelDefinition,
AgentPermissionResponse, type AgentPermissionRequest,
AgentPersistenceHandle, type AgentPermissionResponse,
AgentPromptInput, type AgentPersistenceHandle,
AgentRunOptions, type AgentPromptInput,
AgentRunResult, type AgentRunOptions,
AgentRuntimeInfo, type AgentRunResult,
AgentSession, type AgentRuntimeInfo,
AgentSessionConfig, type AgentSession,
AgentSlashCommand, type AgentSessionConfig,
AgentStreamEvent, type AgentSlashCommand,
AgentTimelineItem, type AgentStreamEvent,
AgentUsage, type AgentTimelineItem,
ListModesOptions, type AgentUsage,
ListModelsOptions, type ListModesOptions,
ToolCallDetail, type ListModelsOptions,
type ToolCallDetail,
} from "../agent-sdk-types.js"; } from "../agent-sdk-types.js";
import type { ProviderRuntimeSettings } from "../provider-launch-config.js"; import type { ProviderRuntimeSettings } from "../provider-launch-config.js";
import { renderPromptAttachmentAsText } from "../prompt-attachments.js"; import { renderPromptAttachmentAsText } from "../prompt-attachments.js";
@@ -738,21 +739,6 @@ function parsePersistenceMetadata(metadata: AgentMetadata | undefined): PiPersis
return {}; return {};
} }
function getStreamEventTurnId(event: AgentStreamEvent): string | undefined {
switch (event.type) {
case "turn_started":
case "turn_completed":
case "turn_failed":
case "turn_canceled":
case "timeline":
case "permission_requested":
case "permission_resolved":
return event.turnId;
default:
return undefined;
}
}
function isPiRequestAbortError(error: unknown): boolean { function isPiRequestAbortError(error: unknown): boolean {
if (error instanceof Error && error.name === "AbortError") { if (error instanceof Error && error.name === "AbortError") {
return true; return true;
@@ -1045,7 +1031,7 @@ export class PiDirectAgentSession implements AgentSession {
return; return;
} }
const eventTurnId = getStreamEventTurnId(event); const eventTurnId = getAgentStreamEventTurnId(event);
if (turnId && eventTurnId && eventTurnId !== turnId) { if (turnId && eventTurnId && eventTurnId !== turnId) {
return; return;
} }
@@ -1,9 +1,10 @@
import type { import {
AgentPromptInput, getAgentStreamEventTurnId,
AgentRunOptions, type AgentPromptInput,
AgentRunResult, type AgentRunOptions,
AgentStreamEvent, type AgentRunResult,
AgentTimelineItem, type AgentStreamEvent,
type AgentTimelineItem,
} from "../agent-sdk-types.js"; } from "../agent-sdk-types.js";
export type ProviderFinalTextReducer = (params: { export type ProviderFinalTextReducer = (params: {
@@ -44,7 +45,7 @@ export async function runProviderTurn({
if (settled) { if (settled) {
return; return;
} }
const eventTurnId = "turnId" in event ? event.turnId : undefined; const eventTurnId = getAgentStreamEventTurnId(event);
if (turnId && eventTurnId && eventTurnId !== turnId) { if (turnId && eventTurnId && eventTurnId !== turnId) {
return; return;
} }
@@ -1,8 +1,9 @@
import type { import {
AgentPromptInput, getAgentStreamEventTurnId,
AgentRunOptions, type AgentPromptInput,
AgentSession, type AgentRunOptions,
AgentStreamEvent, type AgentSession,
type AgentStreamEvent,
} from "../../agent-sdk-types.js"; } from "../../agent-sdk-types.js";
function isTerminalEvent(event: AgentStreamEvent): boolean { function isTerminalEvent(event: AgentStreamEvent): boolean {
@@ -29,7 +30,7 @@ export async function* streamSession(
}; };
const matchesTurn = (event: AgentStreamEvent): boolean => { const matchesTurn = (event: AgentStreamEvent): boolean => {
const eventTurnId = (event as { turnId?: string }).turnId; const eventTurnId = getAgentStreamEventTurnId(event);
return turnId == null || eventTurnId == null || eventTurnId === turnId; return turnId == null || eventTurnId == null || eventTurnId === turnId;
}; };
+25
View File
@@ -106,6 +106,31 @@ describe("resolveLogConfig", () => {
}, },
}); });
}); });
it("defaults file output to info when log.file is present without a level", () => {
const config: PersistedConfig = {
log: {
console: {
level: "warn",
},
file: {
path: "daemon.log",
},
},
};
expect(resolveLogConfig(config, { paseoHome })).toEqual({
level: "info",
console: {
level: "warn",
format: "json",
},
file: {
level: "info",
path: path.resolve(paseoHome, "daemon.log"),
},
});
});
}); });
describe("loadConfig logger config", () => { describe("loadConfig logger config", () => {
+1 -1
View File
@@ -43,7 +43,7 @@ const LOG_LEVEL_PRIORITIES: Record<LogLevel, number> = {
const DEFAULT_CONSOLE_LEVEL: LogLevel = "info"; const DEFAULT_CONSOLE_LEVEL: LogLevel = "info";
const DEFAULT_CONSOLE_FORMAT: LogFormat = "json"; const DEFAULT_CONSOLE_FORMAT: LogFormat = "json";
const DEFAULT_FILE_LEVEL: LogLevel = "debug"; const DEFAULT_FILE_LEVEL: LogLevel = "info";
const DEFAULT_DAEMON_LOG_FILENAME = "daemon.log"; const DEFAULT_DAEMON_LOG_FILENAME = "daemon.log";
const REDACT_PATHS = [ const REDACT_PATHS = [
"authorization", "authorization",
+63 -29
View File
@@ -119,16 +119,17 @@ import {
StructuredAgentResponseError, StructuredAgentResponseError,
generateStructuredAgentResponseWithFallback, generateStructuredAgentResponseWithFallback,
} from "./agent/agent-response-loop.js"; } from "./agent/agent-response-loop.js";
import type { import {
AgentPersistenceHandle, getAgentStreamEventTurnId,
AgentPermissionResponse, type AgentPersistenceHandle,
AgentProvider, type AgentPermissionResponse,
AgentPromptContentBlock, type AgentProvider,
AgentPromptInput, type AgentPromptContentBlock,
AgentRunOptions, type AgentPromptInput,
AgentSessionConfig, type AgentRunOptions,
AgentStreamEvent, type AgentSessionConfig,
ProviderSnapshotEntry, type AgentStreamEvent,
type ProviderSnapshotEntry,
} from "./agent/agent-sdk-types.js"; } from "./agent/agent-sdk-types.js";
import type { StoredAgentRecord } from "./agent/agent-storage.js"; import type { StoredAgentRecord } from "./agent/agent-storage.js";
import type { AgentStorage } from "./agent/agent-storage.js"; import type { AgentStorage } from "./agent/agent-storage.js";
@@ -895,7 +896,7 @@ export class Session {
void this.initializeAgentMcp(); void this.initializeAgentMcp();
this.subscribeToAgentEvents(); this.subscribeToAgentEvents();
this.sessionLogger.trace("Session created"); this.sessionLogger.trace({}, "agent.session.lifecycle.created");
} }
updateAppVersion(appVersion: string | null): void { updateAppVersion(appVersion: string | null): void {
@@ -1017,15 +1018,20 @@ export class Session {
private async interruptAgentIfRunning(agentId: string): Promise<void> { private async interruptAgentIfRunning(agentId: string): Promise<void> {
const snapshot = this.agentManager.getAgent(agentId); const snapshot = this.agentManager.getAgent(agentId);
if (!snapshot) { if (!snapshot) {
this.sessionLogger.trace({ agentId }, "interruptAgentIfRunning: agent not found"); this.sessionLogger.trace({ agentId }, "agent.session.interrupt.not_found");
throw new Error(`Agent ${agentId} not found`); throw new Error(`Agent ${agentId} not found`);
} }
const hasInFlightRun = this.agentManager.hasInFlightRun(agentId); const hasInFlightRun = this.agentManager.hasInFlightRun(agentId);
if (!hasInFlightRun) { if (!hasInFlightRun) {
this.sessionLogger.trace( this.sessionLogger.trace(
{ agentId, lifecycle: snapshot.lifecycle, hasInFlightRun }, {
"interruptAgentIfRunning: skipping because agent is not running", agentId,
provider: snapshot.provider,
lifecycle: snapshot.lifecycle,
hasInFlightRun,
},
"agent.session.interrupt.skip_not_running",
); );
return; return;
} }
@@ -1070,7 +1076,7 @@ export class Session {
promptType: typeof prompt === "string" ? "string" : "structured", promptType: typeof prompt === "string" ? "string" : "structured",
hasRunOptions: Boolean(runOptions), hasRunOptions: Boolean(runOptions),
}, },
"startAgentStream: requested", "agent.session.start_stream.request",
); );
let iterator: AsyncGenerator<AgentStreamEvent>; let iterator: AsyncGenerator<AgentStreamEvent>;
try { try {
@@ -1080,7 +1086,7 @@ export class Session {
: this.agentManager.streamAgent(agentId, prompt, runOptions); : this.agentManager.streamAgent(agentId, prompt, runOptions);
this.sessionLogger.trace( this.sessionLogger.trace(
{ agentId, shouldReplace }, { agentId, shouldReplace },
"startAgentStream: agent iterator returned", "agent.session.start_stream.iterator_returned",
); );
} catch (error) { } catch (error) {
this.handleAgentRunError(agentId, error, "Failed to start agent run"); this.handleAgentRunError(agentId, error, "Failed to start agent run");
@@ -1092,9 +1098,9 @@ export class Session {
for await (const _ of iterator) { for await (const _ of iterator) {
// Events are forwarded via the session's AgentManager subscription. // Events are forwarded via the session's AgentManager subscription.
} }
this.sessionLogger.trace({ agentId }, "startAgentStream: iterator drained"); this.sessionLogger.trace({ agentId }, "agent.session.iterator.drained");
} catch (error) { } catch (error) {
this.sessionLogger.trace({ agentId, err: error }, "startAgentStream: iterator threw"); this.sessionLogger.trace({ agentId, err: error }, "agent.session.iterator.error");
this.handleAgentRunError(agentId, error, "Agent stream failed"); this.handleAgentRunError(agentId, error, "Agent stream failed");
} }
})(); })();
@@ -1135,10 +1141,7 @@ export class Session {
this.agentTools = (await this.agentMcpClient.tools()) as ToolSet; this.agentTools = (await this.agentMcpClient.tools()) as ToolSet;
const agentToolCount = Object.keys(this.agentTools ?? {}).length; const agentToolCount = Object.keys(this.agentTools ?? {}).length;
this.sessionLogger.trace( this.sessionLogger.trace({ agentToolCount }, "agent.session.mcp_init");
{ agentToolCount },
`Agent MCP initialized with ${agentToolCount} tools`,
);
} catch (error) { } catch (error) {
this.sessionLogger.error({ err: error }, "Failed to initialize Agent MCP"); this.sessionLogger.error({ err: error }, "Failed to initialize Agent MCP");
} }
@@ -1210,6 +1213,16 @@ export class Session {
this.unsubscribeAgentEvents = this.agentManager.subscribe( this.unsubscribeAgentEvents = this.agentManager.subscribe(
(event) => { (event) => {
if (event.type === "agent_state") { if (event.type === "agent_state") {
this.sessionLogger.trace(
{
agentId: event.agent.id,
provider: event.agent.provider,
providerSessionId: event.agent.persistence?.sessionId ?? undefined,
turnId: event.agent.activeForegroundTurnId ?? undefined,
lifecycle: event.agent.lifecycle,
},
"agent.session.forward_update",
);
void this.forwardAgentUpdate(event.agent); void this.forwardAgentUpdate(event.agent);
return; return;
} }
@@ -1260,6 +1273,17 @@ export class Session {
if (!serializedEvent) { if (!serializedEvent) {
return; return;
} }
this.sessionLogger.trace(
{
agentId: event.agentId,
provider: event.event.provider,
turnId: getAgentStreamEventTurnId(event.event),
seq: event.seq,
epoch: event.epoch,
event: event.event,
},
"agent.session.forward_stream",
);
const payload = { const payload = {
agentId: event.agentId, agentId: event.agentId,
@@ -1612,8 +1636,11 @@ export class Session {
} }
try { try {
this.sessionLogger.trace( this.sessionLogger.trace(
{ messageType: msg.type, payloadBytes: JSON.stringify(msg).length }, {
"inbound message", messageType: msg.type,
payloadBytes: JSON.stringify(msg).length,
},
"agent.session.inbound",
); );
try { try {
await this.dispatchInboundMessage(msg); await this.dispatchInboundMessage(msg);
@@ -7180,8 +7207,12 @@ export class Session {
const prompt = this.buildAgentPrompt(msg.text, msg.images, msg.attachments); const prompt = this.buildAgentPrompt(msg.text, msg.images, msg.attachments);
this.sessionLogger.trace( this.sessionLogger.trace(
{ agentId, messageId: msg.messageId, textPrefix: msg.text.slice(0, 80) }, {
"send_agent_message_request: dispatching shared sendPromptToAgent", agentId,
messageId: msg.messageId,
textPrefix: msg.text.slice(0, 80),
},
"agent.session.send_agent_message",
); );
let dispatchResult: { outOfBand: boolean }; let dispatchResult: { outOfBand: boolean };
try { try {
@@ -7966,8 +7997,11 @@ export class Session {
*/ */
private emit(msg: SessionOutboundMessage): void { private emit(msg: SessionOutboundMessage): void {
this.sessionLogger.trace( this.sessionLogger.trace(
{ messageType: msg.type, payloadBytes: JSON.stringify(msg).length }, {
"outbound message", messageType: msg.type,
payloadBytes: JSON.stringify(msg).length,
},
"agent.session.outbound",
); );
if ( if (
msg.type === "audio_output" && msg.type === "audio_output" &&
@@ -8035,7 +8069,7 @@ export class Session {
* Clean up session resources * Clean up session resources
*/ */
public async cleanup(): Promise<void> { public async cleanup(): Promise<void> {
this.sessionLogger.trace("Cleaning up"); this.sessionLogger.trace({}, "agent.session.lifecycle.cleanup");
if (this.unsubscribeAgentEvents) { if (this.unsubscribeAgentEvents) {
this.unsubscribeAgentEvents(); this.unsubscribeAgentEvents();