diff --git a/config/vitest/vitest.server.config.ts b/config/vitest/vitest.server.config.ts index fcfe860e4..a603c9ab2 100644 --- a/config/vitest/vitest.server.config.ts +++ b/config/vitest/vitest.server.config.ts @@ -24,6 +24,7 @@ export default defineConfig({ test: { environment: 'node', globalSetup: ['./test/setup/server-global-setup.ts'], + setupFiles: ['./test/setup/server.ts'], include: [ 'test/server/**/*.test.ts', 'test/unit/server/**/*.test.ts', @@ -48,6 +49,9 @@ export default defineConfig({ threads: { singleThread: false, isolate: true, + // node:sqlite emits a one-time ExperimentalWarning on first load. That is + // runtime infrastructure noise, not test output, so silence it in workers. + execArgv: ['--disable-warning=ExperimentalWarning'], }, }, fileParallelism: true, diff --git a/server/bootstrap.ts b/server/bootstrap.ts index e7db9e2da..6ebb9abae 100644 --- a/server/bootstrap.ts +++ b/server/bootstrap.ts @@ -378,17 +378,30 @@ export function resolveProjectRoot(): string { } // --- Auto-run on import --- -const projectRoot = resolveProjectRoot() -const envPath = path.join(projectRoot, '.env') - -const result = ensureEnvFile(envPath) - -if (result.action === 'created') { - console.log(`[bootstrap] Created .env with auto-generated AUTH_TOKEN`) - console.log(`[bootstrap] Token: ${result.token?.slice(0, 8)}...${result.token?.slice(-8)}`) -} else if (result.action === 'patched') { - console.log(`[bootstrap] Patched .env with new AUTH_TOKEN`) - console.log(`[bootstrap] Token: ${result.token?.slice(0, 8)}...${result.token?.slice(-8)}`) -} else if (result.action === 'error') { - console.error(`[bootstrap] Failed to ensure .env: ${result.error}`) +// Only run when this process was launched as the server entry (server/index.ts +// in dev, dist/server/index.js in production, including the compiled server a +// test spawns). When the module is merely imported for its exports — e.g. a unit +// test, or network-manager pulling in detectLanIps — the import must not mutate +// the real project .env or emit first-run setup output. A plain VITEST check is +// insufficient: a test-spawned real server inherits VITEST yet must bootstrap. +function isRunningAsServerEntry(): boolean { + const entry = process.argv[1] ?? '' + return /(^|[\\/])(dist[\\/])?server[\\/]index\.(js|ts)$/.test(entry) +} + +if (isRunningAsServerEntry()) { + const projectRoot = resolveProjectRoot() + const envPath = path.join(projectRoot, '.env') + + const result = ensureEnvFile(envPath) + + if (result.action === 'created') { + console.log(`[bootstrap] Created .env with auto-generated AUTH_TOKEN`) + console.log(`[bootstrap] Token: ${result.token?.slice(0, 8)}...${result.token?.slice(-8)}`) + } else if (result.action === 'patched') { + console.log(`[bootstrap] Patched .env with new AUTH_TOKEN`) + console.log(`[bootstrap] Token: ${result.token?.slice(0, 8)}...${result.token?.slice(-8)}`) + } else if (result.action === 'error') { + console.error(`[bootstrap] Failed to ensure .env: ${result.error}`) + } } diff --git a/server/logger.ts b/server/logger.ts index 8b8952f04..27376450a 100644 --- a/server/logger.ts +++ b/server/logger.ts @@ -6,6 +6,7 @@ import { createRequire } from 'module' import pino, { type DestinationStream, type LevelWithSilent } from 'pino' import { createStream, type RotatingFileStream } from 'rotating-file-stream' import { getFreshellHomeDir } from './freshell-home.js' +import { createConsoleCaptureStream } from './test-log-capture.js' const env = process.env.NODE_ENV || 'development' const level = process.env.LOG_LEVEL || 'debug' @@ -249,6 +250,7 @@ function createConsoleStream(shouldPrettyPrint: boolean): DestinationStream { return pretty } + export function attachDebugStreamWarnings( stream: RotatingFileStream, consoleLogger: pino.Logger, @@ -270,7 +272,9 @@ export function createLogger(destination?: DestinationStream) { } const shouldPrettyPrint = env !== 'production' && env !== 'test' - const consoleStream = createConsoleStream(shouldPrettyPrint) + const consoleStream = isTestRuntime(process.env) + ? createConsoleCaptureStream() + : createConsoleStream(shouldPrettyPrint) const consoleLogger = pino(createPinoOptions({ level: DEFAULT_CONSOLE_LOG_LEVEL }), consoleStream) const consoleDiagnosticLogger = pino(createPinoOptions({ level: 'warn' }), consoleStream) const streams: Array<{ stream: DestinationStream; level: LevelWithSilent }> = [ diff --git a/server/test-log-capture.ts b/server/test-log-capture.ts new file mode 100644 index 000000000..13edd18b4 --- /dev/null +++ b/server/test-log-capture.ts @@ -0,0 +1,61 @@ +import { Writable } from 'node:stream' +import type { DestinationStream } from 'pino' + +// Standalone, dependency-light capture buffer for the shared logger's +// console-bound output under test. It is kept separate from logger.ts (and its +// heavy transitive imports such as freshell-home) so the server test setup can +// read captured records WITHOUT importing the logger graph — importing that +// graph at setup-eval time defeats per-test module mocks (e.g. vi.mock('os')). + +export interface CapturedLogRecord { + level: number + severity: string + msg?: string + raw: string +} + +let capturedConsoleLogRecords: CapturedLogRecord[] = [] + +export function getCapturedConsoleLogRecords(): readonly CapturedLogRecord[] { + return capturedConsoleLogRecords +} + +export function resetCapturedConsoleLogRecords(): void { + capturedConsoleLogRecords = [] +} + +/** + * Assert-and-consume the expected server error/warn logs a test deliberately + * triggers: returns the matching records and removes them from the buffer so the + * server test harness's afterEach only fails on output the test did NOT expect. + */ +export function consumeCapturedLogRecords( + predicate: (record: CapturedLogRecord) => boolean, +): CapturedLogRecord[] { + const matched = capturedConsoleLogRecords.filter(predicate) + capturedConsoleLogRecords = capturedConsoleLogRecords.filter((record) => !predicate(record)) + return matched +} + +export function createConsoleCaptureStream(): DestinationStream { + return new Writable({ + write(chunk, _encoding, callback) { + const raw = chunk.toString() + for (const line of raw.split('\n')) { + if (!line.trim()) continue + try { + const parsed = JSON.parse(line) as { level?: number; severity?: string; msg?: string } + capturedConsoleLogRecords.push({ + level: parsed.level ?? 0, + severity: parsed.severity ?? 'unknown', + msg: parsed.msg, + raw: line, + }) + } catch { + capturedConsoleLogRecords.push({ level: 0, severity: 'unparsed', raw: line }) + } + } + callback() + }, + }) as unknown as DestinationStream +} diff --git a/test/e2e/codex-refresh-rehydrate-flow.test.tsx b/test/e2e/codex-refresh-rehydrate-flow.test.tsx index 0a104ab6c..cafe79266 100644 --- a/test/e2e/codex-refresh-rehydrate-flow.test.tsx +++ b/test/e2e/codex-refresh-rehydrate-flow.test.tsx @@ -657,25 +657,37 @@ describe('codex refresh rehydrate flow (e2e)', () => { const baselineMessages = sentMessages().length - act(() => { - wsHarness.emit({ - type: 'error', - code: 'INVALID_TERMINAL_ID', - message: 'Unknown terminalId', - terminalId: 'term-codex-live-only', + // The live-only recovery path intentionally logs a restore_unavailable notice. + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => undefined) + try { + act(() => { + wsHarness.emit({ + type: 'error', + code: 'INVALID_TERMINAL_ID', + message: 'Unknown terminalId', + terminalId: 'term-codex-live-only', + }) }) - }) - await waitFor(() => { - const recreated = sentMessages().slice(baselineMessages).find((msg) => msg?.type === 'terminal.create') - expect(recreated).toMatchObject({ - type: 'terminal.create', - mode: 'codex', - recoveryIntent: 'fresh_after_restore_unavailable', + await waitFor(() => { + const recreated = sentMessages().slice(baselineMessages).find((msg) => msg?.type === 'terminal.create') + expect(recreated).toMatchObject({ + type: 'terminal.create', + mode: 'codex', + recoveryIntent: 'fresh_after_restore_unavailable', + }) + expect(recreated?.restore).toBeUndefined() + expect(recreated?.sessionRef).toBeUndefined() + expect(recreated?.codexDurability).toBeUndefined() }) - expect(recreated?.restore).toBeUndefined() - expect(recreated?.sessionRef).toBeUndefined() - expect(recreated?.codexDurability).toBeUndefined() - }) + + expect(warnSpy).toHaveBeenCalledWith( + expect.stringContaining('[TerminalView]'), + 'restore_unavailable', + expect.anything(), + ) + } finally { + warnSpy.mockRestore() + } }) }) diff --git a/test/e2e/open-tab-session-sidebar-visibility.test.tsx b/test/e2e/open-tab-session-sidebar-visibility.test.tsx index 12c4a452a..adbaed850 100644 --- a/test/e2e/open-tab-session-sidebar-visibility.test.tsx +++ b/test/e2e/open-tab-session-sidebar-visibility.test.tsx @@ -109,16 +109,20 @@ vi.mock('@/lib/ws-client', () => ({ }), })) -vi.mock('@/lib/api', () => ({ - api: { - get: (url: string) => apiGet(url), - patch: vi.fn().mockResolvedValue({}), - post: vi.fn().mockResolvedValue({}), - }, - fetchSidebarSessionsSnapshot: (options?: unknown) => fetchSidebarSessionsSnapshot(options), - searchSessions: (...args: any[]) => searchSessions(...args), - isApiUnauthorizedError: (err: any) => !!err && typeof err === 'object' && err.status === 401, -})) +vi.mock('@/lib/api', async (importActual) => { + const actual = await importActual() + return { + ...actual, + api: { + get: (url: string) => apiGet(url), + patch: vi.fn().mockResolvedValue({}), + post: vi.fn().mockResolvedValue({}), + }, + fetchSidebarSessionsSnapshot: (options?: unknown) => fetchSidebarSessionsSnapshot(options), + searchSessions: (...args: any[]) => searchSessions(...args), + isApiUnauthorizedError: (err: any) => !!err && typeof err === 'object' && err.status === 401, + } +}) function broadcastWs(msg: any) { for (const handler of Array.from(wsHandlers)) { @@ -445,35 +449,43 @@ describe('open tab session sidebar visibility (e2e)', () => { const store = createStore() - render( - - - , - ) + // The first bootstrap and sidebar loads fail transiently; the app logs the + // contained failure and recovers on the websocket `ready` refetch. + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => undefined) + try { + render( + + + , + ) - await waitFor(() => { - expect(apiGet).toHaveBeenCalledWith('/api/bootstrap') - }) + await waitFor(() => { + expect(apiGet).toHaveBeenCalledWith('/api/bootstrap') + }) - act(() => { - wsMocks.isReady = true - wsMocks.serverInstanceId = 'srv-recovered' - broadcastWs({ - type: 'ready', - timestamp: new Date().toISOString(), - serverInstanceId: 'srv-recovered', + act(() => { + wsMocks.isReady = true + wsMocks.serverInstanceId = 'srv-recovered' + broadcastWs({ + type: 'ready', + timestamp: new Date().toISOString(), + serverInstanceId: 'srv-recovered', + }) }) - }) - await waitFor(() => { - expect(store.getState().connection.availableClis).toEqual({ claude: true, codex: true }) - expect(store.getState().settings.settings.sidebar.excludeFirstChatSubstrings).toEqual(['__AUTO__']) - expect(screen.queryByText('Hidden Auto Session')).not.toBeInTheDocument() - expect(screen.getAllByText('Visible Manual Session').length).toBeGreaterThan(0) - }) + await waitFor(() => { + expect(store.getState().connection.availableClis).toEqual({ claude: true, codex: true }) + expect(store.getState().settings.settings.sidebar.excludeFirstChatSubstrings).toEqual(['__AUTO__']) + expect(screen.queryByText('Hidden Auto Session')).not.toBeInTheDocument() + expect(screen.getAllByText('Visible Manual Session').length).toBeGreaterThan(0) + }) - expect(bootstrapCalls).toBe(2) - expect(sidebarCalls).toBe(2) + expect(bootstrapCalls).toBe(2) + expect(sidebarCalls).toBe(2) + expect(warnSpy).toHaveBeenCalledWith('[App]', 'Failed to load bootstrap data', expect.anything()) + } finally { + warnSpy.mockRestore() + } }) it('ignores legacy sessions.updated websocket pushes because the sidebar window is HTTP-owned', async () => { diff --git a/test/integration/server/api-edge-cases.test.ts b/test/integration/server/api-edge-cases.test.ts index eaccfadf0..e389a8c73 100644 --- a/test/integration/server/api-edge-cases.test.ts +++ b/test/integration/server/api-edge-cases.test.ts @@ -5,6 +5,7 @@ import request from 'supertest' import fsp from 'fs/promises' import path from 'path' import os from 'os' +import { consumeCapturedLogRecords } from '../../../server/test-log-capture.js' // Use vi.hoisted to ensure mockState is available before vi.mock runs const mockState = vi.hoisted(() => ({ @@ -1132,6 +1133,7 @@ describe('API Edge Cases - Security Testing', () => { // Should fall back to defaults expect(settings).toEqual(defaultSettings) + expect(consumeCapturedLogRecords((r) => r.msg === 'Config file parse failed; falling back to defaults')).toHaveLength(1) }) it('recovers from config with wrong version', async () => { @@ -1146,6 +1148,7 @@ describe('API Edge Cases - Security Testing', () => { const settings = await newStore.getSettings() expect(settings).toEqual(defaultSettings) + expect(consumeCapturedLogRecords((r) => r.msg === 'Config file version mismatch; falling back to defaults')).toHaveLength(1) }) it('handles missing .freshell directory', async () => { diff --git a/test/integration/server/lan-info-api.test.ts b/test/integration/server/lan-info-api.test.ts index 4cbb37a9e..1a2ecd466 100644 --- a/test/integration/server/lan-info-api.test.ts +++ b/test/integration/server/lan-info-api.test.ts @@ -3,6 +3,7 @@ import { describe, it, expect, beforeEach, afterEach, vi } from 'vitest' import express, { type Express } from 'express' import request from 'supertest' import { createNetworkRouter } from '../../../server/network-router.js' +import { consumeCapturedLogRecords } from '../../../server/test-log-capture.js' const TEST_AUTH_TOKEN = 'test-auth-token-12345678' @@ -124,6 +125,9 @@ describe('LAN Info API', () => { expect(res.status).toBe(500) expect(res.body).toEqual({ error: 'Failed to get LAN info' }) + expect( + consumeCapturedLogRecords((r) => r.msg === 'Failed to get LAN info'), + ).toHaveLength(1) }) }) }) diff --git a/test/integration/server/network-api.test.ts b/test/integration/server/network-api.test.ts index 7d608d63a..3c494cce0 100644 --- a/test/integration/server/network-api.test.ts +++ b/test/integration/server/network-api.test.ts @@ -17,6 +17,7 @@ import { ConfigStore } from '../../../server/config-store.js' import { httpAuthMiddleware } from '../../../server/auth.js' import { detectFirewall } from '../../../server/firewall.js' import * as wslModule from '../../../server/wsl-port-forward.js' +import { consumeCapturedLogRecords } from '../../../server/test-log-capture.js' // Mock firewall detection to avoid real system calls vi.mock('../../../server/firewall.js', async () => { @@ -1406,6 +1407,9 @@ describe('Network API integration', () => { expect(startedRes.body).toEqual({ method: 'wsl2', status: 'started' }) await waitForFirewallRepairSettled() + expect( + consumeCapturedLogRecords((r) => r.msg === 'WSL2 port forwarding failed').length, + ).toBeGreaterThanOrEqual(1) }) it('returns 409 in-progress for fresh and confirmed requests while a prior elevated repair is still running', async () => { @@ -1492,6 +1496,9 @@ describe('Network API integration', () => { finishRepair?.() await waitForFirewallRepairSettled() + expect( + consumeCapturedLogRecords((r) => r.msg === 'WSL2 port forwarding failed').length, + ).toBeGreaterThanOrEqual(1) }) }) @@ -1800,6 +1807,10 @@ describe('Network API integration', () => { expect(statusRes.body.remoteAccessEnabled).toBe(true) expect(statusRes.body.remoteAccessRequested).toBe(true) expect(statusRes.body.accessUrl).toContain('192.168.1.100') + + expect( + consumeCapturedLogRecords((r) => r.msg === 'WSL2 remote access teardown failed').length, + ).toBeGreaterThanOrEqual(1) }) it('releases the confirmed repair lock when the confirmed noop disable save fails', async () => { @@ -1871,6 +1882,12 @@ describe('Network API integration', () => { expect(followUpRes.status).toBe(200) expect(followUpRes.body).toEqual({ method: 'none', message: 'Remote access disabled' }) + + expect( + consumeCapturedLogRecords( + (r) => r.msg === 'Failed to persist confirmed remote access disable settings', + ), + ).toHaveLength(1) }) it('returns 409 in-progress for disable requests while a confirmed WSL repair is still running', async () => { @@ -1938,6 +1955,9 @@ describe('Network API integration', () => { finishRepair?.() await waitForFirewallRepairSettled() + expect( + consumeCapturedLogRecords((r) => r.msg === 'WSL2 port forwarding failed').length, + ).toBeGreaterThanOrEqual(1) }) it('returns the teardown probe failure instead of treating it as a successful noop', async () => { diff --git a/test/setup/console-trap.ts b/test/setup/console-trap.ts new file mode 100644 index 000000000..681f320bc --- /dev/null +++ b/test/setup/console-trap.ts @@ -0,0 +1,82 @@ +import { vi } from 'vitest' + +// Shared console trap used by both the client (jsdom) and server (node) test +// setups. A test that deliberately exercises an error/warning path must capture +// that output (spy on the console method and assert on it) rather than let it +// leak. Any console.error or console.warn a test does not capture fails that +// test — unexpected console noise is a bug. A test that legitimately cannot spy +// can opt out for a single test by setting __ALLOW_CONSOLE_ERROR__ / +// __ALLOW_CONSOLE_WARN__ to true; the flag resets after each test. + +type ConsoleMethod = 'error' | 'warn' + +interface ConsoleTrap { + method: ConsoleMethod + allowFlag: '__ALLOW_CONSOLE_ERROR__' | '__ALLOW_CONSOLE_WARN__' + spy: ReturnType | null + calls: Array<{ args: unknown[]; stack?: string }> + hasCapturedStack: boolean +} + +// Output that is environmental noise rather than app output, so it never +// signals an app bug: Redux Toolkit's dev-only invariant middleware warns when a +// check exceeds a wall-clock threshold, which is machine-load dependent. +const IGNORED_OUTPUT_PATTERNS = [ + / took \d+ms, which is more than the warning threshold/, +] + +function isIgnoredOutput(args: unknown[]): boolean { + const rendered = args.map(String).join(' ') + return IGNORED_OUTPUT_PATTERNS.some((pattern) => pattern.test(rendered)) +} + +export interface InstalledConsoleTraps { + /** Restore the spies and return a failure message per unexpected method. */ + collectFailures(): string[] +} + +export function installConsoleTraps(): InstalledConsoleTraps { + const traps: ConsoleTrap[] = [ + { method: 'error', allowFlag: '__ALLOW_CONSOLE_ERROR__', spy: null, calls: [], hasCapturedStack: false }, + { method: 'warn', allowFlag: '__ALLOW_CONSOLE_WARN__', spy: null, calls: [], hasCapturedStack: false }, + ] + + for (const trap of traps) { + const impl = (...args: unknown[]) => { + // Capturing stacks for every call can be expensive; keep the first one for debugging. + let stack: string | undefined + if (!trap.hasCapturedStack) { + trap.hasCapturedStack = true + const err = new Error(`console.${trap.method} captured`) + // Exclude this helper from the captured stack for better signal. + // eslint-disable-next-line @typescript-eslint/no-explicit-any + ;(Error as any).captureStackTrace?.(err, impl) + stack = err.stack + } + trap.calls.push({ args, stack }) + } + trap.spy = vi.spyOn(console, trap.method).mockImplementation(impl) + } + + return { + collectFailures(): string[] { + const failures: string[] = [] + for (const trap of traps) { + trap.spy?.mockRestore() + trap.spy = null + + const allow = (globalThis as any)[trap.allowFlag] === true + ;(globalThis as any)[trap.allowFlag] = false + + const relevant = trap.calls.filter((call) => !isIgnoredOutput(call.args)) + if (!allow && relevant.length > 0) { + const first = relevant[0] + const rendered = first?.args?.map(String).join(' ') ?? '' + const stack = first?.stack ? `\n${first.stack}` : '' + failures.push(`Unexpected console.${trap.method}: ${rendered}${stack}`) + } + } + return failures + }, + } +} diff --git a/test/setup/dom.ts b/test/setup/dom.ts index 9afbf653f..d1fe6f7ce 100644 --- a/test/setup/dom.ts +++ b/test/setup/dom.ts @@ -2,6 +2,7 @@ import '@testing-library/jest-dom/vitest' import { afterEach, beforeEach, vi } from 'vitest' import { enableMapSet } from 'immer' import { resetWsClientForTests } from '@/lib/ws-client' +import { installConsoleTraps } from './console-trap' enableMapSet() @@ -98,42 +99,20 @@ beforeEach(() => { }) // ── end matchMedia polyfill ───────────────────────────────────────── -let errorSpy: ReturnType | null = null -let consoleErrorCalls: Array<{ args: unknown[]; stack?: string }> = [] -let hasCapturedErrorStack = false +let installedConsoleTraps: ReturnType | null = null beforeEach(() => { - consoleErrorCalls = [] - hasCapturedErrorStack = false - const impl = (...args: unknown[]) => { - // Capturing stacks for every console.error can be expensive; keep the first one for debugging. - let stack: string | undefined - if (!hasCapturedErrorStack) { - hasCapturedErrorStack = true - const err = new Error('console.error captured') - // Exclude this helper from the captured stack for better signal. - // eslint-disable-next-line @typescript-eslint/no-explicit-any - ;(Error as any).captureStackTrace?.(err, impl) - stack = err.stack - } - consoleErrorCalls.push({ args, stack }) - } - errorSpy = vi.spyOn(console, 'error').mockImplementation(impl) + installedConsoleTraps = installConsoleTraps() }) afterEach(() => { resetWsClientForTests() - errorSpy?.mockRestore() - errorSpy = null - const allow = (globalThis as any).__ALLOW_CONSOLE_ERROR__ === true - ;(globalThis as any).__ALLOW_CONSOLE_ERROR__ = false + const failures = installedConsoleTraps?.collectFailures() ?? [] + installedConsoleTraps = null - if (!allow && consoleErrorCalls.length > 0) { - const first = consoleErrorCalls[0] - const rendered = first?.args?.map(String).join(' ') ?? '' - const stack = first?.stack ? `\n${first.stack}` : '' - throw new Error(`Unexpected console.error: ${rendered}${stack}`) + if (failures.length > 0) { + throw new Error(failures.join('\n')) } }) diff --git a/test/setup/server.ts b/test/setup/server.ts new file mode 100644 index 000000000..5023fa734 --- /dev/null +++ b/test/setup/server.ts @@ -0,0 +1,51 @@ +import { afterEach, beforeEach } from 'vitest' +import { installConsoleTraps } from './console-trap.js' +import { + getCapturedConsoleLogRecords, + resetCapturedConsoleLogRecords, +} from '../../server/test-log-capture.js' + +// Server-side counterpart of test/setup/dom.ts. The server emits output through +// two channels, and unexpected output on either fails the test: +// 1. Direct console.error / console.warn calls — trapped like the client. +// 2. The shared pino logger, whose console-bound records (error level and +// above) are captured in memory by server/logger.ts under test runtime. +// A test that legitimately logs an error must capture it: assert on the pino +// record (getCapturedConsoleLogRecords) or, for the whole test, opt out by +// setting __ALLOW_CONSOLE_ERROR__ = true (also clears captured error records). + +// Node emits an ExperimentalWarning the first time node:sqlite is loaded. That +// is runtime infrastructure noise, not app output, so filter only that warning. +const originalEmitWarning = process.emitWarning.bind(process) +process.emitWarning = ((warning: string | Error, ...rest: unknown[]) => { + const name = warning instanceof Error ? warning.name : (rest[0] as { type?: string })?.type + const message = warning instanceof Error ? warning.message : String(warning) + if (name === 'ExperimentalWarning' && /SQLite/i.test(message)) return + return (originalEmitWarning as (...args: unknown[]) => void)(warning, ...rest) +}) as typeof process.emitWarning + +let installedConsoleTraps: ReturnType | null = null + +beforeEach(() => { + resetCapturedConsoleLogRecords() + installedConsoleTraps = installConsoleTraps() +}) + +afterEach(() => { + // Read the opt-out before collectFailures(), which consumes and resets it. + const allowError = (globalThis as any).__ALLOW_CONSOLE_ERROR__ === true + + const failures = installedConsoleTraps?.collectFailures() ?? [] + installedConsoleTraps = null + + const leakedLogRecords = getCapturedConsoleLogRecords() + resetCapturedConsoleLogRecords() + if (!allowError && leakedLogRecords.length > 0) { + const first = leakedLogRecords[0] + failures.push(`Unexpected server log (${first.severity}): ${first.msg ?? ''}\n${first.raw}`) + } + + if (failures.length > 0) { + throw new Error(failures.join('\n')) + } +}) diff --git a/test/unit/client/components/App.perf-audit-bootstrap.test.tsx b/test/unit/client/components/App.perf-audit-bootstrap.test.tsx index 32b6866b1..2c98dc6bb 100644 --- a/test/unit/client/components/App.perf-audit-bootstrap.test.tsx +++ b/test/unit/client/components/App.perf-audit-bootstrap.test.tsx @@ -174,6 +174,8 @@ describe('App perf audit milestones', () => { }) it('marks auth-required visibility when the auth modal is shown in perf-audit mode', async () => { + // perf-audit mode emits perf_logging_enabled/toggled telemetry to console.info. + vi.spyOn(console, 'info').mockImplementation(() => {}) render( diff --git a/test/unit/client/components/App.ws-bootstrap.test.tsx b/test/unit/client/components/App.ws-bootstrap.test.tsx index 1f1bcac5c..1165cf9a1 100644 --- a/test/unit/client/components/App.ws-bootstrap.test.tsx +++ b/test/unit/client/components/App.ws-bootstrap.test.tsx @@ -466,6 +466,7 @@ describe('App WS bootstrap recovery', () => { }) it('recovers bootstrap-owned provider availability and sidebar filters after transient pre-ready 503s', async () => { + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}) const recoveredSettings = { ...defaultSettings, sidebar: { @@ -597,6 +598,10 @@ describe('App WS bootstrap recovery', () => { expect(sidebarCalls).toBe(2) expect(wsMocks.send).toHaveBeenCalledWith(expect.objectContaining({ type: 'codex.activity.list' })) expect(wsMocks.send).toHaveBeenCalledWith(expect.objectContaining({ type: 'opencode.activity.list' })) + + // The transient 503s are logged as they are contained and recovered from. + expect(warnSpy).toHaveBeenCalledWith('[App]', 'Failed to load bootstrap data', expect.anything()) + expect(warnSpy).toHaveBeenCalledWith('[App]', 'Failed to load initial sidebar session window', expect.anything()) }) it('repairs missing bootstrap platform capabilities from /api/platform after websocket readiness', async () => { @@ -1969,6 +1974,7 @@ describe('App WS bootstrap recovery', () => { // failure leaked an unhandled rejection that fails the whole test run even though every // test "passed" — the same failure class the terminal.inventory site already contains. const store = createStore() + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}) // Reject every snapshot fetch. The bootstrap sidebar load fails but is contained by // ensureSidebarSessionsWindow (so no window ever commits -> hasCommittedWindow stays @@ -2007,6 +2013,9 @@ describe('App WS bootstrap recovery', () => { (reason) => reason instanceof Error && reason.message.includes('window snapshot unavailable'), ), ).toHaveLength(0) + + // The contained sidebar-window failure is logged rather than leaked. + expect(warnSpy).toHaveBeenCalledWith('[App]', 'Failed to load initial sidebar session window', expect.anything()) } finally { process.off('unhandledRejection', onUnhandled) } diff --git a/test/unit/client/components/SettingsView.editor.test.tsx b/test/unit/client/components/SettingsView.editor.test.tsx index 0a282834c..410c1e680 100644 --- a/test/unit/client/components/SettingsView.editor.test.tsx +++ b/test/unit/client/components/SettingsView.editor.test.tsx @@ -342,6 +342,7 @@ describe('SettingsView Editor pane section', () => { it('rolls back debounced custom command previews when the save fails', async () => { const store = createTestStore({ editor: { externalEditor: 'custom' } }) vi.mocked(api.patch).mockRejectedValueOnce(new Error('save failed')) + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}) render( @@ -361,6 +362,11 @@ describe('SettingsView Editor pane section', () => { }) expect(store.getState().settings.settings.editor?.customEditorCommand).toBeUndefined() + expect(warnSpy).toHaveBeenCalledWith( + expect.stringContaining('[settingsThunks]'), + expect.stringContaining('Failed to save server settings patch'), + expect.anything(), + ) }) it('rolls back pending debounced custom command previews on unmount before save dispatch', async () => { diff --git a/test/unit/client/components/SettingsView.network-access.test.tsx b/test/unit/client/components/SettingsView.network-access.test.tsx index f98a686b7..b751e9125 100644 --- a/test/unit/client/components/SettingsView.network-access.test.tsx +++ b/test/unit/client/components/SettingsView.network-access.test.tsx @@ -317,6 +317,7 @@ describe('SettingsView network access section', () => { }) it('surfaces a visible error when disabling WSL remote access fails', async () => { + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}) const { api } = await import('@/lib/api') vi.mocked(api.post).mockRejectedValueOnce({ status: 500, @@ -345,9 +346,15 @@ describe('SettingsView network access section', () => { expect(screen.getByRole('alert')).toHaveTextContent(/disable failed/i) }) expect(screen.getByRole('switch', { name: /remote access/i })).toBeChecked() + expect(warnSpy).toHaveBeenCalledWith( + expect.stringContaining('[NetworkSettings]'), + expect.stringContaining('Failed to disable remote access'), + expect.anything(), + ) }) it('surfaces a visible error when a direct remote access configure request is rejected', async () => { + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}) const { api } = await import('@/lib/api') vi.mocked(api.post).mockRejectedValueOnce(new Error('Configure failed')) @@ -372,6 +379,11 @@ describe('SettingsView network access section', () => { expect(screen.getByRole('alert')).toHaveTextContent(/configure failed/i) }) expect(screen.getByRole('switch', { name: /remote access/i })).not.toBeChecked() + expect(warnSpy).toHaveBeenCalledWith( + expect.stringContaining('[NetworkSettings]'), + expect.stringContaining('Failed to configure remote access'), + expect.anything(), + ) }) it('shows a visible error when WSL teardown polling finishes but remote access is still enabled', async () => { @@ -469,6 +481,7 @@ describe('SettingsView network access section', () => { it('shows a visible error and performs a final status refresh when WSL teardown polling fails', async () => { vi.useFakeTimers() + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}) const { api } = await import('@/lib/api') vi.mocked(api.post).mockResolvedValueOnce({ method: 'wsl2', status: 'started' }) vi.mocked(api.get) @@ -508,6 +521,11 @@ describe('SettingsView network access section', () => { expect(api.get).toHaveBeenCalledTimes(2) expect(screen.getByRole('alert')).toHaveTextContent(/failed to refresh remote access status/i) expect(screen.getByRole('switch', { name: /remote access/i })).not.toBeChecked() + expect(warnSpy).toHaveBeenCalledWith( + expect.stringContaining('[NetworkSettings]'), + expect.stringContaining('Failed to refresh remote access status'), + expect.anything(), + ) }) it('shows an admin-approval modal before starting Windows firewall repair', async () => { diff --git a/test/unit/client/components/TerminalView.lifecycle.test.tsx b/test/unit/client/components/TerminalView.lifecycle.test.tsx index e4fe93559..b16ca68e7 100644 --- a/test/unit/client/components/TerminalView.lifecycle.test.tsx +++ b/test/unit/client/components/TerminalView.lifecycle.test.tsx @@ -3047,16 +3047,26 @@ describe('TerminalView lifecycle updates', () => { expect(terminalInstances.length).toBeGreaterThan(0) }) - act(() => { - messageHandler!({ - type: 'terminal.input.blocked', - terminalId: 'term-codex', - reason: 'codex_identity_pending', + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => undefined) + try { + act(() => { + messageHandler!({ + type: 'terminal.input.blocked', + terminalId: 'term-codex', + reason: 'codex_identity_pending', + }) }) - }) - const term = terminalInstances[0] - expectTerminalWriteContaining(term, 'Input not sent: Codex is still saving restore state. Try again in a moment.') + const term = terminalInstances[0] + expectTerminalWriteContaining(term, 'Input not sent: Codex is still saving restore state. Try again in a moment.') + expect(warnSpy).toHaveBeenCalledWith( + expect.stringContaining('[TerminalView]'), + 'terminal_input_blocked', + expect.objectContaining({ reason: 'codex_identity_pending' }), + ) + } finally { + warnSpy.mockRestore() + } }) it('shows feedback when Codex input is blocked by lifecycle-loss proof', async () => { @@ -3077,16 +3087,26 @@ describe('TerminalView lifecycle updates', () => { expect(terminalInstances.length).toBeGreaterThan(0) }) - act(() => { - messageHandler!({ - type: 'terminal.input.blocked', - terminalId: 'term-codex', - reason: 'codex_lifecycle_loss_pending', + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => undefined) + try { + act(() => { + messageHandler!({ + type: 'terminal.input.blocked', + terminalId: 'term-codex', + reason: 'codex_lifecycle_loss_pending', + }) }) - }) - const term = terminalInstances[0] - expectTerminalWriteContaining(term, 'Input not sent: Codex is resolving a worker disconnect. Try again in a moment.') + const term = terminalInstances[0] + expectTerminalWriteContaining(term, 'Input not sent: Codex is resolving a worker disconnect. Try again in a moment.') + expect(warnSpy).toHaveBeenCalledWith( + expect.stringContaining('[TerminalView]'), + 'terminal_input_blocked', + expect.objectContaining({ reason: 'codex_lifecycle_loss_pending' }), + ) + } finally { + warnSpy.mockRestore() + } }) it('shows feedback when Codex input is blocked by clean-exit state resolution', async () => { @@ -3107,16 +3127,26 @@ describe('TerminalView lifecycle updates', () => { expect(terminalInstances.length).toBeGreaterThan(0) }) - act(() => { - messageHandler!({ - type: 'terminal.input.blocked', - terminalId: 'term-codex', - reason: 'codex_clean_exit_decision_pending', + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => undefined) + try { + act(() => { + messageHandler!({ + type: 'terminal.input.blocked', + terminalId: 'term-codex', + reason: 'codex_clean_exit_decision_pending', + }) }) - }) - const term = terminalInstances[0] - expectTerminalWriteContaining(term, 'Input not sent: Codex is checking whether the session is still active. Try again in a moment.') + const term = terminalInstances[0] + expectTerminalWriteContaining(term, 'Input not sent: Codex is checking whether the session is still active. Try again in a moment.') + expect(warnSpy).toHaveBeenCalledWith( + expect.stringContaining('[TerminalView]'), + 'terminal_input_blocked', + expect.objectContaining({ reason: 'codex_clean_exit_decision_pending' }), + ) + } finally { + warnSpy.mockRestore() + } }) it('mirrors canonical durable identity to pane and tab on terminal.session.associated', async () => { @@ -3724,6 +3754,17 @@ describe('TerminalView lifecycle updates', () => { }) describe('v2 stream lifecycle', () => { + // Invalid/mismatched stream frames intentionally emit `[TerminalView]` warnings + // as part of the fail-closed behavior these tests exercise. + let streamWarnSpy: ReturnType | null = null + beforeEach(() => { + streamWarnSpy = vi.spyOn(console, 'warn').mockImplementation(() => undefined) + }) + afterEach(() => { + streamWarnSpy?.mockRestore() + streamWarnSpy = null + }) + async function renderTerminalHarness(opts?: { status?: 'creating' | 'running' terminalId?: string diff --git a/test/unit/client/components/TerminalView.resumeSession.test.tsx b/test/unit/client/components/TerminalView.resumeSession.test.tsx index 13ae7ae6c..46cc6a1de 100644 --- a/test/unit/client/components/TerminalView.resumeSession.test.tsx +++ b/test/unit/client/components/TerminalView.resumeSession.test.tsx @@ -561,6 +561,9 @@ describe('TerminalView durable session contract', () => { }) wsMocks.send.mockClear() + // INVALID_TERMINAL_ID with no durable session ref logs a restore_unavailable warning. + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => undefined) + messageHandler?.({ type: 'error', code: 'INVALID_TERMINAL_ID', @@ -611,5 +614,12 @@ describe('TerminalView durable session contract', () => { )) expect(secondFreshCreates).toHaveLength(0) }) + + expect(warnSpy).toHaveBeenCalledWith( + expect.stringContaining('[TerminalView]'), + 'restore_unavailable', + expect.objectContaining({ event: 'restore_unavailable' }), + ) + warnSpy.mockRestore() }) }) diff --git a/test/unit/client/components/component-edge-cases.test.tsx b/test/unit/client/components/component-edge-cases.test.tsx index 049f937ec..83855dc46 100644 --- a/test/unit/client/components/component-edge-cases.test.tsx +++ b/test/unit/client/components/component-edge-cases.test.tsx @@ -769,6 +769,7 @@ describe('Component Edge Cases', () => { describe('SettingsView with pending save', () => { it('handles rapid setting changes without crash', async () => { + vi.spyOn(console, 'warn').mockImplementation(() => {}) mockApiTyped.post.mockResolvedValue({ valid: true }) const store = createTestStore() @@ -875,6 +876,7 @@ describe('Component Edge Cases', () => { describe('SettingsView API error handling', () => { it('handles API patch failure gracefully', async () => { + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}) mockApiTyped.post.mockResolvedValue({ valid: true }) mockApiTyped.patch.mockRejectedValueOnce(new Error('Save failed')) @@ -895,6 +897,11 @@ describe('Component Edge Cases', () => { expect(mockApiTyped.post).toHaveBeenCalledWith('/api/files/validate-dir', { path: '/tmp/save-failure' }) expect(mockApiTyped.patch).toHaveBeenCalledWith('/api/settings', { defaultCwd: '/tmp/save-failure' }) expect(screen.getByText('Settings')).toBeInTheDocument() + expect(warnSpy).toHaveBeenCalledWith( + expect.stringContaining('[settingsThunks]'), + expect.stringContaining('Failed to save server settings patch'), + expect.anything(), + ) }) }) }) diff --git a/test/unit/client/components/panes/PanePicker.test.tsx b/test/unit/client/components/panes/PanePicker.test.tsx index 7560c88fc..53c2c7689 100644 --- a/test/unit/client/components/panes/PanePicker.test.tsx +++ b/test/unit/client/components/panes/PanePicker.test.tsx @@ -354,6 +354,8 @@ describe('PanePicker', () => { }) it('retries loading the extension registry after the connection reaches ready', async () => { + // The first (pre-ready) load rejects and is logged before the ready-triggered retry. + vi.spyOn(console, 'warn').mockImplementation(() => {}) mockApiGet .mockRejectedValueOnce({ status: 503, message: 'Service Unavailable' }) .mockResolvedValueOnce([ diff --git a/test/unit/client/hooks/useElectronExternalLinks.test.tsx b/test/unit/client/hooks/useElectronExternalLinks.test.tsx index 4dcb8f2c2..fdd89797e 100644 --- a/test/unit/client/hooks/useElectronExternalLinks.test.tsx +++ b/test/unit/client/hooks/useElectronExternalLinks.test.tsx @@ -1,3 +1,4 @@ +import type { MouseEvent as ReactMouseEvent } from 'react' import { describe, it, expect, vi, beforeEach, afterEach } from 'vitest' import { render, cleanup } from '@testing-library/react' import { useElectronExternalLinks } from '@/hooks/useElectronExternalLinks' @@ -9,6 +10,13 @@ vi.mock('@/lib/open-url', () => ({ shouldOpenLinkExternally: (event: MouseEvent) => event.ctrlKey || event.shiftKey, })) +// Prevent jsdom from attempting a real (unimplemented) navigation on a click +// the hook intentionally leaves alone. The hook acts in the capture phase, so +// this bubble-phase guard never masks its behavior. +function preventNavigation(event: ReactMouseEvent) { + event.preventDefault() +} + function TestHarness() { useElectronExternalLinks() return link @@ -76,11 +84,13 @@ describe('useElectronExternalLinks', () => { vi.stubGlobal('freshellDesktop', { isElectron: true }) function TestHarnessWithMail() { useElectronExternalLinks() - return email + return email } const { container } = render() const link = container.querySelector('a')! - const clickEvent = new MouseEvent('click', { ctrlKey: true, bubbles: true }) + // cancelable so the anchor's onClick preventDefault actually stops jsdom + // from attempting a real (unimplemented) mailto navigation. + const clickEvent = new MouseEvent('click', { ctrlKey: true, bubbles: true, cancelable: true }) link.dispatchEvent(clickEvent) diff --git a/test/unit/client/lib/client-logger.test.ts b/test/unit/client/lib/client-logger.test.ts index 50d15e634..af30377da 100644 --- a/test/unit/client/lib/client-logger.test.ts +++ b/test/unit/client/lib/client-logger.test.ts @@ -17,6 +17,10 @@ describe('client logger', () => { }) it('forwards console warnings to the server', async () => { + // The logger patches console.warn to forward it; a spy would sit under that + // patch and break the forwarding this test asserts. The raw console.warn IS + // the subject, so opt this test out of the global warn trap instead. + ;(globalThis as any).__ALLOW_CONSOLE_WARN__ = true mockFetch.mockResolvedValueOnce({ ok: true }) const logger = createClientLogger({ @@ -50,6 +54,7 @@ describe('client logger', () => { }) it('does not enqueue perf telemetry payloads for remote transport', async () => { + ;(globalThis as any).__ALLOW_CONSOLE_WARN__ = true mockFetch.mockResolvedValueOnce({ ok: true }) const logger = createClientLogger({ @@ -67,6 +72,7 @@ describe('client logger', () => { }) it('drops duplicate warning entries within the dedupe window', async () => { + ;(globalThis as any).__ALLOW_CONSOLE_WARN__ = true mockFetch.mockResolvedValueOnce({ ok: true }) const logger = createClientLogger({ diff --git a/test/unit/client/lib/console-error-collector.test.ts b/test/unit/client/lib/console-error-collector.test.ts index e29090ec9..d95e67d20 100644 --- a/test/unit/client/lib/console-error-collector.test.ts +++ b/test/unit/client/lib/console-error-collector.test.ts @@ -103,11 +103,18 @@ describe('console error collector (index.html inline script)', () => { }) it('does not capture console.warn or console.log', () => { + // The raw console.warn/console.log calls are the SUBJECT here: the test proves the + // collector ignores them. Opt out of the warn trap so the raw warn reaches the (patched) + // console, and silence the raw log so it doesn't leak to stdout. Neither is captured. + ;(globalThis as any).__ALLOW_CONSOLE_WARN__ = true + const logSpy = vi.spyOn(console, 'log').mockImplementation(() => {}) + console.warn('warning') console.log('info') const errors = (window as any).__consoleErrors expect(errors).toHaveLength(0) + logSpy.mockRestore() }) it('handles Error objects by stringifying them', () => { diff --git a/test/unit/client/lib/fresh-agent-turn-complete.test.ts b/test/unit/client/lib/fresh-agent-turn-complete.test.ts index e9b5d56ef..28f8fca5c 100644 --- a/test/unit/client/lib/fresh-agent-turn-complete.test.ts +++ b/test/unit/client/lib/fresh-agent-turn-complete.test.ts @@ -1,4 +1,4 @@ -import { describe, expect, it } from 'vitest' +import { describe, expect, it, vi } from 'vitest' import { configureStore } from '@reduxjs/toolkit' import freshAgentReducer, { setSessionStatus } from '@/store/freshAgentSlice' import turnCompletionReducer from '@/store/turnCompletionSlice' @@ -106,6 +106,9 @@ describe('server-authoritative fresh-agent turn completion (client)', () => { const store = makeStore() store.dispatch(setSessionStatus({ sessionId: SESSION_ID, sessionType: 'freshopencode', provider: 'opencode', status: 'idle' })) + // Dropping a malformed edge warns; that warning is part of the behavior under test. + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}) + const handled = handleFreshAgentMessage(store.dispatch, { type: 'freshAgent.event', sessionId: SESSION_ID, @@ -125,6 +128,8 @@ describe('server-authoritative fresh-agent turn completion (client)', () => { event: { type: 'freshAgent.turn.complete', sessionId: SESSION_ID, at: Number.NaN } as never, }) expect(store.getState().turnCompletion.pendingEvents).toHaveLength(0) + expect(warnSpy).toHaveBeenCalled() + warnSpy.mockRestore() }) it('ignores a completion for a session that owns no live pane', () => { @@ -209,10 +214,13 @@ describe('server-authoritative fresh-agent waiting edge (client)', () => { it('drops a malformed waiting edge without a numeric at', () => { const store = makeClaudeStore() + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}) handleFreshAgentMessage(store.dispatch, { type: 'freshAgent.event', sessionId: RUNTIME_ID, sessionType: 'freshclaude', provider: 'claude', event: { type: 'freshAgent.turn.waiting', sessionId: RUNTIME_ID }, }) expect(store.getState().turnCompletion.pendingEvents).toHaveLength(0) + expect(warnSpy).toHaveBeenCalled() + warnSpy.mockRestore() }) }) diff --git a/test/unit/client/lib/open-url.test.ts b/test/unit/client/lib/open-url.test.ts index a30b2830d..0c3a8a2e1 100644 --- a/test/unit/client/lib/open-url.test.ts +++ b/test/unit/client/lib/open-url.test.ts @@ -78,10 +78,13 @@ describe('openExternalUrl', () => { }) it('ignores non-string URLs', () => { + const consoleWarnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}) vi.stubGlobal('freshellDesktop', undefined) openExternalUrl(undefined as unknown as string) expect(windowOpenSpy).not.toHaveBeenCalled() + expect(consoleWarnSpy).toHaveBeenCalled() + consoleWarnSpy.mockRestore() }) }) diff --git a/test/unit/client/lib/perf-logger.test.ts b/test/unit/client/lib/perf-logger.test.ts index 1e6674519..32bcbee4c 100644 --- a/test/unit/client/lib/perf-logger.test.ts +++ b/test/unit/client/lib/perf-logger.test.ts @@ -20,16 +20,21 @@ describe('client perf logger config', () => { it('can toggle at runtime', async () => { const { getClientPerfConfig, setClientPerfEnabled } = await loadPerfLoggerModule() + // Toggling perf logging emits a perf_logging_enabled console.info; silence it. + const infoSpy = vi.spyOn(console, 'info').mockImplementation(() => {}) const cfg = getClientPerfConfig() setClientPerfEnabled(true, 'test') expect(cfg.enabled).toBe(true) setClientPerfEnabled(false, 'test') expect(cfg.enabled).toBe(false) + infoSpy.mockRestore() }) it('ignores /api/logs/client resource entries in perf.resource_slow warnings', async () => { const { setClientPerfEnabled } = await loadPerfLoggerModule() const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}) + // Toggling perf logging emits a perf_logging_enabled console.info; silence it. + const infoSpy = vi.spyOn(console, 'info').mockImplementation(() => {}) const originalObserver = (globalThis as { PerformanceObserver?: unknown }).PerformanceObserver const resourceCallbacks: Array<(entries: PerformanceResourceTiming[]) => void> = [] @@ -83,6 +88,7 @@ describe('client perf logger config', () => { setClientPerfEnabled(false, 'test') ;(globalThis as { PerformanceObserver?: unknown }).PerformanceObserver = originalObserver warnSpy.mockRestore() + infoSpy.mockRestore() }) it('logs terminal input-to-first-output latency samples with percentiles', async () => { diff --git a/test/unit/client/lib/terminal-cursor.test.ts b/test/unit/client/lib/terminal-cursor.test.ts index e6f567e04..1f012199d 100644 --- a/test/unit/client/lib/terminal-cursor.test.ts +++ b/test/unit/client/lib/terminal-cursor.test.ts @@ -120,11 +120,15 @@ describe('terminal-cursor', () => { }) it('remains resilient when stored payload is malformed', () => { + // The malformed payload is expected to warn; capture it here. + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}) localStorage.setItem(TERMINAL_CURSOR_STORAGE_KEY, '{not valid json') __resetTerminalCursorCacheForTests() expect(loadTerminalCursor('term-bad')).toBe(0) expect(getCursorMapSize()).toBe(0) + expect(warnSpy).toHaveBeenCalled() + warnSpy.mockRestore() }) it('treats legacy persisted cursor records as incompatible by default', () => { diff --git a/test/unit/client/store/sidebar-staleness.test.ts b/test/unit/client/store/sidebar-staleness.test.ts index 0bdbfa789..446188a13 100644 --- a/test/unit/client/store/sidebar-staleness.test.ts +++ b/test/unit/client/store/sidebar-staleness.test.ts @@ -187,8 +187,13 @@ describe('sidebar staleness', () => { }, }) + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}) await store.dispatch(queueActiveSessionWindowRefresh() as any) + // The failed background refresh logs a structured warning. + expect(warnSpy).toHaveBeenCalledWith('[SessionsThunks]', 'Background refresh failed for', expect.anything(), 'Network error') + warnSpy.mockRestore() + const sidebar = store.getState().sessions.windows.sidebar // After a failed refresh, loading should be false expect(sidebar.loading).toBeFalsy() diff --git a/test/unit/client/store/storage-migration.fresh-agent.test.ts b/test/unit/client/store/storage-migration.fresh-agent.test.ts index 38afeb359..835749d9b 100644 --- a/test/unit/client/store/storage-migration.fresh-agent.test.ts +++ b/test/unit/client/store/storage-migration.fresh-agent.test.ts @@ -253,8 +253,12 @@ describe('storage-migration fresh-agent', () => { Object.defineProperty(globalThis, 'localStorage', { value: storage, writable: true }) storage.seed(LAYOUT_KEY, originalRaw) + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}) await import('@/store/storage-migration') + expect(warnSpy).toHaveBeenCalledWith('[StorageMigration]', expect.stringContaining('fresh_agent_layout_backup_write_failed')) + warnSpy.mockRestore() + expect(localStorage.getItem(LAYOUT_KEY)).toBe(originalRaw) expect(localStorage.getItem(BACKUP_KEY)).toBeNull() expect(localStorage.getItem(MARKER_KEY)).toBeNull() @@ -269,8 +273,12 @@ describe('storage-migration fresh-agent', () => { Object.defineProperty(globalThis, 'localStorage', { value: storage, writable: true }) storage.seed(LAYOUT_KEY, originalRaw) + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}) await import('@/store/storage-migration') + expect(warnSpy).toHaveBeenCalledWith('[StorageMigration]', expect.stringContaining('fresh_agent_layout_write_failed')) + warnSpy.mockRestore() + expect(localStorage.getItem(LAYOUT_KEY)).toBe(originalRaw) expect(localStorage.getItem(BACKUP_KEY)).toBe(originalRaw) expect(localStorage.getItem(MARKER_KEY)).toBeNull() @@ -296,9 +304,13 @@ describe('storage-migration fresh-agent', () => { Object.defineProperty(globalThis, 'localStorage', { value: storage, writable: true }) storage.seed(LAYOUT_KEY, originalRaw) + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}) await import('@/store/storage-migration') const { readRecoverablePersistedLayoutRaw } = await import('@/store/persistedState') + expect(warnSpy).toHaveBeenCalledWith('[StorageMigration]', expect.stringContaining('fresh_agent_layout_interleaving_write_detected')) + warnSpy.mockRestore() + expect(localStorage.getItem(LAYOUT_KEY)).toBe(concurrentRaw) expect(localStorage.getItem(BACKUP_KEY)).toBeNull() expect(localStorage.getItem(MARKER_KEY)).toBeNull() @@ -325,9 +337,13 @@ describe('storage-migration fresh-agent', () => { Object.defineProperty(globalThis, 'localStorage', { value: storage, writable: true }) storage.seed(LAYOUT_KEY, originalRaw) + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}) await import('@/store/storage-migration') const { readRecoverablePersistedLayoutRaw } = await import('@/store/persistedState') + expect(warnSpy).toHaveBeenCalledWith('[StorageMigration]', expect.stringContaining('fresh_agent_layout_commit_marker_write_failed')) + warnSpy.mockRestore() + expect(localStorage.getItem(LAYOUT_KEY)).toBe(concurrentRaw) expect(localStorage.getItem(BACKUP_KEY)).toBe(originalRaw) expect(localStorage.getItem(MARKER_KEY)).toBeNull() diff --git a/test/unit/server/coding-cli/codex-app-server/remote-proxy.test.ts b/test/unit/server/coding-cli/codex-app-server/remote-proxy.test.ts index 0d6b75eff..a8f3910eb 100644 --- a/test/unit/server/coding-cli/codex-app-server/remote-proxy.test.ts +++ b/test/unit/server/coding-cli/codex-app-server/remote-proxy.test.ts @@ -224,7 +224,10 @@ async function runLargeForwardStressChild(options: { timeoutMs: number }): Promise { try { - const result = await execFileAsync(process.execPath, [ + // The child exits non-zero (rejecting here) on failure; on success its stdout + // is only a memory diagnostic, which the catch below surfaces on failure. So + // there is nothing to read on success — echoing it would just be test noise. + await execFileAsync(process.execPath, [ `--max-old-space-size=${options.heapMb}`, '--import', 'tsx', @@ -237,10 +240,6 @@ async function runLargeForwardStressChild(options: { timeout: options.timeoutMs, maxBuffer: 1024 * 1024, }) - const stdout = result.stdout.trim() - if (stdout.length > 0) { - console.info(stdout) - } } catch (error) { const failure = error as Error & { stdout?: string; stderr?: string } throw new Error([ diff --git a/test/unit/server/coding-cli/codex-app-server/runtime.test.ts b/test/unit/server/coding-cli/codex-app-server/runtime.test.ts index 34de531fc..24a5c4805 100644 --- a/test/unit/server/coding-cli/codex-app-server/runtime.test.ts +++ b/test/unit/server/coding-cli/codex-app-server/runtime.test.ts @@ -17,6 +17,12 @@ import { runCodexStartupReaper, } from '../../../../../server/coding-cli/codex-app-server/runtime.js' import { allocateLocalhostPort, type LoopbackServerEndpoint } from '../../../../../server/local-port.js' +import { consumeCapturedLogRecords } from '../../../../../server/test-log-capture.js' + +const REFUSE_SIGNAL_UNVERIFIED_LOG = + 'Refusing to signal Codex app-server sidecar because its process-group ownership is not verified (before SIGTERM)' +const GROUP_ALIVE_AFTER_SHUTDOWN_LOG = + 'Codex app-server sidecar process group remained alive after shutdown' const __filename = fileURLToPath(import.meta.url) const __dirname = path.dirname(__filename) @@ -836,6 +842,9 @@ describeWithLinuxProc('CodexAppServerRuntime', () => { }) try { + // The refusal-to-signal error log is emitted from the group teardown that races the + // ensureReady rejection, so its count/timing here is non-deterministic; allow it wholesale. + ;(globalThis as any).__ALLOW_CONSOLE_ERROR__ = true await expect(runtime.ensureReady()).rejects.toThrow(/teardown failed|process-group teardown failed/i) expect(metadataWriteAttempts).toBe(1) } finally { @@ -858,6 +867,7 @@ describeWithLinuxProc('CodexAppServerRuntime', () => { ownership.metadata.processGroupId = await readCurrentProcessGroupId() await expect(runtime.shutdown()).rejects.toThrow(/could not be verified|failed/i) + expect(consumeCapturedLogRecords((r) => r.msg === REFUSE_SIGNAL_UNVERIFIED_LOG)).toHaveLength(1) runtimes.delete(runtime) await killProcessGroupForTest(ready.processGroupId) @@ -1021,6 +1031,7 @@ describeWithLinuxProc('CodexAppServerRuntime', () => { await expect(runtime.shutdown()).rejects.toThrow(/could not be verified|failed|ownership/i) expect(await isProcessGroupAlive(ready.processGroupId)).toBe(true) await expect(fsp.stat(indeterminateMetadataPath)).resolves.toBeDefined() + expect(consumeCapturedLogRecords((r) => r.msg === REFUSE_SIGNAL_UNVERIFIED_LOG)).toHaveLength(1) } finally { readFileSpy.mockRestore() runtimes.delete(runtime) @@ -1054,6 +1065,7 @@ describeWithLinuxProc('CodexAppServerRuntime', () => { await expect(runtime.shutdown()).rejects.toThrow(/could not be verified|failed|ownership/i) await expect(fsp.stat(metadataPath)).resolves.toBeDefined() expect(await isProcessGroupAlive(ready.processGroupId)).toBe(true) + expect(consumeCapturedLogRecords((r) => r.msg === REFUSE_SIGNAL_UNVERIFIED_LOG)).toHaveLength(1) } finally { readFileSpy.mockRestore() runtimes.delete(runtime) @@ -1088,6 +1100,7 @@ describeWithLinuxProc('CodexAppServerRuntime', () => { await expect(runtime.shutdown()).rejects.toThrow(/could not be verified|failed|ownership/i) await expect(fsp.stat(metadataPath)).resolves.toBeDefined() expect(await isProcessGroupAlive(ready.processGroupId)).toBe(true) + expect(consumeCapturedLogRecords((r) => r.msg === REFUSE_SIGNAL_UNVERIFIED_LOG)).toHaveLength(1) } finally { readFileSpy.mockRestore() runtimes.delete(runtime) @@ -1122,6 +1135,7 @@ describeWithLinuxProc('CodexAppServerRuntime', () => { await expect(runtime.shutdown()).rejects.toThrow(/could not be verified|failed|ownership/i) await expect(fsp.stat(metadataPath)).resolves.toBeDefined() expect(await isProcessGroupAlive(ready.processGroupId)).toBe(true) + expect(consumeCapturedLogRecords((r) => r.msg === REFUSE_SIGNAL_UNVERIFIED_LOG)).toHaveLength(1) } finally { readFileSpy.mockRestore() runtimes.delete(runtime) @@ -1183,6 +1197,7 @@ describeWithLinuxProc('CodexAppServerRuntime', () => { await expect(runtime.shutdown()).rejects.toThrow(/could not be verified|failed/i) await expect(runtime.ensureReady()).rejects.toThrow(/teardown failed|blocked/i) expect(metadataWriteAttempts).toBe(metadataWriteAttemptsAfterReady) + expect(consumeCapturedLogRecords((r) => r.msg === REFUSE_SIGNAL_UNVERIFIED_LOG)).toHaveLength(1) runtimes.delete(runtime) await killProcessGroupForTest(ready.processGroupId) @@ -1211,6 +1226,7 @@ describeWithLinuxProc('CodexAppServerRuntime', () => { try { await expect(runtime.shutdown()).rejects.toThrow(/could not be verified|failed|ownership/i) expect(await isProcessGroupAlive(ready.processGroupId)).toBe(true) + expect(consumeCapturedLogRecords((r) => r.msg === REFUSE_SIGNAL_UNVERIFIED_LOG)).toHaveLength(1) } finally { readdirSpy.mockRestore() runtimes.delete(runtime) @@ -2111,6 +2127,7 @@ describeWithLinuxProc('CodexAppServerRuntime', () => { expect(await isProcessGroupAlive(ready.processGroupId)).toBe(true) const state = JSON.parse(await fsp.readFile(`${ready.metadataPath}.reaper.json`, 'utf8')) expect(state.attempts).toBe(1) + expect(consumeCapturedLogRecords((r) => r.msg === GROUP_ALIVE_AFTER_SHUTDOWN_LOG)).toHaveLength(1) } finally { killSpy.mockRestore() } diff --git a/test/unit/server/config-store.test.ts b/test/unit/server/config-store.test.ts index 943972f5c..944e48fe5 100644 --- a/test/unit/server/config-store.test.ts +++ b/test/unit/server/config-store.test.ts @@ -2,6 +2,7 @@ import { describe, it, expect, beforeEach, afterEach, vi } from 'vitest' import fsp from 'fs/promises' import path from 'path' import os from 'os' +import { consumeCapturedLogRecords } from '../../../server/test-log-capture.js' // Use vi.hoisted to ensure mockState is available before vi.mock runs // vitest hoists vi.mock calls to the top, so we need vi.hoisted for dependencies @@ -392,6 +393,7 @@ describe('ConfigStore', () => { expect(config.version).toBe(1) expect(config.settings).toEqual(defaultSettings) expect(store.getLastReadError()).toBe('VERSION_MISMATCH') + expect(consumeCapturedLogRecords((r) => r.msg === 'Config file version mismatch; falling back to defaults')).toHaveLength(1) }) it('returns defaults for malformed JSON', async () => { @@ -404,6 +406,7 @@ describe('ConfigStore', () => { expect(config.version).toBe(1) expect(config.settings).toEqual(defaultSettings) expect(store.getLastReadError()).toBe('PARSE_ERROR') + expect(consumeCapturedLogRecords((r) => r.msg === 'Config file parse failed; falling back to defaults')).toHaveLength(1) }) it('uses cached value on subsequent calls', async () => { diff --git a/test/unit/server/network-manager.test.ts b/test/unit/server/network-manager.test.ts index 80fda4c31..130da4084 100644 --- a/test/unit/server/network-manager.test.ts +++ b/test/unit/server/network-manager.test.ts @@ -11,6 +11,7 @@ import { import { detectLanIps, detectLanIpsAsync } from '../../../server/bootstrap.js' import { detectFirewall, firewallCommands } from '../../../server/firewall.js' import { computeWslPortForwardingPlanAsync } from '../../../server/wsl-port-forward.js' +import { consumeCapturedLogRecords } from '../../../server/test-log-capture.js' // Mock external dependencies vi.mock('../../../server/bootstrap.js', () => ({ @@ -366,6 +367,12 @@ describe('NetworkManager', () => { configured: true, }, }) + + // Let the scheduled rebind finish so its async server close/relisten cannot + // race afterEach teardown and emit a spurious close error into a later test. + await vi.waitFor(() => { + expect((manager as any).rebindInFlight).toBe(false) + }) }) it('does not schedule rebind when host unchanged', async () => { @@ -696,6 +703,10 @@ describe('NetworkManager', () => { expect(mockWsHandler.prepareForRebind).toHaveBeenCalledOnce() // CRITICAL: resumeAfterRebind must still be called (via finally block) expect(mockWsHandler.resumeAfterRebind).toHaveBeenCalledOnce() + expect( + consumeCapturedLogRecords((r) => r.msg === 'Failed to close server for rebind'), + ).toHaveLength(1) + expect(consumeCapturedLogRecords((r) => r.msg === 'Hot rebind failed')).toHaveLength(1) // Restore server.close = originalClose diff --git a/test/unit/server/port-forward.test.ts b/test/unit/server/port-forward.test.ts index 8bec49b37..a9056753c 100644 --- a/test/unit/server/port-forward.test.ts +++ b/test/unit/server/port-forward.test.ts @@ -2,6 +2,7 @@ import { describe, it, expect, afterEach, vi, beforeEach } from 'vitest' import * as net from 'net' import { PortForwardManager } from '../../../server/port-forward.js' import { createRequesterIdentity } from '../../../server/request-ip.js' +import { consumeCapturedLogRecords } from '../../../server/test-log-capture.js' // Helper: create a TCP server on localhost that echoes data back function createEchoServer(): Promise<{ server: net.Server; port: number }> { @@ -379,6 +380,9 @@ describe('PortForwardManager', () => { const { reasons } = await captureUnhandledRejections(async () => manager.closeAll()) expect(reasons).toEqual([]) + expect( + consumeCapturedLogRecords((r) => r.msg === 'Port forward close failed'), + ).toHaveLength(1) }) }) @@ -443,6 +447,9 @@ describe('PortForwardManager', () => { }) expect(reasons).toEqual([]) + expect( + consumeCapturedLogRecords((r) => r.msg === 'Port forward close failed'), + ).toHaveLength(1) await shortManager.closeAll() } finally { diff --git a/test/unit/server/sdk-bridge.test.ts b/test/unit/server/sdk-bridge.test.ts index 25d3eee6a..61b28da81 100644 --- a/test/unit/server/sdk-bridge.test.ts +++ b/test/unit/server/sdk-bridge.test.ts @@ -59,6 +59,7 @@ vi.mock('@anthropic-ai/claude-agent-sdk', () => ({ })) import { SdkBridge } from '../../../server/sdk-bridge.js' +import { consumeCapturedLogRecords } from '../../../server/test-log-capture.js' describe('SdkBridge', () => { let bridge: SdkBridge @@ -230,6 +231,7 @@ describe('SdkBridge', () => { const session = await bridge.createSession({ cwd: '/tmp' }) await new Promise((r) => setTimeout(r, 100)) expect(bridge.getSession(session.sessionId)?.status).toBe('idle') + expect(consumeCapturedLogRecords((r) => r.msg === 'SDK stream ended with error')).toHaveLength(1) }) }) @@ -1143,6 +1145,7 @@ describe('SdkBridge', () => { expect(bridge.getSession(session.sessionId)?.status).toBe('idle') // Process cleaned up expect(bridge.sendUserMessage(session.sessionId, 'hello')).toBe(false) + expect(consumeCapturedLogRecords((r) => r.msg === 'SDK stream ended with error')).toHaveLength(1) }) it('killSession works for sessions whose stream has ended', async () => { diff --git a/test/unit/server/tabs-registry/store.test.ts b/test/unit/server/tabs-registry/store.test.ts index 50742d358..bd5d1e980 100644 --- a/test/unit/server/tabs-registry/store.test.ts +++ b/test/unit/server/tabs-registry/store.test.ts @@ -166,7 +166,12 @@ describe('TabsRegistryStore compact state', () => { expect(missingRef).toBeDefined() await fs.rm(path.join(tempDir, 'v1', missingRef!.path)) + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}) const restarted = await createTabsRegistryStore(tempDir, { now: () => now }) + expect(warnSpy.mock.calls.some(([arg]) => + typeof arg === 'string' && arg.includes('compact_manifest_archived_missing_object'), + )).toBe(true) + warnSpy.mockRestore() expect(restarted.count()).toBe(0) const entries = await fs.readdir(path.join(tempDir, 'v1'))