diff --git a/src/ai-checker-base.ts b/src/ai-checker-base.ts index ddb8bd14..d902a67f 100644 --- a/src/ai-checker-base.ts +++ b/src/ai-checker-base.ts @@ -135,6 +135,7 @@ export abstract class AiCheckerBase< // Active check state protected checkMuxName: string | null = null; protected checkTempFile: string | null = null; + protected checkStderrFile: string | null = null; protected checkPromptFile: string | null = null; protected checkPollTimer: NodeJS.Timeout | null = null; protected checkTimeoutTimer: NodeJS.Timeout | null = null; @@ -376,6 +377,7 @@ export abstract class AiCheckerBase< const shortId = this.sessionId.slice(0, 8); const timestamp = Date.now(); this.checkTempFile = join(tmpdir(), `${this.tempFilePrefix}-${shortId}-${timestamp}.txt`); + this.checkStderrFile = join(tmpdir(), `${this.tempFilePrefix}-stderr-${shortId}-${timestamp}.txt`); this.checkPromptFile = join(tmpdir(), `${this.tempFilePrefix}-prompt-${shortId}-${timestamp}.txt`); this.checkMuxName = `${this.muxNamePrefix}${shortId}`; @@ -386,6 +388,7 @@ export abstract class AiCheckerBase< // Ensure output temp file exists (empty) so we can poll it writeFileSync(this.checkTempFile, ''); + writeFileSync(this.checkStderrFile, ''); // Write prompt to file to avoid E2BIG error (argument list too long) // The prompt can be 16KB+ which exceeds shell argument limits @@ -396,7 +399,7 @@ export abstract class AiCheckerBase< const modelArg = `--model "${this.config.model.replace(/"/g, '\\"')}"`; const augmentedPath = getAugmentedPath(); const claudeCmd = `cat "${this.checkPromptFile}" | claude -p ${modelArg} --output-format text`; - const fullCmd = `export PATH="${augmentedPath}"; ${claudeCmd} > "${this.checkTempFile}" 2>&1; echo "${this.doneMarker}" >> "${this.checkTempFile}"; rm -f "${this.checkPromptFile}"`; + const fullCmd = `export PATH="${augmentedPath}"; ${claudeCmd} > "${this.checkTempFile}" 2> "${this.checkStderrFile}"; echo "${this.doneMarker}" >> "${this.checkTempFile}"; rm -f "${this.checkPromptFile}"`; // Spawn tmux session try { @@ -461,18 +464,32 @@ export abstract class AiCheckerBase< const output = content.replace(this.doneMarker, '').trim(); if (!output) { - return this.createErrorResult(`Empty output from ${this.checkDescription}`, durationMs); + const stderr = this.readStderrDiagnostic(); + const detail = stderr ? `: ${stderr}` : ''; + return this.createErrorResult(`Empty output from ${this.checkDescription}${detail}`, durationMs); } // Delegate to subclass for verdict parsing const parsed = this.parseVerdict(output); if (!parsed) { - return this.createErrorResult(`Could not parse verdict from: "${output.substring(0, 100)}"`, durationMs); + const stderr = this.readStderrDiagnostic(); + const detail = stderr ? `; stderr: "${stderr}"` : ''; + return this.createErrorResult(`Could not parse verdict from: "${output.substring(0, 100)}"${detail}`, durationMs); } return this.createResult(parsed.verdict, parsed.reasoning, durationMs); } + private readStderrDiagnostic(): string { + if (!this.checkStderrFile || !existsSync(this.checkStderrFile)) return ''; + + try { + return readFileSync(this.checkStderrFile, 'utf-8').trim().substring(0, 200); + } catch { + return ''; + } + } + private cleanupCheck(): void { // Clear poll timer if (this.checkPollTimer) { @@ -509,6 +526,17 @@ export abstract class AiCheckerBase< this.checkTempFile = null; } + if (this.checkStderrFile) { + try { + if (existsSync(this.checkStderrFile)) { + unlinkSync(this.checkStderrFile); + } + } catch { + // Best effort cleanup + } + this.checkStderrFile = null; + } + if (this.checkPromptFile) { try { if (existsSync(this.checkPromptFile)) { diff --git a/test/ai-idle-checker.test.ts b/test/ai-idle-checker.test.ts index 342b06d5..e0180a1c 100644 --- a/test/ai-idle-checker.test.ts +++ b/test/ai-idle-checker.test.ts @@ -71,7 +71,8 @@ describe('AiIdleChecker', () => { describe('Output Parsing', () => { it('should parse IDLE verdict', async () => { // Set up mock to return IDLE result after polling - mockedReadFileSync.mockReturnValueOnce('') // writeFileSync creates empty file + mockedReadFileSync + .mockReturnValueOnce('') // writeFileSync creates empty file .mockReturnValueOnce('IDLE\nSession shows completion message and prompt.\n__AICHECK_DONE__'); const checkPromise = checker.check('some terminal output'); @@ -87,7 +88,8 @@ describe('AiIdleChecker', () => { }); it('should parse WORKING verdict', async () => { - mockedReadFileSync.mockReturnValueOnce('') + mockedReadFileSync + .mockReturnValueOnce('') .mockReturnValueOnce('WORKING\nSpinner characters detected, still processing.\n__AICHECK_DONE__'); const checkPromise = checker.check('some terminal output'); @@ -100,8 +102,7 @@ describe('AiIdleChecker', () => { }); it('should handle lowercase verdict', async () => { - mockedReadFileSync.mockReturnValueOnce('') - .mockReturnValueOnce('idle\nDone.\n__AICHECK_DONE__'); + mockedReadFileSync.mockReturnValueOnce('').mockReturnValueOnce('idle\nDone.\n__AICHECK_DONE__'); const checkPromise = checker.check('output'); await vi.advanceTimersByTimeAsync(500); @@ -112,7 +113,8 @@ describe('AiIdleChecker', () => { }); it('should return ERROR for unparseable output', async () => { - mockedReadFileSync.mockReturnValueOnce('') + mockedReadFileSync + .mockReturnValueOnce('') .mockReturnValueOnce('Something unexpected happened.\n__AICHECK_DONE__'); const checkPromise = checker.check('output'); @@ -125,8 +127,7 @@ describe('AiIdleChecker', () => { }); it('should return ERROR for empty output', async () => { - mockedReadFileSync.mockReturnValueOnce('') - .mockReturnValueOnce('__AICHECK_DONE__'); + mockedReadFileSync.mockReturnValueOnce('').mockReturnValueOnce('__AICHECK_DONE__'); const checkPromise = checker.check('output'); await vi.advanceTimersByTimeAsync(500); @@ -175,10 +176,34 @@ describe('AiIdleChecker', () => { await vi.advanceTimersByTimeAsync(500); await checkPromise; - expect(mockedWriteFileSync).toHaveBeenCalledWith( - expect.stringContaining('codeman-aicheck-'), - '' + expect(mockedWriteFileSync).toHaveBeenCalledWith(expect.stringContaining('codeman-aicheck-'), ''); + }); + + it('should keep Claude stderr separate from verdict output', async () => { + mockedReadFileSync.mockReturnValue('IDLE\n__AICHECK_DONE__'); + + const checkPromise = checker.check('output'); + await vi.advanceTimersByTimeAsync(500); + await checkPromise; + + const spawnArgs = mockedSpawn.mock.calls[0]?.[1]; + const command = spawnArgs?.[spawnArgs.length - 1]; + expect(command).toEqual(expect.any(String)); + expect(command).toContain(' 2> "'); + expect(command).not.toContain('2>&1'); + }); + + it('should include Claude stderr when no verdict is produced', async () => { + mockedReadFileSync.mockImplementation((path) => + String(path).includes('-stderr-') ? 'Claude CLI failed to load settings' : '__AICHECK_DONE__' ); + + const checkPromise = checker.check('output'); + await vi.advanceTimersByTimeAsync(500); + + const result = await checkPromise; + expect(result.verdict).toBe('ERROR'); + expect(result.reasoning).toContain('Claude CLI failed to load settings'); }); }); @@ -223,7 +248,7 @@ describe('AiIdleChecker', () => { // Should have tried to kill the tmux session (initial kill + cleanup kill) const killCalls = mockedExecSync.mock.calls.filter( - call => typeof call[0] === 'string' && call[0].includes('kill-session') + (call) => typeof call[0] === 'string' && call[0].includes('kill-session') ); expect(killCalls.length).toBeGreaterThan(0); }); @@ -236,8 +261,7 @@ describe('AiIdleChecker', () => { describe('Cooldown', () => { it('should start cooldown after WORKING verdict', async () => { - mockedReadFileSync.mockReturnValueOnce('') - .mockReturnValueOnce('WORKING\nStill processing.\n__AICHECK_DONE__'); + mockedReadFileSync.mockReturnValueOnce('').mockReturnValueOnce('WORKING\nStill processing.\n__AICHECK_DONE__'); const checkPromise = checker.check('output'); await vi.advanceTimersByTimeAsync(500); @@ -250,8 +274,7 @@ describe('AiIdleChecker', () => { }); it('should return to ready after cooldown expires', async () => { - mockedReadFileSync.mockReturnValueOnce('') - .mockReturnValueOnce('WORKING\nBusy.\n__AICHECK_DONE__'); + mockedReadFileSync.mockReturnValueOnce('').mockReturnValueOnce('WORKING\nBusy.\n__AICHECK_DONE__'); const checkPromise = checker.check('output'); await vi.advanceTimersByTimeAsync(1000); @@ -267,8 +290,7 @@ describe('AiIdleChecker', () => { }); it('should not start new check during cooldown', async () => { - mockedReadFileSync.mockReturnValueOnce('') - .mockReturnValueOnce('WORKING\nBusy.\n__AICHECK_DONE__'); + mockedReadFileSync.mockReturnValueOnce('').mockReturnValueOnce('WORKING\nBusy.\n__AICHECK_DONE__'); const firstCheck = checker.check('output'); await vi.advanceTimersByTimeAsync(1000); @@ -283,8 +305,7 @@ describe('AiIdleChecker', () => { describe('Error Handling', () => { it('should start error cooldown after parse error', async () => { - mockedReadFileSync.mockReturnValueOnce('') - .mockReturnValueOnce('garbage output\n__AICHECK_DONE__'); + mockedReadFileSync.mockReturnValueOnce('').mockReturnValueOnce('garbage output\n__AICHECK_DONE__'); const checkPromise = checker.check('output'); await vi.advanceTimersByTimeAsync(1000); @@ -302,8 +323,7 @@ describe('AiIdleChecker', () => { const cooldowns = [1100, 2100]; // Wait slightly longer than each cooldown for (let i = 0; i < 3; i++) { - mockedReadFileSync.mockReturnValueOnce('') - .mockReturnValueOnce('garbage\n__AICHECK_DONE__'); + mockedReadFileSync.mockReturnValueOnce('').mockReturnValueOnce('garbage\n__AICHECK_DONE__'); const checkPromise = checker.check('output'); await vi.advanceTimersByTimeAsync(1000); @@ -321,8 +341,7 @@ describe('AiIdleChecker', () => { it('should reset error counter on successful check', async () => { // First check: error - mockedReadFileSync.mockReturnValueOnce('') - .mockReturnValueOnce('garbage\n__AICHECK_DONE__'); + mockedReadFileSync.mockReturnValueOnce('').mockReturnValueOnce('garbage\n__AICHECK_DONE__'); const firstCheck = checker.check('output'); await vi.advanceTimersByTimeAsync(1000); await firstCheck; @@ -332,8 +351,7 @@ describe('AiIdleChecker', () => { await vi.advanceTimersByTimeAsync(1100); // Second check: success - mockedReadFileSync.mockReturnValueOnce('') - .mockReturnValueOnce('IDLE\nDone.\n__AICHECK_DONE__'); + mockedReadFileSync.mockReturnValueOnce('').mockReturnValueOnce('IDLE\nDone.\n__AICHECK_DONE__'); const secondCheck = checker.check('output'); await vi.advanceTimersByTimeAsync(1000); await secondCheck; @@ -352,8 +370,7 @@ describe('AiIdleChecker', () => { describe('Buffer Handling', () => { it('should strip ANSI codes from terminal buffer', async () => { - mockedReadFileSync.mockReturnValueOnce('') - .mockReturnValueOnce('IDLE\n__AICHECK_DONE__'); + mockedReadFileSync.mockReturnValueOnce('').mockReturnValueOnce('IDLE\n__AICHECK_DONE__'); const ansiBuffer = '\x1b[1mBold\x1b[0m \x1b[32mGreen\x1b[0m text'; const checkPromise = checker.check(ansiBuffer); @@ -365,8 +382,7 @@ describe('AiIdleChecker', () => { }); it('should trim buffer to maxContextChars', async () => { - mockedReadFileSync.mockReturnValueOnce('') - .mockReturnValueOnce('IDLE\n__AICHECK_DONE__'); + mockedReadFileSync.mockReturnValueOnce('').mockReturnValueOnce('IDLE\n__AICHECK_DONE__'); // Create buffer longer than maxContextChars (1000) const longBuffer = 'x'.repeat(2000); @@ -402,8 +418,7 @@ describe('AiIdleChecker', () => { describe('Reset', () => { it('should clear all state on reset', async () => { // Trigger a WORKING verdict to set state - mockedReadFileSync.mockReturnValueOnce('') - .mockReturnValueOnce('WORKING\nBusy.\n__AICHECK_DONE__'); + mockedReadFileSync.mockReturnValueOnce('').mockReturnValueOnce('WORKING\nBusy.\n__AICHECK_DONE__'); const checkPromise = checker.check('output'); await vi.advanceTimersByTimeAsync(1000); @@ -440,24 +455,24 @@ describe('AiIdleChecker', () => { const handler = vi.fn(); checker.on('checkCompleted', handler); - mockedReadFileSync.mockReturnValueOnce('') - .mockReturnValueOnce('IDLE\nAll done.\n__AICHECK_DONE__'); + mockedReadFileSync.mockReturnValueOnce('').mockReturnValueOnce('IDLE\nAll done.\n__AICHECK_DONE__'); const checkPromise = checker.check('output'); await vi.advanceTimersByTimeAsync(1000); await checkPromise; - expect(handler).toHaveBeenCalledWith(expect.objectContaining({ - verdict: 'IDLE', - })); + expect(handler).toHaveBeenCalledWith( + expect.objectContaining({ + verdict: 'IDLE', + }) + ); }); it('should emit cooldownStarted event after WORKING', async () => { const handler = vi.fn(); checker.on('cooldownStarted', handler); - mockedReadFileSync.mockReturnValueOnce('') - .mockReturnValueOnce('WORKING\nBusy.\n__AICHECK_DONE__'); + mockedReadFileSync.mockReturnValueOnce('').mockReturnValueOnce('WORKING\nBusy.\n__AICHECK_DONE__'); const checkPromise = checker.check('output'); await vi.advanceTimersByTimeAsync(1000); @@ -477,8 +492,7 @@ describe('AiIdleChecker', () => { const cooldowns = [1100, 2100]; // Wait longer than exponential backoff for (let i = 0; i < 3; i++) { - mockedReadFileSync.mockReturnValueOnce('') - .mockReturnValueOnce('garbage\n__AICHECK_DONE__'); + mockedReadFileSync.mockReturnValueOnce('').mockReturnValueOnce('garbage\n__AICHECK_DONE__'); const checkPromise = checker.check('output'); await vi.advanceTimersByTimeAsync(1000); await checkPromise;