From 837337901dc117379389804e1568046d90a7521b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=E7=A8=8B=E5=BA=8F=E5=91=98=E9=98=BF=E6=B1=9F=28Relakkes?= =?UTF-8?q?=29?= Date: Thu, 4 Jun 2026 20:12:45 +0800 Subject: [PATCH] fix(diagnostics): stop logging expected states as errors and isolate tests MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The diagnostics panel filled with red ERROR/WARN entries during normal use because the capture layer treated "wrote to console" as "something failed", with no severity gatekeeping. Much of the noise was also test runs leaking into the user's real ~/.claude/cc-haha/diagnostics. - diagnosticsService: default unclassified events to info (not error); drop writes under NODE_ENV=test when no CLAUDE_CONFIG_DIR is set; document the console-capture contract (expected states use console.debug/info). - index: don't install console/process capture under bun test. - api/diagnostics: an ingested event with missing severity defaults to info. - oauthRefreshLog (new): token refresh failure is gracefully handled and is never an error — expected expiry (401/403/revoked) logs at debug, anything else at warn. Wired into both Haha OAuth services. - conversationService: classify cli_runtime_exit severity by exit code, so clean/SIGTERM/SIGKILL exits are info and only abnormal codes stay error (real "chat died" crashes remain perceivable). - ws/handler: streaming partial tool-input JSON is normal — debug, not warn. Tests: oauth-refresh-log + cli-exit-severity unit tests; diagnostics-service covers the info default and the test-isolation guard. Co-Authored-By: Claude Opus 4.8 (1M context) --- .../__tests__/cli-exit-severity.test.ts | 21 ++++++ .../__tests__/diagnostics-service.test.ts | 35 +++++++++- .../__tests__/oauth-refresh-log.test.ts | 67 +++++++++++++++++++ src/server/api/diagnostics.ts | 3 +- src/server/index.ts | 9 ++- src/server/services/conversationService.ts | 18 ++++- src/server/services/diagnosticsService.ts | 21 +++++- src/server/services/hahaOAuthService.ts | 6 +- src/server/services/hahaOpenAIOAuthService.ts | 6 +- src/server/services/oauthRefreshLog.ts | 32 +++++++++ src/server/ws/handler.ts | 6 +- 11 files changed, 208 insertions(+), 16 deletions(-) create mode 100644 src/server/__tests__/cli-exit-severity.test.ts create mode 100644 src/server/__tests__/oauth-refresh-log.test.ts create mode 100644 src/server/services/oauthRefreshLog.ts diff --git a/src/server/__tests__/cli-exit-severity.test.ts b/src/server/__tests__/cli-exit-severity.test.ts new file mode 100644 index 00000000..7b60aa39 --- /dev/null +++ b/src/server/__tests__/cli-exit-severity.test.ts @@ -0,0 +1,21 @@ +import { describe, expect, test } from 'bun:test' +import { cliExitSeverity } from '../services/conversationService.js' + +describe('cliExitSeverity', () => { + test.each([ + [0, 'info'], + [null, 'info'], + [143, 'info'], // SIGTERM — shutdown / user stop + [137, 'info'], // SIGKILL — OS reclaim + ] as const)('benign exit code %p → %s', (code, expected) => { + expect(cliExitSeverity(code)).toBe(expected) + }) + + test.each([ + [1, 'error'], + [2, 'error'], + [127, 'error'], + ] as const)('abnormal exit code %p → error (real crash, must be perceivable)', (code, expected) => { + expect(cliExitSeverity(code)).toBe(expected) + }) +}) diff --git a/src/server/__tests__/diagnostics-service.test.ts b/src/server/__tests__/diagnostics-service.test.ts index 6063a23d..2c83d78d 100644 --- a/src/server/__tests__/diagnostics-service.test.ts +++ b/src/server/__tests__/diagnostics-service.test.ts @@ -1,4 +1,4 @@ -import { afterEach, beforeEach, describe, expect, test } from 'bun:test' +import { afterEach, beforeEach, describe, expect, spyOn, test } from 'bun:test' import * as fs from 'node:fs/promises' import { createServer } from 'node:net' import * as os from 'node:os' @@ -93,6 +93,35 @@ describe('DiagnosticsService', () => { expect(runtime).not.toContain('sk-secret-token') }) + test('defaults an unclassified event to info, not error', async () => { + const service = new DiagnosticsService() + await service.recordEvent({ type: 'some_unclassified_event', summary: 'no severity given' }) + + const raw = await fs.readFile(path.join(tmpDir, 'cc-haha', 'diagnostics', 'diagnostics.jsonl'), 'utf-8') + const event = JSON.parse(raw.trim().split('\n').at(-1)!) + expect(event.severity).toBe('info') + + // info events stay out of the warning/error runtime log + await expect( + fs.readFile(path.join(tmpDir, 'cc-haha', 'diagnostics', 'runtime-errors.log'), 'utf-8'), + ).rejects.toThrow() + }) + + test('drops events under NODE_ENV=test when no CLAUDE_CONFIG_DIR is set (no real-home pollution)', async () => { + const service = new DiagnosticsService() + const appendSpy = spyOn(fs, 'appendFile') + const savedConfigDir = process.env.CLAUDE_CONFIG_DIR + delete process.env.CLAUDE_CONFIG_DIR + try { + await service.recordEvent({ type: 'leaked_test_event', severity: 'error', summary: 'should not be written' }) + expect(appendSpy).not.toHaveBeenCalled() + } finally { + appendSpy.mockRestore() + if (savedConfigDir === undefined) delete process.env.CLAUDE_CONFIG_DIR + else process.env.CLAUDE_CONFIG_DIR = savedConfigDir + } + }) + test('exports a single diagnostics tarball without provider secrets', async () => { const service = new DiagnosticsService() await fs.mkdir(path.join(tmpDir, 'cc-haha'), { recursive: true }) @@ -143,10 +172,14 @@ describe('DiagnosticsService', () => { test('keeps fatal startup errors visible on stderr while recording diagnostics', async () => { const port = await getPort() const serverArgs = ['bun', 'run', 'src/server/index.ts', '--host', '127.0.0.1', '--port', String(port)] + // This spawns a *real* server, not the in-process test runner. Strip the + // inherited NODE_ENV=test so it installs console/process capture the way a + // production server does (capture is intentionally skipped under test). const env = { ...process.env, CLAUDE_CONFIG_DIR: tmpDir, } + delete (env as Record).NODE_ENV const server = Bun.spawn(serverArgs, { cwd: process.cwd(), env, diff --git a/src/server/__tests__/oauth-refresh-log.test.ts b/src/server/__tests__/oauth-refresh-log.test.ts new file mode 100644 index 00000000..0dfb0058 --- /dev/null +++ b/src/server/__tests__/oauth-refresh-log.test.ts @@ -0,0 +1,67 @@ +import { afterEach, describe, expect, spyOn, test } from 'bun:test' +import { + isExpectedAuthRefreshFailure, + logTokenRefreshFailure, +} from '../services/oauthRefreshLog.js' + +describe('isExpectedAuthRefreshFailure', () => { + test.each([ + 'refresh revoked', + '401 Unauthorized', + 'Request failed with status code 403', + 'OpenAI token refresh failed: 403: {"error":"forbidden"}', + 'invalid_grant', + 'Forbidden', + ])('treats %p as an expected re-auth signal', (message) => { + expect(isExpectedAuthRefreshFailure(new Error(message))).toBe(true) + }) + + test.each([ + 'Failed to fetch', + 'network timeout', + 'Request failed with status code 500', + 'ECONNREFUSED', + ])('treats %p as an unexpected failure', (message) => { + expect(isExpectedAuthRefreshFailure(new Error(message))).toBe(false) + }) + + test('handles non-Error values without throwing', () => { + expect(isExpectedAuthRefreshFailure('401 Unauthorized')).toBe(true) + expect(isExpectedAuthRefreshFailure(null)).toBe(false) + expect(isExpectedAuthRefreshFailure(undefined)).toBe(false) + }) +}) + +describe('logTokenRefreshFailure', () => { + let errorSpy: ReturnType + let warnSpy: ReturnType + let debugSpy: ReturnType + + function install() { + errorSpy = spyOn(console, 'error').mockImplementation(() => {}) + warnSpy = spyOn(console, 'warn').mockImplementation(() => {}) + debugSpy = spyOn(console, 'debug').mockImplementation(() => {}) + } + + afterEach(() => { + errorSpy?.mockRestore() + warnSpy?.mockRestore() + debugSpy?.mockRestore() + }) + + test('never logs an expected expiry as console.error (would become a red ERROR)', () => { + install() + logTokenRefreshFailure('[Svc]', new Error('refresh revoked')) + expect(errorSpy).not.toHaveBeenCalled() + expect(warnSpy).not.toHaveBeenCalled() + expect(debugSpy).toHaveBeenCalledTimes(1) + }) + + test('logs an unexpected failure as a warn, never an error', () => { + install() + logTokenRefreshFailure('[Svc]', new Error('Failed to fetch')) + expect(errorSpy).not.toHaveBeenCalled() + expect(warnSpy).toHaveBeenCalledTimes(1) + expect(debugSpy).not.toHaveBeenCalled() + }) +}) diff --git a/src/server/api/diagnostics.ts b/src/server/api/diagnostics.ts index 7bf3c4aa..a1e3d240 100644 --- a/src/server/api/diagnostics.ts +++ b/src/server/api/diagnostics.ts @@ -40,7 +40,8 @@ export async function handleDiagnosticsApi( const type = typeof body.type === 'string' && body.type.trim() ? body.type.trim().slice(0, 128) : 'client_diagnostic_event' - const severity = isDiagnosticSeverity(body.severity) ? body.severity : 'error' + // A client event that omits/garbles severity is not, by default, an error. + const severity = isDiagnosticSeverity(body.severity) ? body.severity : 'info' const summary = typeof body.summary === 'string' && body.summary.trim() ? body.summary : type diff --git a/src/server/index.ts b/src/server/index.ts index df6dec47..d13f8493 100644 --- a/src/server/index.ts +++ b/src/server/index.ts @@ -125,8 +125,13 @@ function originFromUrl(value: string | null): string | null { export function startServer(port = PORT, host = HOST) { enableConfigs() - diagnosticsService.installConsoleCapture() - diagnosticsService.installProcessCapture() + // Don't hijack the global console / process handlers under `bun test`: + // a test that boots the server would otherwise route every test-side + // console.error/warn into the user's real diagnostics file. + if (process.env.NODE_ENV !== 'test') { + diagnosticsService.installConsoleCapture() + diagnosticsService.installProcessCapture() + } let serverPort = port const localConnectHost = host === '0.0.0.0' || host === '127.0.0.1' || host === 'localhost' diff --git a/src/server/services/conversationService.ts b/src/server/services/conversationService.ts index b12d7a9c..89969c62 100644 --- a/src/server/services/conversationService.ts +++ b/src/server/services/conversationService.ts @@ -45,6 +45,22 @@ const CONTROL_READY_POLL_MS = 50 const AUTO_MEMORY_DIRNAME = 'memory' export const DESKTOP_CLI_GRACEFUL_SHUTDOWN_TIMEOUT_MS = 6_000 +/** + * Severity for a CLI subprocess exit, by exit code. + * + * Reaching handleProcessExit already means the process left outside the clean + * stop path, but the exit code still tells crash from teardown: + * - 0 clean exit + * - null terminated by a signal with no numeric code + * - 143 (SIGTERM), 137 (SIGKILL): killed — shutdown / user stop / OS reclaim + * None of these are a crash the user needs flagged in red. Any other non-zero + * code is a genuine "it died mid-chat" failure and stays an error. + */ +export function cliExitSeverity(code: number | null): 'info' | 'error' { + if (code === 0 || code === null || code === 143 || code === 137) return 'info' + return 'error' +} + type AttachmentRef = { type: 'file' | 'image' name?: string @@ -933,7 +949,7 @@ export class ConversationService { const exitError = this.buildRuntimeExitMessage(sessionId, code) void diagnosticsService.recordEvent({ type: 'cli_runtime_exit', - severity: 'error', + severity: cliExitSeverity(code), sessionId, summary: exitError, details: { diff --git a/src/server/services/diagnosticsService.ts b/src/server/services/diagnosticsService.ts index e02b19e9..77270ebd 100644 --- a/src/server/services/diagnosticsService.ts +++ b/src/server/services/diagnosticsService.ts @@ -80,11 +80,20 @@ export class DiagnosticsService { } async recordEvent(input: DiagnosticEventInput): Promise { + // Test isolation: never let a test run write into the user's real + // ~/.claude/cc-haha/diagnostics. Tests that genuinely exercise diagnostics + // set CLAUDE_CONFIG_DIR to a tmp dir; anything else under NODE_ENV=test is + // a leak (e.g. a fire-and-forget recordEvent resolving after a test's + // afterEach restored CLAUDE_CONFIG_DIR) and must be dropped. + if (process.env.NODE_ENV === 'test' && !process.env.CLAUDE_CONFIG_DIR) return + const event: DiagnosticEvent = { id: crypto.randomUUID(), timestamp: new Date().toISOString(), type: input.type, - severity: input.severity ?? 'error', + // Default to 'info', not 'error': an unclassified event is not evidence + // of a failure. Only callers that know something went wrong pass 'error'. + severity: input.severity ?? 'info', summary: this.sanitizeString(input.summary), ...(input.sessionId ? { sessionId: this.sanitizeString(input.sessionId, 256) } : {}), ...(input.details !== undefined ? { details: this.sanitizeValue(input.details) } : {}), @@ -102,6 +111,16 @@ export class DiagnosticsService { } } + /** + * Mirror console.error / console.warn into the diagnostics stream. + * + * Contract for callers across the codebase: console.error means "error" and + * console.warn means "warn" in the diagnostics panel. An expected, gracefully + * handled state (token expiry, normal process shutdown, streaming partials, + * recovered fallbacks) is NOT an error — log those with console.debug / + * console.info / console.log, which are intentionally not captured here. + * Otherwise the panel fills with red noise and real failures get buried. + */ installConsoleCapture(): void { if (this.consoleCaptureInstalled) return this.consoleCaptureInstalled = true diff --git a/src/server/services/hahaOAuthService.ts b/src/server/services/hahaOAuthService.ts index 4cbd4f3a..9982658e 100644 --- a/src/server/services/hahaOAuthService.ts +++ b/src/server/services/hahaOAuthService.ts @@ -12,6 +12,7 @@ import * as fs from 'fs/promises' import * as os from 'os' import * as path from 'path' +import { logTokenRefreshFailure } from './oauthRefreshLog.js' import { generateCodeVerifier, generateCodeChallenge, @@ -239,10 +240,7 @@ export class HahaOAuthService { await this.saveTokens(updated) return updated } catch (err) { - console.error( - '[HahaOAuthService] token refresh failed:', - err instanceof Error ? err.message : err, - ) + logTokenRefreshFailure('[HahaOAuthService]', err) return null } } diff --git a/src/server/services/hahaOpenAIOAuthService.ts b/src/server/services/hahaOpenAIOAuthService.ts index b812dcdf..93c781c0 100644 --- a/src/server/services/hahaOpenAIOAuthService.ts +++ b/src/server/services/hahaOpenAIOAuthService.ts @@ -12,6 +12,7 @@ import * as fs from 'fs/promises' import * as os from 'os' import * as path from 'path' +import { logTokenRefreshFailure } from './oauthRefreshLog.js' import { AuthCodeListener } from '../../services/oauth/auth-code-listener.js' import { buildOpenAIAuthorizeUrl, @@ -351,10 +352,7 @@ export class HahaOpenAIOAuthService { await this.saveTokens(updated) return updated } catch (err) { - console.error( - '[HahaOpenAIOAuthService] token refresh failed:', - err instanceof Error ? err.message : err, - ) + logTokenRefreshFailure('[HahaOpenAIOAuthService]', err) return null } } diff --git a/src/server/services/oauthRefreshLog.ts b/src/server/services/oauthRefreshLog.ts new file mode 100644 index 00000000..1e276057 --- /dev/null +++ b/src/server/services/oauthRefreshLog.ts @@ -0,0 +1,32 @@ +/** + * Shared logging policy for OAuth token-refresh failures. + * + * A refresh failure is a normal, gracefully-handled lifecycle event: the + * caller returns null and the UI prompts the user to sign in again. It is + * therefore never a program "error" and must not be logged via console.error + * (which the diagnostics service captures as a red ERROR event — see + * diagnosticsService.installConsoleCapture). + * + * - Expected expiry (token revoked / 401 / 403 / invalid_grant): the everyday + * "your session ended, log in again" case → console.debug (not captured). + * - Anything else (network error, 5xx, malformed response): still worth a + * breadcrumb but not a failure of our program → console.warn. + */ + +const EXPECTED_AUTH_EXPIRY_RE = + /(refresh revoked|invalid_grant|\b401\b|\b403\b|unauthorized|forbidden)/i + +export function isExpectedAuthRefreshFailure(error: unknown): boolean { + const message = error instanceof Error ? error.message : String(error ?? '') + return EXPECTED_AUTH_EXPIRY_RE.test(message) +} + +export function logTokenRefreshFailure(serviceLabel: string, error: unknown): void { + const message = error instanceof Error ? error.message : error + if (isExpectedAuthRefreshFailure(error)) { + // Expected: token expired/revoked. Quiet — the user just needs to re-auth. + console.debug(`${serviceLabel} token refresh failed (expected, re-auth required):`, message) + return + } + console.warn(`${serviceLabel} token refresh failed:`, message) +} diff --git a/src/server/ws/handler.ts b/src/server/ws/handler.ts index 02bc6760..c7bc325f 100644 --- a/src/server/ws/handler.ts +++ b/src/server/ws/handler.ts @@ -1456,8 +1456,10 @@ export function translateCliMessage(cliMsg: any, sessionId: string): ServerMessa } // JSON parse failed — defer to the assistant message which - // carries the complete, already-parsed tool input. - console.warn( + // carries the complete, already-parsed tool input. This is the + // normal streaming partial-input case, not a fault: keep it at + // debug so it doesn't surface as a diagnostics warning. + console.debug( `[WS] Tool input JSON parse failed for ${toolBlock.toolName} (${toolBlock.toolUseId}), deferring to assistant message`, ) streamState.pendingToolBlocks.set(toolBlock.toolUseId, {