From 6ad580f5210f44867b068ee8be5b42e31f5e7a71 Mon Sep 17 00:00:00 2001 From: Brennan Benson <79079362+brennanb2025@users.noreply.github.com> Date: Thu, 1 Oct 2026 20:06:39 -0700 Subject: [PATCH 1/4] refactor(native-chat): the rest of structured chat reports failures through the host's logger The structured chat host's required logger (#24312) did not reach the chat journal, the Claude and Codex adapters, or the runtime and orchestration callers outside the host, so their failures still went to console.warn/console.error, which a packaged desktop build never shows. These now report through the same logger: - The journal database takes the logger at open and every chat's journal reports through it: a failed rollback, an import that reads back different, a retired import file left behind, a skipped queued-message repair, skipped row bookkeeping, and an unconfirmed submission. - The Claude and Codex adapters take it as a required dependency: exit cursor and turn-end resume point writes, unreadable attachments, failed message writes, an unprovable history window, an option restore that was never answered, and a child CLI launcher that did not resolve. - The runtime holds the logger it hands the host, so a create refused before the host exists, chat-tab retirement, mail redrive and worker discard report to it too. A failed Stop child end reports from the turn context instead of through an optional callback. - Restart-offer bookkeeping failures name the affected session ids as well as the operation id, still with no error object, since those errors can quote the recovery payload. A ratchet test fails on console.warn/console.error or an optional on*Error/on*Failed/on*Failure callback in structured chat production code; the behavioral optional hooks are listed by file. --- .../claude-adapter-capture-replay.test.ts | 4 + .../claude-agent-sdk-contract-pins.test.ts | 4 + ...hild-work-producer-harness.test-fixture.ts | 4 + .../claude/claude-command-lifecycle.test.ts | 4 + .../claude/claude-fold-steer-receipt.test.ts | 4 + ...laude-history-window-source-budget.test.ts | 4 + .../claude-structured-auth-parity.test.ts | 6 + ...ured-dispatch-attachment-rejection.test.ts | 11 +- .../claude-structured-dispatch-content.ts | 12 +- ...claude-structured-dispatch-test-support.ts | 3 + .../claude/claude-structured-dispatch.test.ts | 11 +- src/main/claude/claude-structured-dispatch.ts | 17 +- ...-structured-effort-default-at-rest.test.ts | 4 + .../claude-structured-history-window.test.ts | 4 + .../claude-structured-history-window.ts | 12 +- ...laude-structured-launch-resolution.test.ts | 10 ++ .../claude-structured-launch-resolution.ts | 17 +- .../claude/claude-structured-options.test.ts | 5 + src/main/claude/claude-structured-options.ts | 9 +- .../claude-structured-real-cli-fold.test.ts | 4 + .../claude/claude-structured-real-cli.test.ts | 4 + .../claude-structured-resume-point.test.ts | 11 +- .../claude/claude-structured-resume-point.ts | 5 +- ...ed-session-acquisition-processless.test.ts | 4 + .../claude-structured-session-acquisition.ts | 20 ++- .../claude-structured-session-adapter.ts | 3 +- ...laude-structured-session-exit-lifecycle.ts | 8 +- .../claude-structured-session-publication.ts | 27 +++- ...claude-structured-session-recovery.test.ts | 5 + .../claude/claude-structured-session-state.ts | 11 +- .../claude-structured-session-test-support.ts | 5 + ...laude-structured-turn-resume-point.test.ts | 15 +- .../codex/codex-collab-call-frames-fixture.ts | 4 + .../codex-default-mode-subagents.test.ts | 4 + ...-structured-acquisition-exit-proof.test.ts | 7 + ...codex-structured-child-environment.test.ts | 20 ++- .../codex-structured-child-environment.ts | 16 +- ...dex-structured-child-work-producer.test.ts | 4 + .../codex-structured-dispatch-test-support.ts | 4 + .../codex/codex-structured-session-acquire.ts | 7 +- ...odex-structured-session-adapter-fixture.ts | 4 + ...ructured-session-adapter-lifecycle.test.ts | 4 + .../codex-structured-session-adapter.test.ts | 7 + ...tructured-session-background-tasks.test.ts | 4 + .../codex-structured-session-cancel.test.ts | 4 + .../codex-structured-session-close.test.ts | 4 + .../codex-structured-session-shutdown.test.ts | 5 + .../codex/codex-structured-session-state.ts | 3 + ...journal-database-records-migration.test.ts | 23 +-- .../journal-database.test.ts | 25 +-- .../agent-session-journal/journal-database.ts | 20 ++- .../journal-host-database-test-support.ts | 10 +- .../journal-host-database.ts | 19 ++- .../journal-open-failure.test.ts | 10 +- .../journal-per-session-import.test.ts | 8 +- .../journal-per-session-import.ts | 11 +- .../journal-per-session-source.ts | 8 +- .../journal-queued-messages.ts | 5 +- .../journal-restart-reconciliation.test.ts | 9 ++ .../journal-restart-reconciliation.ts | 5 +- .../journal-row-writer.ts | 5 +- .../agent-session-journal/journal-store.ts | 3 + ...queued-message-bookkeeping-failure.test.ts | 6 +- .../queued-message-store.test.ts | 13 +- .../structured-agent-session-attach.ts | 1 + .../structured-agent-session-chat-stop.ts | 6 - ...-agent-session-claude-compact-stop.test.ts | 4 + ...-agent-session-claude-echo-working.test.ts | 4 + ...d-agent-session-claude-queued-stop.test.ts | 4 + ...t-session-claude-stop-ends-session.test.ts | 3 + ...agent-session-claude-stop-turn-end.test.ts | 4 + ...-session-claude-unproven-stop-send.test.ts | 3 + ...ed-agent-session-owed-work-release.test.ts | 4 + ...red-agent-session-provider-started.test.ts | 4 + .../structured-agent-session-registry.ts | 13 +- ...ent-session-restart-failure-ledger.test.ts | 80 ++++++++++ ...ed-agent-session-restart-failure-ledger.ts | 10 +- .../structured-agent-session-turns-cancel.ts | 8 +- ...sion-view-start-after-failed-start.test.ts | 4 + .../structured-chat-logger-ratchet.test.ts | 149 ++++++++++++++++++ ...rca-runtime-get-pty-record-for-pane-key.ts | 11 +- .../runtime/orca-runtime-get-worktree-ps.ts | 3 +- .../orca-runtime-preserved-branch-cleanup.ts | 4 + src/main/runtime/orca-runtime-state-fields.ts | 7 + .../structured-mailbox-pointer-host.ts | 6 +- .../structured-session-mail-target.test.ts | 29 ++-- .../structured-session-mail-target.ts | 9 +- ...ration-structured-worker-lifecycle.test.ts | 6 +- ...chestration-structured-worker-lifecycle.ts | 4 +- ...stration-structured-worker-session.test.ts | 5 +- ...orchestration-structured-worker-session.ts | 17 +- .../structured-agent-session-create.ts | 5 +- ...ed-agent-session-precommit-refusal.test.ts | 6 +- ...uctured-agent-session-precommit-refusal.ts | 16 +- .../rpc/methods/structured-agent-session.ts | 2 +- .../structured-worker-tab-retirement.test.ts | 10 +- .../runtime/structured-agent-session-close.ts | 4 +- ...ructured-agent-session-held-signal.test.ts | 6 +- .../structured-agent-session-journal-open.ts | 15 +- .../structured-agent-session-runtime.test.ts | 5 +- .../structured-agent-session-runtime.ts | 2 + ...structured-agent-session-tab-retirement.ts | 12 +- .../structured-claude-pending-rewind.test.ts | 3 + .../structured-claude-runtime-adapter.ts | 6 +- ...uctured-session-child-identity-env.test.ts | 60 ++++--- .../structured-session-child-identity-env.ts | 19 ++- ...ctured-session-login-shell-test-harness.ts | 9 +- ...ctured-session-mail-redrive-wiring.test.ts | 9 +- .../structured-session-worktree-teardown.ts | 4 +- .../structured-worker-identity.test.ts | 5 +- 110 files changed, 927 insertions(+), 221 deletions(-) create mode 100644 src/main/native-chat/agent-session-wire/structured-agent-session-restart-failure-ledger.test.ts create mode 100644 src/main/native-chat/agent-session-wire/structured-chat-logger-ratchet.test.ts diff --git a/src/main/claude/claude-adapter-capture-replay.test.ts b/src/main/claude/claude-adapter-capture-replay.test.ts index 8e877a135a83..8e2c953c4965 100644 --- a/src/main/claude/claude-adapter-capture-replay.test.ts +++ b/src/main/claude/claude-adapter-capture-replay.test.ts @@ -26,6 +26,9 @@ import { identityFor, PROVIDER_SESSION_ID } from './claude-structured-session-test-support' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger type CapturedEvent = | { at: number; kind: 'meta'; providerSessionId: string } @@ -108,6 +111,7 @@ async function replayCapture(name: string): Promise { // The capture supplies every frame, startup proof included. const claude = fakeClaude({ initProof: 'none', replayUuid: null }) const deps: ClaudeStructuredSessionAdapterDeps = { + logger: TEST_LOGGER, resolveLaunch: async () => ({ pathToClaudeCodeExecutable: 'claude', options: {}, diff --git a/src/main/claude/claude-agent-sdk-contract-pins.test.ts b/src/main/claude/claude-agent-sdk-contract-pins.test.ts index dcd331d70a4f..64c821353e83 100644 --- a/src/main/claude/claude-agent-sdk-contract-pins.test.ts +++ b/src/main/claude/claude-agent-sdk-contract-pins.test.ts @@ -18,6 +18,9 @@ import { LOCAL_EXECUTION_HOST_ID } from '../../shared/execution-host' import type { AgentSessionRecordStore } from '../runtime/agent-session-record-store' import { claudeQuerySettingsReader } from './claude-agent-sdk-control-requests' import { createClaudeStructuredLaunchResolver } from './claude-structured-launch-resolution' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger // Contract pins for @anthropic-ai/claude-agent-sdk, run against the real SDK // driving a scripted fake CLI (never the real Claude binary). These tests exist @@ -159,6 +162,7 @@ function resolvedLaunch(permissionMode: PermissionMode, launchArgs: string[] = [ launchArgs } as unknown as AgentSessionRecord return createClaudeStructuredLaunchResolver({ + logger: TEST_LOGGER, store: { getRecord: () => record } as unknown as AgentSessionRecordStore, resolveWorkspacePath: async () => '/repos/workspace-1', resolveCommand: () => FAKE_CLI, diff --git a/src/main/claude/claude-child-work-producer-harness.test-fixture.ts b/src/main/claude/claude-child-work-producer-harness.test-fixture.ts index 0b460d91b4a7..056da5c74280 100644 --- a/src/main/claude/claude-child-work-producer-harness.test-fixture.ts +++ b/src/main/claude/claude-child-work-producer-harness.test-fixture.ts @@ -22,6 +22,9 @@ import { identityFor, PROVIDER_SESSION_ID } from './claude-structured-session-test-support' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger export const parent = makeStructuredAgentStatusSubject( { @@ -115,6 +118,7 @@ export async function producer(host?: AgentHookServer) { const evidenceLog: AgentChildWorkEvidence[][] = [] const ingested: (AgentChildWorkReconcileOutcome | null)[] = [] const adapter = new ClaudeStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ pathToClaudeCodeExecutable: 'claude', options: {}, diff --git a/src/main/claude/claude-command-lifecycle.test.ts b/src/main/claude/claude-command-lifecycle.test.ts index f4182a601747..c1eabaae77d5 100644 --- a/src/main/claude/claude-command-lifecycle.test.ts +++ b/src/main/claude/claude-command-lifecycle.test.ts @@ -25,6 +25,9 @@ import { PROVIDER_SESSION_ID, type FakeConnection } from './claude-structured-session-test-support' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger type CapturedEvent = | { kind: 'meta'; providerSessionId: string } @@ -115,6 +118,7 @@ async function replayCapture( // The capture supplies every frame, startup proof included. const claude = fakeClaude({ initProof: 'none', replayUuid: null }) const adapter = new ClaudeStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ pathToClaudeCodeExecutable: 'claude', options: {}, diff --git a/src/main/claude/claude-fold-steer-receipt.test.ts b/src/main/claude/claude-fold-steer-receipt.test.ts index 4726dc55d823..7506326f6c40 100644 --- a/src/main/claude/claude-fold-steer-receipt.test.ts +++ b/src/main/claude/claude-fold-steer-receipt.test.ts @@ -50,6 +50,9 @@ import { twoSteersCapture, TWO_STEERS_SEND_AT } from './claude-captured-fold-steer-frames.test-fixture' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const T0 = 1_700_000_100_000 @@ -80,6 +83,7 @@ async function riggedAdapter( const settled = vi.fn() const claude = fakeClaude({ replayUuid: null, ...claudeOptions }) const deps: ClaudeStructuredSessionAdapterDeps = { + logger: TEST_LOGGER, resolveLaunch: async () => ({ pathToClaudeCodeExecutable: 'claude', options: {}, diff --git a/src/main/claude/claude-history-window-source-budget.test.ts b/src/main/claude/claude-history-window-source-budget.test.ts index 90d74b94e373..19c117b5d138 100644 --- a/src/main/claude/claude-history-window-source-budget.test.ts +++ b/src/main/claude/claude-history-window-source-budget.test.ts @@ -10,6 +10,9 @@ import { tmpdir } from 'node:os' import type { FileHandle } from 'node:fs/promises' import type * as FsPromises from 'node:fs/promises' import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const state = vi.hoisted(() => ({ path: '', @@ -95,6 +98,7 @@ let directory = '' const read = (previousLeafUuid: string | null = 'anchor') => readClaudeProviderHistoryWindow({ + logger: TEST_LOGGER, transcriptPath: state.path, providerSessionId: 'provider', previousLeafUuid, diff --git a/src/main/claude/claude-structured-auth-parity.test.ts b/src/main/claude/claude-structured-auth-parity.test.ts index 002240e4dd77..aa99b1a04255 100644 --- a/src/main/claude/claude-structured-auth-parity.test.ts +++ b/src/main/claude/claude-structured-auth-parity.test.ts @@ -15,6 +15,9 @@ import { fakeClaude, identityFor } from './claude-structured-session-test-support' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const SESSION_ID = 'orca-session-auth' const IDENTITY = { sessionId: SESSION_ID } as Parameters< @@ -42,6 +45,7 @@ function resolverFor(options: { authSwitchSettleTimeoutMs?: number }): ReturnType { return createClaudeStructuredLaunchResolver({ + logger: TEST_LOGGER, store: { getRecord: () => record() } as unknown as AgentSessionRecordStore, resolveWorkspacePath: async (id) => `/repos/${id}`, resolveCommand: () => '/usr/local/bin/claude', @@ -67,7 +71,9 @@ function realResolverAdapter( ] } as unknown as AgentSessionRecord return new ClaudeStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: createClaudeStructuredLaunchResolver({ + logger: TEST_LOGGER, store: { getRecord: () => resumable } as unknown as AgentSessionRecordStore, resolveWorkspacePath: async (id) => `/repos/${id}`, resolveCommand: () => '/usr/local/bin/claude', diff --git a/src/main/claude/claude-structured-dispatch-attachment-rejection.test.ts b/src/main/claude/claude-structured-dispatch-attachment-rejection.test.ts index a23767c09681..13a99db98a1f 100644 --- a/src/main/claude/claude-structured-dispatch-attachment-rejection.test.ts +++ b/src/main/claude/claude-structured-dispatch-attachment-rejection.test.ts @@ -152,8 +152,8 @@ describe('Claude structured dispatch attachment rejections', () => { }) it('rejects an attachment it cannot read with the generic sentence and no path', async () => { - const warn = vi.spyOn(console, 'warn').mockImplementation(() => {}) const session = sessionFor() + const warn = vi.spyOn(session.logger, 'warn') const path = join(tmpdir(), 'orca-claude-image-missing', 'gone.png') await expect( @@ -169,9 +169,12 @@ describe('Claude structured dispatch attachment rejections', () => { expect(session.connection.send).not.toHaveBeenCalled() // The row drops the error, so the log is the only place left to find why. expect(warn).toHaveBeenCalledWith( - '[claude-dispatch] attachment could not be read:', - expect.objectContaining({ code: 'ENOENT' }) + 'an attachment could not be read', + expect.objectContaining({ + scope: 'claude-attachment-read', + sessionId: session.sessionId, + error: expect.objectContaining({ code: 'ENOENT' }) + }) ) - warn.mockRestore() }) }) diff --git a/src/main/claude/claude-structured-dispatch-content.ts b/src/main/claude/claude-structured-dispatch-content.ts index 035b0a594926..e8a915ae7c3a 100644 --- a/src/main/claude/claude-structured-dispatch-content.ts +++ b/src/main/claude/claude-structured-dispatch-content.ts @@ -14,6 +14,7 @@ import { } from '../../shared/agent-session-failure-words' import { TUI_AGENT_DISPLAY_NAMES } from '../../shared/tui-agent-display-names' import { claudeRecord } from './claude-structured-item-translation' +import type { ClaudeSession } from './claude-structured-session-state' /** Orca refused the message's content, as opposed to failing to read an attachment. */ export class ClaudeDispatchContentError extends Error { @@ -47,12 +48,19 @@ export function claudeDispatchRejection( /** Why a message whose content could not be built was not sent: Orca's own refusal of it, or an * attachment it could not read. Never the provider. */ -export function claudeDispatchContentRejection(error: unknown): AgentJournalDispatchRejection { +export function claudeDispatchContentRejection( + error: unknown, + session: Pick +): AgentJournalDispatchRejection { if (error instanceof ClaudeDispatchContentError) { return claudeDispatchRejection(error.failure) } // The row says only that it could not be read; why belongs in the log. - console.warn('[claude-dispatch] attachment could not be read:', error) + session.logger.warn('an attachment could not be read', { + scope: 'claude-attachment-read', + sessionId: session.sessionId, + error + }) return claudeDispatchRejection(agentSessionFailureFact('attachmentUnreadable')) } diff --git a/src/main/claude/claude-structured-dispatch-test-support.ts b/src/main/claude/claude-structured-dispatch-test-support.ts index 5af0f17243b5..3111cf08fa73 100644 --- a/src/main/claude/claude-structured-dispatch-test-support.ts +++ b/src/main/claude/claude-structured-dispatch-test-support.ts @@ -6,10 +6,13 @@ import { ClaudeBackgroundTaskTracker } from './claude-background-task-tracker' import { ClaudeChildWorkDecoder } from './claude-child-work-decoder' import { ClaudeSlashCommandCatalog } from './claude-slash-command-catalog' import { createClaudeSessionStartup } from './claude-structured-session-startup-state' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' export function sessionFor(send: Mock = vi.fn().mockResolvedValue(undefined)): ClaudeSession { return { connection: { send } as unknown as ClaudeSession['connection'], + sessionId: 'session-1', + logger: recordingStructuredAgentSessionLogger().logger, providerSessionId: 'provider-session', leafUuid: null, turnEndLeafUuid: null, diff --git a/src/main/claude/claude-structured-dispatch.test.ts b/src/main/claude/claude-structured-dispatch.test.ts index 92ae0253711a..96d501bf7875 100644 --- a/src/main/claude/claude-structured-dispatch.test.ts +++ b/src/main/claude/claude-structured-dispatch.test.ts @@ -397,12 +397,12 @@ describe('Claude structured dispatch image limits', () => { }) it('does not let a provably unwritten attempt block retry correlation', async () => { - const warn = vi.spyOn(console, 'warn').mockImplementation(() => {}) const send = vi .fn() .mockRejectedValueOnce(claudeUnwrittenUserMessageError(new Error('broken pipe'))) .mockResolvedValue(undefined) const session = sessionFor(send) + const warn = vi.spyOn(session.logger, 'warn') const body = userMessage([{ type: 'text', text: 'retry me' }]) await expect( @@ -414,10 +414,13 @@ describe('Claude structured dispatch image limits', () => { }) // The row keeps only the marker; why the write failed goes to the log. expect(warn).toHaveBeenCalledWith( - '[claude-dispatch] message could not be handed to Claude:', - expect.objectContaining({ message: expect.stringContaining('broken pipe') }) + 'a message could not be handed to Claude', + expect.objectContaining({ + scope: 'claude-dispatch-write', + sessionId: session.sessionId, + error: expect.objectContaining({ message: expect.stringContaining('broken pipe') }) + }) ) - warn.mockRestore() expect(session.dispatchWaiters).toHaveLength(0) expect(session.retiredDispatchWaiters).toHaveLength(0) diff --git a/src/main/claude/claude-structured-dispatch.ts b/src/main/claude/claude-structured-dispatch.ts index 87e706ddbbc3..436468c0c03c 100644 --- a/src/main/claude/claude-structured-dispatch.ts +++ b/src/main/claude/claude-structured-dispatch.ts @@ -107,8 +107,15 @@ export function retireClaudeDispatchWaiters(session: ClaudeSession): void { } /** The row keeps only the marker released clients hide; why the write failed belongs in the log. */ -function claudeWriteFailureRejection(error: unknown): AgentJournalDispatchRejection { - console.warn('[claude-dispatch] message could not be handed to Claude:', error) +function claudeWriteFailureRejection( + error: unknown, + session: ClaudeSession +): AgentJournalDispatchRejection { + session.logger.warn('a message could not be handed to Claude', { + scope: 'claude-dispatch-write', + sessionId: session.sessionId, + error + }) return claudeDispatchRejection(agentSessionFailureFact('writeFailed')) } @@ -127,7 +134,7 @@ export async function dispatchClaudeTurn( try { content = await claudeDispatchMessageContent(input.body) } catch (error) { - return { state: 'rejected', ...claudeDispatchContentRejection(error) } + return { state: 'rejected', ...claudeDispatchContentRejection(error, session) } } if (session.dispatchWaiters.length >= MAX_ACTIVE_DISPATCH_WAITERS) { return { state: 'rejected', ...claudeDispatchRejection(agentSessionFailureFact('queueFull')) } @@ -180,7 +187,7 @@ export async function dispatchClaudeTurn( if (error instanceof AgentSessionPreDispatchError) { throw error } - return { state: 'rejected', ...claudeWriteFailureRejection(error) } + return { state: 'rejected', ...claudeWriteFailureRejection(error, session) } } const waiter = replay.waiter if (waiter.settledUuid) { @@ -198,7 +205,7 @@ export async function dispatchClaudeTurn( waiter.resolve(null) // The frame was never handed to the SDK's input pump, so this is not doubt: // the message provably did not happen, which is what `rejected` means. - return { state: 'rejected', ...claudeWriteFailureRejection(error) } + return { state: 'rejected', ...claudeWriteFailureRejection(error, session) } } if (!waiter.retired) { retireWaiter(session, waiter) diff --git a/src/main/claude/claude-structured-effort-default-at-rest.test.ts b/src/main/claude/claude-structured-effort-default-at-rest.test.ts index 0228b1171683..df37db26e090 100644 --- a/src/main/claude/claude-structured-effort-default-at-rest.test.ts +++ b/src/main/claude/claude-structured-effort-default-at-rest.test.ts @@ -26,6 +26,9 @@ import { identityFor, recordingJournalSink } from './claude-structured-session-test-support' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const SESSION = 'session-1' const ACCOUNT_HOME = '/accounts/claude' @@ -95,6 +98,7 @@ async function startChild( cli: { runs?: string; lists?: unknown[] } = {} ): Promise { const adapter = new ClaudeStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ pathToClaudeCodeExecutable: 'claude', options: {}, diff --git a/src/main/claude/claude-structured-history-window.test.ts b/src/main/claude/claude-structured-history-window.test.ts index 851831b86f19..86c9a0169d54 100644 --- a/src/main/claude/claude-structured-history-window.test.ts +++ b/src/main/claude/claude-structured-history-window.test.ts @@ -13,6 +13,9 @@ import { claudeProviderHistoryWindowFromJsonl, resolveClaudeProviderHistoryWindow } from './claude-structured-history-window' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const PROVIDER_SESSION = 'provider-1' const ORCA_SESSION = 'session-1' @@ -77,6 +80,7 @@ describe('claudeProviderHistoryWindowFromJsonl', () => { ) const window = await resolveClaudeProviderHistoryWindow({ + logger: TEST_LOGGER, identity: { sessionId: ORCA_SESSION, workspaceId: 'workspace-1', diff --git a/src/main/claude/claude-structured-history-window.ts b/src/main/claude/claude-structured-history-window.ts index 00ae86920251..8904c9104ef4 100644 --- a/src/main/claude/claude-structured-history-window.ts +++ b/src/main/claude/claude-structured-history-window.ts @@ -25,6 +25,7 @@ import { claudeContentBlocks } from '../native-chat/transcript-record-blocks' import { isKnownHarnessInjectedUserTurnText } from '../../shared/harness-injected-user-turns' import { computeAgentSessionPayloadFingerprint } from '../../shared/agent-session-mutation-envelope' import type { NativeChatBlock } from '../../shared/native-chat-types' +import type { StructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger' import { replayClaudeTranscriptBranchAncestry, replayClaudeTranscriptBranchAncestryFromJsonl @@ -240,6 +241,7 @@ export async function resolveClaudeProviderHistoryWindow(input: { identity: AgentSessionJournalIdentity accountHomePath: string hasLiveSession: boolean + logger: StructuredAgentSessionLogger }): Promise { const handle = input.identity.providerHandle if (handle.kind !== 'claude') { @@ -256,12 +258,13 @@ export async function resolveClaudeProviderHistoryWindow(input: { providerSessionId: handle.sessionId, previousLeafUuid: handle.leafUuid, sessionId: input.identity.sessionId, - turnInFlight: input.hasLiveSession + turnInFlight: input.hasLiveSession, + logger: input.logger }) } export async function readClaudeProviderHistoryWindow( - input: HistoryWindowInput & { transcriptPath: string } + input: HistoryWindowInput & { transcriptPath: string; logger: StructuredAgentSessionLogger } ): Promise { const ancestryAnchorUuid = input.previousLeafUuid if (!ancestryAnchorUuid) { @@ -282,9 +285,10 @@ export async function readClaudeProviderHistoryWindow( // Unreadable, unprovable, or a single record too large to frame: all of them // leave the boundary unvouched for, which is not the same as an empty window. // Oversize is no longer among them, so only the log separates what is left. - console.warn('[claude-history-window] transcript unprovable; boundary inconsistent:', { - transcriptPath: input.transcriptPath, + input.logger.warn('the transcript is unprovable, so the history boundary is inconsistent', { + scope: 'claude-history-window', sessionId: input.sessionId, + transcriptPath: input.transcriptPath, error }) return INCONSISTENT diff --git a/src/main/claude/claude-structured-launch-resolution.test.ts b/src/main/claude/claude-structured-launch-resolution.test.ts index 66fed64c3230..97f8d4d9526d 100644 --- a/src/main/claude/claude-structured-launch-resolution.test.ts +++ b/src/main/claude/claude-structured-launch-resolution.test.ts @@ -16,6 +16,9 @@ import { createClaudeStructuredLaunchResolver } from './claude-structured-launch-resolution' import { claudeStructuredPermissionModeForSettings } from './claude-structured-permission-mode' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const SESSION_ID = 'orca-session-1' const IDENTITY = { sessionId: SESSION_ID } as Parameters< @@ -62,6 +65,7 @@ function resolverFor( hasTranscript: () => Promise = async () => true ) { return createClaudeStructuredLaunchResolver({ + logger: TEST_LOGGER, store: { getRecord: () => value } as unknown as AgentSessionRecordStore, resolveWorkspacePath: async (id) => `/repos/${id}`, resolveCommand: () => '/usr/local/bin/claude', @@ -356,6 +360,7 @@ describe('claude structured launch resolution', () => { it('builds on the supplied inherited env instead of Orca process env', async () => { const launch = await createClaudeStructuredLaunchResolver({ + logger: TEST_LOGGER, store: { getRecord: () => record() } as unknown as AgentSessionRecordStore, resolveWorkspacePath: async (id) => `/repos/${id}`, resolveCommand: () => '/usr/local/bin/claude', @@ -368,6 +373,7 @@ describe('claude structured launch resolution', () => { it('drops an inherited CLAUDE_CONFIG_DIR so the record stays the only Claude home the pin sees', async () => { const launch = await createClaudeStructuredLaunchResolver({ + logger: TEST_LOGGER, store: { getRecord: () => record() } as unknown as AgentSessionRecordStore, resolveWorkspacePath: async (id) => `/repos/${id}`, resolveCommand: () => '/usr/local/bin/claude', @@ -386,6 +392,7 @@ describe('claude structured launch resolution', () => { it('keeps a configured overlay CLAUDE_CONFIG_DIR over the dropped inherited one', async () => { const launch = await createClaudeStructuredLaunchResolver({ + logger: TEST_LOGGER, store: { getRecord: () => record() } as unknown as AgentSessionRecordStore, resolveWorkspacePath: async (id) => `/repos/${id}`, resolveCommand: () => '/usr/local/bin/claude', @@ -399,6 +406,7 @@ describe('claude structured launch resolution', () => { it('still strips an inherited auth key under a managed account', async () => { const launch = await createClaudeStructuredLaunchResolver({ + logger: TEST_LOGGER, store: { getRecord: () => record() } as unknown as AgentSessionRecordStore, resolveWorkspacePath: async (id) => `/repos/${id}`, resolveCommand: () => '/usr/local/bin/claude', @@ -436,6 +444,7 @@ describe('claude structured launch resolution', () => { makeExecutable(nodeCommand) const launch = await createClaudeStructuredLaunchResolver({ + logger: TEST_LOGGER, store: { getRecord: () => record() } as unknown as AgentSessionRecordStore, resolveWorkspacePath: async (id) => `/repos/${id}`, resolveCommand: () => claudeCommand, @@ -478,6 +487,7 @@ describe('claude structured launch resolution', () => { describe('managed-account gate on every acquisition', () => { function resolverWithGate(read: () => ClaudeManagedAccountGateSettings | null) { return createClaudeStructuredLaunchResolver({ + logger: TEST_LOGGER, store: { getRecord: () => RESUMABLE } as unknown as AgentSessionRecordStore, resolveWorkspacePath: async (id) => `/repos/${id}`, resolveCommand: () => '/usr/local/bin/claude', diff --git a/src/main/claude/claude-structured-launch-resolution.ts b/src/main/claude/claude-structured-launch-resolution.ts index 29703dfd8eb7..b1adb78176ae 100644 --- a/src/main/claude/claude-structured-launch-resolution.ts +++ b/src/main/claude/claude-structured-launch-resolution.ts @@ -30,6 +30,7 @@ import { resolveClaudeCommand } from '../codex-cli/command' import { resolveSessionFilePath } from '../native-chat/session-file-resolver' import { withoutInheritedClaudeConfigDir } from './claude-config-dir-pin' import type { AgentSessionRecordStore } from '../runtime/agent-session-record-store' +import type { StructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger' export const CLAUDE_DEFAULT_SETTING_SOURCES = ['user', 'project', 'local'] as const export const CLAUDE_SESSION_STATE_EVENTS_ENV = 'CLAUDE_CODE_EMIT_SESSION_STATE_EVENTS' @@ -107,6 +108,8 @@ export type ClaudeStructuredLaunch = { export type ClaudeStructuredLaunchResolverDeps = { store: AgentSessionRecordStore + /** Where a launch step that carries on past a failure reports it: the host's logger. */ + logger: StructuredAgentSessionLogger resolveWorkspacePath: (workspaceId: string) => Promise resolveCommand?: () => string resolveEnv?: () => @@ -289,11 +292,15 @@ export function createClaudeStructuredLaunchResolver( ) const { command, env } = await resolveClaudeStructuredInvocation(deps, (base) => // Every structured session speaks orchestration as itself: its injected id and the Orca CLI. - structuredSessionChildIdentityEnv(record.sessionId, { - ...base, - // The turn translator relies on Claude's authoritative idle frame when no result arrives. - [CLAUDE_SESSION_STATE_EVENTS_ENV]: '1' - }) + structuredSessionChildIdentityEnv( + record.sessionId, + { + ...base, + // The turn translator relies on Claude's authoritative idle frame when no result arrives. + [CLAUDE_SESSION_STATE_EVENTS_ENV]: '1' + }, + deps.logger + ) ) return { pathToClaudeCodeExecutable: command, diff --git a/src/main/claude/claude-structured-options.test.ts b/src/main/claude/claude-structured-options.test.ts index e5b7a7ea8a77..234054351482 100644 --- a/src/main/claude/claude-structured-options.test.ts +++ b/src/main/claude/claude-structured-options.test.ts @@ -17,6 +17,9 @@ import { observeClaudeFastModeFacts, readClaudeStructuredSessionOptions } from './claude-structured-session-options' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger function sessionFor(setModel: ClaudeSession['connection']['setModel']): ClaudeSession { return { @@ -26,6 +29,8 @@ function sessionFor(setModel: ClaudeSession['connection']['setModel']): ClaudeSe setModel, supportedModels: async (): Promise => [] } as ClaudeSession['connection'], + sessionId: 'session-1', + logger: TEST_LOGGER, providerSessionId: 'provider-session', leafUuid: null, turnEndLeafUuid: null, diff --git a/src/main/claude/claude-structured-options.ts b/src/main/claude/claude-structured-options.ts index 2f0b7ac4b707..eec779a359cf 100644 --- a/src/main/claude/claude-structured-options.ts +++ b/src/main/claude/claude-structured-options.ts @@ -268,9 +268,12 @@ export async function restoreClaudeStructuredSessionOptions( // A write the CLI never answered must not fault a start that is otherwise fine. Silence is // not a refusal, so the choice stays wanted, unconfirmed, and the next start retries it. if (error instanceof ClaudeControlRequestTimeoutError) { - console.warn( - `[claude-structured] restore of ${key} for ${session.providerSessionId} was not answered in time; keeping it unconfirmed` - ) + session.logger.warn('restoring an option was not answered in time; it stays unconfirmed', { + scope: 'claude-option-restore', + sessionId: session.sessionId, + providerSessionId: session.providerSessionId, + key + }) session.options.set(key, value) session.confirmedOptions.delete(key) continue diff --git a/src/main/claude/claude-structured-real-cli-fold.test.ts b/src/main/claude/claude-structured-real-cli-fold.test.ts index 5ce21d83f170..599a221dad89 100644 --- a/src/main/claude/claude-structured-real-cli-fold.test.ts +++ b/src/main/claude/claude-structured-real-cli-fold.test.ts @@ -27,6 +27,9 @@ import { realClaudeCommand, realClaudeLaunchHome } from './claude-real-cli-availability-test-support' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const SESSION_ID = 'real-cli-fold' // Pins the live proof order (SessionStart hook frame before system/init) and lets the @@ -78,6 +81,7 @@ describe.skipIf(!realClaudeAvailable)('Claude structured real CLI fold', () => { } const settled = vi.fn() const adapter = new ClaudeStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ pathToClaudeCodeExecutable: realClaudeCommand, options: { diff --git a/src/main/claude/claude-structured-real-cli.test.ts b/src/main/claude/claude-structured-real-cli.test.ts index 677d2de4cb9e..ada39adf729c 100644 --- a/src/main/claude/claude-structured-real-cli.test.ts +++ b/src/main/claude/claude-structured-real-cli.test.ts @@ -18,6 +18,9 @@ import { type ClaudeStructuredSessionEvent } from './claude-structured-session-adapter' import type { ClaudeStructuredSessionAdapterDeps } from './claude-structured-session-state' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const command = realClaudeCommand const suiteTitle = `Claude structured real CLI handshake${realClaudeCliGate.skipReason ? ` (skipped: ${realClaudeCliGate.skipReason})` : ''}` @@ -30,6 +33,7 @@ function realAdapter( onDispatchSettledLate?: ClaudeStructuredSessionAdapterDeps['onDispatchSettledLate'] ): ClaudeStructuredSessionAdapter { const adapter = new ClaudeStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ pathToClaudeCodeExecutable: command, options: { ...CLAUDE_STRUCTURED_BASE_OPTIONS, sessionId: providerSessionId }, diff --git a/src/main/claude/claude-structured-resume-point.test.ts b/src/main/claude/claude-structured-resume-point.test.ts index 862909a2cd66..76bbe0a36d88 100644 --- a/src/main/claude/claude-structured-resume-point.test.ts +++ b/src/main/claude/claude-structured-resume-point.test.ts @@ -2,6 +2,7 @@ import { afterEach, describe, expect, it, vi } from 'vitest' import type { ClaudeStructuredSessionEvent } from './claude-structured-session-adapter' import { adapterFor, + CLAUDE_ADAPTER_TEST_LOGGER, fakeClaude, identityFor, PROVIDER_SESSION_ID, @@ -106,7 +107,7 @@ describe('Claude resume point is the last completed turn on every exit path', () }) it('on an unexpected exit whose durable write fails, still ends the session and logs', async () => { - const warn = vi.spyOn(console, 'warn').mockImplementation(() => {}) + const warn = vi.spyOn(CLAUDE_ADAPTER_TEST_LOGGER, 'warn') const events: ClaudeStructuredSessionEvent[] = [] const claude = fakeClaude() const adapter = adapterFor( @@ -135,8 +136,12 @@ describe('Claude resume point is the last completed turn on every exit path', () await tick() expect(events.at(-1)).toMatchObject({ type: 'ended', cause: 'unexpected-exit' }) expect(warn).toHaveBeenCalledWith( - '[claude-resume-point] exit cursor was not persisted:', - expect.objectContaining({ sessionId: 'session-1', error: expect.any(Error) }) + 'the exit cursor was not persisted', + expect.objectContaining({ + scope: 'claude-exit-cursor-persist', + sessionId: 'session-1', + error: expect.any(Error) + }) ) }) }) diff --git a/src/main/claude/claude-structured-resume-point.ts b/src/main/claude/claude-structured-resume-point.ts index b15d2e3507c9..67e68563eec1 100644 --- a/src/main/claude/claude-structured-resume-point.ts +++ b/src/main/claude/claude-structured-resume-point.ts @@ -12,7 +12,7 @@ import { settleClaudeTurnEndWaiters } from './claude-request-end-wait' export function persistClaudeTurnResumePoint( sessionId: string, session: ClaudeSession, - deps: Pick + deps: Pick ): void { if (session.closeFinalization || session.closeFinalized) { return @@ -38,7 +38,8 @@ export function persistClaudeTurnResumePoint( }) ) .catch((error: unknown) => { - console.warn('[claude-resume-point] turn-end resume point was not persisted:', { + deps.logger.warn('the turn-end resume point was not persisted', { + scope: 'claude-resume-point-persist', sessionId, leafUuid, error diff --git a/src/main/claude/claude-structured-session-acquisition-processless.test.ts b/src/main/claude/claude-structured-session-acquisition-processless.test.ts index eb4babdb9aca..20617a573320 100644 --- a/src/main/claude/claude-structured-session-acquisition-processless.test.ts +++ b/src/main/claude/claude-structured-session-acquisition-processless.test.ts @@ -6,6 +6,9 @@ import type { openClaudeStreamJsonConnection } from './claude-stream-json-connection' import { ClaudeStructuredSessionAdapter } from './claude-structured-session-adapter' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const PROVIDER_SESSION_ID = '819cf9f8-e43c-4ad7-b50f-54aa158a726a' const IDENTITY: AgentSessionJournalIdentity = { @@ -48,6 +51,7 @@ describe('Claude structured processless acquisition', () => { return connection } const adapter = new ClaudeStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ pathToClaudeCodeExecutable: 'claude', options: {}, diff --git a/src/main/claude/claude-structured-session-acquisition.ts b/src/main/claude/claude-structured-session-acquisition.ts index 404787620e95..7ab1cb65ef6e 100644 --- a/src/main/claude/claude-structured-session-acquisition.ts +++ b/src/main/claude/claude-structured-session-acquisition.ts @@ -27,13 +27,12 @@ import { settleClaudeSessionStartup } from './claude-structured-session-startup' import { createClaudeSessionPublication } from './claude-structured-session-publication' -import { - mintClaudeAcquisitionGeneration, - type ClaudeAcquisitionRegistry, - type ClaudeSession, - type ClaudeSessionExit, - type ClaudeStructuredSessionAdapterDeps, - type ClaudeAcquireCallbacks +import type { + ClaudeAcquisitionRegistry, + ClaudeSession, + ClaudeSessionExit, + ClaudeStructuredSessionAdapterDeps, + ClaudeAcquireCallbacks } from './claude-structured-session-state' import { resolveClaudeAcquisitionError } from './claude-structured-session-close' import { withObservedProviderExit } from '../native-chat/agent-session-wire/structured-agent-session-failure-text' @@ -240,6 +239,8 @@ export async function acquireClaudeSession({ } const publication = createClaudeSessionPublication({ connection, + sessionId, + deps, providerSessionId: launch.providerSessionId, leafUuid: observedLeafUuid, turnEndLeafUuid: launch.resumeLeafUuid, @@ -250,10 +251,7 @@ export async function acquireClaudeSession({ events: input.events, ...(unbindReadingControl ? { unbindReadingControl } : {}), process, - acquisitionGeneration: mintClaudeAcquisitionGeneration(deps), - options: restoredClaudeStructuredSessionOptions(input.options), - ...(deps.mintLinkId ? { linkId: deps.mintLinkId() } : {}), - observedAt: deps.now?.() ?? Date.now() + options: restoredClaudeStructuredSessionOptions(input.options) }) const session = publication.session liveSession = session diff --git a/src/main/claude/claude-structured-session-adapter.ts b/src/main/claude/claude-structured-session-adapter.ts index 746d603308f1..c226898a922b 100644 --- a/src/main/claude/claude-structured-session-adapter.ts +++ b/src/main/claude/claude-structured-session-adapter.ts @@ -140,7 +140,8 @@ export class ClaudeStructuredSessionAdapter implements StructuredAgentSessionAda identity: input.identity, accountHomePath: input.accountHome.path, hasLiveSession: - this.sessions.has(input.identity.sessionId) || this.exits.has(input.identity.sessionId) + this.sessions.has(input.identity.sessionId) || this.exits.has(input.identity.sessionId), + logger: this.deps.logger }) private emit(session: ClaudeSession | null, event: ClaudeStructuredSessionEvent): void { diff --git a/src/main/claude/claude-structured-session-exit-lifecycle.ts b/src/main/claude/claude-structured-session-exit-lifecycle.ts index 854646490a8c..6f678d0c36f8 100644 --- a/src/main/claude/claude-structured-session-exit-lifecycle.ts +++ b/src/main/claude/claude-structured-session-exit-lifecycle.ts @@ -22,7 +22,7 @@ export type ClaudeExitLifecycle = { exits: Map /** A settled exit's diagnostic, kept for a send admitted before the host heard of the exit. */ settledExitErrors: Map - deps: Pick + deps: Pick emit: (session: ClaudeSession, event: ClaudeStructuredSessionEvent) => void } @@ -80,7 +80,11 @@ export function settleClaudeUnexpectedExit( // event that lets the host release and reacquire this exact child. await persistClaudeSessionHandle(sessionId, exit.session, deps).catch((error: unknown) => { // Recovery still publishes: the record keeps its last durable point, and the loss is logged. - console.warn('[claude-resume-point] exit cursor was not persisted:', { sessionId, error }) + deps.logger.warn('the exit cursor was not persisted', { + scope: 'claude-exit-cursor-persist', + sessionId, + error + }) }) if (exits.get(sessionId) !== exit) { settleClaudeExitedSession(exit.session) diff --git a/src/main/claude/claude-structured-session-publication.ts b/src/main/claude/claude-structured-session-publication.ts index c685c2cd2ae7..00fc74ea004a 100644 --- a/src/main/claude/claude-structured-session-publication.ts +++ b/src/main/claude/claude-structured-session-publication.ts @@ -2,7 +2,11 @@ import type { AgentSessionAcquisition } from '../native-chat/agent-session-wire/ import { claudeProviderHandleLink } from './claude-structured-owner-identity' import type { ClaudePromptRegistry } from './claude-structured-prompt-replies' import type { ClaudeJournalTranslator } from './claude-journal-translator-contract' -import type { ClaudeSession } from './claude-structured-session-state' +import { + mintClaudeAcquisitionGeneration, + type ClaudeSession, + type ClaudeStructuredSessionAdapterDeps +} from './claude-structured-session-state' import { ClaudeBackgroundTaskTracker } from './claude-background-task-tracker' import { ClaudeChildWorkDecoder } from './claude-child-work-decoder' import { ClaudeSlashCommandCatalog } from './claude-slash-command-catalog' @@ -11,12 +15,16 @@ import { createClaudeSessionStartup } from './claude-structured-session-startup- /** The session as published at spawn: nothing the CLI reports at init is assumed yet. */ export function createClaudeSessionPublication(input: { connection: ClaudeSession['connection'] + sessionId: string + deps: Pick< + ClaudeStructuredSessionAdapterDeps, + 'logger' | 'mintAcquisitionGeneration' | 'mintLinkId' | 'now' + > providerSessionId: string leafUuid: string | null /** The launch's stored leaf: a frame seen before publication is not a completed turn. */ turnEndLeafUuid: string | null fence: number - acquisitionGeneration: string /** The record's chain already heads this provider session: the link resumes, never creates. */ continuesChain: boolean prompts: ClaudePromptRegistry @@ -24,10 +32,11 @@ export function createClaudeSessionPublication(input: { events: ClaudeSession['events'] unbindReadingControl?: () => void process: AgentSessionAcquisition['process'] - linkId?: string - observedAt: number options?: ReadonlyMap }): { acquisition: AgentSessionAcquisition; session: ClaudeSession } { + const { deps } = input + const acquisitionGeneration = mintClaudeAcquisitionGeneration(deps) + const linkId = deps.mintLinkId?.() return { acquisition: { process: input.process, @@ -36,18 +45,20 @@ export function createClaudeSessionPublication(input: { leafUuid: input.leafUuid, resumed: input.continuesChain, fence: input.fence, - ...(input.linkId ? { linkId: input.linkId } : {}), - observedAt: input.observedAt + ...(linkId ? { linkId } : {}), + observedAt: deps.now?.() ?? Date.now() }), - acquisitionGeneration: input.acquisitionGeneration + acquisitionGeneration }, session: { connection: input.connection, + sessionId: input.sessionId, + logger: deps.logger, providerSessionId: input.providerSessionId, leafUuid: input.leafUuid, turnEndLeafUuid: input.turnEndLeafUuid, fence: input.fence, - acquisitionGeneration: input.acquisitionGeneration, + acquisitionGeneration, prompts: input.prompts, dispatchWaiters: [], retiredDispatchWaiters: [], diff --git a/src/main/claude/claude-structured-session-recovery.test.ts b/src/main/claude/claude-structured-session-recovery.test.ts index 71a7ac9ce319..d276908d7ed6 100644 --- a/src/main/claude/claude-structured-session-recovery.test.ts +++ b/src/main/claude/claude-structured-session-recovery.test.ts @@ -13,6 +13,9 @@ import { tick } from './claude-structured-session-test-support' import { invokeCanUseTool } from './claude-can-use-tool-test-support' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger describe('ClaudeStructuredSessionAdapter close and exit recovery', () => { it('shares concurrent close finalization and emits lifecycle once', async () => { @@ -57,6 +60,7 @@ describe('ClaudeStructuredSessionAdapter close and exit recovery', () => { const events: ClaudeStructuredSessionEvent[] = [] const callbackError = new Error('handle delivery failed') const adapter = new ClaudeStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ pathToClaudeCodeExecutable: 'claude', options: {}, @@ -325,6 +329,7 @@ describe('ClaudeStructuredSessionAdapter close and exit recovery', () => { } ) const adapter = new ClaudeStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch, openConnection: claude.openConnection, onEvent: (event) => events.push(event), diff --git a/src/main/claude/claude-structured-session-state.ts b/src/main/claude/claude-structured-session-state.ts index d61df04ac75c..f907acc1d86a 100644 --- a/src/main/claude/claude-structured-session-state.ts +++ b/src/main/claude/claude-structured-session-state.ts @@ -26,6 +26,7 @@ import type { ClaudeChildWorkDecoder } from './claude-child-work-decoder' import type { ClaudeSlashCommandCatalog } from './claude-slash-command-catalog' import type { ClaudeAtRestCommandCatalog } from './claude-at-rest-commands' import type { ClaudeSessionStartup } from './claude-structured-session-startup-state' +import type { StructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger' export type ClaudeAuthDiagnostic = { apiKeySourceConfigured: boolean @@ -124,6 +125,8 @@ export type ClaudeStructuredSessionAdapterDeps = { }) => Promise /** Host model catalog; sessions write their listings through. */ modelCatalog?: AgentModelCatalogStore + /** Where a failure this adapter carries on past is reported: the host's logger. */ + logger: StructuredAgentSessionLogger } export type ClaudeDispatchWaiter = { @@ -149,6 +152,10 @@ export type ClaudeDispatchWaiter = { export type ClaudeSession = { connection: ClaudeStreamJsonConnection + /** The Orca chat this child serves. */ + sessionId: string + /** The adapter's logger, for a step on this session that carries on past a failure. */ + logger: StructuredAgentSessionLogger providerSessionId: string /** Latest main-chain message seen on the live stream, mid-turn included. */ leafUuid: string | null @@ -207,7 +214,9 @@ export type ClaudeSession = { startup: ClaudeSessionStartup } -export function mintClaudeAcquisitionGeneration(deps: ClaudeStructuredSessionAdapterDeps): string { +export function mintClaudeAcquisitionGeneration( + deps: Pick +): string { return deps.mintAcquisitionGeneration?.() ?? randomUUID() } diff --git a/src/main/claude/claude-structured-session-test-support.ts b/src/main/claude/claude-structured-session-test-support.ts index dd7ad1e8d8c5..d766767a8c09 100644 --- a/src/main/claude/claude-structured-session-test-support.ts +++ b/src/main/claude/claude-structured-session-test-support.ts @@ -15,6 +15,10 @@ import { type ClaudeStructuredSessionEvent } from './claude-structured-session-adapter' import type { StructuredAgentSessionEventSink } from '../native-chat/agent-session-wire/structured-agent-session-event-sink' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +/** The logger every adapter built here reports to; spy on it to read what was reported. */ +export const CLAUDE_ADAPTER_TEST_LOGGER = recordingStructuredAgentSessionLogger().logger export const PROVIDER_SESSION_ID = '819cf9f8-e43c-4ad7-b50f-54aa158a726a' @@ -264,6 +268,7 @@ export function adapterAtPublishFor( onDispatchSettledLate?: ClaudeStructuredSessionAdapterDeps['onDispatchSettledLate'] ): ClaudeStructuredSessionAdapter { return new ClaudeStructuredSessionAdapter({ + logger: CLAUDE_ADAPTER_TEST_LOGGER, resolveLaunch: async () => ({ pathToClaudeCodeExecutable: 'claude', options: {}, diff --git a/src/main/claude/claude-structured-turn-resume-point.test.ts b/src/main/claude/claude-structured-turn-resume-point.test.ts index 4cb72eaa53a6..fb63e2666cf2 100644 --- a/src/main/claude/claude-structured-turn-resume-point.test.ts +++ b/src/main/claude/claude-structured-turn-resume-point.test.ts @@ -20,6 +20,9 @@ import { recordingJournalSink, tick } from './claude-structured-session-test-support' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const FENCE = 7 @@ -58,6 +61,7 @@ async function liveOwner( const events: ClaudeStructuredSessionEvent[] = [] const persistedHandles: unknown[] = [] const adapter = new ClaudeStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ pathToClaudeCodeExecutable: 'claude', options: { resume: PROVIDER_SESSION_ID }, @@ -138,6 +142,7 @@ describe('Claude durable resume point at turn end', () => { expect(head).toMatchObject({ leafUuid: 'a2' }) const resolve = createClaudeStructuredLaunchResolver({ + logger: TEST_LOGGER, // oxlint-disable-next-line typescript/consistent-type-assertions -- SAFETY: the resolver reads only getRecord from its store. store: { getRecord: () => store.record } as unknown as AgentSessionRecordStore, resolveWorkspacePath: async (id) => `/repos/${id}`, @@ -168,7 +173,7 @@ describe('Claude durable resume point at turn end', () => { }) it('never fails or holds up a turn when the write fails', async () => { - const warn = vi.spyOn(console, 'warn').mockImplementation(() => {}) + const warn = vi.spyOn(TEST_LOGGER, 'warn') const persist = vi.fn(async () => { throw new Error('record write failed') }) @@ -180,8 +185,12 @@ describe('Claude durable resume point at turn end', () => { events.filter((event) => event.type === 'message' && event.message.type === 'result') ).toHaveLength(2) expect(warn).toHaveBeenCalledWith( - '[claude-resume-point] turn-end resume point was not persisted:', - expect.objectContaining({ leafUuid: 'a2' }) + 'the turn-end resume point was not persisted', + expect.objectContaining({ + scope: 'claude-resume-point-persist', + sessionId: 'session-1', + leafUuid: 'a2' + }) ) await expect(adapter.closeSession('session-1')).resolves.toBe(true) expect(persistedHandles).toEqual([expect.objectContaining({ leafUuid: 'a2' })]) diff --git a/src/main/codex/codex-collab-call-frames-fixture.ts b/src/main/codex/codex-collab-call-frames-fixture.ts index 8926e46dcca9..14b747e6e3de 100644 --- a/src/main/codex/codex-collab-call-frames-fixture.ts +++ b/src/main/codex/codex-collab-call-frames-fixture.ts @@ -5,6 +5,9 @@ import type { AgentJournalRenderItem } from '../../shared/agent-session-journal- import type { StructuredAgentSessionEventSink } from '../native-chat/agent-session-wire/structured-agent-session-event-sink' import { fakeCodex, identityFor, THREAD_ID } from './codex-structured-session-adapter-fixture' import { CodexStructuredSessionAdapter } from './codex-structured-session-adapter' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger // Shapes as a live default-mode session sent them (codex-cli 0.157); only the sender is remapped. export const HELPER = '01a0ea72-80bc-7632-a97f-4a9a0d50d08f' @@ -80,6 +83,7 @@ export const waitStarted = collab('item/started', { export async function publishedRows(frames: Frame[]): Promise { const codex = fakeCodex() const adapter = new CodexStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ command: 'codex', args: ['app-server'], diff --git a/src/main/codex/codex-default-mode-subagents.test.ts b/src/main/codex/codex-default-mode-subagents.test.ts index 335f903efbbf..4684bdf2ccf6 100644 --- a/src/main/codex/codex-default-mode-subagents.test.ts +++ b/src/main/codex/codex-default-mode-subagents.test.ts @@ -18,6 +18,9 @@ import { createCodexJournalTranslator } from './codex-structured-journal-transla import { CodexSubagentExecutions } from './codex-subagent-executions' import { readCodexSubagentAnnouncements } from './codex-subagent-activity' import type { CodexThreadItem } from './codex-thread-item-identity' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const parent = makeStructuredAgentStatusSubject( { @@ -141,6 +144,7 @@ async function session() { mintChildWorkId: () => `child-${++minted}` }) const adapter = new CodexStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ command: 'codex', args: ['app-server'], diff --git a/src/main/codex/codex-structured-acquisition-exit-proof.test.ts b/src/main/codex/codex-structured-acquisition-exit-proof.test.ts index f0737fc36a36..60ba82b25969 100644 --- a/src/main/codex/codex-structured-acquisition-exit-proof.test.ts +++ b/src/main/codex/codex-structured-acquisition-exit-proof.test.ts @@ -3,6 +3,9 @@ import { describe, expect, it, vi } from 'vitest' import type { AgentSessionJournalIdentity } from '../../shared/agent-session-journal-types' import type { CodexAppServerConnection } from './codex-app-server-connection-types' import { CodexStructuredSessionAdapter } from './codex-structured-session-adapter' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const IDENTITY: AgentSessionJournalIdentity = { sessionId: 'session-1', @@ -32,6 +35,7 @@ describe('Codex failed-acquisition exit proof', () => { connection }) const adapter = new CodexStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ command: 'codex', args: ['app-server'], @@ -70,6 +74,7 @@ describe('Codex failed-acquisition exit proof', () => { close } const adapter = new CodexStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ command: 'codex', args: ['app-server'], @@ -102,6 +107,7 @@ describe('Codex failed-acquisition exit proof', () => { close } const adapter = new CodexStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ command: 'codex', args: ['app-server'], @@ -140,6 +146,7 @@ describe('Codex failed-acquisition exit proof', () => { close } const adapter = new CodexStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ command: 'codex', args: ['app-server'], diff --git a/src/main/codex/codex-structured-child-environment.test.ts b/src/main/codex/codex-structured-child-environment.test.ts index 4dcd49e96459..7ad3a20a8b75 100644 --- a/src/main/codex/codex-structured-child-environment.test.ts +++ b/src/main/codex/codex-structured-child-environment.test.ts @@ -8,6 +8,9 @@ import { structuredWorkerIdentities, structuredWorkerProcessIncarnation } from '../runtime/structured-worker-identity' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const DEV_CLI_BIN_FIRST = /^[^:;]*[\\/]cli[\\/]bin[:;]/ // The dev launcher by absolute path: a login shell's profile cannot reorder it behind a global. @@ -26,7 +29,8 @@ describe('buildCodexStructuredChildEnvironment', () => { env: { EXAMPLE_GATEWAY_TOKEN: 'shell-exported', CODEX_HOME: '/shell/home' } }, 'spawn-token', - 'session-not-a-worker' + 'session-not-a-worker', + TEST_LOGGER ) ).toEqual({ EXAMPLE_GATEWAY_TOKEN: 'shell-exported', @@ -51,7 +55,9 @@ describe('buildCodexStructuredChildEnvironment', () => { env: {} } const sessionId = 'a1b2c3d4-e5f6-4a7b-8c9d-0e1f2a3b4c5d' - expect(buildCodexStructuredChildEnvironment(launch, 'spawn-token', sessionId)).toEqual({ + expect( + buildCodexStructuredChildEnvironment(launch, 'spawn-token', sessionId, TEST_LOGGER) + ).toEqual({ [CODEX_SPAWN_TOKEN_ENV]: 'spawn-token', // Not a worker, so no handle: the id alone names this chat as a caller. ORCA_AGENT_SESSION_ID: sessionId, @@ -72,7 +78,12 @@ describe('buildCodexStructuredChildEnvironment', () => { hostScope: { kind: 'local', hostId: 'local' } }) try { - const env = buildCodexStructuredChildEnvironment(launch, 'spawn-token', sessionId) + const env = buildCodexStructuredChildEnvironment( + launch, + 'spawn-token', + sessionId, + TEST_LOGGER + ) expect(env.ORCA_TERMINAL_HANDLE).toBe(handle) expect(env.ORCA_AGENT_SESSION_ID).toBe(sessionId) expect(env.ORCA_CLI_COMMAND).toMatch(DEV_CLI_LAUNCHER) @@ -124,7 +135,8 @@ describe('the spawned Codex child', () => { env: {} }, 'spawn-token', - sessionId + sessionId, + TEST_LOGGER ) const connection = await openCodexAppServerConnection({ command: process.execPath, diff --git a/src/main/codex/codex-structured-child-environment.ts b/src/main/codex/codex-structured-child-environment.ts index 38ea91abe268..201c00d4005d 100644 --- a/src/main/codex/codex-structured-child-environment.ts +++ b/src/main/codex/codex-structured-child-environment.ts @@ -1,18 +1,24 @@ import type { CodexStructuredLaunch } from './codex-structured-session-state' import { CODEX_SPAWN_TOKEN_ENV } from './codex-structured-owner-identity' import { structuredSessionChildIdentityEnv } from '../runtime/structured-session-child-identity-env' +import type { StructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger' export function buildCodexStructuredChildEnvironment( launch: CodexStructuredLaunch, spawnToken: string, - sessionId: string + sessionId: string, + logger: StructuredAgentSessionLogger ): Record { return { // Every structured session speaks orchestration as itself: its injected id and the Orca CLI. - ...structuredSessionChildIdentityEnv(sessionId, { - ...launch.env, - ...(launch.codexHome ? { CODEX_HOME: launch.codexHome } : {}) - }), + ...structuredSessionChildIdentityEnv( + sessionId, + { + ...launch.env, + ...(launch.codexHome ? { CODEX_HOME: launch.codexHome } : {}) + }, + logger + ), [CODEX_SPAWN_TOKEN_ENV]: spawnToken } } diff --git a/src/main/codex/codex-structured-child-work-producer.test.ts b/src/main/codex/codex-structured-child-work-producer.test.ts index 4317b5669d77..4cee1119c923 100644 --- a/src/main/codex/codex-structured-child-work-producer.test.ts +++ b/src/main/codex/codex-structured-child-work-producer.test.ts @@ -26,6 +26,9 @@ import { makeStructuredAgentStatusSubject } from '../../shared/agent-status-subj import type { StructuredAgentSessionEventSink } from '../native-chat/agent-session-wire/structured-agent-session-event-sink' import { fakeCodex, identityFor, THREAD_ID } from './codex-structured-session-adapter-fixture' import { CodexStructuredSessionAdapter } from './codex-structured-session-adapter' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const parent = makeStructuredAgentStatusSubject( { @@ -105,6 +108,7 @@ async function producer() { ) }) const adapter = new CodexStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ command: 'codex', args: ['app-server'], diff --git a/src/main/codex/codex-structured-dispatch-test-support.ts b/src/main/codex/codex-structured-dispatch-test-support.ts index 7513ec1fbbe4..9813f7fbdc3e 100644 --- a/src/main/codex/codex-structured-dispatch-test-support.ts +++ b/src/main/codex/codex-structured-dispatch-test-support.ts @@ -14,6 +14,9 @@ import type { StructuredAgentSessionEventSink } from '../native-chat/agent-sessi import { CodexStructuredSessionAdapter } from './codex-structured-session-adapter' import { codexTurnLifecycleFake } from './codex-turn-lifecycle-fake' import type { CodexStructuredSessionAdapterDeps } from './codex-structured-session-state' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger export const CODEX_TEST_THREAD_ID = 'thread-abc' @@ -96,6 +99,7 @@ export async function acquiredCodexAdapter(input: { requestTimeoutMs?: number }): Promise { const adapter = new CodexStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ command: 'codex', args: ['app-server'], diff --git a/src/main/codex/codex-structured-session-acquire.ts b/src/main/codex/codex-structured-session-acquire.ts index 37c34a4bf3a1..7f746bbc8464 100644 --- a/src/main/codex/codex-structured-session-acquire.ts +++ b/src/main/codex/codex-structured-session-acquire.ts @@ -126,7 +126,12 @@ export async function acquireCodexStructuredSession(input: { command: launch.command, args: launch.args, cwd: launch.cwd, - env: buildCodexStructuredChildEnvironment(launch, acquireInput.spawnToken, sessionId) + env: buildCodexStructuredChildEnvironment( + launch, + acquireInput.spawnToken, + sessionId, + deps.logger + ) }, { onNotification: (method, params) => { diff --git a/src/main/codex/codex-structured-session-adapter-fixture.ts b/src/main/codex/codex-structured-session-adapter-fixture.ts index f2b4e102c355..a6a1938360e5 100644 --- a/src/main/codex/codex-structured-session-adapter-fixture.ts +++ b/src/main/codex/codex-structured-session-adapter-fixture.ts @@ -14,6 +14,9 @@ import { type CodexStructuredSessionEvent } from './codex-structured-session-adapter' import type { CodexStructuredSessionAdapterDeps } from './codex-structured-session-state' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger export const THREAD_ID = 'thread-abc' @@ -111,6 +114,7 @@ export function adapterFor( ): CodexStructuredSessionAdapter { let acquisitionGeneration = 0 return new CodexStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ command: 'codex', args: ['app-server'], diff --git a/src/main/codex/codex-structured-session-adapter-lifecycle.test.ts b/src/main/codex/codex-structured-session-adapter-lifecycle.test.ts index e3211f320e85..2fe718f2708b 100644 --- a/src/main/codex/codex-structured-session-adapter-lifecycle.test.ts +++ b/src/main/codex/codex-structured-session-adapter-lifecycle.test.ts @@ -16,6 +16,9 @@ import { type CodexStructuredLaunch, type CodexStructuredSessionEvent } from './codex-structured-session-adapter' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const THREAD_ID = 'thread-abc' @@ -102,6 +105,7 @@ function adapterFor( ): CodexStructuredSessionAdapter { let acquisitionGeneration = 0 return new CodexStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ command: 'codex', args: ['app-server'], diff --git a/src/main/codex/codex-structured-session-adapter.test.ts b/src/main/codex/codex-structured-session-adapter.test.ts index 70b2ecd7147a..3c3bc8a96937 100644 --- a/src/main/codex/codex-structured-session-adapter.test.ts +++ b/src/main/codex/codex-structured-session-adapter.test.ts @@ -20,6 +20,9 @@ import { fakeCodex, identityFor } from './codex-structured-session-adapter-fixture' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger describe('CodexStructuredSessionAdapter.acquire', () => { it('starts a new thread and reports the process and link the lease will prove', async () => { @@ -239,6 +242,7 @@ describe('CodexStructuredSessionAdapter.acquire', () => { it('refuses to publish a session whose child died while it was being acquired', async () => { const codex = fakeCodex() const adapter = new CodexStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ command: 'codex', args: ['app-server'], @@ -271,6 +275,7 @@ describe('CodexStructuredSessionAdapter.acquire', () => { it('classifies launch validation failure as pre-spawn without opening a child', async () => { const codex = fakeCodex() const adapter = new CodexStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => { throw new Error('workspace no longer exists') }, @@ -316,6 +321,7 @@ describe('CodexStructuredSessionAdapter.acquire', () => { return codex.openConnection(...args) } const adapter = new CodexStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ command: 'codex', args: ['app-server'], @@ -345,6 +351,7 @@ describe('CodexStructuredSessionAdapter.acquire', () => { const launch = Promise.withResolvers() const codex = fakeCodex() const adapter = new CodexStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: () => launch.promise, openConnection: codex.openConnection, readProcessStartTime: async () => 1_700_000_000_000 diff --git a/src/main/codex/codex-structured-session-background-tasks.test.ts b/src/main/codex/codex-structured-session-background-tasks.test.ts index 4e2515da7d43..b3e163e35b8c 100644 --- a/src/main/codex/codex-structured-session-background-tasks.test.ts +++ b/src/main/codex/codex-structured-session-background-tasks.test.ts @@ -10,6 +10,9 @@ import { CodexStructuredSessionAdapter } from './codex-structured-session-adapte import { CodexBackgroundTaskTracker } from './codex-background-task-tracker' import type { CodexStructuredSessionEvent } from './codex-structured-session-state' import type { StructuredAgentSessionEventSink } from '../native-chat/agent-session-wire/structured-agent-session-event-sink' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger // Proves the host's child records are actually REACHED from provider traffic: the tracker is // unit-tested separately, and a producer that is correct but unwired publishes nothing while @@ -85,6 +88,7 @@ async function adapterWithSession( ): Promise<{ adapter: CodexStructuredSessionAdapter; codex: ReturnType }> { const codex = fakeCodex(close) const adapter = new CodexStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ command: 'codex', args: ['app-server'], diff --git a/src/main/codex/codex-structured-session-cancel.test.ts b/src/main/codex/codex-structured-session-cancel.test.ts index cd30bfa2e6d1..4edcf9f0c139 100644 --- a/src/main/codex/codex-structured-session-cancel.test.ts +++ b/src/main/codex/codex-structured-session-cancel.test.ts @@ -47,6 +47,9 @@ import { type CodexStructuredSessionAdapterDeps, type CodexStructuredSessionEvent } from './codex-structured-session-adapter' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const THREAD_ID = 'thread-abc' const USER_MESSAGE: AgentJournalMessageItem = { @@ -113,6 +116,7 @@ async function acquired( overrides: Partial> = {} ): Promise { const adapter = new CodexStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ command: 'codex', args: ['app-server'], diff --git a/src/main/codex/codex-structured-session-close.test.ts b/src/main/codex/codex-structured-session-close.test.ts index 9d80a0fa9829..6b5374f58b55 100644 --- a/src/main/codex/codex-structured-session-close.test.ts +++ b/src/main/codex/codex-structured-session-close.test.ts @@ -17,6 +17,9 @@ import { CodexPromptRegistry } from './codex-structured-prompt-replies' import type { CodexSession } from './codex-structured-session-state' import type { StructuredAgentSessionAdapter } from '../native-chat/agent-session-wire/structured-agent-session-adapter' import { StructuredAgentSessionAdapterRouter } from '../native-chat/agent-session-wire/structured-agent-session-adapter-router' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const THREAD = 'thread-1' @@ -51,6 +54,7 @@ function adapterFixture() { return connection }) as typeof openCodexAppServerConnection const adapter = new CodexStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ command: 'codex', args: ['app-server'], diff --git a/src/main/codex/codex-structured-session-shutdown.test.ts b/src/main/codex/codex-structured-session-shutdown.test.ts index 3883dad4600e..091a2272ce6c 100644 --- a/src/main/codex/codex-structured-session-shutdown.test.ts +++ b/src/main/codex/codex-structured-session-shutdown.test.ts @@ -8,6 +8,9 @@ import { CodexStructuredSessionAdapter, type CodexStructuredLaunch } from './codex-structured-session-adapter' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const SESSION_ID = 'session-1' const THREAD_ID = 'thread-1' @@ -49,6 +52,7 @@ describe('CodexStructuredSessionAdapter shutdown', () => { const firstLaunch = Promise.withResolvers() let launchCount = 0 const adapter = new CodexStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: () => { launchCount += 1 return launchCount === 1 ? firstLaunch.promise : Promise.resolve(LAUNCH) @@ -88,6 +92,7 @@ describe('CodexStructuredSessionAdapter shutdown', () => { close }) satisfies CodexAppServerConnection) as typeof openCodexAppServerConnection const adapter = new CodexStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => LAUNCH, openConnection, readProcessStartTime: async () => 1_700_000_000_000 diff --git a/src/main/codex/codex-structured-session-state.ts b/src/main/codex/codex-structured-session-state.ts index a47cb5a78fe2..cb9adc65f4b6 100644 --- a/src/main/codex/codex-structured-session-state.ts +++ b/src/main/codex/codex-structured-session-state.ts @@ -20,6 +20,7 @@ import type { CodexBackgroundTaskTracker } from './codex-background-task-tracker import type { CodexJournalTranslator } from './codex-structured-journal-translation' import type { StructuredAgentSessionEndedEvent } from '../native-chat/agent-session-wire/structured-agent-session-adapter' import type { CodexStructuredPermissionPolicy } from './codex-structured-permission-policy' +import type { StructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger' import type { AgentModelCatalogSessionAccess, AgentModelCatalogStore @@ -98,6 +99,8 @@ export type CodexStructuredSessionAdapterDeps = { requestTimeoutMs?: number /** Host model catalog; sessions write their listings through and read back. */ modelCatalog?: AgentModelCatalogStore + /** Where a failure this adapter carries on past is reported: the host's logger. */ + logger: StructuredAgentSessionLogger } export type CodexSession = { diff --git a/src/main/native-chat/agent-session-journal/journal-database-records-migration.test.ts b/src/main/native-chat/agent-session-journal/journal-database-records-migration.test.ts index 120588b306dd..a2ec96499c35 100644 --- a/src/main/native-chat/agent-session-journal/journal-database-records-migration.test.ts +++ b/src/main/native-chat/agent-session-journal/journal-database-records-migration.test.ts @@ -16,6 +16,9 @@ import { } from './journal-database' import { createJournalTablesSql } from './journal-database-schema' import { journalDatabasePath } from './journal-host-database' +import { recordingStructuredAgentSessionLogger } from '../agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger let root: string let dbPath: string @@ -82,7 +85,7 @@ describe('the version-4 migration', () => { seedVersion3() const copy = importOf('session-a') - const opened = openJournalDatabase(dbPath, copy) + const opened = openJournalDatabase(dbPath, copy, TEST_LOGGER) opened.db.close() expect(opened).toMatchObject({ readOnly: false, legacyRecordImportOwed: false }) @@ -96,10 +99,10 @@ describe('the version-4 migration', () => { it('never runs the copy again once the database is at 4', () => { seedVersion3() - openJournalDatabase(dbPath, importOf('session-a')).db.close() + openJournalDatabase(dbPath, importOf('session-a'), TEST_LOGGER).db.close() const again = importOf('session-b') - openJournalDatabase(dbPath, again).db.close() + openJournalDatabase(dbPath, again, TEST_LOGGER).db.close() expect(again.runs).toBe(0) inspect((db) => expect(recordIds(db)).toEqual(['session-a'])) @@ -119,7 +122,7 @@ describe('the version-4 migration', () => { return original.call(this, sql, options) }) - expect(() => openJournalDatabase(dbPath, importOf('session-a'))).toThrow( + expect(() => openJournalDatabase(dbPath, importOf('session-a'), TEST_LOGGER)).toThrow( 'crash before the version is published' ) pragma.mockRestore() @@ -129,7 +132,7 @@ describe('the version-4 migration', () => { }) const retry = importOf('session-a') - openJournalDatabase(dbPath, retry).db.close() + openJournalDatabase(dbPath, retry, TEST_LOGGER).db.close() expect(retry.runs).toBe(1) inspect((db) => { expect(journalPragmaNumber(db, 'user_version')).toBe(4) @@ -140,7 +143,7 @@ describe('the version-4 migration', () => { it('makes the tables but keeps the copy owed when the records file could not be read', () => { seedVersion3() - const opened = openJournalDatabase(dbPath, { owed: true }) + const opened = openJournalDatabase(dbPath, { owed: true }, TEST_LOGGER) // A chat created while the copy is owed keeps its row through the copy that follows. opened.db .prepare("INSERT INTO agent_session_records (session_id, record_json) VALUES ('new', '{}')") @@ -149,7 +152,7 @@ describe('the version-4 migration', () => { expect(opened.legacyRecordImportOwed).toBe(true) inspect((db) => expect(journalPragmaNumber(db, 'user_version')).toBe(3)) - openJournalDatabase(dbPath, importOf('session-a')).db.close() + openJournalDatabase(dbPath, importOf('session-a'), TEST_LOGGER).db.close() inspect((db) => { expect(journalPragmaNumber(db, 'user_version')).toBe(4) expect(recordIds(db)).toEqual(['new', 'session-a']) @@ -157,7 +160,7 @@ describe('the version-4 migration', () => { }) it('stamps a fresh file with the released version while the copy is owed', () => { - openJournalDatabase(dbPath, { owed: true }).db.close() + openJournalDatabase(dbPath, { owed: true }, TEST_LOGGER).db.close() inspect((db) => { expect(journalPragmaNumber(db, 'user_version')).toBe(3) @@ -173,7 +176,7 @@ describe('the version-4 migration', () => { }) it('creates every table on a fresh file at version 4', () => { - openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS).db.close() + openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS, TEST_LOGGER).db.close() inspect((db) => { expect(journalPragmaNumber(db, 'user_version')).toBe(4) @@ -208,7 +211,7 @@ function openAsVersion3Build(path: string): { db: Database.Database; readOnly: b describe('a build from before the move', () => { it('opens a version-4 database read-only, so it never writes beside the records', () => { - openJournalDatabase(dbPath, importOf('session-a')).db.close() + openJournalDatabase(dbPath, importOf('session-a'), TEST_LOGGER).db.close() const older = openAsVersion3Build(dbPath) try { diff --git a/src/main/native-chat/agent-session-journal/journal-database.test.ts b/src/main/native-chat/agent-session-journal/journal-database.test.ts index 677efc21c4d7..b0703ac2b9d1 100644 --- a/src/main/native-chat/agent-session-journal/journal-database.test.ts +++ b/src/main/native-chat/agent-session-journal/journal-database.test.ts @@ -26,6 +26,9 @@ import { } from './journal-row-table' import type { JournalRow } from './journal-row-schema' import { AGENT_SESSION_JOURNAL_SCHEMA_VERSION } from '../../../shared/agent-session-journal-types' +import { recordingStructuredAgentSessionLogger } from '../agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger let root: string let dbPath: string @@ -67,7 +70,7 @@ afterEach(async () => { describe('the host journal database open', () => { it('creates every table and reads back every load-bearing pragma', () => { - const db = openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS).db + const db = openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS, TEST_LOGGER).db try { const tables = db .prepare("SELECT name FROM sqlite_master WHERE type = 'table' ORDER BY name") @@ -98,14 +101,14 @@ describe('the host journal database open', () => { // T5: a newer build's database opens read-only, its rows readable, and is left byte-identical. it('opens a newer user_version read-only without touching the file', async () => { - const seeded = openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS).db + const seeded = openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS, TEST_LOGGER).db publishJournalSessionEpoch(seeded, SESSION, 'epoch-1') insertJournalRow(seeded, 'session-1', epochRow(1)) seeded.pragma(`user_version = ${JOURNAL_DB_SCHEMA_VERSION + 5}`) seeded.close() const before = await digest(dbPath) - const opened = openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS) + const opened = openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS, TEST_LOGGER) try { expect(opened.readOnly).toBe(true) expect(readJournalSessionEpoch(opened.db, 'session-1')).toBe('epoch-1') @@ -122,7 +125,7 @@ describe('the host journal database open', () => { it('closes the raw connection when schema setup throws', async () => { const failing = join(root, 'nested', 'agent-session-journal.db') - expect(() => openJournalDatabase(failing, NO_LEGACY_JOURNAL_RECORDS)).toThrow() + expect(() => openJournalDatabase(failing, NO_LEGACY_JOURNAL_RECORDS, TEST_LOGGER)).toThrow() await expect(stat(`${failing}-wal`)).rejects.toThrow() await expect(rm(root, { recursive: true, force: true })).resolves.toBeUndefined() root = await mkdtemp(join(tmpdir(), 'orca-journal-db-')) @@ -131,7 +134,7 @@ describe('the host journal database open', () => { describe('journal row statements', () => { it('serves replay, resume, suffix truncation and an epoch discard', () => { - const db = openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS).db + const db = openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS, TEST_LOGGER).db try { db.exec('BEGIN IMMEDIATE') for (let seq = 1; seq <= 5; seq += 1) { @@ -162,7 +165,7 @@ describe('journal row statements', () => { }) it('deletes only the rows no pointer names', () => { - const db = openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS).db + const db = openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS, TEST_LOGGER).db try { insertJournalRow(db, 'session-1', epochRow(1, 'epoch-copying')) insertJournalRow(db, 'session-2', epochRow(1, 'epoch-live')) @@ -181,7 +184,7 @@ describe('journal row statements', () => { }) it('refuses a duplicate sequence inside one epoch of one chat', () => { - const db = openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS).db + const db = openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS, TEST_LOGGER).db try { insertJournalRow(db, 'session-1', epochRow(1)) expect(() => insertJournalRow(db, 'session-1', epochRow(1))).toThrow() @@ -193,7 +196,7 @@ describe('journal row statements', () => { }) it('moves the epoch pointer in place', () => { - const db = openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS).db + const db = openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS, TEST_LOGGER).db try { publishJournalSessionEpoch(db, SESSION, 'epoch-1') publishJournalSessionEpoch(db, SESSION, 'epoch-2') @@ -221,7 +224,7 @@ describe('schema creation', () => { return original.call(this, sql, options) }) - expect(() => openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS)).toThrow( + expect(() => openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS, TEST_LOGGER)).toThrow( 'crash before the version is published' ) pragma.mockRestore() @@ -253,10 +256,10 @@ INSERT INTO journal_sessions VALUES ('s1', 'ws', 'e1', 0, NULL, NULL);`) earlier.close() const before = await digest(dbPath) - expect(() => openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS)).toThrow( + expect(() => openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS, TEST_LOGGER)).toThrow( `unreleased schema ${version}` ) - expect(() => openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS)).toThrow( + expect(() => openJournalDatabase(dbPath, NO_LEGACY_JOURNAL_RECORDS, TEST_LOGGER)).toThrow( JournalUnreleasedSchemaError ) diff --git a/src/main/native-chat/agent-session-journal/journal-database.ts b/src/main/native-chat/agent-session-journal/journal-database.ts index a306ad6e564e..69edab3ca2eb 100644 --- a/src/main/native-chat/agent-session-journal/journal-database.ts +++ b/src/main/native-chat/agent-session-journal/journal-database.ts @@ -15,6 +15,7 @@ import { } from './journal-database-schema' import { JournalUnreleasedSchemaError } from './journal-open-failure' import { ensureQueuedMessagesTable } from './queued-message-schema' +import type { StructuredAgentSessionLogger } from '../agent-session-wire/structured-agent-session-logger' export const JOURNAL_BUSY_TIMEOUT_MS = 5000 /** Bounds the WAL a checkpoint leaves behind; SQLite truncates it back to this after a reset. */ @@ -98,7 +99,8 @@ export function journalDatabaseHoldsAgentSessions(dbPath: string): boolean | und export function openJournalDatabase( dbPath: string, - legacyRecords: JournalLegacyRecordImport + legacyRecords: JournalLegacyRecordImport, + logger: StructuredAgentSessionLogger ): OpenJournalDatabase { const probe = new Database(dbPath) let stored: number @@ -125,7 +127,7 @@ export function openJournalDatabase( ) } configureJournalPragmas(probe, stored) - const legacyRecordImportOwed = migrateJournalSchema(probe, stored, legacyRecords) + const legacyRecordImportOwed = migrateJournalSchema(probe, stored, legacyRecords, logger) // Outside `migrateJournalSchema` on purpose: its early return skips a db // already at the current version, and this table must exist at EVERY // writable open with no `user_version` bump (see `ensureQueuedMessagesTable`). @@ -167,12 +169,13 @@ function configureJournalPragmas(db: Database.Database, stored: number): void { function migrateJournalSchema( db: Database.Database, stored: number, - legacyRecords: JournalLegacyRecordImport + legacyRecords: JournalLegacyRecordImport, + logger: StructuredAgentSessionLogger ): boolean { if (stored >= JOURNAL_DB_SCHEMA_VERSION) { return false } - runJournalTransaction(db, () => { + runJournalTransaction(db, logger, () => { if (stored === 0) { db.exec(createJournalTablesSql()) } @@ -199,6 +202,7 @@ function migrateJournalSchema( */ export function runJournalTransaction( db: Database.Database, + logger: StructuredAgentSessionLogger, run: (db: Database.Database) => T, onStranded: () => void = () => undefined ): T { @@ -215,10 +219,10 @@ export function runJournalTransaction( try { db.exec('ROLLBACK') } catch (rollbackError) { - console.warn( - '[agent-session-journal] rolling back a failed transaction failed', - rollbackError - ) + logger.warn('rolling back a failed chat journal transaction failed', { + scope: 'journal-transaction-rollback', + error: rollbackError + }) onStranded() } } diff --git a/src/main/native-chat/agent-session-journal/journal-host-database-test-support.ts b/src/main/native-chat/agent-session-journal/journal-host-database-test-support.ts index dbe15b4709ed..e5665e71b185 100644 --- a/src/main/native-chat/agent-session-journal/journal-host-database-test-support.ts +++ b/src/main/native-chat/agent-session-journal/journal-host-database-test-support.ts @@ -17,16 +17,22 @@ import type Database from '../../sqlite/sync-database' import type { AgentSessionJournal } from './journal-store' import type { AgentSessionJournalOptions } from './journal-store-contracts' import { openAgentSessionJournal } from './journal-store-factory' +import type { StructuredAgentSessionLogger } from '../agent-session-wire/structured-agent-session-logger' +import { recordingStructuredAgentSessionLogger } from '../agent-session-wire/structured-agent-session-logger-test-support' const opened = new Map() -export function openTestJournalHostDatabase(stateDirectory: string): JournalHostDatabase { +/** `logger` applies only to the open that creates this directory's database. */ +export function openTestJournalHostDatabase( + stateDirectory: string, + logger: StructuredAgentSessionLogger = recordingStructuredAgentSessionLogger().logger +): JournalHostDatabase { const directory = resolve(stateDirectory) const existing = opened.get(directory) if (existing && !existing.isClosed) { return existing } - const database = JournalHostDatabase.openWith(directory, NO_LEGACY_JOURNAL_RECORDS) + const database = JournalHostDatabase.openWith(directory, NO_LEGACY_JOURNAL_RECORDS, logger) opened.set(directory, database) return database } diff --git a/src/main/native-chat/agent-session-journal/journal-host-database.ts b/src/main/native-chat/agent-session-journal/journal-host-database.ts index ca6036d3a9d0..799c9ef8d0dd 100644 --- a/src/main/native-chat/agent-session-journal/journal-host-database.ts +++ b/src/main/native-chat/agent-session-journal/journal-host-database.ts @@ -21,6 +21,7 @@ import { import { journalOpenRefusalError } from './journal-open-failure' import { journalDirectoryFor } from './journal-paths' import { AgentSessionJournalError } from './journal-write-guards' +import type { StructuredAgentSessionLogger } from '../agent-session-wire/structured-agent-session-logger' const JOURNAL_DATABASE_FILE = 'agent-session-journal.db' @@ -39,7 +40,9 @@ export class JournalHostDatabase { private constructor( readonly stateDirectory: string, - opened: OpenJournalDatabase + opened: OpenJournalDatabase, + /** The host's logger: every chat's journal reports a failure it carries on past here. */ + readonly logger: StructuredAgentSessionLogger ) { this.connection = opened.db this.readOnly = opened.readOnly @@ -49,7 +52,8 @@ export class JournalHostDatabase { /** `readLegacyRecords` runs only when this open migrates to version 4, before any transaction. */ static async open( stateDirectory: string, - readLegacyRecords: () => Promise + readLegacyRecords: () => Promise, + logger: StructuredAgentSessionLogger ): Promise { mkdirSync(stateDirectory, { recursive: true }) const migrates = journalDatabaseMigratesRecords( @@ -57,19 +61,22 @@ export class JournalHostDatabase { ) return JournalHostDatabase.openWith( stateDirectory, - migrates ? await readLegacyRecords() : NO_LEGACY_JOURNAL_RECORDS + migrates ? await readLegacyRecords() : NO_LEGACY_JOURNAL_RECORDS, + logger ) } /** The same open with the records file already read; tests pass `NO_LEGACY_JOURNAL_RECORDS`. */ static openWith( stateDirectory: string, - legacyRecords: JournalLegacyRecordImport + legacyRecords: JournalLegacyRecordImport, + logger: StructuredAgentSessionLogger ): JournalHostDatabase { mkdirSync(stateDirectory, { recursive: true }) return new JournalHostDatabase( stateDirectory, - openJournalDatabase(journalDatabasePath(stateDirectory), legacyRecords) + openJournalDatabase(journalDatabasePath(stateDirectory), legacyRecords, logger), + logger ) } @@ -90,7 +97,7 @@ export class JournalHostDatabase { /** One IMMEDIATE transaction; see `runJournalTransaction`. */ transaction(run: (db: Database.Database) => T): T { - return runJournalTransaction(this.db, run, () => { + return runJournalTransaction(this.db, this.logger, run, () => { this.stranded = true }) } diff --git a/src/main/native-chat/agent-session-journal/journal-open-failure.test.ts b/src/main/native-chat/agent-session-journal/journal-open-failure.test.ts index 787b1aa6491b..b8d49c55174f 100644 --- a/src/main/native-chat/agent-session-journal/journal-open-failure.test.ts +++ b/src/main/native-chat/agent-session-journal/journal-open-failure.test.ts @@ -16,6 +16,8 @@ import { journalDatabasePath } from './journal-host-database' import { replayJournal } from './journal-open' import { recordingStructuredAgentSessionLogger } from '../agent-session-wire/structured-agent-session-logger-test-support' +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger + let root: string beforeEach(async () => { @@ -29,7 +31,11 @@ afterEach(async () => { /** What the journal's own open, then a chat's replay, throws for the file as it stands. */ function openFailure(): unknown { try { - const db = openJournalDatabase(journalDatabasePath(root), NO_LEGACY_JOURNAL_RECORDS).db + const db = openJournalDatabase( + journalDatabasePath(root), + NO_LEGACY_JOURNAL_RECORDS, + TEST_LOGGER + ).db try { replayJournal(db, 'session-1') } finally { @@ -60,7 +66,7 @@ describe('classifyJournalOpenFailure', () => { it('calls a journal whose pages are damaged corrupt', async () => { const path = journalDatabasePath(root) - const opened = openJournalDatabase(path, NO_LEGACY_JOURNAL_RECORDS).db + const opened = openJournalDatabase(path, NO_LEGACY_JOURNAL_RECORDS, TEST_LOGGER).db opened.exec('PRAGMA journal_mode = DELETE') opened.close() const bytes = await readFile(path) diff --git a/src/main/native-chat/agent-session-journal/journal-per-session-import.test.ts b/src/main/native-chat/agent-session-journal/journal-per-session-import.test.ts index 9ec154d0e5df..bf54007d5501 100644 --- a/src/main/native-chat/agent-session-journal/journal-per-session-import.test.ts +++ b/src/main/native-chat/agent-session-journal/journal-per-session-import.test.ts @@ -380,7 +380,7 @@ describe('importing a per-chat journal', () => { const { epoch, rows } = await historyRows() await writeLegacyJournal(epoch, rows) const database = openTestJournalHostDatabase(root) - const errors = vi.spyOn(console, 'error').mockImplementation(() => undefined) + const errors = vi.spyOn(database.logger, 'error') const input = { database, identity: IDENTITY, @@ -403,6 +403,10 @@ describe('importing a per-chat journal', () => { total: 0 }) expect(errors).toHaveBeenCalledOnce() + expect(errors.mock.calls[0]?.[1]).toMatchObject({ + scope: 'journal-import-verify', + sessionId: IDENTITY.sessionId + }) // A copy that reads back whole then imports it, over what the refused ones left. const journal = await openChat() expect(readTestJournalRows(database.db, IDENTITY.sessionId, epoch)).toEqual(rows) @@ -416,7 +420,7 @@ describe('importing a per-chat journal', () => { expect(rows.filter((row) => row.rowJson.includes('On it.'))).toHaveLength(1) await writeLegacyJournal(epoch, rows) const database = openTestJournalHostDatabase(root) - const errors = vi.spyOn(console, 'error').mockImplementation(() => undefined) + const errors = vi.spyOn(database.logger, 'error') const input = { database, identity: IDENTITY, diff --git a/src/main/native-chat/agent-session-journal/journal-per-session-import.ts b/src/main/native-chat/agent-session-journal/journal-per-session-import.ts index 5f85fdded437..f0aad843ad6a 100644 --- a/src/main/native-chat/agent-session-journal/journal-per-session-import.ts +++ b/src/main/native-chat/agent-session-journal/journal-per-session-import.ts @@ -130,7 +130,7 @@ async function importOnce(input: ImportInput): Promise void = (path) => rmSync(path, { force: true }) ): void { const file = legacyJournalDatabaseFile(legacyDirectory) @@ -133,7 +135,11 @@ export function retireLegacyJournal( remove(path) } } catch (error) { - console.warn(`[agent-session-journal] deleting imported ${legacyDirectory} failed`, error) + logger.warn('deleting an imported per-chat journal failed', { + scope: 'journal-import-retire', + legacyDirectory, + error + }) return } try { diff --git a/src/main/native-chat/agent-session-journal/journal-queued-messages.ts b/src/main/native-chat/agent-session-journal/journal-queued-messages.ts index b8fcafc0b6c0..f0cb91fd19f6 100644 --- a/src/main/native-chat/agent-session-journal/journal-queued-messages.ts +++ b/src/main/native-chat/agent-session-journal/journal-queued-messages.ts @@ -293,9 +293,10 @@ export class JournalQueuedMessages { * never allowed to fail opening the chat. */ repairAndPruneAtOpen(): Promise { return this.repairAndPrune().catch((error: unknown) => { - console.warn('[journal-open] queued-message repair skipped:', { + this.deps.database().logger.warn('repairing queued messages at open was skipped', { + scope: 'journal-queued-message-repair', sessionId: this.deps.sessionId, - error: error instanceof Error ? error.message : String(error) + error }) }) } diff --git a/src/main/native-chat/agent-session-journal/journal-restart-reconciliation.test.ts b/src/main/native-chat/agent-session-journal/journal-restart-reconciliation.test.ts index 2f28adf0d545..61db09ad6d49 100644 --- a/src/main/native-chat/agent-session-journal/journal-restart-reconciliation.test.ts +++ b/src/main/native-chat/agent-session-journal/journal-restart-reconciliation.test.ts @@ -103,6 +103,7 @@ describe('reconcileJournalSubmissionsAgainstHistory', () => { const journal = await reopenAfterCrash() const settled = await reconcileJournalSubmissionsAgainstHistory({ + sessionId: IDENTITY.sessionId, journal, fence: 2, history: window([history('uuid-1', 'deploy the thing')]) @@ -118,6 +119,7 @@ describe('reconcileJournalSubmissionsAgainstHistory', () => { const journal = await reopenAfterCrash() const settled = await reconcileJournalSubmissionsAgainstHistory({ + sessionId: IDENTITY.sessionId, journal, fence: 2, history: window([]) @@ -144,6 +146,7 @@ describe('reconcileJournalSubmissionsAgainstHistory', () => { const journal = await reopenAfterCrash() const settled = await reconcileJournalSubmissionsAgainstHistory({ + sessionId: IDENTITY.sessionId, journal, fence: 2, history: window([], { turnInFlight: true }) @@ -157,6 +160,7 @@ describe('reconcileJournalSubmissionsAgainstHistory', () => { const journal = await reopenAfterCrash() const settled = await reconcileJournalSubmissionsAgainstHistory({ + sessionId: IDENTITY.sessionId, journal, fence: 2, history: window([], { boundaryConsistent: false }) @@ -180,6 +184,7 @@ describe('reconcileJournalSubmissionsAgainstHistory', () => { ) const settled = await reconcileJournalSubmissionsAgainstHistory({ + sessionId: IDENTITY.sessionId, journal, fence: 2, history: window([]) @@ -203,6 +208,7 @@ describe('reconcileJournalSubmissionsAgainstHistory', () => { ) const settled = await reconcileJournalSubmissionsAgainstHistory({ + sessionId: IDENTITY.sessionId, journal, fence: 2, history: window([history('uuid-1', 'first\nsecond')]) @@ -229,6 +235,7 @@ describe('reconcileJournalSubmissionsAgainstHistory', () => { await restarted.markPendingSubmissionsUnknown(2) await reconcileJournalSubmissionsAgainstHistory({ + sessionId: IDENTITY.sessionId, journal: restarted, fence: 2, history: window([history('uuid-old', 'deploy the thing')]) @@ -261,6 +268,7 @@ describe('reconcileJournalSubmissionsAgainstHistory', () => { await restarted.markPendingSubmissionsUnknown(2) await reconcileJournalSubmissionsAgainstHistory({ + sessionId: IDENTITY.sessionId, journal: restarted, fence: 2, history: window([history('uuid-old', 'deploy the thing')]) @@ -287,6 +295,7 @@ describe('reconcileJournalSubmissionsAgainstHistory', () => { await restarted.markPendingSubmissionsUnknown(2) await reconcileJournalSubmissionsAgainstHistory({ + sessionId: IDENTITY.sessionId, journal: restarted, fence: 2, history: window([history('uuid-1', 'ping'), history('uuid-2', 'ping')]) diff --git a/src/main/native-chat/agent-session-journal/journal-restart-reconciliation.ts b/src/main/native-chat/agent-session-journal/journal-restart-reconciliation.ts index f1484bf5da8a..dbfe4079d401 100644 --- a/src/main/native-chat/agent-session-journal/journal-restart-reconciliation.ts +++ b/src/main/native-chat/agent-session-journal/journal-restart-reconciliation.ts @@ -86,6 +86,7 @@ function unseenHistory( * ids this pass settled, so the attach result stops reporting them unconfirmed. */ export async function reconcileJournalSubmissionsAgainstHistory(input: { + sessionId: string journal: AgentSessionJournal fence: number history: ProviderHistoryWindow @@ -101,7 +102,9 @@ export async function reconcileJournalSubmissionsAgainstHistory(input: { })) { if (outcome.outcome === 'unknown') { // Narrowing failed: the submission stays unconfirmed, so record why. - console.warn('[journal-reconcile] submission left unconfirmed:', { + input.journal.logger.warn('a submission was left unconfirmed', { + scope: 'journal-submission-reconcile', + sessionId: input.sessionId, clientMessageId: outcome.clientMessageId, reason: outcome.reason, fence: input.fence diff --git a/src/main/native-chat/agent-session-journal/journal-row-writer.ts b/src/main/native-chat/agent-session-journal/journal-row-writer.ts index a29585580ebe..ce1d7274dbd3 100644 --- a/src/main/native-chat/agent-session-journal/journal-row-writer.ts +++ b/src/main/native-chat/agent-session-journal/journal-row-writer.ts @@ -83,10 +83,11 @@ export class JournalRowWriter { this.deps.rolledBack?.() // The draft store re-derives what this missed from the committed rows: at open, and in // the drain step before a draft sends. - console.warn('[journal-append] row bookkeeping skipped:', { + this.deps.database().logger.warn('row bookkeeping was skipped', { + scope: 'journal-row-bookkeeping', sessionId: this.deps.sessionId, kind: row.kind, - error: error instanceof Error ? error.message : String(error) + error }) } } diff --git a/src/main/native-chat/agent-session-journal/journal-store.ts b/src/main/native-chat/agent-session-journal/journal-store.ts index 3de15cc3df60..95d053095c59 100644 --- a/src/main/native-chat/agent-session-journal/journal-store.ts +++ b/src/main/native-chat/agent-session-journal/journal-store.ts @@ -77,6 +77,8 @@ export { AgentSessionJournalError } from './journal-write-guards' export class AgentSessionJournal { private readonly identity: AgentSessionJournalIdentity private readonly database: JournalHostDatabase + /** The host's logger, for a step on this chat that carries on past a failure. */ + readonly logger: JournalHostDatabase['logger'] private readonly now: () => number private readonly mintEpoch: () => string @@ -99,6 +101,7 @@ export class AgentSessionJournal { constructor(options: AgentSessionJournalOptions) { this.identity = options.identity this.database = options.database + this.logger = options.database.logger this.now = options.now ?? (() => Date.now()) this.mintEpoch = options.mintEpoch ?? randomUUID this.state = createJournalReducerState(options.identity.sessionId, '') diff --git a/src/main/native-chat/agent-session-journal/queued-message-bookkeeping-failure.test.ts b/src/main/native-chat/agent-session-journal/queued-message-bookkeeping-failure.test.ts index 638a62bdf02a..59b220a2726d 100644 --- a/src/main/native-chat/agent-session-journal/queued-message-bookkeeping-failure.test.ts +++ b/src/main/native-chat/agent-session-journal/queued-message-bookkeeping-failure.test.ts @@ -93,7 +93,7 @@ describe('draft bookkeeping inside a journal append', () => { it('a throwing draft transition still commits the rejection row, and the next open recovers the draft', async () => { let journal = await open() await queueAndConsume(journal, 'draft-1') - const warn = vi.spyOn(console, 'warn').mockImplementation(() => undefined) + const warn = vi.spyOn(journal.logger, 'warn') vi.spyOn(JournalQueuedMessages.prototype, 'onRowInTransaction').mockImplementationOnce(() => { throw new Error('table queued_messages has no column named returned_rejection') }) @@ -107,8 +107,8 @@ describe('draft bookkeeping inside a journal append', () => { expect(journal.submission('sub-draft-1')?.dispatchState).toBe('rejected') expect(journal.queuedMessages.get('draft-1')?.state).toBe('dispatched') expect(warn).toHaveBeenCalledWith( - '[journal-append] row bookkeeping skipped:', - expect.objectContaining({ kind: 'dispatch' }) + 'row bookkeeping was skipped', + expect.objectContaining({ scope: 'journal-row-bookkeeping', kind: 'dispatch' }) ) await journal.close() journal = await open() diff --git a/src/main/native-chat/agent-session-journal/queued-message-store.test.ts b/src/main/native-chat/agent-session-journal/queued-message-store.test.ts index c3910e466854..2f1b4d0b52da 100644 --- a/src/main/native-chat/agent-session-journal/queued-message-store.test.ts +++ b/src/main/native-chat/agent-session-journal/queued-message-store.test.ts @@ -24,7 +24,8 @@ import { import type { AgentSessionJournal } from './journal-store' import { closeTestJournalHostDatabases, - createTrackedJournalOpener + createTrackedJournalOpener, + openTestJournalHostDatabase } from './journal-host-database-test-support' const IDENTITY: AgentSessionJournalIdentity = { @@ -505,12 +506,16 @@ describe('open-time repair and retention', () => { const repair = vi .spyOn(JournalQueuedMessages.prototype, 'repairAndPrune') .mockRejectedValueOnce(new Error('SQLITE_FULL')) - const warn = vi.spyOn(console, 'warn').mockImplementation(() => undefined) + const warn = vi.spyOn(openTestJournalHostDatabase(root).logger, 'warn') try { const journal = await open() expect(warn).toHaveBeenCalledWith( - '[journal-open] queued-message repair skipped:', - expect.objectContaining({ error: 'SQLITE_FULL' }) + 'repairing queued messages at open was skipped', + expect.objectContaining({ + scope: 'journal-queued-message-repair', + sessionId: IDENTITY.sessionId, + error: new Error('SQLITE_FULL') + }) ) await queueDraft(journal, 'draft-1') expect(journal.queuedMessages.list()).toHaveLength(1) diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-attach.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-attach.ts index 85f99056c3a7..9960812275e5 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-attach.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-attach.ts @@ -248,6 +248,7 @@ async function reconcileAgainstProviderHistory(input: { return [] } return reconcileJournalSubmissionsAgainstHistory({ + sessionId: input.identity.sessionId, journal: input.journal, fence: input.fence, history diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-chat-stop.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-chat-stop.ts index 77a6fa3434e0..8e0646e489ee 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-chat-stop.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-chat-stop.ts @@ -99,12 +99,6 @@ export function mutateWithChatStop( clientOperationId: envelope.clientOperationId, ...named, stopChild, - onStopChildError: (error) => - context.deps.logger.warn('ending the agent process on Stop failed', { - scope: 'stop-child', - sessionId, - error - }), // The host drops its child only once the exit is proven, and nothing else runs meanwhile. childReleased: () => context.sessions.get(sessionId)?.child !== child, endSession: (owed) => { diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-claude-compact-stop.test.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-claude-compact-stop.test.ts index bbdc2b50b2fd..e720305bb02c 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-claude-compact-stop.test.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-claude-compact-stop.test.ts @@ -29,6 +29,9 @@ import { } from './structured-agent-session-host-test-data' import { openTestJournalHostDatabase } from '../agent-session-journal/journal-host-database-test-support' import { createStructuredAgentSessionLogger } from './structured-agent-session-logger' +import { recordingStructuredAgentSessionLogger } from './structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const CALLER = { callerKey: 'client-1' } @@ -47,6 +50,7 @@ beforeEach(async () => { // No echo of its own: each test writes the frames Claude would. claude = fakeClaude({ replayUuid: null }) adapter = new ClaudeStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ pathToClaudeCodeExecutable: 'claude', options: {}, diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-claude-echo-working.test.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-claude-echo-working.test.ts index 747319c3c66b..eb36fb5f0aa8 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-claude-echo-working.test.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-claude-echo-working.test.ts @@ -28,6 +28,9 @@ import { } from './structured-agent-session-host-test-data' import { openTestJournalHostDatabase } from '../agent-session-journal/journal-host-database-test-support' import { createStructuredAgentSessionLogger } from './structured-agent-session-logger' +import { recordingStructuredAgentSessionLogger } from './structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const CALLER = { callerKey: 'client-1' } @@ -43,6 +46,7 @@ beforeEach(async () => { claude.current = fakeClaude({ replayUuid: null }) const lifecycle: Promise[] = [] adapter = new ClaudeStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ pathToClaudeCodeExecutable: 'claude', options: {}, diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-claude-queued-stop.test.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-claude-queued-stop.test.ts index 5e4ac75b0662..a7344b561f81 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-claude-queued-stop.test.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-claude-queued-stop.test.ts @@ -30,6 +30,9 @@ import { resetHostTestOperationIds } from './structured-agent-session-host-test-data' import { createStructuredAgentSessionLogger } from './structured-agent-session-logger' +import { recordingStructuredAgentSessionLogger } from './structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const CALLER = { callerKey: 'client-1' } // As Claude Code 2.1.280 advertises them on a turn's system/init frame. @@ -59,6 +62,7 @@ beforeEach(async () => { }) const lifecycle: Promise[] = [] adapter = new ClaudeStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ pathToClaudeCodeExecutable: 'claude', options: {}, diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-claude-stop-ends-session.test.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-claude-stop-ends-session.test.ts index ddef0ed0bb65..410c1458b38c 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-claude-stop-ends-session.test.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-claude-stop-ends-session.test.ts @@ -42,6 +42,8 @@ import { resetHostTestOperationIds } from './structured-agent-session-host-test-data' +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger + const CALLER = { callerKey: 'client-1' } // As Claude Code 2.1.280 advertises them on a turn's system/init frame. const CAPABILITIES = ['interrupt_receipt_v1', 'interrupt_cancel_queued_v1', 'msg_lifecycle_v1'] @@ -77,6 +79,7 @@ beforeEach(async () => { }) const lifecycle: Promise[] = [] adapter = new ClaudeStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ pathToClaudeCodeExecutable: 'claude', options: {}, diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-claude-stop-turn-end.test.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-claude-stop-turn-end.test.ts index 9e10a753f07e..b86e95dd42a7 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-claude-stop-turn-end.test.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-claude-stop-turn-end.test.ts @@ -30,6 +30,9 @@ import { hostTestOperationId, resetHostTestOperationIds } from './structured-agent-session-host-test-data' +import { recordingStructuredAgentSessionLogger } from './structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const CALLER = { callerKey: 'client-1' } // As Claude Code 2.1.280 advertises them on a turn's system/init frame. @@ -47,6 +50,7 @@ beforeEach(async () => { claude = fakeClaude({ replayUuid: null }) const lifecycle: Promise[] = [] adapter = new ClaudeStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ pathToClaudeCodeExecutable: 'claude', options: {}, diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-claude-unproven-stop-send.test.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-claude-unproven-stop-send.test.ts index b86e25674641..0533be3ef6c5 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-claude-unproven-stop-send.test.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-claude-unproven-stop-send.test.ts @@ -31,6 +31,8 @@ import { resetHostTestOperationIds } from './structured-agent-session-host-test-data' +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger + const CALLER = { callerKey: 'client-1' } const CAPABILITIES = ['interrupt_receipt_v1', 'interrupt_cancel_queued_v1', 'msg_lifecycle_v1'] @@ -51,6 +53,7 @@ beforeEach(async () => { }) const lifecycle: Promise[] = [] adapter = new ClaudeStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ pathToClaudeCodeExecutable: 'claude', options: {}, diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-owed-work-release.test.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-owed-work-release.test.ts index 8b2586a9ccba..ef45025f5ab0 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-owed-work-release.test.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-owed-work-release.test.ts @@ -33,6 +33,9 @@ import { } from './structured-agent-session-host-test-data' import { openTestJournalHostDatabase } from '../agent-session-journal/journal-host-database-test-support' import { createStructuredAgentSessionLogger } from './structured-agent-session-logger' +import { recordingStructuredAgentSessionLogger } from './structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const CALLER = { callerKey: 'client-1' } const SWEEP_MS = 5 @@ -59,6 +62,7 @@ beforeEach(async () => { landInit = resolve }) adapter = new ClaudeStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ pathToClaudeCodeExecutable: 'claude', options: {}, diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-provider-started.test.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-provider-started.test.ts index 2922c3fdb2ec..7c8470b04039 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-provider-started.test.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-provider-started.test.ts @@ -24,6 +24,9 @@ import { } from './structured-agent-session-host-test-data' import { openTestJournalHostDatabase } from '../agent-session-journal/journal-host-database-test-support' import { createStructuredAgentSessionLogger } from './structured-agent-session-logger' +import { recordingStructuredAgentSessionLogger } from './structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const CALLER = { callerKey: 'client-1' } const INIT_DELAY_MS = 40 @@ -52,6 +55,7 @@ beforeEach(async () => { } }) adapter = new ClaudeStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ pathToClaudeCodeExecutable: 'claude', options: {}, diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-registry.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-registry.ts index 3b675c4054a2..3f7bdd2a1e3b 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-registry.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-registry.ts @@ -6,8 +6,11 @@ // Tests install a host with a stub adapter and clear it on teardown. import type { StructuredAgentSessionHost } from './structured-agent-session-host' +import type { StructuredAgentSessionLogger } from './structured-agent-session-logger' let host: StructuredAgentSessionHost | null = null +// Kept past teardown, so a listener that throws when the last chat is released still reports. +let logger: StructuredAgentSessionLogger | null = null let held = false let stopWatchingHost: (() => void) | null = null const heldListeners = new Set<(held: boolean) => void>() @@ -29,11 +32,11 @@ function publishHeld(): void { try { listener(next) } catch (error) { - console.warn('[structured-agent-session] a held-chats listener threw', error) + logger?.warn('a held-chats listener threw', { scope: 'held-chats-listener', error }) } } } catch (error) { - console.warn('[structured-agent-session] reading whether chats are held failed', error) + logger?.warn('reading whether chats are held failed', { scope: 'held-chats-read', error }) } } @@ -41,11 +44,15 @@ export function setStructuredAgentSessionHost(next: StructuredAgentSessionHost | stopWatchingHost?.() stopWatchingHost = null host = next + // Why typeof: tests install partial hosts. + if (typeof next?.deps?.logger?.warn === 'function') { + logger = next.deps.logger + } try { stopWatchingHost = typeof next?.onSessionsHeld === 'function' ? next.onSessionsHeld(publishHeld) : null } catch (error) { - console.warn('[structured-agent-session] watching for held chats failed', error) + logger?.warn('watching for held chats failed', { scope: 'held-chats-watch', error }) } publishHeld() } diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-restart-failure-ledger.test.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-restart-failure-ledger.test.ts new file mode 100644 index 000000000000..58f91b0ebc64 --- /dev/null +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-restart-failure-ledger.test.ts @@ -0,0 +1,80 @@ +import { describe, expect, it } from 'vitest' +import type { StructuredAgentSessionAdapter } from './structured-agent-session-adapter' +import { createStructuredAgentSessionRestartFailureLedger } from './structured-agent-session-restart-failure-ledger' +import { recordingStructuredAgentSessionLogger } from './structured-agent-session-logger-test-support' +import { STRUCTURED_AGENT_SESSION_RESUME_NOT_ELIGIBLE } from './structured-agent-session-restart-resume-runner' + +const PROMPT = 'private prompt the user typed' + +const adapter: StructuredAgentSessionAdapter = { + acquire: async () => { + throw new Error('not acquired in this test') + }, + dispatch: async () => { + throw new Error('not dispatched in this test') + }, + cancelTurn: async () => ({ cancelled: false }), + answerPrompt: async () => undefined, + setOption: async () => undefined +} + +describe('restart failure ledger settlement', () => { + it('names the operation and every affected session when a capsule write fails, and no error', async () => { + const log = recordingStructuredAgentSessionLogger() + // A capsule error can quote the recovery payload, which holds the user's prompt. + const fail = async (): Promise => { + throw new Error(`capsule write failed: ${PROMPT}`) + } + const ledger = createStructuredAgentSessionRestartFailureLedger({ + capsule: { + listFailed: async () => [], + completeResume: fail, + failResume: fail, + rollbackResume: fail, + dismiss: async () => 0, + clearAll: async () => 0 + }, + getRecord: () => null, + adapter, + retryable: () => false, + reveal: async () => undefined, + logger: log.logger, + now: () => 1_000, + enqueue: (operation) => operation() + }) + + await ledger.settle( + 'operation-1', + [ + { + sessionId: 'session-done', + outcome: 'refused', + reason: STRUCTURED_AGENT_SESSION_RESUME_NOT_ELIGIBLE + }, + { sessionId: 'session-a', outcome: 'refused', reason: 'agent_session_resume_refused' }, + { sessionId: 'session-b', outcome: 'refused', reason: 'agent_session_resume_refused' } + ], + { + candidates: [], + markers: new Map(), + failureAfterResume: () => null, + failureReason: () => 'unused' + } + ) + + expect(log.entries.map(({ fields }) => fields)).toEqual([ + { scope: 'restart-offer-complete', operationId: 'operation-1', sessionIds: ['session-done'] }, + { + scope: 'restart-failure-record', + operationId: 'operation-1', + sessionIds: ['session-a', 'session-b'] + }, + { + scope: 'restart-offer-rollback', + operationId: 'operation-1', + sessionIds: ['session-done', 'session-a', 'session-b'] + } + ]) + expect(JSON.stringify(log.entries)).not.toContain(PROMPT) + }) +}) diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-restart-failure-ledger.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-restart-failure-ledger.ts index 63722d1737cc..800af9ddb681 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-restart-failure-ledger.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-restart-failure-ledger.ts @@ -182,7 +182,8 @@ export function createStructuredAgentSessionRestartFailureLedger(deps: { .catch(() => { deps.logger.warn('completing a restart offer failed', { scope: 'restart-offer-complete', - operationId + operationId, + sessionIds: completed }) }) // Filed before the rollback so a failure the user must act on is never reopened as an offer @@ -192,7 +193,8 @@ export function createStructuredAgentSessionRestartFailureLedger(deps: { .catch(() => { deps.logger.warn('recording a restart failure failed', { scope: 'restart-failure-record', - operationId + operationId, + sessionIds: failures.map((failure) => failure.sessionId) }) }) // This only reopens rows still owned by this operation. Rows removed by completeResume stay @@ -202,7 +204,9 @@ export function createStructuredAgentSessionRestartFailureLedger(deps: { .catch(() => { deps.logger.warn('rolling back a restart offer failed', { scope: 'restart-offer-rollback', - operationId + operationId, + // Every session the operation settled: which rows it still owned depends on the writes above. + sessionIds: outcomes.map((outcome) => outcome.sessionId) }) }) } diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-turns-cancel.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-turns-cancel.ts index 48500afa12f3..d970bf40bf91 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-turns-cancel.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-turns-cancel.ts @@ -111,8 +111,6 @@ export async function performCancel( /** Ends the provider child, for a running command the provider did not take the Stop on, or a * turn whose interrupt failed. */ stopChild?: () => Promise - /** A child end after a failed interrupt that threw. */ - onStopChildError?: (error: unknown) => void /** After that throw: whether the host let go of the child, its exit proven before a later * cleanup step failed. */ childReleased?: () => boolean @@ -242,7 +240,11 @@ export async function performCancel( await input.stopChild() ended = true } catch (error) { - input.onStopChildError?.(error) + ctx.logger.warn('ending the agent process on Stop failed', { + scope: 'stop-child', + sessionId: ctx.sessionId, + error + }) // Unless the exit was proven, the child may still run the turn and the failed row stays true. ended = input.childReleased?.() === true } diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-view-start-after-failed-start.test.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-view-start-after-failed-start.test.ts index 20c5abd595e8..221ce58b7ecc 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-view-start-after-failed-start.test.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-view-start-after-failed-start.test.ts @@ -26,6 +26,9 @@ import { } from './structured-agent-session-host-test-data' import { openTestJournalHostDatabase } from '../agent-session-journal/journal-host-database-test-support' import { createStructuredAgentSessionLogger } from './structured-agent-session-logger' +import { recordingStructuredAgentSessionLogger } from './structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger /** Delivery runs on its own serialized steps; under a loaded runner they take more than a second. */ function eventually(assertion: () => unknown): Promise { @@ -54,6 +57,7 @@ beforeEach(async () => { // Every start spawns, is published, and exits before it answers initialize. claude = fakeClaude({ initDelayMs: 20, exitBeforeInit: LAUNCH_FAILURE }) adapter = new ClaudeStructuredSessionAdapter({ + logger: TEST_LOGGER, resolveLaunch: async () => ({ pathToClaudeCodeExecutable: 'claude', options: {}, diff --git a/src/main/native-chat/agent-session-wire/structured-chat-logger-ratchet.test.ts b/src/main/native-chat/agent-session-wire/structured-chat-logger-ratchet.test.ts new file mode 100644 index 000000000000..efdde8d2d49b --- /dev/null +++ b/src/main/native-chat/agent-session-wire/structured-chat-logger-ratchet.test.ts @@ -0,0 +1,149 @@ +import { join, resolve } from 'node:path' +import { describe, expect, it } from 'vitest' +import { scanSourceTree, stripComments } from '../../../shared/source-scan/source-tree-scan' + +/** + * Structured chat reports a failure it carries on past through the host's logger, and nowhere else. + * + * A packaged desktop main process has no console, so a `console.warn` there reaches nobody. An + * optional `on*Error?` callback compiles fine when a caller forgets it, and the failure is dropped. + * Both shapes are how failures went missing before the logger was required. + */ + +const SCOPE_PREFIXES = [ + 'main/native-chat/agent-session-wire/', + 'main/native-chat/agent-session-journal/', + 'main/claude/claude-structured-', + 'main/codex/codex-structured-', + 'main/runtime/structured-agent-session-', + 'main/runtime/structured-session-', + 'main/runtime/structured-claude-', + 'main/runtime/structured-codex-', + 'main/runtime/orchestration/structured-', + 'main/runtime/rpc/methods/structured-agent-session-', + 'main/runtime/rpc/methods/orchestration-structured-' +] + +/** The logger's own sink. */ +const CONSOLE_ALLOWED = new Set([ + 'main/native-chat/agent-session-wire/structured-agent-session-logger.ts' +]) + +const WIRE = 'main/native-chat/agent-session-wire/' + +/** Optional hooks that change what happens, not whether a failure is reported, by file. */ +const BEHAVIORAL_OPTIONAL_HOOKS: ReadonlyMap> = new Map([ + // Hands the refusal to the attach caller that answers the client. + [`${WIRE}structured-agent-session-attach-flow.ts`, new Set(['onAcquisitionFailed'])], + [`${WIRE}structured-agent-session-attach-orchestration.ts`, new Set(['onAcquisitionFailed'])], + // Ends the Claude session whose background-task journal writes failed. + [ + 'main/claude/claude-structured-journal-translation.ts', + new Set(['onBackgroundTaskJournalFailure']) + ], + // Stops the provider whose own journal sink failed; the sink reports the failure itself. + [`${WIRE}structured-agent-session-event-sink.ts`, new Set(['onFailed'])], + [`${WIRE}structured-agent-session-event-sink-queue.ts`, new Set(['onFailed'])], + [`${WIRE}structured-agent-session-host-runtime-state.ts`, new Set(['onEventSinkFailure'])] +]) + +const CONSOLE_PATTERNS = [ + /\bconsole\s*(?:\?\.|\.)\s*(?:warn|error)\b/g, + /\bconsole\s*(?:\?\.)?\s*\[\s*['"`](?:warn|error)['"`]\s*\]/g, + /\{[^}]*\b(?:warn|error)\b[^}]*\}\s*=\s*console\b/g +] + +const OPTIONAL_FAILURE_CALLBACK = + /\b(on(?:[A-Z]\w*)?(?:Error|Errors|Failed|Failure|Failures))\s*\?\s*:/g + +function lineOf(code: string, index: number): number { + return code.slice(0, index).split('\n').length +} + +/** `line: what` for each console failure write and each reporting-only optional failure hook. */ +export function findStructuredChatLoggerBypasses( + source: string, + options: { consoleAllowed?: boolean; behavioralHooks?: ReadonlySet } = {} +): string[] { + const code = stripComments(source) + const found: string[] = [] + if (!options.consoleAllowed) { + for (const pattern of CONSOLE_PATTERNS) { + for (const match of code.matchAll(pattern)) { + found.push(`${lineOf(code, match.index)}: ${match[0]}`) + } + } + } + for (const match of code.matchAll(OPTIONAL_FAILURE_CALLBACK)) { + if (!options.behavioralHooks?.has(match[1])) { + found.push(`${lineOf(code, match.index)}: ${match[1]}?`) + } + } + return found +} + +function inScope(relativePath: string): boolean { + return ( + SCOPE_PREFIXES.some((prefix) => relativePath.startsWith(prefix)) && + !relativePath.includes('-test-support') + ) +} + +describe('structured chat logger ratchet', () => { + it('flags console failure writes in every spelling', () => { + const flagged = [ + `console.warn('x', error)`, + `console.error('x')`, + `console?.warn('x')`, + `console['warn']('x')`, + `const { warn } = console` + ] + for (const source of flagged) { + expect(findStructuredChatLoggerBypasses(source), source).toHaveLength(1) + } + }) + + it('flags an optional failure callback, and leaves required and behavioral ones alone', () => { + expect(findStructuredChatLoggerBypasses('type D = { onError?: (e: unknown) => void }')).toEqual( + ['1: onError?'] + ) + expect( + findStructuredChatLoggerBypasses('type D = { onSinkFailed ?: () => void }') + ).toHaveLength(1) + expect(findStructuredChatLoggerBypasses('type D = { onFailure?: () => void }')).toHaveLength(1) + expect(findStructuredChatLoggerBypasses('type D = { onFailed: () => void }')).toEqual([]) + expect( + findStructuredChatLoggerBypasses('type D = { onAcquisitionFailed?: () => void }', { + behavioralHooks: new Set(['onAcquisitionFailed']) + }) + ).toEqual([]) + }) + + it('leaves prose, console.log and the logger itself alone', () => { + expect(findStructuredChatLoggerBypasses('// console.warn used to drop this')).toEqual([]) + expect(findStructuredChatLoggerBypasses(`console.log('x')`)).toEqual([]) + expect(findStructuredChatLoggerBypasses(`console.warn('x')`, { consoleAllowed: true })).toEqual( + [] + ) + }) + + const repoRoot = resolve(__dirname, '..', '..', '..', '..') + const files = scanSourceTree(join(repoRoot, 'src')).filter(({ relativePath }) => + inScope(relativePath) + ) + + it('scans a plausible number of files', () => { + // A broken root or prefix list would make the guard silently vacuous. + expect(files.length).toBeGreaterThan(300) + }) + + it('has no structured chat failure that bypasses the logger', () => { + const offenders = files.flatMap(({ relativePath, source }) => + findStructuredChatLoggerBypasses(source, { + consoleAllowed: CONSOLE_ALLOWED.has(relativePath), + behavioralHooks: BEHAVIORAL_OPTIONAL_HOOKS.get(relativePath) + }).map((hit) => `src/${relativePath}:${hit}`) + ) + expect(offenders).toEqual([]) + }) +}) diff --git a/src/main/runtime/orca-runtime-get-pty-record-for-pane-key.ts b/src/main/runtime/orca-runtime-get-pty-record-for-pane-key.ts index 5906ee91866c..4c0554647935 100644 --- a/src/main/runtime/orca-runtime-get-pty-record-for-pane-key.ts +++ b/src/main/runtime/orca-runtime-get-pty-record-for-pane-key.ts @@ -211,11 +211,16 @@ export class OrcaRuntimeWithGetPtyRecordForPaneKey extends OrcaRuntimeWithPruneM this.notifyStructuredSessionJournalActivity(summary.sessionId) const openDb = () => this.getExistingOrchestrationDb() const deliver = (mailbox: string) => this.deliverPendingMessagesForHandle(mailbox) - structuredSessionIdleEdgeMailboxes(summary.sessionId, openDb).forEach(deliver) + structuredSessionIdleEdgeMailboxes( + summary.sessionId, + openDb, + this.structuredAgentSessionLogger + ).forEach(deliver) } catch (error) { - console.warn('[orchestration] structured session mail redrive failed', { + this.structuredAgentSessionLogger.warn('a structured session mail redrive failed', { + scope: 'mail-redrive', sessionId: summary.sessionId, - error: error instanceof Error ? error.message : String(error) + error }) } } diff --git a/src/main/runtime/orca-runtime-get-worktree-ps.ts b/src/main/runtime/orca-runtime-get-worktree-ps.ts index b25ce381def3..2de295bc7d76 100644 --- a/src/main/runtime/orca-runtime-get-worktree-ps.ts +++ b/src/main/runtime/orca-runtime-get-worktree-ps.ts @@ -14,7 +14,6 @@ import { compareWorktreePs } from './runtime-worktree-status-projection' import type { Repo } from '../../shared/repo-types' import { enrichMissingRepoGitRemoteIdentities } from '../repo-git-remote-identity-enrichment' import { ensureStructuredAgentSessionHost as installStructuredAgentSessionHost } from './structured-agent-session-runtime' -import { createStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger' import { maybeAutoRenameWorkspaceOnFirstStructuredTurn } from '../agent-hooks/first-work-structured-session-rename' import { firstWorkRenameDeps } from '../agent-hooks/first-work-rename-runtime' import { getProfileUserDataPath } from '../orca-profiles/profile-storage-paths' @@ -144,7 +143,7 @@ export class OrcaRuntimeWithGetWorktreePs extends OrcaRuntimeWithStartTuiIdleVis hostId: LOCAL_EXECUTION_HOST_ID, claimKeyId: this.agentSessionClaimSigner.keyId, // The host's local trace file (the desktop's or orcad's own), plus the console. - logger: createStructuredAgentSessionLogger(), + logger: this.structuredAgentSessionLogger, // Resolves folder workspaces as well as git worktrees, so a chat session // in a plain folder lands in the folder rather than failing to resolve. resolveWorkspacePath: async (workspaceId) => diff --git a/src/main/runtime/orca-runtime-preserved-branch-cleanup.ts b/src/main/runtime/orca-runtime-preserved-branch-cleanup.ts index 37f8121f99ae..7ae32c426ba8 100644 --- a/src/main/runtime/orca-runtime-preserved-branch-cleanup.ts +++ b/src/main/runtime/orca-runtime-preserved-branch-cleanup.ts @@ -11,6 +11,7 @@ import type { import type { TerminalSideEffectBatch } from '../../shared/terminal-side-effect-facts' import type { AgentStatusIpcPayload } from '../../shared/agent-status-types' import type { StructuredAgentSessionStatusSink } from '../native-chat/agent-session-wire/structured-agent-session-status-feed' +import type { StructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger' import type { ObservedAgentStatusPaneIdentity } from '../ipc/agent-status-ipc-boundary' import type { AgentHookAuthorityAttestation } from '../agent-hooks/server' import type { RuntimeDesktopWindowStatus } from '../../shared/runtime-types' @@ -69,6 +70,9 @@ export class OrcaRuntimeWithPreservedBranchCleanup extends OrcaRuntimeWithTermin protected readonly structuredAgentStatusSinkFn: StructuredAgentSessionStatusSink | null + /** The structured chat host's logger, held here so callers outside the host report to it too. */ + readonly structuredAgentSessionLogger: StructuredAgentSessionLogger + protected readonly readObservedAgentStatusPaneIdentityFn: ( paneKey: string ) => ObservedAgentStatusPaneIdentity diff --git a/src/main/runtime/orca-runtime-state-fields.ts b/src/main/runtime/orca-runtime-state-fields.ts index ede9c6edce59..7eda81136620 100644 --- a/src/main/runtime/orca-runtime-state-fields.ts +++ b/src/main/runtime/orca-runtime-state-fields.ts @@ -8,6 +8,10 @@ import type { RuntimeTerminalAgentStatusEvent } from './runtime-terminal-contrac import type { TerminalSideEffectBatch } from '../../shared/terminal-side-effect-facts' import type { AgentStatusIpcPayload } from '../../shared/agent-status-types' import type { StructuredAgentSessionStatusSink } from '../native-chat/agent-session-wire/structured-agent-session-status-feed' +import { + createStructuredAgentSessionLogger, + type StructuredAgentSessionLogger +} from '../native-chat/agent-session-wire/structured-agent-session-logger' import type { ObservedAgentStatusPaneIdentity } from '../ipc/agent-status-ipc-boundary' import type { AgentHookAuthorityAttestation } from '../agent-hooks/server' import type { @@ -66,6 +70,7 @@ export class OrcaRuntimeWithStateFields extends OrcaRuntimeWithLinearCommands { /** Where structured (native chat) sessions publish into that same store, so the snapshot * above lists them like every other agent. */ structuredAgentStatusSink?: StructuredAgentSessionStatusSink + structuredAgentSessionLogger?: StructuredAgentSessionLogger /** The identity the runtime resolved for a pane as each status arrived. Without it the * fleet path reminted cached rows against whatever the pane owns now. */ readObservedAgentStatusPaneIdentity?: (paneKey: string) => ObservedAgentStatusPaneIdentity @@ -219,6 +224,8 @@ export class OrcaRuntimeWithStateFields extends OrcaRuntimeWithLinearCommands { } this.getAgentStatusSnapshotFn = deps?.getAgentStatusSnapshot ?? null this.structuredAgentStatusSinkFn = deps?.structuredAgentStatusSink ?? null + this.structuredAgentSessionLogger = + deps?.structuredAgentSessionLogger ?? createStructuredAgentSessionLogger() this.readObservedAgentStatusPaneIdentityFn = deps?.readObservedAgentStatusPaneIdentity ?? (() => ({ kind: 'unobserved' })) this.getAgentProviderSessionSnapshotFn = diff --git a/src/main/runtime/orchestration/structured-mailbox-pointer-host.ts b/src/main/runtime/orchestration/structured-mailbox-pointer-host.ts index ecfdff0dff5f..7fa5cefb8588 100644 --- a/src/main/runtime/orchestration/structured-mailbox-pointer-host.ts +++ b/src/main/runtime/orchestration/structured-mailbox-pointer-host.ts @@ -70,7 +70,11 @@ async function readSessionJournal(sessionId: string): Promise = {}): MailTargetProbe { return Object.assign(Object.create(MailTargetProbe.prototype), { _orchestrationDb: db, ptysById: new Map(), + structuredAgentSessionLogger: recordingStructuredAgentSessionLogger().logger, ...extra }) as MailTargetProbe } @@ -244,8 +246,12 @@ describe('the idle edge after a restart, before any orchestration call', () => { }) /** A runtime whose database has not been opened in this process yet. */ - function restarted(delivered: string[]): MailTargetProbe { + function restarted( + delivered: string[], + logger = recordingStructuredAgentSessionLogger().logger + ): MailTargetProbe { return probe({ + structuredAgentSessionLogger: logger, _orchestrationDb: null, ensureOrchestrationFederationRelay: vi.fn(), scheduleRestoredMessageRepoints: vi.fn(), @@ -277,22 +283,25 @@ describe('the idle edge after a restart, before any orchestration call', () => { it('creates no database for a profile that never orchestrated, and says nothing', () => { installStore(chatRecord()) - const warn = vi.spyOn(console, 'warn').mockImplementation(() => {}) + const log = recordingStructuredAgentSessionLogger() const delivered: string[] = [] - restarted(delivered).onStructuredSessionStatusForMail({ sessionId: CHAT, status: 'idle' }) + restarted(delivered, log.logger).onStructuredSessionStatusForMail({ + sessionId: CHAT, + status: 'idle' + }) expect(delivered).toEqual([]) expect(existsSync(join(userData, 'orchestration.db'))).toBe(false) - expect(warn).not.toHaveBeenCalled() - warn.mockRestore() + expect(log.entries).toEqual([]) }) it('says so when the database cannot be opened, instead of skipping silently', () => { installStore(chatRecord()) - const warn = vi.spyOn(console, 'warn').mockImplementation(() => {}) + const log = recordingStructuredAgentSessionLogger() const deliver = vi.fn() probe({ + structuredAgentSessionLogger: log.logger, _orchestrationDb: null, getExistingOrchestrationDb: () => { throw new Error('userData unavailable') @@ -301,11 +310,9 @@ describe('the idle edge after a restart, before any orchestration call', () => { notifyStructuredSessionJournalActivity: vi.fn() }).onStructuredSessionStatusForMail({ sessionId: CHAT, status: 'idle' }) expect(deliver).not.toHaveBeenCalled() - expect(warn).toHaveBeenCalledWith( - '[orchestration] skipped a structured session mail edge: no database', - { sessionId: CHAT, error: 'userData unavailable' } - ) - warn.mockRestore() + expect(log.entries.map(({ fields }) => fields)).toEqual([ + { scope: 'mail-edge-database', sessionId: CHAT, error: new Error('userData unavailable') } + ]) }) }) diff --git a/src/main/runtime/orchestration/structured-session-mail-target.ts b/src/main/runtime/orchestration/structured-session-mail-target.ts index 73bec03c1a56..15b95294090b 100644 --- a/src/main/runtime/orchestration/structured-session-mail-target.ts +++ b/src/main/runtime/orchestration/structured-session-mail-target.ts @@ -25,6 +25,7 @@ import { type AgentSessionRecordReader } from './structured-session-lineage' import type { RunRow } from './types' +import type { StructuredAgentSessionLogger } from '../../native-chat/agent-session-wire/structured-agent-session-logger' /** * The session a Run's coordinator binding names when that binding has no handle. A structured @@ -112,15 +113,17 @@ export function structuredSessionOwnedMailboxes(sessionId: string, db: Orchestra * no mail, so `openDb` answers null and nothing is created. */ export function structuredSessionIdleEdgeMailboxes( sessionId: string, - openDb: () => OrchestrationDb | null + openDb: () => OrchestrationDb | null, + logger: StructuredAgentSessionLogger ): string[] { let db: OrchestrationDb | null try { db = openDb() } catch (error) { - console.warn('[orchestration] skipped a structured session mail edge: no database', { + logger.warn('a structured session mail edge was skipped: no database', { + scope: 'mail-edge-database', sessionId, - error: error instanceof Error ? error.message : String(error) + error }) return [] } diff --git a/src/main/runtime/rpc/methods/orchestration-structured-worker-lifecycle.test.ts b/src/main/runtime/rpc/methods/orchestration-structured-worker-lifecycle.test.ts index b669233c31fb..c58a252f2d9c 100644 --- a/src/main/runtime/rpc/methods/orchestration-structured-worker-lifecycle.test.ts +++ b/src/main/runtime/rpc/methods/orchestration-structured-worker-lifecycle.test.ts @@ -1,6 +1,9 @@ import { beforeEach, describe, expect, it, vi } from 'vitest' import type { AgentJournalRenderItem } from '../../../../shared/agent-session-journal-types' import type { StructuredWorkerIdentity } from '../../structured-worker-identity' +import { recordingStructuredAgentSessionLogger } from '../../../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const hostRef: { current: unknown } = { current: null } @@ -149,7 +152,8 @@ describe('structured worker stop', () => { const retireStructuredAgentSessionTabFromSnapshot = vi.fn() const result = await stopStructuredWorker(IDENTITY, 'd1', { forgetStructuredSessionMail: vi.fn(), - retireStructuredAgentSessionTabFromSnapshot + retireStructuredAgentSessionTabFromSnapshot, + structuredAgentSessionLogger: TEST_LOGGER }) expect(result).toMatchObject({ stopped: false, closeAttempted: true }) expect(retireStructuredAgentSessionTabFromSnapshot).not.toHaveBeenCalled() diff --git a/src/main/runtime/rpc/methods/orchestration-structured-worker-lifecycle.ts b/src/main/runtime/rpc/methods/orchestration-structured-worker-lifecycle.ts index bec15537c49d..c175c86c6ba9 100644 --- a/src/main/runtime/rpc/methods/orchestration-structured-worker-lifecycle.ts +++ b/src/main/runtime/rpc/methods/orchestration-structured-worker-lifecycle.ts @@ -78,7 +78,9 @@ export async function stopStructuredWorker( dispatchId: string, runtime?: Pick< OrcaRuntimeService, - 'forgetStructuredSessionMail' | 'retireStructuredAgentSessionTabFromSnapshot' + | 'forgetStructuredSessionMail' + | 'retireStructuredAgentSessionTabFromSnapshot' + | 'structuredAgentSessionLogger' > ): Promise { return closeStructuredAgentSessionChild(identity.sessionId, { diff --git a/src/main/runtime/rpc/methods/orchestration-structured-worker-session.test.ts b/src/main/runtime/rpc/methods/orchestration-structured-worker-session.test.ts index c3c69dc15fd2..0f5081156a56 100644 --- a/src/main/runtime/rpc/methods/orchestration-structured-worker-session.test.ts +++ b/src/main/runtime/rpc/methods/orchestration-structured-worker-session.test.ts @@ -3,6 +3,9 @@ import { beforeEach, describe, expect, it, vi } from 'vitest' import type { AgentJournalSubmission } from '../../../../shared/agent-session-journal-types' import { getAppEnvironment } from '../../../../shared/app-environment' import { DISPATCH_REJECTED_WRITE_FAILED } from '../../../../shared/structured-agent-session-dispatch-rejection' +import { recordingStructuredAgentSessionLogger } from '../../../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const hostRef: { current: unknown } = { current: null } const createSpy = vi.fn() @@ -84,7 +87,7 @@ describe('structured worker session', () => { createSpy.mockImplementation(async (args: { envelope: { sessionId: string } }) => { // `attach` is what spawns the provider child, and the child's env is read from the registry // at spawn time. Registering afterwards ships a worker with no ORCA_TERMINAL_HANDLE. - envAtSpawn = structuredSessionChildIdentityEnv(args.envelope.sessionId, {}) + envAtSpawn = structuredSessionChildIdentityEnv(args.envelope.sessionId, {}, TEST_LOGGER) return { ok: true, value: { sessionId: args.envelope.sessionId } } }) const created = await createStructuredWorkerSession({ diff --git a/src/main/runtime/rpc/methods/orchestration-structured-worker-session.ts b/src/main/runtime/rpc/methods/orchestration-structured-worker-session.ts index a5a79b6be153..8896dd64a4b6 100644 --- a/src/main/runtime/rpc/methods/orchestration-structured-worker-session.ts +++ b/src/main/runtime/rpc/methods/orchestration-structured-worker-session.ts @@ -180,7 +180,10 @@ function structuredCreateMayHaveCommitted( */ export async function discardStructuredWorkerSession( sessionId: string, - runtime: Pick + runtime: Pick< + OrcaRuntimeService, + 'retireStructuredAgentSessionTabFromSnapshot' | 'structuredAgentSessionLogger' + > ): Promise { const host = getStructuredAgentSessionHost() if (!host) { @@ -190,11 +193,11 @@ export async function discardStructuredWorkerSession( await host.setSessionTabVisibility?.(sessionId, false) await host.close(sessionId, 'evict') } catch (error) { - console.warn( - '[orchestration] failed to discard a half-started structured worker', + host.deps.logger.warn('discarding a half-started structured worker failed', { + scope: 'worker-discard', sessionId, error - ) + }) return } retireSettledStructuredWorkerTab(sessionId, runtime) @@ -346,7 +349,11 @@ async function subscribeForRedrive( unsubscribe() } } catch (error) { - console.warn('[orchestration] structured worker redrive subscription failed', sessionId, error) + host.deps.logger.warn('subscribing a structured worker for mail redrive failed', { + scope: 'worker-redrive-subscribe', + sessionId, + error + }) coalescer.dispose() return () => {} } diff --git a/src/main/runtime/rpc/methods/structured-agent-session-create.ts b/src/main/runtime/rpc/methods/structured-agent-session-create.ts index 1d0899a014df..1a82aaa3bcd7 100644 --- a/src/main/runtime/rpc/methods/structured-agent-session-create.ts +++ b/src/main/runtime/rpc/methods/structured-agent-session-create.ts @@ -173,8 +173,9 @@ export async function createStructuredAgentSessionForWorktree(args: { tabId?: string }): Promise> { const prepared: PreparedStructuredAgentSessionCreate | StructuredCreateRefused = - await resolveUncommittedStructuredCreate(() => - prepareStructuredAgentSessionCreateForWorktree(args) + await resolveUncommittedStructuredCreate( + () => prepareStructuredAgentSessionCreateForWorktree(args), + args.runtime.structuredAgentSessionLogger ) if ('refusal' in prepared) { return { ok: false, refusal: prepared.refusal } diff --git a/src/main/runtime/rpc/methods/structured-agent-session-precommit-refusal.test.ts b/src/main/runtime/rpc/methods/structured-agent-session-precommit-refusal.test.ts index 17aadf32a801..97a5a8766f99 100644 --- a/src/main/runtime/rpc/methods/structured-agent-session-precommit-refusal.test.ts +++ b/src/main/runtime/rpc/methods/structured-agent-session-precommit-refusal.test.ts @@ -88,6 +88,7 @@ async function create( ...resolvedIntent })), publishStructuredAgentSessionTab: vi.fn(async () => undefined), + structuredAgentSessionLogger: log.logger, ...runtimeOverrides } const replies: RpcResponse[] = [] @@ -115,9 +116,11 @@ function refusalOf(response: RpcResponse): { code: string; message: string } | n return result.ok ? null : (result.refusal ?? null) } +let log: ReturnType + beforeEach(() => { setStructuredAgentSessionHost(hostStub()) - vi.spyOn(console, 'warn').mockImplementation(() => undefined) + log = recordingStructuredAgentSessionLogger() }) afterEach(() => { @@ -155,6 +158,7 @@ describe('a create refused before it commits', () => { expect(refusal?.message).not.toContain('Codex') expect(refusal?.message).toContain('No worktree matches id:workspace-1') expect(attach).not.toHaveBeenCalled() + expect(log.scopes()).toEqual(['create-precommit']) }) it('answers a host that will not install as a definitive envelope', async () => { diff --git a/src/main/runtime/rpc/methods/structured-agent-session-precommit-refusal.ts b/src/main/runtime/rpc/methods/structured-agent-session-precommit-refusal.ts index 4038fe9e40d2..7e55725cad7c 100644 --- a/src/main/runtime/rpc/methods/structured-agent-session-precommit-refusal.ts +++ b/src/main/runtime/rpc/methods/structured-agent-session-precommit-refusal.ts @@ -18,6 +18,7 @@ import { type AgentSessionWireRefusal, type AgentSessionWireRefusalCode } from '../../../../shared/agent-session-wire' +import type { StructuredAgentSessionLogger } from '../../../native-chat/agent-session-wire/structured-agent-session-logger' export type StructuredCreateRefused = { refusal: AgentSessionWireRefusal } @@ -45,7 +46,10 @@ function wireRefusalCode(error: unknown): AgentSessionWireRefusalCode | null { const PRECOMMIT_REFUSAL_MESSAGE = 'Orca cannot open a structured agent chat for this workspace.' -function precommitRefusal(error: unknown): AgentSessionWireRefusal { +function precommitRefusal( + error: unknown, + logger: StructuredAgentSessionLogger +): AgentSessionWireRefusal { // A refusal the host raised keeps its situation; a bare code names none. if (isAgentSessionRefusalError(error)) { return agentSessionRefusalFromReference(error.refusal, PRECOMMIT_REFUSAL_MESSAGE) @@ -57,7 +61,10 @@ function precommitRefusal(error: unknown): AgentSessionWireRefusal { const message = error instanceof Error ? error.message : String(error) // A code-less failure here is often a defect, not a policy answer; the refusal keeps the user // moving, the log keeps the cause findable. Nothing names its situation, so it carries no reason. - console.warn('[agent-session] create refused before it committed anything', error) + logger.warn('a create was refused before it committed anything', { + scope: 'create-precommit', + error + }) return refuseUnclassified( UNCODED_PRECOMMIT_REFUSAL_CODE, `Orca could not prepare a structured agent chat for this workspace: ${message}` @@ -70,11 +77,12 @@ function precommitRefusal(error: unknown): AgentSessionWireRefusal { * longer proves the session does not exist. */ export async function resolveUncommittedStructuredCreate( - prepare: () => Promise + prepare: () => Promise, + logger: StructuredAgentSessionLogger ): Promise { try { return await prepare() } catch (error) { - return { refusal: precommitRefusal(error) } + return { refusal: precommitRefusal(error, logger) } } } diff --git a/src/main/runtime/rpc/methods/structured-agent-session.ts b/src/main/runtime/rpc/methods/structured-agent-session.ts index e0d24119086c..cd8ac6abd5a0 100644 --- a/src/main/runtime/rpc/methods/structured-agent-session.ts +++ b/src/main/runtime/rpc/methods/structured-agent-session.ts @@ -183,7 +183,7 @@ export const STRUCTURED_AGENT_SESSION_METHODS = [ } const { host, attachParams } = await resolveClientSuppliedAttach(params, ctx) return { host, attachParams, tab: null } - }) + }, ctx.runtime.structuredAgentSessionLogger) if ('refusal' in prepared) { return { ok: false, refusal: prepared.refusal } } diff --git a/src/main/runtime/rpc/methods/structured-worker-tab-retirement.test.ts b/src/main/runtime/rpc/methods/structured-worker-tab-retirement.test.ts index cee7adf64256..4dfb7b333b29 100644 --- a/src/main/runtime/rpc/methods/structured-worker-tab-retirement.test.ts +++ b/src/main/runtime/rpc/methods/structured-worker-tab-retirement.test.ts @@ -18,6 +18,7 @@ import { structuredWorkerProcessIncarnation, type StructuredWorkerIdentity } from '../../structured-worker-identity' +import { recordingStructuredAgentSessionLogger } from '../../../native-chat/agent-session-wire/structured-agent-session-logger-test-support' const createSpy = vi.fn() vi.mock('./structured-agent-session-create', () => ({ @@ -160,18 +161,23 @@ describe('structured worker stop retires the chat tab', () => { it('cannot turn a proven stop into a retained one when the prune throws', async () => { installHost() const identity = registerIdentity() + const log = recordingStructuredAgentSessionLogger() const runtime = { forgetStructuredSessionMail: vi.fn(), retireStructuredAgentSessionTabFromSnapshot: vi.fn(() => { throw new Error('snapshot is wedged') - }) - } as unknown as OrcaRuntimeService + }), + structuredAgentSessionLogger: log.logger + } await expect(stopStructuredWorker(identity, 'd1', runtime)).resolves.toEqual({ stopped: true, closeAttempted: true }) expect(runtime.retireStructuredAgentSessionTabFromSnapshot).toHaveBeenCalledWith(SESSION) + expect(log.entries.map(({ fields }) => [fields.scope, fields.sessionId])).toEqual([ + ['chat-tab-retire', SESSION] + ]) }) it('settles a runtime that has no tab surface at all', async () => { diff --git a/src/main/runtime/structured-agent-session-close.ts b/src/main/runtime/structured-agent-session-close.ts index 16bf8cce71d7..de8b44cc0acd 100644 --- a/src/main/runtime/structured-agent-session-close.ts +++ b/src/main/runtime/structured-agent-session-close.ts @@ -30,7 +30,9 @@ export type StructuredAgentSessionCloseOutcome = { export type StructuredAgentSessionCloseOptions = { runtime?: Pick< OrcaRuntimeService, - 'forgetStructuredSessionMail' | 'retireStructuredAgentSessionTabFromSnapshot' + | 'forgetStructuredSessionMail' + | 'retireStructuredAgentSessionTabFromSnapshot' + | 'structuredAgentSessionLogger' > /** * Runs after the close is issued and BEFORE the proof is read. diff --git a/src/main/runtime/structured-agent-session-held-signal.test.ts b/src/main/runtime/structured-agent-session-held-signal.test.ts index 2ce91a287f5a..a8acf47e5bc6 100644 --- a/src/main/runtime/structured-agent-session-held-signal.test.ts +++ b/src/main/runtime/structured-agent-session-held-signal.test.ts @@ -20,6 +20,9 @@ import { ensureStructuredAgentSessionHost, stopStructuredAgentSessionRuntime } from './structured-agent-session-runtime' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger vi.mock('../ai-vault/session-scanner-worker-spawn', () => ({ scanAiVaultSessionsInWorker: vi.fn(), @@ -41,7 +44,8 @@ function installHost(): Promise { claimKeyId: 'key-1', resolveWorkspacePath: async () => stateDirectory, resolveClaudeAuthPolicy: () => ({ stripAuthEnv: true }), - resolveEnvironment: async () => ({}) + resolveEnvironment: async () => ({}), + logger: TEST_LOGGER }) } diff --git a/src/main/runtime/structured-agent-session-journal-open.ts b/src/main/runtime/structured-agent-session-journal-open.ts index 54c27fbfe963..65d5d1412ec1 100644 --- a/src/main/runtime/structured-agent-session-journal-open.ts +++ b/src/main/runtime/structured-agent-session-journal-open.ts @@ -37,12 +37,15 @@ export async function openStructuredAgentSessionJournalDatabase(args: { logger: StructuredAgentSessionLogger }): Promise { try { - const opened = await JournalHostDatabase.open(args.stateDirectory, async () => - legacyAgentSessionRecordImport( - await readLegacyAgentSessionRecords(args.stateDirectory, args.hostId), - args.hostId, - (report) => reportLegacyRecordImport(args.logger, report) - ) + const opened = await JournalHostDatabase.open( + args.stateDirectory, + async () => + legacyAgentSessionRecordImport( + await readLegacyAgentSessionRecords(args.stateDirectory, args.hostId), + args.hostId, + (report) => reportLegacyRecordImport(args.logger, report) + ), + args.logger ) recordStructuredAgentSessionHostInstallRefusal(null) lastLoggedOpenFailure = null diff --git a/src/main/runtime/structured-agent-session-runtime.test.ts b/src/main/runtime/structured-agent-session-runtime.test.ts index f572e8909833..cb0c7f436ed3 100644 --- a/src/main/runtime/structured-agent-session-runtime.test.ts +++ b/src/main/runtime/structured-agent-session-runtime.test.ts @@ -29,6 +29,9 @@ import { stopStructuredAgentSessionRuntime } from './structured-agent-session-runtime' import { createStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const HOST_ID = 'local' @@ -76,7 +79,7 @@ describe('structured agent-session store presence', () => { legacyRecords: JournalLegacyRecordImport = NO_LEGACY_JOURNAL_RECORDS ): Promise { profile = await mkdtemp(join(tmpdir(), 'orca-session-presence-')) - return JournalHostDatabase.openWith(profile, legacyRecords) + return JournalHostDatabase.openWith(profile, legacyRecords, TEST_LOGGER) } async function writeRecordsFile(): Promise { diff --git a/src/main/runtime/structured-agent-session-runtime.ts b/src/main/runtime/structured-agent-session-runtime.ts index 3785fdeaf5ce..684d689203cf 100644 --- a/src/main/runtime/structured-agent-session-runtime.ts +++ b/src/main/runtime/structured-agent-session-runtime.ts @@ -266,6 +266,7 @@ async function installOnJournal( ...(deps.openCodexConnection ? { openConnection: deps.openCodexConnection } : {}), ...(deps.readProcessStartTime ? { readProcessStartTime: deps.readProcessStartTime } : {}), modelCatalog: agentModelCatalogStore, + logger: deps.logger, onChildWorkEvidence: (sessionId, evidence) => host?.publishChildWorkEvidence(sessionId, evidence), onDispatchSettledLate, @@ -278,6 +279,7 @@ async function installOnJournal( }) const claude = createStructuredClaudeRuntimeAdapter({ store, + logger: deps.logger, resolveWorkspacePath: deps.resolveWorkspacePath, ...(deps.resolveClaudeCommand ? { resolveClaudeCommand: deps.resolveClaudeCommand } : {}), ...(deps.resolveClaudeLaunchEnv ? { resolveClaudeLaunchEnv: deps.resolveClaudeLaunchEnv } : {}), diff --git a/src/main/runtime/structured-agent-session-tab-retirement.ts b/src/main/runtime/structured-agent-session-tab-retirement.ts index aee5ef6d719d..b24128bbe65c 100644 --- a/src/main/runtime/structured-agent-session-tab-retirement.ts +++ b/src/main/runtime/structured-agent-session-tab-retirement.ts @@ -10,6 +10,7 @@ import type { RuntimeMobileSessionSnapshotTab, RuntimeMobileSessionTabsSnapshot } from '../../shared/runtime-types' +import type { StructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger' import { structuredAgentSessionTabId } from '../../shared/structured-agent-session-projection' /** The snapshot's tab for a structured session, matched by session id and by published tab id. */ @@ -68,12 +69,19 @@ export function retireStructuredAgentSessionTabFrom( export function retireSettledStructuredWorkerTab( sessionId: string, runtime: - | { retireStructuredAgentSessionTabFromSnapshot?: (sessionId: string) => boolean } + | { + retireStructuredAgentSessionTabFromSnapshot?: (sessionId: string) => boolean + structuredAgentSessionLogger: StructuredAgentSessionLogger + } | undefined ): void { try { runtime?.retireStructuredAgentSessionTabFromSnapshot?.(sessionId) } catch (error) { - console.warn('[orchestration] structured worker tab retirement failed', sessionId, error) + runtime?.structuredAgentSessionLogger.warn('retiring a settled chat tab failed', { + scope: 'chat-tab-retire', + sessionId, + error + }) } } diff --git a/src/main/runtime/structured-claude-pending-rewind.test.ts b/src/main/runtime/structured-claude-pending-rewind.test.ts index 47fa6d201009..2e2f6e3dce77 100644 --- a/src/main/runtime/structured-claude-pending-rewind.test.ts +++ b/src/main/runtime/structured-claude-pending-rewind.test.ts @@ -26,6 +26,8 @@ import { createStructuredClaudeRuntimeAdapter } from './structured-claude-runtim import { openTestJournalHostDatabase } from '../native-chat/agent-session-journal/journal-host-database-test-support' import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger + const caller = { callerKey: 'desktop' } const PROVIDER_SESSION_ID = claudeSessionIdForOrcaSession(HOST_TEST_SESSION) const TARGET = agentJournalItemKey({ @@ -112,6 +114,7 @@ beforeEach(async () => { store = await openTestAgentSessionRecordStore(directory) claude = fakeClaude({ initSessionId: PROVIDER_SESSION_ID }) adapter = createStructuredClaudeRuntimeAdapter({ + logger: TEST_LOGGER, store, resolveWorkspacePath: async (id) => `/repos/${id}`, resolveClaudeCommand: () => '/usr/local/bin/claude', diff --git a/src/main/runtime/structured-claude-runtime-adapter.ts b/src/main/runtime/structured-claude-runtime-adapter.ts index 9024c65b503d..63809b2e2d9d 100644 --- a/src/main/runtime/structured-claude-runtime-adapter.ts +++ b/src/main/runtime/structured-claude-runtime-adapter.ts @@ -16,10 +16,12 @@ import { } from './agent-session-provider-handle-transition' import type { ClaudeManagedAccountGateSettings } from '../native-chat/claude-structured-managed-account-support' import type { AgentSessionRecordStore } from './agent-session-record-store' +import type { StructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger' import { ClaudeAtRestCommandCatalog } from '../claude/claude-at-rest-commands' export type StructuredClaudeRuntimeAdapterDeps = { store: AgentSessionRecordStore + logger: StructuredAgentSessionLogger resolveWorkspacePath: (workspaceId: string) => Promise resolveClaudeCommand?: () => string resolveClaudeLaunchEnv?: () => Promise> | Record @@ -79,6 +81,7 @@ export function createStructuredClaudeRuntimeAdapter( }), resolveLaunch: createClaudeStructuredLaunchResolver({ store, + logger: deps.logger, resolveWorkspacePath: deps.resolveWorkspacePath, resolveCommand: deps.resolveClaudeCommand ?? resolveClaudeCommand, ...(deps.resolveClaudeLaunchEnv ? { resolveEnv: deps.resolveClaudeLaunchEnv } : {}), @@ -133,6 +136,7 @@ export function createStructuredClaudeRuntimeAdapter( ...(deps.onChildWorkEvidence ? { onChildWorkEvidence: deps.onChildWorkEvidence } : {}), ...(deps.openClaudeConnection ? { openConnection: deps.openClaudeConnection } : {}), ...(deps.readProcessStartTime ? { readProcessStartTime: deps.readProcessStartTime } : {}), - ...(deps.modelCatalog ? { modelCatalog: deps.modelCatalog } : {}) + ...(deps.modelCatalog ? { modelCatalog: deps.modelCatalog } : {}), + logger: deps.logger }) } diff --git a/src/main/runtime/structured-session-child-identity-env.test.ts b/src/main/runtime/structured-session-child-identity-env.test.ts index 1289e979ad63..c09df77b0a6f 100644 --- a/src/main/runtime/structured-session-child-identity-env.test.ts +++ b/src/main/runtime/structured-session-child-identity-env.test.ts @@ -1,6 +1,9 @@ import { join } from 'node:path' import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest' import { installFakeAppEnvironment } from '../../../config/scripts/vitest-host-ports-setup' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const shim = vi.hoisted(() => ({ ensureLinuxTerminalOrcaCliShimDir: vi.fn() })) vi.mock('../cli/linux-terminal-orca-cli-shim', () => shim) @@ -63,7 +66,7 @@ describe('structuredSessionChildIdentityEnv', () => { pinPlatform('linux') installFakeAppEnvironment({ isPackaged: () => true, getPath: () => USER_DATA }) const childEnv = { PATH: '/usr/bin' } - const env = structuredSessionChildIdentityEnv(SESSION_ID, childEnv) + const env = structuredSessionChildIdentityEnv(SESSION_ID, childEnv, TEST_LOGGER) expect(env).toEqual({ PATH: `${SHIM_DIR}:/usr/bin`, ORCA_AGENT_SESSION_ID: SESSION_ID, @@ -81,10 +84,14 @@ describe('structuredSessionChildIdentityEnv', () => { it('replaces an id inherited from an Orca launched inside another session', () => { installFakeAppEnvironment({ isPackaged: () => false, getPath: () => USER_DATA }) - const env = structuredSessionChildIdentityEnv(SESSION_ID, { - ORCA_AGENT_SESSION_ID: 'a0b1c2d3-0000-4000-8000-00000000abcd', - PATH: '/usr/bin' - }) + const env = structuredSessionChildIdentityEnv( + SESSION_ID, + { + ORCA_AGENT_SESSION_ID: 'a0b1c2d3-0000-4000-8000-00000000abcd', + PATH: '/usr/bin' + }, + TEST_LOGGER + ) expect(env.ORCA_AGENT_SESSION_ID).toBe(SESSION_ID) }) @@ -93,7 +100,7 @@ describe('structuredSessionChildIdentityEnv', () => { // one identity; the handle stays for the handle-based surfaces outside orchestration. installFakeAppEnvironment({ isPackaged: () => false, getPath: () => USER_DATA }) const handle = registerWorker() - const env = structuredSessionChildIdentityEnv(SESSION_ID, { PATH: '/usr/bin' }) + const env = structuredSessionChildIdentityEnv(SESSION_ID, { PATH: '/usr/bin' }, TEST_LOGGER) expect(env.ORCA_AGENT_SESSION_ID).toBe(SESSION_ID) expect(env.ORCA_TERMINAL_HANDLE).toBe(handle) }) @@ -110,7 +117,11 @@ describe('structuredSessionChildIdentityEnv', () => { // installs as `orca-ide` on Linux (stablyai/orca#7904) — and the dispatch hangs to timeout. pinPlatform('linux') installFakeAppEnvironment({ isPackaged: () => true, getPath: () => USER_DATA }) - const env = structuredSessionChildIdentityEnv(SESSION_ID, { PATH: '/usr/bin:/bin' }) + const env = structuredSessionChildIdentityEnv( + SESSION_ID, + { PATH: '/usr/bin:/bin' }, + TEST_LOGGER + ) expect(env.ORCA_CLI_COMMAND).toBe(join(SHIM_DIR, 'orca')) expect(env.PATH).toBe(`${SHIM_DIR}:/usr/bin:/bin`) }) @@ -118,7 +129,7 @@ describe('structuredSessionChildIdentityEnv', () => { it('on packaged macOS, through the bundled CLI dir', () => { pinPlatform('darwin') installFakeAppEnvironment({ isPackaged: () => true, getPath: () => USER_DATA }) - const env = structuredSessionChildIdentityEnv(SESSION_ID, { PATH: '/usr/bin' }) + const env = structuredSessionChildIdentityEnv(SESSION_ID, { PATH: '/usr/bin' }, TEST_LOGGER) expect(env.PATH).toBe(`${join(RESOURCES, 'bin')}:/usr/bin`) expect(env.ORCA_CLI_COMMAND).toBe(join(RESOURCES, 'bin', 'orca')) }) @@ -126,7 +137,11 @@ describe('structuredSessionChildIdentityEnv', () => { it('on packaged Windows, through the bundled CLI dir under the env block spelling', () => { pinPlatform('win32') installFakeAppEnvironment({ isPackaged: () => true, getPath: () => USER_DATA }) - const env = structuredSessionChildIdentityEnv(SESSION_ID, { Path: 'C:\\Windows' }) + const env = structuredSessionChildIdentityEnv( + SESSION_ID, + { Path: 'C:\\Windows' }, + TEST_LOGGER + ) expect(env.Path).toBe(`${join(RESOURCES, 'bin')};C:\\Windows`) expect(env.PATH).toBeUndefined() // The native launcher: `orca.cmd` refuses message bodies cmd.exe would mangle. @@ -136,7 +151,7 @@ describe('structuredSessionChildIdentityEnv', () => { it('unpackaged, through the dev launcher dir', () => { pinPlatform('darwin') installFakeAppEnvironment({ isPackaged: () => false, getPath: () => USER_DATA }) - const env = structuredSessionChildIdentityEnv(SESSION_ID, { PATH: '/usr/bin' }) + const env = structuredSessionChildIdentityEnv(SESSION_ID, { PATH: '/usr/bin' }, TEST_LOGGER) expect(env.PATH).toBe(`${join(USER_DATA, 'cli', 'bin')}:/usr/bin`) expect(env.ORCA_CLI_COMMAND).toBe(join(USER_DATA, 'cli', 'bin', 'orca-dev')) }) @@ -148,16 +163,22 @@ describe('structuredSessionChildIdentityEnv', () => { pinPlatform('linux') installFakeAppEnvironment({ isPackaged: () => true, getPath: () => USER_DATA }) shim.ensureLinuxTerminalOrcaCliShimDir.mockReturnValue(null) - vi.spyOn(console, 'warn').mockImplementation(() => {}) - const env = structuredSessionChildIdentityEnv(SESSION_ID, { - PATH: '/usr/bin', - ORCA_CLI_COMMAND: '/Applications/Other Orca.app/Contents/Resources/bin/orca', - ORCA_USER_DATA_PATH: '/data/other-orca' - }) + const log = recordingStructuredAgentSessionLogger() + const env = structuredSessionChildIdentityEnv( + SESSION_ID, + { + PATH: '/usr/bin', + ORCA_CLI_COMMAND: '/Applications/Other Orca.app/Contents/Resources/bin/orca', + ORCA_USER_DATA_PATH: '/data/other-orca' + }, + log.logger + ) expect(env).not.toHaveProperty('ORCA_CLI_COMMAND') expect(env.PATH).toBe('/usr/bin') expect(env.ORCA_USER_DATA_PATH).toBe(USER_DATA) - expect(console.warn).toHaveBeenCalledOnce() + expect(log.entries.map(({ fields }) => fields)).toEqual([ + { scope: 'child-cli-launcher', sessionId: SESSION_ID } + ]) }) it('never puts a pane key in the child environment', () => { @@ -166,7 +187,7 @@ describe('structuredSessionChildIdentityEnv', () => { pinPlatform('linux') installFakeAppEnvironment({ isPackaged: () => true, getPath: () => USER_DATA }) registerWorker() - const env = structuredSessionChildIdentityEnv(SESSION_ID, { PATH: '/usr/bin' }) + const env = structuredSessionChildIdentityEnv(SESSION_ID, { PATH: '/usr/bin' }, TEST_LOGGER) expect(env.ORCA_PANE_KEY).toBeUndefined() expect(Object.keys(env).filter((key) => key.includes('PANE'))).toEqual([]) }) @@ -187,7 +208,8 @@ describe('structuredSessionChildIdentityEnv', () => { installFakeAppEnvironment({ isPackaged: () => true, getPath: () => USER_DATA }) registerWorker() expect( - structuredSessionChildIdentityEnv(SESSION_ID, { PATH: '/usr/bin' }).ORCA_CLI_COMMAND + structuredSessionChildIdentityEnv(SESSION_ID, { PATH: '/usr/bin' }, TEST_LOGGER) + .ORCA_CLI_COMMAND ).not.toBe('orca-ide') }) }) diff --git a/src/main/runtime/structured-session-child-identity-env.ts b/src/main/runtime/structured-session-child-identity-env.ts index 4d3e85c34140..fead507f8082 100644 --- a/src/main/runtime/structured-session-child-identity-env.ts +++ b/src/main/runtime/structured-session-child-identity-env.ts @@ -49,10 +49,12 @@ import { ORCA_AGENT_SESSION_ID_ENV } from '../../shared/agent-session-caller-env import { ORCA_STRUCTURED_SESSION_ENV } from '../../shared/structured-session-marker' import { prependOrcaCliDirToChildPath } from '../cli/orca-cli-child-path' import { structuredWorkerIdentities } from './structured-worker-identity' +import type { StructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger' export function structuredSessionChildIdentityEnv( sessionId: string, - childEnv: Record + childEnv: Record, + logger: StructuredAgentSessionLogger ): Record { const identity = structuredWorkerIdentities.getBySessionId(sessionId) const env: Record = { @@ -61,7 +63,7 @@ export function structuredSessionChildIdentityEnv( [ORCA_AGENT_SESSION_ID_ENV]: sessionId, [ORCA_STRUCTURED_SESSION_ENV]: '1' } - applyThisAppCli(env) + applyThisAppCli(env, sessionId, logger) return env } @@ -69,7 +71,11 @@ export function structuredSessionChildIdentityEnv( * A host with no app environment installed — a plain-Node fork, or a unit test — has no userData * root to resolve, and inventing one would write a shim into the wrong directory. */ -function applyThisAppCli(env: Record): void { +function applyThisAppCli( + env: Record, + sessionId: string, + logger: StructuredAgentSessionLogger +): void { delete env.ORCA_CLI_COMMAND if (!hasAppEnvironment()) { return @@ -86,8 +92,9 @@ function applyThisAppCli(env: Record): void { if (launcher) { env.ORCA_CLI_COMMAND = launcher } else { - console.warn( - "[structured-session] This app's CLI launcher did not resolve; the session's child has no ORCA_CLI_COMMAND." - ) + logger.warn("this app's CLI launcher did not resolve; the child has no ORCA_CLI_COMMAND", { + scope: 'child-cli-launcher', + sessionId + }) } } diff --git a/src/main/runtime/structured-session-login-shell-test-harness.ts b/src/main/runtime/structured-session-login-shell-test-harness.ts index 943dfe0f4d3d..fadcdb4fcdd4 100644 --- a/src/main/runtime/structured-session-login-shell-test-harness.ts +++ b/src/main/runtime/structured-session-login-shell-test-harness.ts @@ -10,6 +10,9 @@ import { join } from 'node:path' import { installFakeAppEnvironment } from '../../../config/scripts/vitest-host-ports-setup' import { runProcess } from '../../shared/child-process/run-process' import { structuredSessionChildIdentityEnv } from './structured-session-child-identity-env' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const SESSION_ID = 'f7a1c0de-1111-4222-8333-444455556666' @@ -40,7 +43,11 @@ export function createLoginShellHarness(): LoginShellHarness { writeFileSync(join(home, '.zprofile'), prependGlobal) writeFileSync(join(home, '.bash_profile'), prependGlobal) installFakeAppEnvironment({ isPackaged: () => false, getPath: () => userData }) - const env = structuredSessionChildIdentityEnv(SESSION_ID, { HOME: home, PATH: '/usr/bin:/bin' }) + const env = structuredSessionChildIdentityEnv( + SESSION_ID, + { HOME: home, PATH: '/usr/bin:/bin' }, + TEST_LOGGER + ) return { run: async (spec) => (await runProcess({ ...spec, env })).stdout, dispose: () => rmSync(root, { recursive: true, force: true }) diff --git a/src/main/runtime/structured-session-mail-redrive-wiring.test.ts b/src/main/runtime/structured-session-mail-redrive-wiring.test.ts index d7779112cc63..4dfb3db1e44c 100644 --- a/src/main/runtime/structured-session-mail-redrive-wiring.test.ts +++ b/src/main/runtime/structured-session-mail-redrive-wiring.test.ts @@ -50,7 +50,7 @@ describe("the runtime's own structured host install", () => { const closed = new OrchestrationDb(':memory:') closed.close() vi.spyOn(runtime, 'getExistingOrchestrationDb').mockReturnValue(closed) - const warn = vi.spyOn(console, 'warn').mockImplementation(() => {}) + const warn = vi.spyOn(runtime.structuredAgentSessionLogger, 'warn').mockImplementation(() => {}) expect(() => runtime.onStructuredSessionStatusForMail({ sessionId: '4a1f6c2e-8b3d-4e7a-9c15-0d2b6e8f1a37', @@ -58,8 +58,11 @@ describe("the runtime's own structured host install", () => { }) ).not.toThrow() expect(warn).toHaveBeenCalledWith( - '[orchestration] structured session mail redrive failed', - expect.objectContaining({ sessionId: '4a1f6c2e-8b3d-4e7a-9c15-0d2b6e8f1a37' }) + 'a structured session mail redrive failed', + expect.objectContaining({ + scope: 'mail-redrive', + sessionId: '4a1f6c2e-8b3d-4e7a-9c15-0d2b6e8f1a37' + }) ) }) }) diff --git a/src/main/runtime/structured-session-worktree-teardown.ts b/src/main/runtime/structured-session-worktree-teardown.ts index 047b4a216445..e90780814a0e 100644 --- a/src/main/runtime/structured-session-worktree-teardown.ts +++ b/src/main/runtime/structured-session-worktree-teardown.ts @@ -48,7 +48,9 @@ export type UnclosedStructuredSession = StructuredSessionInWorkspace & { export type StructuredWorktreeSweepRuntime = Pick< OrcaRuntimeService, - 'forgetStructuredSessionMail' | 'retireStructuredAgentSessionTabFromSnapshot' + | 'forgetStructuredSessionMail' + | 'retireStructuredAgentSessionTabFromSnapshot' + | 'structuredAgentSessionLogger' > /** diff --git a/src/main/runtime/structured-worker-identity.test.ts b/src/main/runtime/structured-worker-identity.test.ts index 17ba897de479..4c21b07a80db 100644 --- a/src/main/runtime/structured-worker-identity.test.ts +++ b/src/main/runtime/structured-worker-identity.test.ts @@ -20,6 +20,9 @@ import { } from './structured-worker-identity' import type { AgentSessionRecord } from '../../shared/agent-session-record' import type { ExecutionHostId } from '../../shared/execution-host' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' + +const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger const SESSION_ID = 'a1b2c3d4-e5f6-4a7b-8c9d-0e1f2a3b4c5d' @@ -300,7 +303,7 @@ describe('structured workers stay outside the PTY-only fail-closed paths', () => hostScope: { kind: 'local', hostId: 'local' } }) try { - const env = structuredSessionChildIdentityEnv(SESSION_ID, {}) + const env = structuredSessionChildIdentityEnv(SESSION_ID, {}, TEST_LOGGER) // Registered, so the worker's handle is present; without it the pane-key assertion would pass // for the wrong reason. expect(env.ORCA_TERMINAL_HANDLE).toBe(handle) From 02b1128a3432de2b643c4a84f3a4775737814a27 Mon Sep 17 00:00:00 2001 From: Brennan Benson <79079362+brennanb2025@users.noreply.github.com> Date: Thu, 1 Oct 2026 20:49:37 -0700 Subject: [PATCH 2/4] refactor(native-chat): report the remaining structured-chat failures through the logger, and widen the ratchet to match - Claude: a descendant that survives a close and a failed at-rest `/` command scan now go to the chat's logger with its session id. The stream-json connection and the at-rest catalog take the logger as a required dependency; only structured Claude code opens or builds either. - Runtime: a failed structured host install before a worker stop or release, and a forced worktree removal that leaves structured sessions unclosed, report through the runtime's logger. The removal keeps its console line when no runtime is passed. The runtime wraps an injected logger so a throwing one cannot fail the step it reports. - The structured mail redrive's catch moves into structured-session-mail-target.ts, so the ratchet covers it without scanning the PTY record file's own mailbox warnings. - The WSL transcript gate's deadline warning also writes a failed span to the trace file through the existing tracer; the console line stays because scanner workers install no trace sink. - Ratchet scope: drop the trailing dash that skipped rpc/methods/structured-agent-session.ts, cover the runtime's structured-* files, the structured worker stop/release files and the two Claude files, and fail if a listed file stops being scanned. - The held-signal test is back to main's version (#24494 fixed it the same way). - The option-restore test asserts the logger entry instead of a console spy that no longer fired. --- src/main/claude/claude-at-rest-commands.ts | 8 ++- src/main/claude/claude-stop-ack-race.test.ts | 2 + ...laude-stream-json-connection-close.test.ts | 58 ++++++++++++++++++- .../claude-stream-json-connection.test.ts | 6 +- .../claude/claude-stream-json-connection.ts | 10 +++- .../claude/claude-structured-options.test.ts | 17 +++++- ...ed-session-acquisition-processless.test.ts | 5 +- .../claude-structured-session-acquisition.ts | 2 + .../claude-structured-session-close.test.ts | 10 ++-- ...structured-session-reading-control.test.ts | 2 +- .../claude-structured-session-test-support.ts | 2 +- .../claude-supervised-stop-real-cli.test.ts | 3 +- ...red-agent-session-at-rest-commands.test.ts | 41 +++++++------ .../structured-chat-logger-ratchet.test.ts | 29 +++++++--- .../wsl-transcript-fs-gate.test.ts | 29 ++++++++++ .../native-chat/wsl-transcript-fs-gate.ts | 6 +- .../wsl-transcript-fs-timeout-report.ts | 17 ++++++ ...structured-fake-connection-test-fixture.ts | 2 +- ...rca-runtime-get-pty-record-for-pane-key.ts | 25 +++----- src/main/runtime/orca-runtime-state-fields.ts | 4 +- .../structured-session-mail-target.ts | 23 ++++++++ .../worker/worker-release-completion.ts | 7 +-- .../orchestration/worker/worker-stop.ts | 7 +-- ...ructured-agent-session-held-signal.test.ts | 6 +- .../structured-claude-runtime-adapter.ts | 1 + ...ed-claude-scripted-runtime-test-support.ts | 2 +- ...ructured-session-worktree-teardown.test.ts | 16 +++++ src/main/runtime/worktree-teardown.ts | 13 ++++- 28 files changed, 265 insertions(+), 88 deletions(-) create mode 100644 src/main/native-chat/wsl-transcript-fs-timeout-report.ts diff --git a/src/main/claude/claude-at-rest-commands.ts b/src/main/claude/claude-at-rest-commands.ts index 7eaa9c143ed3..e4ba94dedca5 100644 --- a/src/main/claude/claude-at-rest-commands.ts +++ b/src/main/claude/claude-at-rest-commands.ts @@ -5,6 +5,7 @@ import { structuredSlashCommands } from '../../shared/structured-agent-session-c import { discoverSkills } from '../skills/discovery' import { scanClaudeCommandFolders } from './claude-command-folder-scan' import { supportsClaudeStructuredLocation } from './claude-structured-location-support' +import type { StructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger' /** How long one scan answers for a workspace and account before the next read scans again. */ export const CLAUDE_AT_REST_COMMANDS_TTL_MS = 10_000 @@ -14,6 +15,7 @@ const SCAN_OVERDUE_MS = 30_000 const MAX_SCANS_IN_FLIGHT = 2 export type ClaudeAtRestCommandsDeps = { + logger: StructuredAgentSessionLogger resolveWorkspacePath: (workspaceId: string) => Promise now?: () => number discover?: typeof discoverSkills @@ -101,7 +103,11 @@ export class ClaudeAtRestCommandCatalog { (error: unknown) => { // Waits out the window before trying again, but leaves room for an older scan's answer. entry.scannedAt = this.now() - console.warn('[claude] reading the at-rest `/` commands failed:', error) + this.deps.logger.warn('reading the at-rest `/` commands failed', { + scope: 'claude-at-rest-commands', + sessionId: record.sessionId, + error + }) } ) .finally(() => { diff --git a/src/main/claude/claude-stop-ack-race.test.ts b/src/main/claude/claude-stop-ack-race.test.ts index 5f2f60d3a692..c0b8fdc7dd14 100644 --- a/src/main/claude/claude-stop-ack-race.test.ts +++ b/src/main/claude/claude-stop-ack-race.test.ts @@ -21,6 +21,7 @@ import { import { stopClaudeBackgroundTasks } from './claude-structured-control-actions' import { CLAUDE_STRUCTURED_BASE_OPTIONS } from './claude-structured-launch-resolution' import type { ClaudeSession } from './claude-structured-session-state' +import { testEventSinkLogging } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' const FAKE_CLI = join(__dirname, '__fixtures__', 'claude-agent-sdk-scripted-cli.mjs') const SESSION_ID = '5348c19f-6a54-4c2e-9c68-9c2b1a3d4e5f' @@ -107,6 +108,7 @@ async function stoppedAsItCompleted(ahead: number) { } }, { + ...testEventSinkLogging(), onMessage: (message) => { seen.push(`${String(message.type)}:${String(message.subtype ?? '')}`) decoder.observe(message) diff --git a/src/main/claude/claude-stream-json-connection-close.test.ts b/src/main/claude/claude-stream-json-connection-close.test.ts index 22076f3600ea..36956450adf2 100644 --- a/src/main/claude/claude-stream-json-connection-close.test.ts +++ b/src/main/claude/claude-stream-json-connection-close.test.ts @@ -7,6 +7,10 @@ import { openClaudeStreamJsonConnection, type ClaudeStreamJsonLaunch } from './claude-stream-json-connection' +import { + recordingStructuredAgentSessionLogger, + testEventSinkLogging +} from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' const mocks = vi.hoisted(() => { const refresh = vi.fn() @@ -66,6 +70,7 @@ describe('Claude stream-json close ordering', () => { connection = await openClaudeStreamJsonConnection( { pathToClaudeCodeExecutable: 'claude', options: {}, cwd: '/work/repo' }, { + ...testEventSinkLogging(), onMessage: (message) => { seen.push(String(message.type)) if (message.type === 'first') { @@ -115,6 +120,7 @@ describe('Claude stream-json close ordering', () => { const connection = await openClaudeStreamJsonConnection( { pathToClaudeCodeExecutable: 'claude', options: {}, cwd: '/work/repo' }, { + ...testEventSinkLogging(), onMessage: (message) => events.push(`message:${String(message.type)}`), onExit: () => events.push('exit') }, @@ -153,7 +159,7 @@ describe('Claude stream-json close ordering', () => { }) as unknown as typeof query const connection = await openClaudeStreamJsonConnection( { pathToClaudeCodeExecutable: 'claude', options: {}, cwd: '/work/repo' }, - {}, + testEventSinkLogging(), () => child, queryImpl ) @@ -190,7 +196,12 @@ describe('Claude stream-json close ordering', () => { })() return (async function* () {})() }) as typeof query - const connection = await openClaudeStreamJsonConnection(launch, {}, () => child, queryImpl) + const connection = await openClaudeStreamJsonConnection( + launch, + testEventSinkLogging(), + () => child, + queryImpl + ) const closing = connection.close() await new Promise((resolve) => setImmediate(resolve)) @@ -231,7 +242,12 @@ describe('Claude stream-json close ordering', () => { })() return (async function* () {})() }) as typeof query - const connection = await openClaudeStreamJsonConnection(launch, {}, () => child, queryImpl) + const connection = await openClaudeStreamJsonConnection( + launch, + testEventSinkLogging(), + () => child, + queryImpl + ) child.stderr.emit('data', 'output') await vi.waitFor(() => expect(mocks.refresh).toHaveBeenCalledTimes(1)) @@ -248,4 +264,40 @@ describe('Claude stream-json close ordering', () => { await expect(closing).resolves.toBe(true) expect(child.stdin.writableEnded).toBe(true) }) + + it('reports a descendant that outlived an exited root through the chat logger', async () => { + mocks.refresh.mockReset() + mocks.proveClaudeChildExit.mockReset() + mocks.refresh.mockResolvedValue(undefined) + mocks.proveClaudeChildExit.mockResolvedValueOnce(false) + const child = fakeChild() + // oxlint-disable-next-line typescript/consistent-type-assertions -- SAFETY: This injected query only has to spawn the child; the close never reads a message. + const queryImpl = ((params: Parameters[0]) => { + params.options?.spawnClaudeCodeProcess?.({ + command: 'claude', + args: [], + env: {}, + signal: new AbortController().signal + }) + return (async function* () {})() + }) as typeof query + const logged = recordingStructuredAgentSessionLogger() + const connection = await openClaudeStreamJsonConnection( + { pathToClaudeCodeExecutable: 'claude', options: {}, cwd: '/work/repo' }, + { sessionId: 'session-1', logger: logged.logger }, + () => child, + queryImpl + ) + child.emit('exit', 0, null) + Object.assign(mocks.tree, { treeVerdict: 'live' }) + try { + await expect(connection.close()).resolves.toBe(false) + } finally { + Object.assign(mocks.tree, { treeVerdict: 'unverifiable' }) + } + + expect(logged.entries.map((entry) => entry.fields)).toEqual([ + { scope: 'claude-close-descendant', sessionId: 'session-1', pid: 424242 } + ]) + }) }) diff --git a/src/main/claude/claude-stream-json-connection.test.ts b/src/main/claude/claude-stream-json-connection.test.ts index 082ed4c12ce7..d565ae9710ce 100644 --- a/src/main/claude/claude-stream-json-connection.test.ts +++ b/src/main/claude/claude-stream-json-connection.test.ts @@ -91,12 +91,12 @@ const spawnedChildren: SpawnedProcess[] = [] async function open( launch: ClaudeStreamJsonLaunch, - handlers: Parameters[1] = {}, + handlers: Omit[1], 'sessionId' | 'logger'> = {}, queryImpl?: typeof query ): Promise { const connection = await openClaudeStreamJsonConnection( launch, - handlers, + { ...testEventSinkLogging(), ...handlers }, (spec) => { spawned.push(spec) const child = spawnProcess(spec) @@ -804,7 +804,7 @@ describe('the managed-auth live gate', () => { try { await expect( - openClaudeStreamJsonConnection(launchFor(scenario), {}, (spec) => { + openClaudeStreamJsonConnection(launchFor(scenario), testEventSinkLogging(), (spec) => { const child = spawnProcess(spec) started = child const attach = child.stderr.on.bind(child.stderr) diff --git a/src/main/claude/claude-stream-json-connection.ts b/src/main/claude/claude-stream-json-connection.ts index 6f67e04b36ea..4e6ea653c65e 100644 --- a/src/main/claude/claude-stream-json-connection.ts +++ b/src/main/claude/claude-stream-json-connection.ts @@ -22,6 +22,7 @@ import { createClaudeUserMessageQueue } from './claude-agent-sdk-user-message-queue' import type { ClaudeStructuredSdkOptions } from './claude-structured-launch-resolution' +import type { StructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger' export { ClaudeControlRequestError } @@ -53,6 +54,9 @@ export type ClaudeStreamJsonLaunch = { } export type ClaudeStreamJsonConnectionHandlers = { + /** The chat this connection serves, and where its close reports what it could not reap. */ + sessionId: string + logger: StructuredAgentSessionLogger onMessage?: (message: Record) => void /** * The SDK owns inbound permission control: it hands `can_use_tool` to this callback with @@ -114,7 +118,7 @@ function exitError(stderrTail: string, status: ExitStatus | null, cause?: Error) export async function openClaudeStreamJsonConnection( launch: ClaudeStreamJsonLaunch, - handlers: ClaudeStreamJsonConnectionHandlers = {}, + handlers: ClaudeStreamJsonConnectionHandlers, spawnImpl: typeof spawnProcess = spawnProcess, queryImpl?: typeof ClaudeAgentSdk.query ): Promise { @@ -323,7 +327,9 @@ export async function openClaudeStreamJsonConnection( inbox.fail(new Error('claude stream-json connection closed')) if (!proven) { if (exited && tree.treeVerdict === 'live') { - console.warn('[claude-stream-json] root exited but a descendant survived the close:', { + handlers.logger.warn('the Claude process exited but a descendant survived the close', { + scope: 'claude-close-descendant', + sessionId: handlers.sessionId, pid: spawner.pid }) } diff --git a/src/main/claude/claude-structured-options.test.ts b/src/main/claude/claude-structured-options.test.ts index 234054351482..c8912288f5d4 100644 --- a/src/main/claude/claude-structured-options.test.ts +++ b/src/main/claude/claude-structured-options.test.ts @@ -463,10 +463,25 @@ describe('Claude structured option restore under the request deadline', () => { ['effort', 'high'], ['permissionMode', 'plan'] ]) - vi.spyOn(console, 'warn').mockImplementation(() => {}) + const logged = recordingStructuredAgentSessionLogger() + session.logger = logged.logger await expect(restoreClaudeStructuredSessionOptions(session, 10)).resolves.toBeUndefined() + expect(logged.entries.map(({ level, fields }) => ({ level, ...fields }))).toEqual([ + expect.objectContaining({ + level: 'warn', + scope: 'claude-option-restore', + sessionId: 'session-1', + key: 'model' + }), + expect.objectContaining({ + level: 'warn', + scope: 'claude-option-restore', + sessionId: 'session-1', + key: 'effort' + }) + ]) expect(Object.fromEntries(session.options)).toEqual({ model: 'sonnet', effort: 'high' }) expect([...session.restoreSkippedOptions]).toEqual(['permissionMode']) expect(claudeStructuredSessionOptionsFrom(session, null).current).toEqual({ diff --git a/src/main/claude/claude-structured-session-acquisition-processless.test.ts b/src/main/claude/claude-structured-session-acquisition-processless.test.ts index 20617a573320..887356b42a96 100644 --- a/src/main/claude/claude-structured-session-acquisition-processless.test.ts +++ b/src/main/claude/claude-structured-session-acquisition-processless.test.ts @@ -23,10 +23,7 @@ describe('Claude structured processless acquisition', () => { it('classifies pre-pid error and close as processless with idempotent cleanup', async () => { const fault = new Error('spawn claude ENOENT') const close = vi.fn(async () => true) - const openConnection: typeof openClaudeStreamJsonConnection = async ( - _launch, - handlers = {} - ) => { + const openConnection: typeof openClaudeStreamJsonConnection = async (_launch, handlers) => { // A failed spawn reports its error on a later tick, as child_process does. setTimeout(() => handlers.onFault?.(fault), 0) const connection: ClaudeStreamJsonConnection = { diff --git a/src/main/claude/claude-structured-session-acquisition.ts b/src/main/claude/claude-structured-session-acquisition.ts index 7ab1cb65ef6e..474c88030656 100644 --- a/src/main/claude/claude-structured-session-acquisition.ts +++ b/src/main/claude/claude-structured-session-acquisition.ts @@ -192,6 +192,8 @@ export async function acquireClaudeSession({ } }, { + sessionId, + logger: deps.logger, onMessage, canUseTool, onUserDialog, diff --git a/src/main/claude/claude-structured-session-close.test.ts b/src/main/claude/claude-structured-session-close.test.ts index 8881c6ae74b8..455cb3f24a2c 100644 --- a/src/main/claude/claude-structured-session-close.test.ts +++ b/src/main/claude/claude-structured-session-close.test.ts @@ -15,6 +15,7 @@ import { AgentSessionAcquisitionRootExitObservedError } from '../native-chat/age import { ClaudePromptRegistry } from './claude-structured-prompt-replies' import { closeClaudeSession } from './claude-structured-session-close' import { ClaudeAcquisitionRegistry } from './claude-structured-session-state' +import { testEventSinkLogging } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' describe('Claude published session close lifecycle', () => { it('reports a proven root exit when published-session close cannot prove descendants', async () => { @@ -69,11 +70,10 @@ describe('Claude published session close lifecycle', () => { }) const acquisitions = new ClaudeAcquisitionRegistry() const { attempt } = acquisitions.start('session-1', new ClaudePromptRegistry()) - attempt.connection = await claude.openConnection({ - pathToClaudeCodeExecutable: 'claude', - options: {}, - cwd: '/work/repo' - }) + attempt.connection = await claude.openConnection( + { pathToClaudeCodeExecutable: 'claude', options: {}, cwd: '/work/repo' }, + testEventSinkLogging() + ) await expect( closeClaudeSession({ sessionId: 'session-1', sessions: new Map(), acquisitions }) diff --git a/src/main/claude/claude-structured-session-reading-control.test.ts b/src/main/claude/claude-structured-session-reading-control.test.ts index d90e5538964e..4cb12a0c41b9 100644 --- a/src/main/claude/claude-structured-session-reading-control.test.ts +++ b/src/main/claude/claude-structured-session-reading-control.test.ts @@ -100,7 +100,7 @@ describe('Claude structured reading control', () => { // The child exits before publish, so only the failed acquisition can release the binding. const claude = fakeClaude() const open = claude.openConnection - claude.openConnection = async (launch, handlers = {}) => { + claude.openConnection = async (launch, handlers) => { const connection = await open(launch, handlers) claude.connections[0].closed = true handlers.onExit?.(new Error('claude stream-json exited (code 1)')) diff --git a/src/main/claude/claude-structured-session-test-support.ts b/src/main/claude/claude-structured-session-test-support.ts index d766767a8c09..65bdfff6db5d 100644 --- a/src/main/claude/claude-structured-session-test-support.ts +++ b/src/main/claude/claude-structured-session-test-support.ts @@ -87,7 +87,7 @@ export function fakeClaude( const route = routes[subtype] return route ? route(params) : undefined } - const openConnection: typeof openClaudeStreamJsonConnection = async (launch, handlers = {}) => { + const openConnection: typeof openClaudeStreamJsonConnection = async (launch, handlers) => { let cycleInitEmitted = false // Keys mirror the real system/init frame, which carries `model` but no // effort of any kind: the current effort only comes back from get_settings. diff --git a/src/main/claude/claude-supervised-stop-real-cli.test.ts b/src/main/claude/claude-supervised-stop-real-cli.test.ts index 82432e3fd6e6..d6ba7a2c9c45 100644 --- a/src/main/claude/claude-supervised-stop-real-cli.test.ts +++ b/src/main/claude/claude-supervised-stop-real-cli.test.ts @@ -14,6 +14,7 @@ import { CLAUDE_STRUCTURED_BASE_OPTIONS, claudeStructuredPermissionOptions } from './claude-structured-launch-resolution' +import { testEventSinkLogging } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' // Opt-in only: spends a real (haiku) turn per case. Run it in an isolated HOME with // ORCA_REAL_CLAUDE_BIN set, and ORCA_REAL_CLAUDE_SETTINGS when auth lives in a settings file. @@ -96,7 +97,7 @@ async function open(sessionId: string, cwd: string, resume: boolean, frames: Fra }, cwd }, - { onMessage: (message) => frames.push({ at: Date.now(), message }) } + { ...testEventSinkLogging(), onMessage: (message) => frames.push({ at: Date.now(), message }) } ) connections.push(connection) recordedPids.add(connection.pid!) diff --git a/src/main/native-chat/agent-session-wire/structured-agent-session-at-rest-commands.test.ts b/src/main/native-chat/agent-session-wire/structured-agent-session-at-rest-commands.test.ts index 140a99201156..a83557fa6b50 100644 --- a/src/main/native-chat/agent-session-wire/structured-agent-session-at-rest-commands.test.ts +++ b/src/main/native-chat/agent-session-wire/structured-agent-session-at-rest-commands.test.ts @@ -71,6 +71,7 @@ function adapter(catalog: ClaudeAtRestCommandCatalog): StructuredAgentSessionAda function catalogFor(workspacePath: string): ClaudeAtRestCommandCatalog { return new ClaudeAtRestCommandCatalog({ + logger: recordingStructuredAgentSessionLogger().logger, resolveWorkspacePath: async () => workspacePath, now: () => clock, // Only the folders this test writes, never the machine's own home. @@ -173,6 +174,7 @@ describe("a Claude chat whose Claude isn't running shows the `/` surface from it it('keeps a slow scan once it answers, never a staler one after a newer, and runs at most two', async () => { const pending: ((skills: string[]) => void)[] = [] const catalog = new ClaudeAtRestCommandCatalog({ + logger: recordingStructuredAgentSessionLogger().logger, resolveWorkspacePath: async () => workspace, now: () => clock, discover: () => @@ -231,7 +233,9 @@ describe("a Claude chat whose Claude isn't running shows the `/` surface from it it('waits out the window from when a scan lands, even one that failed', async () => { let calls = 0 let failNext = true + const logged = recordingStructuredAgentSessionLogger() const catalog = new ClaudeAtRestCommandCatalog({ + logger: logged.logger, resolveWorkspacePath: async () => workspace, now: () => clock, discover: async (args) => { @@ -247,25 +251,24 @@ describe("a Claude chat whose Claude isn't running shows the `/` surface from it } }) const record = store.getRecord(SESSION)! - const warned = vi.spyOn(console, 'warn').mockImplementation(() => undefined) - try { - catalog.read(record) - await vi.waitFor(() => expect(warned).toHaveBeenCalledOnce()) - catalog.read(record) - await new Promise((resolve) => setTimeout(resolve, 20)) - expect(calls).toBe(1) - clock += CLAUDE_AT_REST_COMMANDS_TTL_MS - catalog.read(record) - await vi.waitFor(() => - expect(namesOf(catalog.read(record) ?? null, 'skill')).toEqual(['review-pr']) - ) - clock += CLAUDE_AT_REST_COMMANDS_TTL_MS - 1 - catalog.read(record) - await new Promise((resolve) => setTimeout(resolve, 20)) - expect(calls).toBe(2) - } finally { - warned.mockRestore() - } + catalog.read(record) + await vi.waitFor(() => expect(logged.entries).toHaveLength(1)) + expect(logged.entries[0].fields).toMatchObject({ + scope: 'claude-at-rest-commands', + sessionId: SESSION + }) + catalog.read(record) + await new Promise((resolve) => setTimeout(resolve, 20)) + expect(calls).toBe(1) + clock += CLAUDE_AT_REST_COMMANDS_TTL_MS + catalog.read(record) + await vi.waitFor(() => + expect(namesOf(catalog.read(record) ?? null, 'skill')).toEqual(['review-pr']) + ) + clock += CLAUDE_AT_REST_COMMANDS_TTL_MS - 1 + catalog.read(record) + await new Promise((resolve) => setTimeout(resolve, 20)) + expect(calls).toBe(2) }) it('after a relaunch, with nothing remembered from before it', async () => { diff --git a/src/main/native-chat/agent-session-wire/structured-chat-logger-ratchet.test.ts b/src/main/native-chat/agent-session-wire/structured-chat-logger-ratchet.test.ts index efdde8d2d49b..dcb48cb73a0b 100644 --- a/src/main/native-chat/agent-session-wire/structured-chat-logger-ratchet.test.ts +++ b/src/main/native-chat/agent-session-wire/structured-chat-logger-ratchet.test.ts @@ -10,20 +10,32 @@ import { scanSourceTree, stripComments } from '../../../shared/source-scan/sourc * Both shapes are how failures went missing before the logger was required. */ +// Paths are '/'-separated on every platform (scanSourceTree normalizes them). const SCOPE_PREFIXES = [ 'main/native-chat/agent-session-wire/', 'main/native-chat/agent-session-journal/', + 'main/native-chat/structured-agent-session-', 'main/claude/claude-structured-', 'main/codex/codex-structured-', - 'main/runtime/structured-agent-session-', - 'main/runtime/structured-session-', - 'main/runtime/structured-claude-', - 'main/runtime/structured-codex-', + 'main/runtime/structured-', 'main/runtime/orchestration/structured-', - 'main/runtime/rpc/methods/structured-agent-session-', - 'main/runtime/rpc/methods/orchestration-structured-' + // No trailing dash: the agentSession RPC file itself is `structured-agent-session.ts`. + 'main/runtime/rpc/methods/structured-agent-session', + 'main/runtime/rpc/methods/structured-session-', + 'main/runtime/rpc/methods/orchestration-structured-', + 'main/runtime/rpc/methods/orchestration/worker/structured-worker-' ] +/** Structured chat code whose name does not say so. */ +const SCOPE_FILES = new Set([ + // Opened and built only by structured Claude chats. + 'main/claude/claude-stream-json-connection.ts', + 'main/claude/claude-at-rest-commands.ts', + // Install the structured host before a structured worker's stop or release. + 'main/runtime/rpc/methods/orchestration/worker/worker-stop.ts', + 'main/runtime/rpc/methods/orchestration/worker/worker-release-completion.ts' +]) + /** The logger's own sink. */ const CONSOLE_ALLOWED = new Set([ 'main/native-chat/agent-session-wire/structured-agent-session-logger.ts' @@ -84,7 +96,8 @@ export function findStructuredChatLoggerBypasses( function inScope(relativePath: string): boolean { return ( - SCOPE_PREFIXES.some((prefix) => relativePath.startsWith(prefix)) && + (SCOPE_FILES.has(relativePath) || + SCOPE_PREFIXES.some((prefix) => relativePath.startsWith(prefix))) && !relativePath.includes('-test-support') ) } @@ -135,6 +148,8 @@ describe('structured chat logger ratchet', () => { it('scans a plausible number of files', () => { // A broken root or prefix list would make the guard silently vacuous. expect(files.length).toBeGreaterThan(300) + const scanned = new Set(files.map(({ relativePath }) => relativePath)) + expect([...SCOPE_FILES].filter((path) => !scanned.has(path))).toEqual([]) }) it('has no structured chat failure that bypasses the logger', () => { diff --git a/src/main/native-chat/wsl-transcript-fs-gate.test.ts b/src/main/native-chat/wsl-transcript-fs-gate.test.ts index b886168949a2..2bf909b5ecfa 100644 --- a/src/main/native-chat/wsl-transcript-fs-gate.test.ts +++ b/src/main/native-chat/wsl-transcript-fs-gate.test.ts @@ -9,6 +9,7 @@ import { WSL_TRANSCRIPT_FS_SCAN_TIMEOUT_MS, WslTranscriptFsError } from './wsl-transcript-fs-gate' +import { _resetTracerForTests, setActiveSink } from '../observability/tracer' const SLOW_MESSAGE = 'WSL transcript files are temporarily unavailable because filesystem access is taking too long. Try again shortly or restart Orca if the issue continues.' @@ -764,6 +765,34 @@ describe('WSL transcript filesystem task scheduling', () => { } }) + it('writes a task that outlives its deadline to the trace, not only the console', async () => { + vi.useFakeTimers() + const records: unknown[] = [] + setActiveSink({ push: (record) => records.push(record), flush: () => {}, close: () => {} }) + const stalled = deferred() + try { + const stuck = run('\\\\wsl.localhost\\Ubuntu\\traced', 'exact', () => stalled.promise) + const stuckRejected = expect(stuck).rejects.toMatchObject({ code: 'timeout' }) + await vi.advanceTimersByTimeAsync(WSL_TRANSCRIPT_FS_EXACT_TIMEOUT_MS) + await stuckRejected + expect(records).toEqual([ + expect.objectContaining({ + name: 'wslTranscriptFs.timeout', + attributes: expect.objectContaining({ + priority: 'exact', + timeoutMs: WSL_TRANSCRIPT_FS_EXACT_TIMEOUT_MS + }), + exit: expect.objectContaining({ _tag: 'Failure' }) + }) + ]) + } finally { + stalled.resolve('late') + await vi.advanceTimersByTimeAsync(0) + vi.useRealTimers() + _resetTracerForTests() + } + }) + it('does not mark a scan permit stuck before the scan deadline', async () => { vi.useFakeTimers() const exactWork = deferred() diff --git a/src/main/native-chat/wsl-transcript-fs-gate.ts b/src/main/native-chat/wsl-transcript-fs-gate.ts index d4413c91323f..66db0634c04a 100644 --- a/src/main/native-chat/wsl-transcript-fs-gate.ts +++ b/src/main/native-chat/wsl-transcript-fs-gate.ts @@ -1,4 +1,5 @@ import { wslTranscriptFsLaneKey, wslTranscriptFsRouteKey } from './wsl-transcript-fs-route' +import { reportWslTranscriptFsTimeout } from './wsl-transcript-fs-timeout-report' import { WslTranscriptFsError, wslTranscriptFsCapacityError as capacityError, @@ -257,10 +258,7 @@ function pumpTasks(): void { activeTasks.add(task) task.deadlineTimer = setTimeout(() => { const error = timeoutError() - console.warn( - `[wsl-transcript-fs-gate] ${task.priority} filesystem task exceeded ` + - `${timeoutMs(task.priority)}ms; replacing its I/O process: ${task.key}` - ) + reportWslTranscriptFsTimeout(task, timeoutMs(task.priority), error) // Keep polling from churning replacement processes on the same stalled mount. quarantineRoute(task.route, timeoutMs(task.priority), task.startedAt ?? performance.now()) failQueuedRouteTasks(task.route) diff --git a/src/main/native-chat/wsl-transcript-fs-timeout-report.ts b/src/main/native-chat/wsl-transcript-fs-timeout-report.ts new file mode 100644 index 000000000000..550de214d181 --- /dev/null +++ b/src/main/native-chat/wsl-transcript-fs-timeout-report.ts @@ -0,0 +1,17 @@ +import { startSpan } from '../observability/tracer' + +/** A filesystem task that outlived its deadline. The trace keeps it in a packaged app; scanner + * workers install no trace sink, so the console line stays. */ +export function reportWslTranscriptFsTimeout( + task: { priority: string; key: string }, + timeoutMs: number, + error: Error +): void { + startSpan('wslTranscriptFs.timeout', { + attributes: { priority: task.priority, timeoutMs, taskKey: task.key } + }).fail(error) + console.warn( + `[wsl-transcript-fs-gate] ${task.priority} filesystem task exceeded ` + + `${timeoutMs}ms; replacing its I/O process: ${task.key}` + ) +} diff --git a/src/main/runtime/claude-structured-fake-connection-test-fixture.ts b/src/main/runtime/claude-structured-fake-connection-test-fixture.ts index 3404bcbf283c..5a1e0f60373c 100644 --- a/src/main/runtime/claude-structured-fake-connection-test-fixture.ts +++ b/src/main/runtime/claude-structured-fake-connection-test-fixture.ts @@ -24,7 +24,7 @@ export function fakeClaude(providerSession: string) { null let contextUsage: () => Promise = async () => ({}) // oxlint-disable-next-line typescript/consistent-type-assertions -- SAFETY: the fake answers every control request the session issues; the real opener's signature is what the runtime under test calls. - const openConnection = (async (launch, handlers = {}) => { + const openConnection = (async (launch, handlers) => { const connection: FakeClaudeConnection = { launch, handlers, diff --git a/src/main/runtime/orca-runtime-get-pty-record-for-pane-key.ts b/src/main/runtime/orca-runtime-get-pty-record-for-pane-key.ts index 4c0554647935..37c4cdead788 100644 --- a/src/main/runtime/orca-runtime-get-pty-record-for-pane-key.ts +++ b/src/main/runtime/orca-runtime-get-pty-record-for-pane-key.ts @@ -11,7 +11,7 @@ import { handleLessCoordinatorSessionId, structuredSessionAddressTarget, structuredSessionMailTarget, - structuredSessionIdleEdgeMailboxes, + redriveStructuredSessionMail, structuredWorkerMailSessionId } from './orchestration/structured-session-mail-target' import { @@ -206,23 +206,12 @@ export class OrcaRuntimeWithGetPtyRecordForPaneKey extends OrcaRuntimeWithPruneM if (summary.status === 'working' || summary.status === 'attention') { return } - // Logged, never thrown: the same status callback goes on to the first-turn workspace rename. - try { - this.notifyStructuredSessionJournalActivity(summary.sessionId) - const openDb = () => this.getExistingOrchestrationDb() - const deliver = (mailbox: string) => this.deliverPendingMessagesForHandle(mailbox) - structuredSessionIdleEdgeMailboxes( - summary.sessionId, - openDb, - this.structuredAgentSessionLogger - ).forEach(deliver) - } catch (error) { - this.structuredAgentSessionLogger.warn('a structured session mail redrive failed', { - scope: 'mail-redrive', - sessionId: summary.sessionId, - error - }) - } + redriveStructuredSessionMail(summary.sessionId, { + notifyJournalActivity: (sessionId) => this.notifyStructuredSessionJournalActivity(sessionId), + openDb: () => this.getExistingOrchestrationDb(), + deliver: (mailbox) => this.deliverPendingMessagesForHandle(mailbox), + logger: this.structuredAgentSessionLogger + }) } /** Settlement drops anything parked for the session; nothing will ever redrive it again. */ diff --git a/src/main/runtime/orca-runtime-state-fields.ts b/src/main/runtime/orca-runtime-state-fields.ts index 7eda81136620..15d981f98c81 100644 --- a/src/main/runtime/orca-runtime-state-fields.ts +++ b/src/main/runtime/orca-runtime-state-fields.ts @@ -10,6 +10,7 @@ import type { AgentStatusIpcPayload } from '../../shared/agent-status-types' import type { StructuredAgentSessionStatusSink } from '../native-chat/agent-session-wire/structured-agent-session-status-feed' import { createStructuredAgentSessionLogger, + neverThrowingStructuredAgentSessionLogger, type StructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger' import type { ObservedAgentStatusPaneIdentity } from '../ipc/agent-status-ipc-boundary' @@ -224,8 +225,9 @@ export class OrcaRuntimeWithStateFields extends OrcaRuntimeWithLinearCommands { } this.getAgentStatusSnapshotFn = deps?.getAgentStatusSnapshot ?? null this.structuredAgentStatusSinkFn = deps?.structuredAgentStatusSink ?? null - this.structuredAgentSessionLogger = + this.structuredAgentSessionLogger = neverThrowingStructuredAgentSessionLogger( deps?.structuredAgentSessionLogger ?? createStructuredAgentSessionLogger() + ) this.readObservedAgentStatusPaneIdentityFn = deps?.readObservedAgentStatusPaneIdentity ?? (() => ({ kind: 'unobserved' })) this.getAgentProviderSessionSnapshotFn = diff --git a/src/main/runtime/orchestration/structured-session-mail-target.ts b/src/main/runtime/orchestration/structured-session-mail-target.ts index 15b95294090b..04f7f14475eb 100644 --- a/src/main/runtime/orchestration/structured-session-mail-target.ts +++ b/src/main/runtime/orchestration/structured-session-mail-target.ts @@ -129,3 +129,26 @@ export function structuredSessionIdleEdgeMailboxes( } return db ? structuredSessionOwnedMailboxes(sessionId, db) : [] } + +/** A session's idle edge: retry what is parked on it and point the mail it owns again. Logged, + * never thrown: the same status callback goes on to the first-turn workspace rename. */ +export function redriveStructuredSessionMail( + sessionId: string, + deps: { + notifyJournalActivity: (sessionId: string) => void + openDb: () => OrchestrationDb | null + deliver: (mailbox: string) => void + logger: StructuredAgentSessionLogger + } +): void { + try { + deps.notifyJournalActivity(sessionId) + structuredSessionIdleEdgeMailboxes(sessionId, deps.openDb, deps.logger).forEach(deps.deliver) + } catch (error) { + deps.logger.warn('a structured session mail redrive failed', { + scope: 'mail-redrive', + sessionId, + error + }) + } +} diff --git a/src/main/runtime/rpc/methods/orchestration/worker/worker-release-completion.ts b/src/main/runtime/rpc/methods/orchestration/worker/worker-release-completion.ts index 4aca4d0420a0..37e2ae2d90c2 100644 --- a/src/main/runtime/rpc/methods/orchestration/worker/worker-release-completion.ts +++ b/src/main/runtime/rpc/methods/orchestration/worker/worker-release-completion.ts @@ -101,10 +101,9 @@ async function completeWorkerTerminalReleaseOnce( // worker's redrive subscription. Until that exists, a worker that survives a restart has its // parked mail wait for the next arrival rather than a settle edge. await runtime.ensureStructuredAgentSessionHost().catch((error: unknown) => { - console.warn( - '[orchestration] structured host install failed before release', - dispatchId, - error + runtime.structuredAgentSessionLogger.warn( + 'installing the structured host before a worker release failed', + { scope: 'worker-release-host-install', dispatchId, error } ) }) } diff --git a/src/main/runtime/rpc/methods/orchestration/worker/worker-stop.ts b/src/main/runtime/rpc/methods/orchestration/worker/worker-stop.ts index ee0e73c904f8..a07643fcfba3 100644 --- a/src/main/runtime/rpc/methods/orchestration/worker/worker-stop.ts +++ b/src/main/runtime/rpc/methods/orchestration/worker/worker-stop.ts @@ -133,10 +133,9 @@ export const ORCHESTRATION_WORKER_STOP_METHODS = [ // installed the structured host, and both the observation below and the close read it. // Without this a restarted worker answers `unknown` forever and can never be stopped. await runtime.ensureStructuredAgentSessionHost().catch((error: unknown) => { - console.warn( - '[orchestration] structured host install failed before stop', - handle, - error + runtime.structuredAgentSessionLogger.warn( + 'installing the structured host before a worker stop failed', + { scope: 'worker-stop-host-install', handle, error } ) }) } diff --git a/src/main/runtime/structured-agent-session-held-signal.test.ts b/src/main/runtime/structured-agent-session-held-signal.test.ts index a8acf47e5bc6..a467e45521f4 100644 --- a/src/main/runtime/structured-agent-session-held-signal.test.ts +++ b/src/main/runtime/structured-agent-session-held-signal.test.ts @@ -20,9 +20,7 @@ import { ensureStructuredAgentSessionHost, stopStructuredAgentSessionRuntime } from './structured-agent-session-runtime' -import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' - -const TEST_LOGGER = recordingStructuredAgentSessionLogger().logger +import { createStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger' vi.mock('../ai-vault/session-scanner-worker-spawn', () => ({ scanAiVaultSessionsInWorker: vi.fn(), @@ -45,7 +43,7 @@ function installHost(): Promise { resolveWorkspacePath: async () => stateDirectory, resolveClaudeAuthPolicy: () => ({ stripAuthEnv: true }), resolveEnvironment: async () => ({}), - logger: TEST_LOGGER + logger: createStructuredAgentSessionLogger() }) } diff --git a/src/main/runtime/structured-claude-runtime-adapter.ts b/src/main/runtime/structured-claude-runtime-adapter.ts index 63809b2e2d9d..b7ffca0e9042 100644 --- a/src/main/runtime/structured-claude-runtime-adapter.ts +++ b/src/main/runtime/structured-claude-runtime-adapter.ts @@ -77,6 +77,7 @@ export function createStructuredClaudeRuntimeAdapter( const { store } = deps return new ClaudeStructuredSessionAdapter({ atRestCommands: new ClaudeAtRestCommandCatalog({ + logger: deps.logger, resolveWorkspacePath: deps.resolveWorkspacePath }), resolveLaunch: createClaudeStructuredLaunchResolver({ diff --git a/src/main/runtime/structured-claude-scripted-runtime-test-support.ts b/src/main/runtime/structured-claude-scripted-runtime-test-support.ts index 7a69cbe9c86d..b0e71082e051 100644 --- a/src/main/runtime/structured-claude-scripted-runtime-test-support.ts +++ b/src/main/runtime/structured-claude-scripted-runtime-test-support.ts @@ -75,7 +75,7 @@ export function createScriptedClaudeRuntime(sessionIds: readonly string[]) { let root: string | null = null let operations = 0 - const openConnection: typeof openClaudeStreamJsonConnection = async (launch, handlers = {}) => { + const openConnection: typeof openClaudeStreamJsonConnection = async (launch, handlers) => { const providerSessionId = String(launch.options.sessionId ?? launch.options.resume) const sessionId = sessionIds.find( (candidate) => claudeSessionIdForOrcaSession(candidate) === providerSessionId diff --git a/src/main/runtime/structured-session-worktree-teardown.test.ts b/src/main/runtime/structured-session-worktree-teardown.test.ts index f33d7889b31f..ea48f57d568e 100644 --- a/src/main/runtime/structured-session-worktree-teardown.test.ts +++ b/src/main/runtime/structured-session-worktree-teardown.test.ts @@ -1,6 +1,7 @@ import { beforeEach, describe, expect, it, vi } from 'vitest' import type { AgentSessionRecord } from '../../shared/agent-session-record' import type { IPtyProvider } from '../providers/types' +import { recordingStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger-test-support' const hostRef: { current: unknown } = { current: null } @@ -473,6 +474,21 @@ describe('worktree teardown and structured agent sessions', () => { expect(isProvenLiveStructuredSessionRemovalError(error as string)).toBe(true) }) + it("records a forced removal's unclosed sessions through the runtime's chat logger", async () => { + const logged = recordingStructuredAgentSessionLogger() + installHost({ records: [record('s1', WORKTREE)], stuck: new Set(['s1']) }) + await killAllProcessesForWorktree(WORKTREE, { + ...destructiveDeps({ allowUnverifiedStop: true }), + runtime: runtimeDouble({ structuredAgentSessionLogger: logged.logger }) + }) + expect(logged.entries).toHaveLength(1) + expect(logged.entries[0].message).toContain('still live: 1 agent session (claude)') + expect(logged.entries[0].fields).toEqual({ + scope: 'worktree-forced-removal', + sessionIds: ['s1'] + }) + }) + it('still reports what it closed when a forced removal skips the PTY verdict', async () => { // A sweep that fails outright short-circuits the per-PTY verdict — but not the structured // close that already ran, so the count has to survive that return or the removal log claims diff --git a/src/main/runtime/worktree-teardown.ts b/src/main/runtime/worktree-teardown.ts index 417bf4ff1f76..0fc69ac0c1ab 100644 --- a/src/main/runtime/worktree-teardown.ts +++ b/src/main/runtime/worktree-teardown.ts @@ -404,9 +404,16 @@ async function sweepStructuredSessions( // verbatim, like the unstopped-PTY warn above: this line is the only record a forced removal // leaves, and appending "still attached" asserted the live verdict over sessions the sweep had // just said it could not confirm either way. - console.warn( - `[worktree-teardown] forcing removal of ${worktreeId}${UNSTOPPED_PTY_DETAIL_SEPARATOR}${describeUnclosedStructuredSessions(unstopped)}` - ) + const forced = `forcing removal of ${worktreeId}${UNSTOPPED_PTY_DETAIL_SEPARATOR}${describeUnclosedStructuredSessions(unstopped)}` + const logger = deps.runtime?.structuredAgentSessionLogger + if (logger) { + logger.warn(forced, { + scope: 'worktree-forced-removal', + sessionIds: unstopped.map((session) => session.sessionId) + }) + } else { + console.warn(`[worktree-teardown] ${forced}`) + } // A best-effort or forced removal still discards the workspace when a live close remains // unproven. Its close path intentionally leaves the live snapshot tab in place, so carry those // sessions into the post-removal retirement pass alongside the detached members. From 412d1e611064675f62eac264c09dd67b20b1d5ee Mon Sep 17 00:00:00 2001 From: Brennan Benson <79079362+brennanb2025@users.noreply.github.com> Date: Thu, 1 Oct 2026 20:56:34 -0700 Subject: [PATCH 3/4] fix(native-chat): a failed per-chat journal retire names the chat it belonged to The journal-import-retire entry carried only the legacy directory; its one caller holds the chat's session id, so the entry now carries it like the other per-chat journal sites. --- .../journal-per-session-import.test.ts | 10 ++++++++++ .../journal-per-session-import.ts | 4 ++-- .../journal-per-session-source.ts | 2 ++ 3 files changed, 14 insertions(+), 2 deletions(-) diff --git a/src/main/native-chat/agent-session-journal/journal-per-session-import.test.ts b/src/main/native-chat/agent-session-journal/journal-per-session-import.test.ts index bf54007d5501..6e4351cb08bf 100644 --- a/src/main/native-chat/agent-session-journal/journal-per-session-import.test.ts +++ b/src/main/native-chat/agent-session-journal/journal-per-session-import.test.ts @@ -29,6 +29,7 @@ import { journalDirectoryFor, legacyJournalDatabaseFile } from './journal-paths' import { importPerSessionJournal } from './journal-per-session-import' import { readJournalSessionEpoch, type JournalStoredRow } from './journal-row-table' import { createStructuredAgentSessionLogger } from '../agent-session-wire/structured-agent-session-logger' +import { recordingStructuredAgentSessionLogger } from '../agent-session-wire/structured-agent-session-logger-test-support' vi.mock('node:fs', async (importOriginal) => { const actual = await importOriginal() @@ -445,6 +446,8 @@ describe('importing a per-chat journal', () => { await writeLegacyJournal(epoch, rows) removeFails() vi.spyOn(console, 'warn').mockImplementation(() => undefined) + const logged = recordingStructuredAgentSessionLogger() + openTestJournalHostDatabase(root, logged.logger) const journal = await openChat() await journal.appendItem( @@ -453,6 +456,13 @@ describe('importing a per-chat journal', () => { { fence: 1, turnScope: AGENT_JOURNAL_THREAD_SCOPE } ) expect(existsSync(legacyJournalDatabaseFile(legacyDir()))).toBe(true) + expect(logged.entries.map(({ fields }) => fields)).toEqual([ + expect.objectContaining({ + scope: 'journal-import-retire', + sessionId: IDENTITY.sessionId, + legacyDirectory: legacyDir() + }) + ]) // The process exits and the database closes. await journals.closeAll() await removeWorks() diff --git a/src/main/native-chat/agent-session-journal/journal-per-session-import.ts b/src/main/native-chat/agent-session-journal/journal-per-session-import.ts index f0aad843ad6a..6736da1a71a7 100644 --- a/src/main/native-chat/agent-session-journal/journal-per-session-import.ts +++ b/src/main/native-chat/agent-session-journal/journal-per-session-import.ts @@ -130,7 +130,7 @@ async function importOnce(input: ImportInput): Promise void = (path) => rmSync(path, { force: true }) ): void { @@ -137,6 +138,7 @@ export function retireLegacyJournal( } catch (error) { logger.warn('deleting an imported per-chat journal failed', { scope: 'journal-import-retire', + sessionId, legacyDirectory, error }) From ef3f0358b2871d0069e17b6f7c957b48c23810d7 Mon Sep 17 00:00:00 2001 From: Brennan Benson <79079362+brennanb2025@users.noreply.github.com> Date: Thu, 1 Oct 2026 21:10:45 -0700 Subject: [PATCH 4/4] fix(orchestration): a failed host install before a worker stop logs the dispatch, not the worker handle A structured worker's handle is a bearer credential, and the entry now reaches the trace file and the diagnostic bundle. Log the dispatch id instead, as the release path already does. --- .../methods/orchestration/worker/worker-stop.ts | 2 +- .../structured-worker-stop-receipt.test.ts | 16 ++++++++++++++++ 2 files changed, 17 insertions(+), 1 deletion(-) diff --git a/src/main/runtime/rpc/methods/orchestration/worker/worker-stop.ts b/src/main/runtime/rpc/methods/orchestration/worker/worker-stop.ts index a07643fcfba3..1d40131987ab 100644 --- a/src/main/runtime/rpc/methods/orchestration/worker/worker-stop.ts +++ b/src/main/runtime/rpc/methods/orchestration/worker/worker-stop.ts @@ -135,7 +135,7 @@ export const ORCHESTRATION_WORKER_STOP_METHODS = [ await runtime.ensureStructuredAgentSessionHost().catch((error: unknown) => { runtime.structuredAgentSessionLogger.warn( 'installing the structured host before a worker stop failed', - { scope: 'worker-stop-host-install', handle, error } + { scope: 'worker-stop-host-install', dispatchId: params.dispatch, error } ) }) } diff --git a/src/main/runtime/rpc/methods/structured-worker-stop-receipt.test.ts b/src/main/runtime/rpc/methods/structured-worker-stop-receipt.test.ts index d6f41acdeee9..8a1e583ba18a 100644 --- a/src/main/runtime/rpc/methods/structured-worker-stop-receipt.test.ts +++ b/src/main/runtime/rpc/methods/structured-worker-stop-receipt.test.ts @@ -126,4 +126,20 @@ describe('worker-stop on a structured worker this runtime cannot reach', () => { } ) }) + + it('reports a failed host install by dispatch, never by the worker handle', async () => { + const dispatchId = startStructuredWorker() + const failure = new Error('journal database unavailable') + vi.spyOn(runtime, 'ensureStructuredAgentSessionHost').mockRejectedValue(failure) + const warn = vi.spyOn(runtime.structuredAgentSessionLogger, 'warn') + + await expect(call('orchestration.workerStop', { dispatch: dispatchId })).resolves.toMatchObject( + { processAction: 'none', state: 'stop_unknown' } + ) + expect(warn).toHaveBeenCalledOnce() + const fields = warn.mock.calls[0][1] + // The handle is a bearer credential; the trace file and diagnostic bundle must not carry it. + expect(fields).toEqual({ scope: 'worker-stop-host-install', dispatchId, error: failure }) + expect(JSON.stringify(fields)).not.toContain(HANDLE) + }) })