mirror of
https://github.com/NanmiCoder/cc-haha
synced 2026-07-18 13:23:33 +08:00
fix(diagnostics): stop logging expected states as errors and isolate tests
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) <noreply@anthropic.com>
This commit is contained in:
parent
d2a99e01c2
commit
837337901d
21
src/server/__tests__/cli-exit-severity.test.ts
Normal file
21
src/server/__tests__/cli-exit-severity.test.ts
Normal file
@ -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)
|
||||
})
|
||||
})
|
||||
@ -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<string, string | undefined>).NODE_ENV
|
||||
const server = Bun.spawn(serverArgs, {
|
||||
cwd: process.cwd(),
|
||||
env,
|
||||
|
||||
67
src/server/__tests__/oauth-refresh-log.test.ts
Normal file
67
src/server/__tests__/oauth-refresh-log.test.ts
Normal file
@ -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<typeof spyOn>
|
||||
let warnSpy: ReturnType<typeof spyOn>
|
||||
let debugSpy: ReturnType<typeof spyOn>
|
||||
|
||||
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()
|
||||
})
|
||||
})
|
||||
@ -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
|
||||
|
||||
@ -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'
|
||||
|
||||
@ -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: {
|
||||
|
||||
@ -80,11 +80,20 @@ export class DiagnosticsService {
|
||||
}
|
||||
|
||||
async recordEvent(input: DiagnosticEventInput): Promise<void> {
|
||||
// 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
|
||||
|
||||
@ -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
|
||||
}
|
||||
}
|
||||
|
||||
@ -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
|
||||
}
|
||||
}
|
||||
|
||||
32
src/server/services/oauthRefreshLog.ts
Normal file
32
src/server/services/oauthRefreshLog.ts
Normal file
@ -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)
|
||||
}
|
||||
@ -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, {
|
||||
|
||||
Loading…
x
Reference in New Issue
Block a user