Skip to content
64 changes: 64 additions & 0 deletions docs/design/2026-08-24-debug-log-session-routing-residuals.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,64 @@
# Debug log session routing residuals

## Problem

ACP hosts multiple sessions in one process, while the debug logger retains a
process-wide fallback for the single-session CLI. PR #9538 made
`sessionIdContext` take precedence over that fallback, but several entry points
still ran without a context and each `Config` construction or rotation could
replace the fallback.

The remaining failures have three ownership classes:

- Live or persisted-session work belongs to the target session.
- Workspace discovery belongs to its dedicated workspace discovery Config.
- Non-interactive OpenAI log housekeeping is process-scoped because jobs are
deduplicated by log directory, not by session.

## Design

All ACP session Config creation, including new, load, resume, and transcript
replay, runs inside `sessionIdContext`. A true new session receives its ID
before Config loading, while the intentionally id-less transcript replay Config
inherits the requested session's existing context. Config construction and
rotation only update the process-wide debug fallback when no session context is
active. The workspace MCP discovery Config receives its own explicit context,
so neither kind of daemon Config can move the single-session fallback.

Generating the ID before Config loading must not change session-management
behavior: the caller-id occupancy check exists to protect caller-chosen IDs
from case-twins, so a daemon-generated fresh UUID is marked as such
(`sessionIdGenerated`) and skips the check — otherwise the id-less creation
hot path would pay two readdirs per session and a transient FS error would
fail closed into a spurious `session_id_conflict`.

MCP budget callbacks and persisted-session delete/rename operations restore the
target session context at callback or dispatch time. Budget notifications keep
the stable ACP-facing session ID in their payload, while debug logging follows
the Config's current ID after a `/clear` rotation. This is required even when
the callback was registered under a context because its eventual invoker may
belong to a shared transport or another async resource. A dead-session ID is
bound only after the existing path-safe session ID validation; arbitrary caller
text must never become a debug-log filename.

Non-interactive housekeeping explicitly exits `sessionIdContext`. Its queue is
process-scoped and may be shared by sessions that resolve to the same log
directory, so assigning it to the first or latest session would both be wrong.
With daemon Configs prevented from replacing the fallback, process-scoped logs
remain in the bootstrap log.

The latest-log alias remains best-effort. After calling the existing
best-effort `updateSymlink`, the debug logger verifies the link's target and
clears its dedup marker only when the latest scheduled update failed. This lets
the next write for that session retry without changing the shared symlink API,
while preserving serialized cross-session updates. Retries are bounded: after a
few consecutive failures the marker stays sticky (one attempt per session
change, the pre-retry behavior), so hosts where symlinks never succeed — e.g.
Windows without symlink privilege — do not re-run a doomed unlink/symlink
cycle on every debug line. A single success resets the streak.

## Non-goals

- Changing session management behavior beyond debug-log ownership.
- Making debug-log writes or alias updates durable.
- Replacing the single-session CLI fallback.
135 changes: 126 additions & 9 deletions packages/cli/src/acp-integration/acpAgent.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -3678,7 +3678,12 @@ describe('QwenAgent MCP SSE/HTTP support', () => {
});

it('forwards a caller-supplied sessionId from _meta to loadCliConfig', async () => {
await setupSessionMocks('meta-session');
const innerConfig = await setupSessionMocks('meta-session');
let configLoadSessionContext: string | undefined;
vi.mocked(loadCliConfig).mockImplementation(async () => {
configLoadSessionContext = sessionIdContext.getStore();
return innerConfig as unknown as Config;
});
const { agent, agentPromise } = await bootAcpAgent();

await agent.newSession({
Expand All @@ -3691,6 +3696,12 @@ describe('QwenAgent MCP SSE/HTTP support', () => {
expect(argv).toMatchObject({
sessionId: '550e8400-e29b-41d4-a716-446655440000',
});
// Caller-supplied ids keep the occupancy check: the generated-id skip
// must not be set for them.
expect(argv.sessionIdGenerated).toBeUndefined();
expect(configLoadSessionContext).toBe(
'550e8400-e29b-41d4-a716-446655440000',
);
// Index 8 is `throwOnSessionIdConflict`: it must be true so a duplicate
// caller-supplied id throws (mapped to a RequestError) instead of
// process.exit(1)-ing the shared ACP child.
Expand All @@ -3700,6 +3711,30 @@ describe('QwenAgent MCP SSE/HTTP support', () => {
await agentPromise;
});

it('generates and binds a sessionId before loading a new Config', async () => {
const innerConfig = await setupSessionMocks('generated-session');
let configLoadSessionContext: string | undefined;
vi.mocked(loadCliConfig).mockImplementation(async () => {
configLoadSessionContext = sessionIdContext.getStore();
return innerConfig as unknown as Config;
});
const { agent, agentPromise } = await bootAcpAgent();

await agent.newSession({ cwd: '/tmp', mcpServers: [] });

const argv = vi.mocked(loadCliConfig).mock.calls[0]![1];
expect(argv.sessionId).toMatch(
/^[0-9a-f]{8}-[0-9a-f]{4}-4[0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}$/,
);
// A daemon-generated fresh UUID must skip the caller-id occupancy check
// (readdir cost + fail-closed policy don't apply to it).
expect(argv.sessionIdGenerated).toBe(true);
expect(configLoadSessionContext).toBe(argv.sessionId);

mockConnectionState.resolve();
await agentPromise;
});

it('rejects invalid sessionId meta before settings access without closing the child', async () => {
await setupSessionMocks('meta-session');
const { agent, agentPromise } = await bootAcpAgent();
Expand Down Expand Up @@ -13176,9 +13211,11 @@ describe('QwenAgent MCP SSE/HTTP support', () => {
...makeInnerConfig(),
enableFileCheckpointing: vi.fn(),
};
vi.mocked(loadCliConfig).mockResolvedValue(
transcriptConfig as unknown as Config,
);
let transcriptConfigContext: string | undefined;
vi.mocked(loadCliConfig).mockImplementation(async () => {
transcriptConfigContext = sessionIdContext.getStore();
return transcriptConfig as unknown as Config;
});
const readPage = vi.fn().mockResolvedValue({
sessionId: VALID_SESSION_ID,
records: [{ uuid: 'u1' }],
Expand Down Expand Up @@ -13282,6 +13319,7 @@ describe('QwenAgent MCP SSE/HTTP support', () => {
.mock.calls.at(-1)?.[1] as CliArgs | undefined;
expect(transcriptConfigArgv?.sessionId).toBeUndefined();
expect(transcriptConfigArgv?.resume).toBeUndefined();
expect(transcriptConfigContext).toBe(VALID_SESSION_ID);
expect(transcriptConfig.enableFileCheckpointing).not.toHaveBeenCalled();
expect(transcriptConfig.initialize).toHaveBeenCalledWith({
sendSdkMcpMessage: expect.any(Function),
Expand Down Expand Up @@ -16322,6 +16360,7 @@ describe('QwenAgent MCP SSE/HTTP support', () => {
// it inside `createToolRegistry` to the freshly-constructed manager.
it('newSession wires Config.setMcpBudgetEventCallback BEFORE initialize() (codex fix #2)', async () => {
const sessionId = 'session-budget-events';
const rotatedDebugSessionId = 'session-budget-events-after-clear';
const innerConfig = await setupSessionMocks(sessionId);
// Stub `setMcpBudgetEventCallback` on the inner Config. The
// production path delegates the manager apply to Config; the test
Expand Down Expand Up @@ -16356,7 +16395,10 @@ describe('QwenAgent MCP SSE/HTTP support', () => {
// Spy connection: only `extNotification` is exercised here, but
// the AgentSideConnection contract is wide. Stubbing only what the
// PR 14b code path touches keeps the test focused.
const extNotification = vi.fn().mockResolvedValue(undefined);
const notificationContexts: Array<string | undefined> = [];
const extNotification = vi.fn().mockImplementation(async () => {
notificationContexts.push(sessionIdContext.getStore());
});
const fakeConn = {
get closed() {
return mockConnectionState.promise;
Expand All @@ -16368,6 +16410,7 @@ describe('QwenAgent MCP SSE/HTTP support', () => {
) as AgentLike;

await agent.newSession({ cwd: '/tmp', mcpServers: [] });
innerConfig.getSessionId.mockReturnValue(rotatedDebugSessionId);

// Strict ordering invariant — codex review fix #2.
expect(callOrder).toEqual(['setMcpBudgetEventCallback', 'initialize']);
Expand All @@ -16386,6 +16429,7 @@ describe('QwenAgent MCP SSE/HTTP support', () => {
};
capturedCallback!(warningEvent);

expect(notificationContexts).toEqual([rotatedDebugSessionId]);
expect(extNotification).toHaveBeenCalledTimes(1);
expect(extNotification).toHaveBeenCalledWith(
'qwen/notify/session/mcp-budget-event',
Expand Down Expand Up @@ -16419,6 +16463,10 @@ describe('QwenAgent MCP SSE/HTTP support', () => {
...refusedEvent,
},
);
expect(notificationContexts).toEqual([
rotatedDebugSessionId,
rotatedDebugSessionId,
]);

mockConnectionState.resolve();
await agentPromise;
Expand Down Expand Up @@ -17033,6 +17081,25 @@ describe('QwenAgent extMethod renameSession routing', () => {
return { agent, agentPromise };
}

it('does not bind an unvalidated dead session id to debug context', async () => {
const innerConfig = makeLiveSessionInnerConfig(null);
const { agent, agentPromise } = await bootAgent(innerConfig);
const runSpy = vi.spyOn(sessionIdContext, 'run');

try {
await expect(
agent.extMethod(SERVE_CONTROL_EXT_METHODS.sessionRecap, {
sessionId: '../../escape',
}),
).rejects.toThrow();
expect(runSpy).not.toHaveBeenCalled();
} finally {
runSpy.mockRestore();
mockConnectionState.resolve();
await agentPromise;
}
});

it('routes through ChatRecordingService.recordCustomTitle when the target session is live', async () => {
const recording = makeRecordingService();
const innerConfig = makeLiveSessionInnerConfig(recording);
Expand Down Expand Up @@ -17155,7 +17222,11 @@ describe('QwenAgent extMethod renameSession routing', () => {

await agent.newSession({ cwd: '/tmp', mcpServers: [] });

const renameSpy = vi.fn().mockResolvedValue(true);
let renameContext: string | undefined;
const renameSpy = vi.fn().mockImplementation(async () => {
renameContext = sessionIdContext.getStore();
return true;
});
vi.mocked(SessionService).mockImplementation(
() =>
({
Expand All @@ -17172,6 +17243,7 @@ describe('QwenAgent extMethod renameSession routing', () => {

expect(SessionService).toHaveBeenCalledWith('/tmp');
expect(renameSpy).toHaveBeenCalledWith(deadSessionId, 'Renamed Offline');
expect(renameContext).toBe(deadSessionId);
// The live recording belongs to a *different* sessionId; it must
// be left untouched, otherwise we'd corrupt an unrelated session's
// title cache.
Expand All @@ -17184,13 +17256,20 @@ describe('QwenAgent extMethod renameSession routing', () => {

it('fires SessionDelete after an offline session is removed', async () => {
const innerConfig = makeLiveSessionInnerConfig(null);
const sessionDeleteHook = vi.fn().mockResolvedValue(undefined);
let deleteHookContext: string | undefined;
const sessionDeleteHook = vi.fn().mockImplementation(async () => {
deleteHookContext = sessionIdContext.getStore();
});
mockConfig.getHookSystem = vi.fn().mockReturnValue({
fireSessionDeleteEvent: sessionDeleteHook,
});
const { agent, agentPromise } = await bootAgent(innerConfig);

const removeSession = vi.fn().mockResolvedValue(true);
let removeSessionContext: string | undefined;
const removeSession = vi.fn().mockImplementation(async () => {
removeSessionContext = sessionIdContext.getStore();
return true;
});
vi.mocked(SessionService).mockImplementation(
() =>
({ removeSession }) as unknown as InstanceType<typeof SessionService>,
Expand All @@ -17205,9 +17284,11 @@ describe('QwenAgent extMethod renameSession routing', () => {
).resolves.toEqual({ success: true });

expect(removeSession).toHaveBeenCalledWith(deletedSessionId);
expect(removeSessionContext).toBe(deletedSessionId);
await vi.waitFor(() =>
expect(sessionDeleteHook).toHaveBeenCalledWith(deletedSessionId),
);
expect(deleteHookContext).toBe(deletedSessionId);

mockConnectionState.resolve();
await agentPromise;
Expand Down Expand Up @@ -18977,6 +19058,37 @@ describe('QwenAgent loadSession / unstable_resumeSession', () => {
await agentPromise;
});

it.each(['load', 'resume'] as const)(
'%s binds sessionIdContext while loading the Config',
async (action) => {
const innerConfig = bindRestoreMocks({ sessionExists: true });
let configLoadSessionContext: string | undefined;
vi.mocked(loadCliConfig).mockImplementationOnce(async () => {
configLoadSessionContext = sessionIdContext.getStore();
return innerConfig as unknown as Config;
});
const { agent, agentPromise } = await spawnAgent();

try {
const params = {
cwd: '/tmp',
sessionId: 'persisted-1',
mcpServers: [],
};
if (action === 'load') {
await agent.loadSession(params);
} else {
await agent.unstable_resumeSession(params);
}

expect(configLoadSessionContext).toBe('persisted-1');
} finally {
mockConnectionState.resolve();
await agentPromise;
}
},
);

it.each(['load', 'resume'] as const)(
'%s rejects a standalone restore without a trusted daemon parent',
async (action) => {
Expand Down Expand Up @@ -21952,7 +22064,11 @@ describe('QwenAgent extMethod runtime MCP add/remove (T2.8)', () => {
getUserHooks: vi.fn().mockReturnValue({}),
getProjectHooks: vi.fn().mockReturnValue({}),
} as unknown as LoadedSettings);
vi.mocked(loadCliConfig).mockResolvedValue(discoveryConfig);
let discoveryConfigSessionContext: string | undefined;
vi.mocked(loadCliConfig).mockImplementation(async () => {
discoveryConfigSessionContext = sessionIdContext.getStore();
return discoveryConfig;
});
mockConfig.getMcpServers = vi
.fn()
.mockReturnValue({ runtime: runtimeServer });
Expand Down Expand Up @@ -21985,6 +22101,7 @@ describe('QwenAgent extMethod runtime MCP add/remove (T2.8)', () => {
discoveryManager.discoverAllMcpToolsIncremental,
).toHaveBeenCalledWith(discoveryConfig),
);
expect(discoveryConfigSessionContext).toBe('workspace-mcp-discovery');
expect(mockConfig.reinitializeMcpServers).not.toHaveBeenCalled();

const persistedServer = {
Expand Down
Loading
Loading