diff --git a/src/cliproxy/auth/__tests__/oauth-diagnose-failure.test.ts b/src/cliproxy/auth/__tests__/oauth-diagnose-failure.test.ts new file mode 100644 index 00000000..12efb200 --- /dev/null +++ b/src/cliproxy/auth/__tests__/oauth-diagnose-failure.test.ts @@ -0,0 +1,197 @@ +import { describe, expect, test } from 'bun:test'; +import { diagnoseFailure, formatErrorMessage } from '../oauth-trace/diagnose-failure'; +import { OAuthTracePhase, type OAuthTraceEvent } from '../oauth-trace/trace-events'; + +let tCounter = 1000; +function ev(phase: OAuthTracePhase, over: Partial = {}): OAuthTraceEvent { + tCounter += 10; + return { + sessionId: 's', + provider: 'codex', + phase, + ts: tCounter, + elapsedMs: tCounter - 1000, + ...over, + }; +} + +function reset() { + tCounter = 1000; +} + +describe('diagnoseFailure', () => { + test('empty snapshot -> UNKNOWN', () => { + expect(diagnoseFailure([]).branchId).toBe('UNKNOWN'); + }); + + test('URL_NOT_DISPLAYED when no AuthUrlDisplayed and exit=0', () => { + reset(); + const snap = [ + ev(OAuthTracePhase.BinarySpawn), + ev(OAuthTracePhase.BinaryExit, { data: { code: 0 } }), + ]; + expect(diagnoseFailure(snap).branchId).toBe('URL_NOT_DISPLAYED'); + }); + + test('BROWSER_NOT_OPENED after URL displayed past heuristic window', () => { + reset(); + const snap: OAuthTraceEvent[] = [ + { ...ev(OAuthTracePhase.AuthUrlDisplayed), ts: 1000 }, + { ...ev(OAuthTracePhase.BinaryStdout), ts: 1000 + 6000 }, + ]; + expect(diagnoseFailure(snap).branchId).toBe('BROWSER_NOT_OPENED'); + }); + + test('CALLBACK_NEVER_OBSERVED when browser opened, exit=0, no callback heuristic', () => { + reset(); + const snap = [ + ev(OAuthTracePhase.AuthUrlDisplayed), + ev(OAuthTracePhase.BrowserOpened), + ev(OAuthTracePhase.BinaryExit, { data: { code: 0 } }), + ]; + expect(diagnoseFailure(snap).branchId).toBe('CALLBACK_NEVER_OBSERVED'); + }); + + test('BINARY_ERROR_EXIT when exit code non-zero', () => { + reset(); + const snap = [ + ev(OAuthTracePhase.BinarySpawn), + ev(OAuthTracePhase.BinaryExit, { data: { code: 2, stderrTail: 'oops' } }), + ]; + const r = diagnoseFailure(snap); + expect(r.branchId).toBe('BINARY_ERROR_EXIT'); + expect(r.data['code']).toBe(2); + }); + + test('TOKEN_FILE_MISSING_POST_EXIT when token-missing event present', () => { + reset(); + const snap = [ + ev(OAuthTracePhase.AuthUrlDisplayed), + ev(OAuthTracePhase.BrowserOpened), + ev(OAuthTracePhase.CallbackObservedHeuristic), + ev(OAuthTracePhase.BinaryExit, { data: { code: 0 } }), + ev(OAuthTracePhase.TokenFileMissing), + ]; + expect(diagnoseFailure(snap).branchId).toBe('TOKEN_FILE_MISSING_POST_EXIT'); + }); + + test('TIMEOUT when timeout event present', () => { + reset(); + const snap = [ + ev(OAuthTracePhase.BinarySpawn), + ev(OAuthTracePhase.Timeout, { data: { timeoutMs: 120000 } }), + ]; + const r = diagnoseFailure(snap); + expect(r.branchId).toBe('TIMEOUT'); + expect(r.data['timeoutMs']).toBe(120000); + }); + + test('SESSION_CANCELLED on cancel event', () => { + reset(); + const snap = [ev(OAuthTracePhase.Cancelled)]; + expect(diagnoseFailure(snap).branchId).toBe('SESSION_CANCELLED'); + }); + + test('TOKEN_EXCHANGE_REJECTED via Error code=CALLBACK_REJECTED', () => { + reset(); + const snap = [ + ev(OAuthTracePhase.PasteCallbackSubmitted), + ev(OAuthTracePhase.Error, { + error: { code: 'CALLBACK_REJECTED', message: 'invalid_grant' }, + }), + ]; + const r = diagnoseFailure(snap); + expect(r.branchId).toBe('TOKEN_EXCHANGE_REJECTED'); + expect(r.data['upstreamError']).toBe('invalid_grant'); + }); + + test('PASTE_INVALID from invalid event', () => { + reset(); + const snap = [ + ev(OAuthTracePhase.PasteCallbackPrompted), + ev(OAuthTracePhase.PasteCallbackInvalid, { data: { reason: 'missing_code' } }), + ]; + const r = diagnoseFailure(snap); + expect(r.branchId).toBe('PASTE_INVALID'); + expect(r.data['reason']).toBe('missing_code'); + }); + + test('GEMINI_PLUS_MISSING_CRED from explicit error', () => { + reset(); + const snap = [ + ev(OAuthTracePhase.Error, { + error: { code: 'GEMINI_PLUS_MISSING_CRED', message: 'missing' }, + }), + ]; + expect(diagnoseFailure(snap).branchId).toBe('GEMINI_PLUS_MISSING_CRED'); + }); + + test('AGY_RESPONSIBILITY_DECLINED from explicit error', () => { + reset(); + const snap = [ + ev(OAuthTracePhase.Error, { + error: { code: 'AGY_RESPONSIBILITY_DECLINED', message: 'declined' }, + }), + ]; + expect(diagnoseFailure(snap).branchId).toBe('AGY_RESPONSIBILITY_DECLINED'); + }); + + test('diagnose is pure: same input -> same output, no side-effects', () => { + reset(); + const snap = [ev(OAuthTracePhase.BinarySpawn), ev(OAuthTracePhase.Timeout)]; + const a = diagnoseFailure(snap); + const b = diagnoseFailure(snap); + expect(a).toEqual(b); + // ensure snapshot wasn't mutated + expect(snap).toHaveLength(2); + }); +}); + +describe('formatErrorMessage', () => { + const baseOpts = { + verbose: false, + platform: 'linux' as NodeJS.Platform, + callbackPort: 1455, + provider: 'codex', + }; + + test('UNKNOWN preserves backward-compat 3-bullet feel and ends with verbose hint', () => { + const lines = formatErrorMessage({ branchId: 'UNKNOWN', data: {} }, baseOpts); + expect(lines.some((l) => l.includes('Token not found'))).toBe(true); + expect(lines.some((l) => l.startsWith('Try: ccs codex --auth --verbose'))).toBe(true); + // body lines (excluding trailing remediation) ≤ 5 -> not exploding + expect(lines.length).toBeLessThanOrEqual(6); + }); + + test('CALLBACK_NEVER_OBSERVED includes paste-callback hint with provider', () => { + const lines = formatErrorMessage({ branchId: 'CALLBACK_NEVER_OBSERVED', data: {} }, baseOpts); + expect(lines.some((l) => l.includes('--no-browser'))).toBe(true); + }); + + test('CALLBACK_NEVER_OBSERVED on win32 appends netsh hint', () => { + const lines = formatErrorMessage( + { branchId: 'CALLBACK_NEVER_OBSERVED', data: {} }, + { ...baseOpts, platform: 'win32' } + ); + expect(lines.some((l) => l.includes('netsh advfirewall'))).toBe(true); + }); + + test('contains no emoji and no sensitive keys', () => { + const lines = formatErrorMessage( + { branchId: 'BINARY_ERROR_EXIT', data: { code: 7, stderrTail: 'fail' } }, + baseOpts + ); + const blob = lines.join('\n'); + // No common emoji ranges + expect(/[\u{1F300}-\u{1FAFF}\u{2600}-\u{27BF}]/u.test(blob)).toBe(false); + expect(blob).not.toMatch(/access_token|refresh_token|id_token|client_secret/i); + }); + + test('verbose mode appends trace hint line', () => { + const lines = formatErrorMessage( + { branchId: 'UNKNOWN', data: {} }, + { ...baseOpts, verbose: true } + ); + expect(lines.some((l) => l.includes('--verbose'))).toBe(true); + }); +}); diff --git a/src/cliproxy/auth/__tests__/oauth-trace-recorder.test.ts b/src/cliproxy/auth/__tests__/oauth-trace-recorder.test.ts new file mode 100644 index 00000000..86dc7fc8 --- /dev/null +++ b/src/cliproxy/auth/__tests__/oauth-trace-recorder.test.ts @@ -0,0 +1,128 @@ +import { describe, expect, test } from 'bun:test'; +import { createOAuthTraceRecorder } from '../oauth-trace/trace-recorder'; +import { OAuthTracePhase } from '../oauth-trace/trace-events'; +import { REDACTED_PLACEHOLDER } from '../oauth-trace/redactor'; + +function makeRecorder(verbose = false, lines: string[] = []) { + let t = 1000; + const rec = createOAuthTraceRecorder({ + sessionId: 'sess-1', + provider: 'codex', + verbose, + now: () => t, + verboseOut: (line) => lines.push(line), + }); + return { + rec, + advance(ms: number) { + t += ms; + }, + }; +} + +describe('createOAuthTraceRecorder', () => { + test('records event with sessionId and provider correlation', () => { + const { rec } = makeRecorder(); + rec.record(OAuthTracePhase.BinarySpawn); + const snap = rec.snapshot(); + expect(snap).toHaveLength(1); + expect(snap[0].sessionId).toBe('sess-1'); + expect(snap[0].provider).toBe('codex'); + expect(snap[0].phase).toBe(OAuthTracePhase.BinarySpawn); + }); + + test('phase ordering preserved with monotonic elapsedMs', () => { + const { rec, advance } = makeRecorder(); + rec.record(OAuthTracePhase.PreflightOk); + advance(10); + rec.record(OAuthTracePhase.BinarySpawn); + advance(50); + rec.record(OAuthTracePhase.AuthUrlDisplayed); + const snap = rec.snapshot(); + expect(snap.map((e) => e.phase)).toEqual([ + OAuthTracePhase.PreflightOk, + OAuthTracePhase.BinarySpawn, + OAuthTracePhase.AuthUrlDisplayed, + ]); + expect(snap[0].elapsedMs).toBe(0); + expect(snap[1].elapsedMs).toBe(10); + expect(snap[2].elapsedMs).toBe(60); + }); + + test('memory sink returns full event log via snapshot()', () => { + const { rec } = makeRecorder(); + for (let i = 0; i < 5; i++) { + rec.record(OAuthTracePhase.BinaryStdout, { i }); + } + expect(rec.snapshot()).toHaveLength(5); + }); + + test('verbose sink writes only when verbose=true', () => { + const linesOff: string[] = []; + const { rec: off } = makeRecorder(false, linesOff); + off.record(OAuthTracePhase.BinarySpawn); + expect(linesOff).toHaveLength(0); + + const linesOn: string[] = []; + const { rec: on } = makeRecorder(true, linesOn); + on.record(OAuthTracePhase.BinarySpawn, { port: 1455 }); + expect(linesOn).toHaveLength(1); + expect(linesOn[0]).toMatch(/^\[oauth-trace\] \+0ms binary\.spawn/); + expect(linesOn[0]).toContain('port=1455'); + }); + + test('summary returns counts and lastPhase', () => { + const { rec, advance } = makeRecorder(); + rec.record(OAuthTracePhase.BinaryStdout); + rec.record(OAuthTracePhase.BinaryStdout); + advance(5); + rec.record(OAuthTracePhase.BinaryExit); + const s = rec.summary(); + expect(s.phaseCounts[OAuthTracePhase.BinaryStdout]).toBe(2); + expect(s.phaseCounts[OAuthTracePhase.BinaryExit]).toBe(1); + expect(s.lastPhase).toBe(OAuthTracePhase.BinaryExit); + expect(s.totalMs).toBe(5); + }); + + test('snapshot during in-flight events does not throw and returns copy', () => { + const { rec } = makeRecorder(); + rec.record(OAuthTracePhase.BinarySpawn); + const snap = rec.snapshot(); + rec.record(OAuthTracePhase.BinaryExit); + expect(snap).toHaveLength(1); // earlier snapshot unaffected + expect(rec.snapshot()).toHaveLength(2); + }); + + test('redactor invoked: raw OAuth params do not reach sinks', () => { + const lines: string[] = []; + const { rec } = makeRecorder(true, lines); + rec.record(OAuthTracePhase.AuthUrlDisplayed, { + url: 'https://example.com/auth?code=AUTHCODE_SECRET&state=ST', + access_token: 'AT_LEAK', + }); + const snap = rec.snapshot(); + const blob = JSON.stringify(snap) + '\n' + lines.join('\n'); + expect(blob).not.toContain('AUTHCODE_SECRET'); + expect(blob).not.toContain('AT_LEAK'); + expect(blob).toContain(REDACTED_PLACEHOLDER); + }); + + test('flush() resolves even with no file sink', async () => { + const { rec } = makeRecorder(); + rec.record(OAuthTracePhase.BinaryExit); + await expect(rec.flush()).resolves.toBeUndefined(); + }); + + test('error param surfaces as event.error', () => { + const { rec } = makeRecorder(); + rec.record(OAuthTracePhase.Error, { branch: 'X' }, { code: 'E1', message: 'boom' }); + const snap = rec.snapshot(); + expect(snap[0].error).toEqual({ code: 'E1', message: 'boom' }); + }); + + test('Error instance accepted', () => { + const { rec } = makeRecorder(); + rec.record(OAuthTracePhase.Error, undefined, new Error('plain')); + expect(rec.snapshot()[0].error?.message).toBe('plain'); + }); +}); diff --git a/src/cliproxy/auth/__tests__/oauth-trace-redactor.test.ts b/src/cliproxy/auth/__tests__/oauth-trace-redactor.test.ts new file mode 100644 index 00000000..beec9578 --- /dev/null +++ b/src/cliproxy/auth/__tests__/oauth-trace-redactor.test.ts @@ -0,0 +1,270 @@ +import { describe, expect, test } from 'bun:test'; +import { + redactString, + redactUrl, + redactJsonShallow, + redactBearer, + REDACTED_PLACEHOLDER, +} from '../oauth-trace/redactor'; +import { createMemorySink, MEMORY_SINK_MAX_EVENTS } from '../oauth-trace/sink-memory'; + +describe('redactString', () => { + test('redacts code= query value', () => { + const out = redactString('http://localhost:1455/cb?code=AUTHCODE_SECRET&foo=bar'); + expect(out).not.toContain('AUTHCODE_SECRET'); + expect(out).toContain(`code=${REDACTED_PLACEHOLDER}`); + expect(out).toContain('foo=bar'); + }); + + test('redacts state= query value', () => { + const out = redactString('?state=STATE_SECRET&x=1'); + expect(out).not.toContain('STATE_SECRET'); + expect(out).toContain(`state=${REDACTED_PLACEHOLDER}`); + }); + + test('redacts access_token, refresh_token, id_token query values', () => { + const s = '?access_token=A&refresh_token=B&id_token=C'; + const out = redactString(s); + expect(out).not.toContain('access_token=A'); + expect(out).not.toContain('refresh_token=B'); + expect(out).not.toContain('id_token=C'); + }); + + test('redacts bearer header value', () => { + expect(redactString('Authorization: Bearer abc.def.ghi')).toContain( + `Bearer ${REDACTED_PLACEHOLDER}` + ); + }); + + test('preserves non-sensitive params and host/path', () => { + const out = redactString('https://example.com/auth/cb?code=X&client_id=public'); + expect(out).toContain('example.com'); + expect(out).toContain('/auth/cb'); + expect(out).toContain('client_id=public'); + }); + + test('idempotent: redacting twice == once', () => { + const once = redactString('?code=X&state=Y'); + expect(redactString(once)).toBe(once); + }); + + test('empty input passthrough', () => { + expect(redactString('')).toBe(''); + }); +}); + +describe('redactUrl', () => { + test('redacts known sensitive params via URL parser', () => { + const out = redactUrl('https://example.com/cb?code=AUTHCODE&state=ST&keep=1'); + expect(out).toContain(`code=${encodeURIComponent(REDACTED_PLACEHOLDER)}`); + expect(out).toContain(`state=${encodeURIComponent(REDACTED_PLACEHOLDER)}`); + expect(out).toContain('keep=1'); + expect(out).not.toContain('AUTHCODE'); + }); + + test('falls back gracefully on invalid URL', () => { + expect(redactUrl('not a url ?code=X')).toContain(REDACTED_PLACEHOLDER); + }); +}); + +describe('redactJsonShallow', () => { + test('replaces sensitive top-level keys', () => { + const out = redactJsonShallow({ + access_token: 'AT', + refresh_token: 'RT', + id_token: 'IT', + client_secret: 'CS', + keep: 'visible', + }); + expect(out['access_token']).toBe(REDACTED_PLACEHOLDER); + expect(out['refresh_token']).toBe(REDACTED_PLACEHOLDER); + expect(out['id_token']).toBe(REDACTED_PLACEHOLDER); + expect(out['client_secret']).toBe(REDACTED_PLACEHOLDER); + expect(out['keep']).toBe('visible'); + }); + + test('redacts string values for sensitive params inside string fields', () => { + const out = redactJsonShallow({ url: 'https://x/cb?code=SECRET' }); + expect(String(out['url'])).not.toContain('SECRET'); + }); + + test('recurses into nested plain objects', () => { + const out = redactJsonShallow({ + headers: { Authorization: 'Bearer XYZ', host: 'a' }, + }); + const headers = out['headers'] as Record; + expect(headers['Authorization']).toBe(REDACTED_PLACEHOLDER); + expect(headers['host']).toBe('a'); + }); + + test('case-insensitive key match', () => { + const out = redactJsonShallow({ Access_Token: 'X', AUTHORIZATION: 'Y' }); + expect(out['Access_Token']).toBe(REDACTED_PLACEHOLDER); + expect(out['AUTHORIZATION']).toBe(REDACTED_PLACEHOLDER); + }); +}); + +describe('redactBearer', () => { + test('replaces bearer value preserving prefix', () => { + expect(redactBearer('Bearer abc.def.ghi')).toBe(`Bearer ${REDACTED_PLACEHOLDER}`); + }); +}); + +// ---- adversarial / edge-case coverage (findings #1-3, #4, #7) ---- + +describe('redactUrl — fragment leak (finding #1)', () => { + test('redacts code in fragment — first param after #', () => { + const out = redactUrl('https://x/cb#code=SECRET&state=X'); + expect(out).not.toContain('SECRET'); + expect(out).not.toContain('state=X'); + }); + + test('redacts access_token in fragment', () => { + const out = redactUrl('https://x/cb#access_token=AT&token_type=bearer'); + expect(out).not.toContain('AT'); + expect(out).toContain('token_type=bearer'); + }); + + test('non-sensitive fragment params preserved', () => { + const out = redactUrl('https://x/cb#section=1&code=S'); + expect(out).toContain('section=1'); + expect(out).not.toContain('=S'); + }); + + test('Google OAuth fragment flow (real shape)', () => { + const url = + 'https://accounts.google.com/o/oauth2/auth/oauthchooseaccount#access_token=ya29.secret&token_type=Bearer&expires_in=3599'; + const out = redactUrl(url); + expect(out).not.toContain('ya29.secret'); + expect(out).toContain('token_type=Bearer'); + }); +}); + +describe('redactUrl — URL-encoded key bypass (finding #2)', () => { + test('redacts %63%6F%64%65 (= "code") key', () => { + // %63%6F%64%65 is "code" percent-encoded + const out = redactUrl('https://x/cb?%63%6F%64%65=SECRET'); + expect(out).not.toContain('SECRET'); + }); + + test('redacts %73%74%61%74%65 (= "state") key', () => { + const out = redactUrl('https://x/cb?%73%74%61%74%65=STATEVAL'); + expect(out).not.toContain('STATEVAL'); + }); +}); + +describe('redactJsonShallow — array passthrough (finding #3)', () => { + test('redacts access_token inside array of objects', () => { + const out = redactJsonShallow({ tokens: [{ access_token: 'AT', scope: 'read' }] }); + const tokens = out['tokens'] as Array>; + expect(tokens[0]['access_token']).toBe(REDACTED_PLACEHOLDER); + expect(tokens[0]['scope']).toBe('read'); + }); + + test('nested arrays of token objects', () => { + const out = redactJsonShallow({ + batches: [{ tokens: [{ refresh_token: 'RT' }] }], + }); + const batches = out['batches'] as Array>; + const inner = (batches[0]['tokens'] as Array>)[0]; + // Only one level of array recursion; inner object is recursed as plain obj + expect(inner['refresh_token']).toBe(REDACTED_PLACEHOLDER); + }); + + test('mixed-case key Code redacted', () => { + const out = redactJsonShallow({ Code: 'abc', CODE: 'xyz' }); + expect(out['Code']).toBe(REDACTED_PLACEHOLDER); + expect(out['CODE']).toBe(REDACTED_PLACEHOLDER); + }); + + test('string value with url-embedded code is redacted', () => { + const out = redactJsonShallow({ log: 'callback?code=SECRET&state=ST' }); + expect(String(out['log'])).not.toContain('SECRET'); + }); +}); + +describe('PKCE / device-flow keys (finding #4)', () => { + test('redactUrl redacts code_verifier', () => { + const out = redactUrl('https://x/token?code_verifier=VERIFIER&grant_type=pkce'); + expect(out).not.toContain('VERIFIER'); + expect(out).toContain('grant_type=pkce'); + }); + + test('redactUrl redacts device_code', () => { + const out = redactUrl('https://x/token?device_code=DC123'); + expect(out).not.toContain('DC123'); + }); + + test('redactUrl redacts assertion', () => { + const out = redactUrl('https://x/token?assertion=JWT_VAL'); + expect(out).not.toContain('JWT_VAL'); + }); + + test('redactUrl redacts subject_token', () => { + const out = redactUrl('https://x/token?subject_token=ST_VAL'); + expect(out).not.toContain('ST_VAL'); + }); + + test('redactString redacts code_verifier in raw string', () => { + const out = redactString('?code_verifier=MY_VERIFIER&other=1'); + expect(out).not.toContain('MY_VERIFIER'); + expect(out).toContain('other=1'); + }); +}); + +describe('createMemorySink — bounded ring buffer (finding #6)', () => { + test('default capacity is MEMORY_SINK_MAX_EVENTS (1000)', () => { + expect(MEMORY_SINK_MAX_EVENTS).toBe(1000); + }); + + test('older events dropped when capacity exceeded', () => { + const sink = createMemorySink(3); + const makeEvent = (i: number) => + ({ + sessionId: 's', + provider: 'p', + phase: `phase.${i}` as never, + ts: i, + elapsedMs: i, + }) as never; + + sink.write(makeEvent(1)); + sink.write(makeEvent(2)); + sink.write(makeEvent(3)); + sink.write(makeEvent(4)); // should drop event 1 + + const snap = sink.snapshot(); + expect(snap).toHaveLength(3); + expect(snap[0].ts).toBe(2); + expect(snap[2].ts).toBe(4); + }); + + test('droppedCount tracks number of dropped events', () => { + const sink = createMemorySink(2); + const makeEvent = (i: number) => + ({ + sessionId: 's', + provider: 'p', + phase: 'p' as never, + ts: i, + elapsedMs: i, + }) as never; + + sink.write(makeEvent(1)); + sink.write(makeEvent(2)); + expect(sink.droppedCount()).toBe(0); + sink.write(makeEvent(3)); + expect(sink.droppedCount()).toBe(1); + sink.write(makeEvent(4)); + expect(sink.droppedCount()).toBe(2); + }); + + test('snapshot returns copy — mutations do not affect buffer', () => { + const sink = createMemorySink(5); + const ev = { sessionId: 's', provider: 'p', phase: 'x' as never, ts: 1, elapsedMs: 0 }; + sink.write(ev as never); + const snap = sink.snapshot(); + snap.pop(); + expect(sink.snapshot()).toHaveLength(1); + }); +}); diff --git a/src/cliproxy/auth/__tests__/oauth-trace-sink-file.test.ts b/src/cliproxy/auth/__tests__/oauth-trace-sink-file.test.ts new file mode 100644 index 00000000..15e03901 --- /dev/null +++ b/src/cliproxy/auth/__tests__/oauth-trace-sink-file.test.ts @@ -0,0 +1,94 @@ +import { describe, expect, test, beforeEach, afterEach } from 'bun:test'; +import * as fs from 'fs'; +import * as path from 'path'; +import * as os from 'os'; +import { createFileSink } from '../oauth-trace/sink-file'; +import { OAuthTracePhase, type OAuthTraceEvent } from '../oauth-trace/trace-events'; + +let tmpDir: string; + +function makeEvent(over: Partial = {}): OAuthTraceEvent { + return { + sessionId: 'sess-1', + provider: 'codex', + phase: OAuthTracePhase.BinarySpawn, + ts: 1000, + elapsedMs: 0, + ...over, + }; +} + +beforeEach(() => { + tmpDir = fs.mkdtempSync(path.join(os.tmpdir(), 'oauth-trace-test-')); +}); + +afterEach(() => { + fs.rmSync(tmpDir, { recursive: true, force: true }); +}); + +describe('createFileSink', () => { + test('writes one JSONL line per event', () => { + const fixed = new Date(2026, 4, 10); + const sink = createFileSink({ dir: tmpDir, now: () => fixed }); + sink.write(makeEvent({ phase: OAuthTracePhase.BinarySpawn })); + sink.write(makeEvent({ phase: OAuthTracePhase.BinaryExit, elapsedMs: 5 })); + const file = path.join(tmpDir, 'oauth-20260510.log'); + const lines = fs.readFileSync(file, 'utf8').trim().split('\n'); + expect(lines).toHaveLength(2); + const parsed1 = JSON.parse(lines[0]); + expect(parsed1.phase).toBe(OAuthTracePhase.BinarySpawn); + expect(parsed1.sessionId).toBe('sess-1'); + expect(parsed1.provider).toBe('codex'); + }); + + test('file mode is 0600 (user-only)', () => { + const fixed = new Date(2026, 4, 10); + const sink = createFileSink({ dir: tmpDir, now: () => fixed }); + sink.write(makeEvent()); + const file = path.join(tmpDir, 'oauth-20260510.log'); + const mode = fs.statSync(file).mode & 0o777; + expect(mode).toBe(0o600); + }); + + test('rotates by date — different day yields different file', () => { + let day = new Date(2026, 4, 10); + const sink = createFileSink({ dir: tmpDir, now: () => day }); + sink.write(makeEvent({ sessionId: 'a' })); + day = new Date(2026, 4, 11); + sink.write(makeEvent({ sessionId: 'b' })); + expect(fs.existsSync(path.join(tmpDir, 'oauth-20260510.log'))).toBe(true); + expect(fs.existsSync(path.join(tmpDir, 'oauth-20260511.log'))).toBe(true); + }); + + test('write failure does not throw and notifies once', () => { + const errors: string[] = []; + const badDir = path.join(tmpDir, 'nonexistent', 'a', 'b'); + // Force mkdir failure by simulating EROFS via permission-denied path + // (we bypass mkdir error by making `dir` a file) + fs.writeFileSync(path.join(tmpDir, 'as_file'), 'x'); + const sink = createFileSink({ + dir: path.join(tmpDir, 'as_file', 'sub'), + onError: (msg) => errors.push(msg), + }); + expect(() => sink.write(makeEvent())).not.toThrow(); + expect(errors.length).toBeGreaterThanOrEqual(1); + void badDir; + }); + + test('flush resolves cleanly', async () => { + const sink = createFileSink({ dir: tmpDir }); + sink.write(makeEvent()); + await expect(sink.flush?.()).resolves.toBeUndefined(); + }); + + test('concurrent recorders with separate sessionIds both land in file', () => { + const fixed = new Date(2026, 4, 10); + const sink = createFileSink({ dir: tmpDir, now: () => fixed }); + sink.write(makeEvent({ sessionId: 'A' })); + sink.write(makeEvent({ sessionId: 'B' })); + const file = path.join(tmpDir, 'oauth-20260510.log'); + const lines = fs.readFileSync(file, 'utf8').trim().split('\n'); + const ids = lines.map((l) => JSON.parse(l).sessionId).sort(); + expect(ids).toEqual(['A', 'B']); + }); +}); diff --git a/src/cliproxy/auth/oauth-process.ts b/src/cliproxy/auth/oauth-process.ts index 2557fcb7..10c9a806 100644 --- a/src/cliproxy/auth/oauth-process.ts +++ b/src/cliproxy/auth/oauth-process.ts @@ -42,6 +42,12 @@ import { unregisterAuthSession, authSessionEvents, } from '../auth/auth-session-manager'; +import { createOAuthTraceRecorder, OAuthTracePhase, type OAuthTraceRecorder } from './oauth-trace'; +import { redactString } from './oauth-trace/redactor'; +import { createFileSink } from './oauth-trace/sink-file'; +import { diagnoseFailure, formatErrorMessage } from './oauth-trace/diagnose-failure'; +import * as path from 'path'; +import { getCcsDir } from '../../utils/config-manager'; /** Options for OAuth process execution */ export interface OAuthProcessOptions { @@ -575,7 +581,8 @@ async function handleTokenNotFound( nickname: string | undefined, expectedAccountId: string | undefined, verbose: boolean, - failureReason?: string + failureReason?: string, + trace?: OAuthTraceRecorder ): Promise { console.log(''); @@ -611,6 +618,22 @@ async function handleTokenNotFound( return null; } + // Branch-specific diagnosis when trace recorder is wired (Phase 7). + if (trace) { + const diagnosis = diagnoseFailure(trace.snapshot()); + if (diagnosis.branchId !== 'UNKNOWN') { + console.log(fail('Authentication failed')); + const lines = formatErrorMessage(diagnosis, { + verbose, + platform: process.platform, + callbackPort, + provider, + }); + for (const line of lines) console.log(line); + return null; + } + } + console.log(fail('Token not found after authentication')); console.log(''); console.log('The browser showed success but callback was not received.'); @@ -698,10 +721,22 @@ export function executeOAuthProcess(options: OAuthProcessOptions): Promise | null = null; + // Mutable ref so cleanup/handleCancel can flush trace even though `trace` + // is assigned after them. DEFERRED: per-event syscall throttling. + let traceRef: OAuthTraceRecorder | null = null; + // H5: Signal handling - properly kill child process on SIGINT/SIGTERM // H8: Also clear stdinKeepalive interval to prevent memory leak const cleanup = () => { if (stdinKeepalive) clearInterval(stdinKeepalive); + if (traceRef) { + try { + traceRef.record(OAuthTracePhase.Cancelled, { reason: 'signal' }); + void traceRef.flush(); + } catch { + // never block shutdown on trace errors + } + } if (authProcess && authProcess.exitCode === null) { killWithEscalation(authProcess); } @@ -724,6 +759,25 @@ export function executeOAuthProcess(options: OAuthProcessOptions): Promise { if (cancelledSessionId === state.sessionId && authProcess && authProcess.exitCode === null) { log('Session cancelled externally'); + if (traceRef) { + try { + traceRef.record(OAuthTracePhase.Cancelled, { reason: 'external' }); + void traceRef.flush(); + } catch { + // never block shutdown on trace errors + } + } killWithEscalation(authProcess); } }; @@ -754,13 +816,30 @@ export function executeOAuthProcess(options: OAuthProcessOptions): Promise { - await handleStdout(data.toString(), state, options, authProcess, log); + const out = data.toString(); + const wasUrlDisplayed = state.urlDisplayed; + const wasBrowserOpened = state.browserOpened; + await handleStdout(out, state, options, authProcess, log); + if (!wasUrlDisplayed && state.urlDisplayed) { + trace.record(OAuthTracePhase.AuthUrlDisplayed, {}); + } + if (!wasBrowserOpened && state.browserOpened) { + trace.record(OAuthTracePhase.BrowserOpened, { port: callbackPort }); + // CLIProxyAPI emits "Callback server listening" when bind succeeds; treat as + // best-available signal that the loopback path is reachable. This is a heuristic. + trace.record(OAuthTracePhase.CallbackObservedHeuristic, { port: callbackPort }); + } + // Capture redacted snippet (cap at 200 chars; high-frequency lines accepted as data). + const snippet = redactString(out.trim().slice(0, 200)); + if (snippet) trace.record(OAuthTracePhase.BinaryStdout, { snippet }); }); authProcess.stderr?.on('data', async (data: Buffer) => { const output = data.toString(); state.stderrData += output; log(`stderr: ${output.trim()}`); + const snippet = redactString(output.trim().slice(0, 200)); + if (snippet) trace.record(OAuthTracePhase.BinaryStderr, { snippet }); if (headless && !state.urlDisplayed) { displayUrlFromStderr(output, state, oauthConfig); } @@ -828,6 +907,8 @@ export function executeOAuthProcess(options: OAuthProcessOptions): Promise; +} + +const BROWSER_OPEN_HEURISTIC_MS = 5000; + +/** + * Pure function: read a recorder snapshot and decide which failure branch fits best. + * No side effects, no console writes. + */ +export function diagnoseFailure(snapshot: OAuthTraceEvent[]): DiagnosisResult { + if (snapshot.length === 0) { + return { branchId: 'UNKNOWN', data: {} }; + } + + const has = (phase: OAuthTracePhase) => snapshot.some((e) => e.phase === phase); + const last = (phase: OAuthTracePhase) => [...snapshot].reverse().find((e) => e.phase === phase); + const lastError = [...snapshot].reverse().find((e) => e.phase === OAuthTracePhase.Error); + + // Provider gate aborts (highest priority — explicit error code) + if (lastError?.error?.code === 'GEMINI_PLUS_MISSING_CRED') { + return { branchId: 'GEMINI_PLUS_MISSING_CRED', data: lastError.data ?? {} }; + } + if (lastError?.error?.code === 'AGY_RESPONSIBILITY_DECLINED') { + return { branchId: 'AGY_RESPONSIBILITY_DECLINED', data: lastError.data ?? {} }; + } + if (lastError?.error?.code === 'CALLBACK_REJECTED') { + return { + branchId: 'TOKEN_EXCHANGE_REJECTED', + data: { upstreamError: lastError.error.message, ...(lastError.data ?? {}) }, + }; + } + + if (has(OAuthTracePhase.PasteCallbackInvalid)) { + const ev = last(OAuthTracePhase.PasteCallbackInvalid); + return { branchId: 'PASTE_INVALID', data: ev?.data ?? {} }; + } + + if (has(OAuthTracePhase.Cancelled)) { + return { branchId: 'SESSION_CANCELLED', data: {} }; + } + + if (has(OAuthTracePhase.Timeout)) { + const ev = last(OAuthTracePhase.Timeout); + return { branchId: 'TIMEOUT', data: ev?.data ?? {} }; + } + + const exitEv = last(OAuthTracePhase.BinaryExit); + if (exitEv) { + const code = (exitEv.data?.code as number | undefined) ?? null; + if (code !== null && code !== 0) { + return { + branchId: 'BINARY_ERROR_EXIT', + data: { + code, + stderrTail: exitEv.data?.stderrTail ?? '', + }, + }; + } + } + + // exit=0 (or no exit) plus token-file states + if (has(OAuthTracePhase.TokenFileMissing)) { + return { branchId: 'TOKEN_FILE_MISSING_POST_EXIT', data: {} }; + } + + if (!has(OAuthTracePhase.AuthUrlDisplayed)) { + return { branchId: 'URL_NOT_DISPLAYED', data: {} }; + } + + // URL was displayed: did browser open within heuristic window? + if (!has(OAuthTracePhase.BrowserOpened)) { + const urlEv = last(OAuthTracePhase.AuthUrlDisplayed); + const lastTs = snapshot[snapshot.length - 1].ts; + if (urlEv && lastTs - urlEv.ts >= BROWSER_OPEN_HEURISTIC_MS) { + return { branchId: 'BROWSER_NOT_OPENED', data: {} }; + } + } + + if ( + has(OAuthTracePhase.BrowserOpened) && + !has(OAuthTracePhase.CallbackObservedHeuristic) && + has(OAuthTracePhase.BinaryExit) + ) { + return { branchId: 'CALLBACK_NEVER_OBSERVED', data: {} }; + } + + return { branchId: 'UNKNOWN', data: {} }; +} + +export interface FormatErrorOptions { + verbose: boolean; + platform: NodeJS.Platform; + callbackPort: number | null; + provider: string; +} + +/** + * Map a diagnosed branch to user-facing message lines (ASCII only, no emojis). + * Always ends with a concrete next-step command. + */ +export function formatErrorMessage(result: DiagnosisResult, opts: FormatErrorOptions): string[] { + const { branchId, data } = result; + const { provider, callbackPort, platform, verbose } = opts; + const lines: string[] = []; + + switch (branchId) { + case 'URL_NOT_DISPLAYED': + lines.push('OAuth URL was never produced.'); + lines.push('The CLIProxy binary may have failed to start or exited too early.'); + lines.push(`Try: ccs ${provider} --auth --verbose`); + break; + + case 'BROWSER_NOT_OPENED': + lines.push('OAuth URL was displayed but the browser did not open.'); + lines.push('Copy the URL above and open it manually in any browser.'); + break; + + case 'CALLBACK_NEVER_OBSERVED': + lines.push( + `Browser completed login but no callback reached localhost:${callbackPort ?? '?'}.` + ); + lines.push('Common cause: firewall, antivirus, or browser on a different machine.'); + lines.push(`Try paste-callback mode: ccs ${provider} --auth --no-browser`); + if (platform === 'win32' && callbackPort) { + lines.push('On Windows, try as Administrator:'); + lines.push( + ` netsh advfirewall firewall add rule name="CCS OAuth" dir=in action=allow protocol=TCP localport=${callbackPort}` + ); + } + break; + + case 'BINARY_ERROR_EXIT': { + const code = (data['code'] as number | undefined) ?? '?'; + lines.push(`CLIProxy binary exited with code ${code}.`); + const tail = String(data['stderrTail'] ?? '').trim(); + if (tail) lines.push(` ${tail}`); + lines.push(`Try: ccs ${provider} --auth --verbose`); + break; + } + + case 'TOKEN_FILE_MISSING_POST_EXIT': + lines.push('Authentication appeared to succeed but no token file was created.'); + lines.push('Update CLIProxy and retry: ccs update'); + break; + + case 'TIMEOUT': { + const min = data['timeoutMs'] ? Math.round((data['timeoutMs'] as number) / 60000) : '?'; + lines.push(`OAuth flow timed out after ${min} minutes.`); + lines.push(`Re-run and complete login faster: ccs ${provider} --auth`); + break; + } + + case 'SESSION_CANCELLED': + lines.push('OAuth flow was cancelled.'); + break; + + case 'TOKEN_EXCHANGE_REJECTED': + lines.push( + `Token exchange rejected by provider: ${String(data['upstreamError'] ?? 'unknown')}.` + ); + lines.push(`Try: ccs ${provider} --auth --verbose`); + break; + + case 'PASTE_INVALID': + lines.push(`Pasted callback URL invalid: ${String(data['reason'] ?? 'unknown')}.`); + lines.push('Re-run and paste the full URL after browser login.'); + break; + + case 'GEMINI_PLUS_MISSING_CRED': + lines.push('Gemini-plus OAuth credentials missing.'); + lines.push('See: docs/providers/gemini.md'); + break; + + case 'AGY_RESPONSIBILITY_DECLINED': + lines.push('Antigravity responsibility prompt was declined.'); + lines.push(`Re-run and accept to proceed: ccs ${provider} --auth`); + break; + + case 'UNKNOWN': + default: + lines.push('Token not found after authentication'); + lines.push('Common causes:'); + lines.push(' 1. OAuth session timed out'); + lines.push(' 2. Callback server could not receive the redirect'); + lines.push(' 3. Browser did not redirect to localhost properly'); + lines.push(`Try: ccs ${provider} --auth --verbose`); + break; + } + + if (verbose) { + lines.push(''); + lines.push('Run with --verbose for the trace summary.'); + } + + return lines; +} diff --git a/src/cliproxy/auth/oauth-trace/index.ts b/src/cliproxy/auth/oauth-trace/index.ts new file mode 100644 index 00000000..d81164bf --- /dev/null +++ b/src/cliproxy/auth/oauth-trace/index.ts @@ -0,0 +1,13 @@ +export { OAuthTracePhase, type OAuthTraceEvent, type OAuthTraceSink } from './trace-events'; +export { + createOAuthTraceRecorder, + type OAuthTraceRecorder, + type OAuthTraceRecorderOptions, +} from './trace-recorder'; +export { + redactString, + redactUrl, + redactJsonShallow, + redactBearer, + REDACTED_PLACEHOLDER, +} from './redactor'; diff --git a/src/cliproxy/auth/oauth-trace/redactor.ts b/src/cliproxy/auth/oauth-trace/redactor.ts new file mode 100644 index 00000000..328d9744 --- /dev/null +++ b/src/cliproxy/auth/oauth-trace/redactor.ts @@ -0,0 +1,119 @@ +/** + * OAuth secret redactor — single choke point. + * + * Every value reaching any sink passes through these helpers first. + * Adding a new sensitive key here is the only place it has to change. + * + * DEFERRED: per-event syscall throttling; fsync / file-size cap on file sink. + */ + +const SENSITIVE_QUERY_KEYS = [ + 'code', + 'state', + 'access_token', + 'refresh_token', + 'id_token', + 'client_secret', + 'authorization', + // PKCE / device-flow / assertion keys + 'code_verifier', + 'device_code', + 'assertion', + 'subject_token', +] as const; + +const SENSITIVE_OBJECT_KEYS = new Set( + SENSITIVE_QUERY_KEYS.map((k) => k.toLowerCase()).concat(['authorization', 'bearer', 'token']) +); + +const REDACTED = '***REDACTED***'; + +/** + * Matches sensitive keys in query strings, fragments, and standard params. + * Lookbehind covers: `?`, `&`, `#`, and `&#` (fragment-then-amp) delimiters. + * Keys are decoded before matching to catch URL-encoded bypass attempts. + */ +const QUERY_PARAM_REGEX = new RegExp( + `(?<=[?&#])(${SENSITIVE_QUERY_KEYS.join('|')})=[^&#\\s]+`, + 'gi' +); + +const BEARER_REGEX = /Bearer\s+[A-Za-z0-9._\-~+/=]+/gi; + +/** Redact sensitive query-param values inside any string. Idempotent. */ +export function redactString(s: string): string { + if (!s) return s; + return s + .replace(QUERY_PARAM_REGEX, (_full, key) => `${key}=${REDACTED}`) + .replace(BEARER_REGEX, `Bearer ${REDACTED}`); +} + +/** Redact a parsed URL by name; returns redacted href or original on parse error. */ +export function redactUrl(u: string): string { + try { + const url = new URL(u); + + // Redact query params — URL parser already decoded keys, compare decoded. + for (const key of SENSITIVE_QUERY_KEYS) { + if (url.searchParams.has(key)) url.searchParams.set(key, REDACTED); + } + // Also catch URL-encoded key names that URL.searchParams may not normalise + // (e.g. `?%63%6F%64%65=SECRET`). Decode all keys and re-check. + for (const [rawKey, rawVal] of [...url.searchParams.entries()]) { + const decoded = decodeURIComponent(rawKey).toLowerCase(); + if ( + (SENSITIVE_OBJECT_KEYS.has(decoded) || SENSITIVE_QUERY_KEYS.includes(decoded as never)) && + rawVal !== REDACTED + ) { + url.searchParams.set(rawKey, REDACTED); + } + } + + // Redact fragment — strip leading `#`, prepend `?` so QUERY_PARAM_REGEX + // matches the first param (lookbehind requires `?`, `&`, or `#`). + if (url.hash) { + const bare = url.hash.slice(1); // remove leading '#' + const fakeQuery = `?${bare}`; + const redacted = redactString(fakeQuery); + url.hash = redacted.slice(1); // put back without the fake '?' + } + + return url.toString(); + } catch { + return redactString(u); + } +} + +/** + * Shallow-redact a plain object. Returns a new object; original is not mutated. + * Arrays are recursed so token arrays (e.g. `{tokens:[{access_token:'AT'}]}`) + * do not bypass redaction. + */ +export function redactJsonShallow(input: Record): Record { + const out: Record = {}; + for (const [key, value] of Object.entries(input)) { + if (SENSITIVE_OBJECT_KEYS.has(key.toLowerCase())) { + out[key] = REDACTED; + } else if (typeof value === 'string') { + out[key] = redactString(value); + } else if (Array.isArray(value)) { + out[key] = value.map((item) => + item && typeof item === 'object' && !Array.isArray(item) + ? redactJsonShallow(item as Record) + : item + ); + } else if (value && typeof value === 'object') { + out[key] = redactJsonShallow(value as Record); + } else { + out[key] = value; + } + } + return out; +} + +/** Redact an Authorization header value. */ +export function redactBearer(header: string): string { + return header.replace(BEARER_REGEX, `Bearer ${REDACTED}`); +} + +export const REDACTED_PLACEHOLDER = REDACTED; diff --git a/src/cliproxy/auth/oauth-trace/sink-file.ts b/src/cliproxy/auth/oauth-trace/sink-file.ts new file mode 100644 index 00000000..1e3e5e39 --- /dev/null +++ b/src/cliproxy/auth/oauth-trace/sink-file.ts @@ -0,0 +1,84 @@ +import * as fs from 'fs'; +import * as path from 'path'; +import { OAuthTraceEvent, OAuthTraceSink } from './trace-events'; + +/** + * Append-mode JSONL file sink. Off by default; enabled when callers pass an instance. + * + * - File path: `${dir}/oauth-YYYYMMDD.log` (date from `now()` per write call). + * - Permissions: dir 0o700, file 0o600 (user-only). World-readable would leak machine info. + * - Failure-tolerant: if write fails (disk full, perm denied), logs once to stderr and + * keeps dropping events silently — sink must never throw out of `write()`. + */ +export interface FileSinkOptions { + dir: string; + /** Test seam — defaults to `() => new Date()`. */ + now?: () => Date; + /** Test seam — error notifier (defaults to one-shot stderr write). */ + onError?: (msg: string) => void; +} + +export function createFileSink(options: FileSinkOptions): OAuthTraceSink { + const now = options.now ?? (() => new Date()); + let warned = false; + const onError = + options.onError ?? + ((msg: string) => { + if (!warned) { + warned = true; + process.stderr.write(`[oauth-trace] file sink disabled: ${msg}\n`); + } + }); + + let cachedDate: string | null = null; + + function ensureDir(): void { + fs.mkdirSync(options.dir, { recursive: true, mode: 0o700 }); + } + + function dateStr(d: Date): string { + const yyyy = d.getFullYear().toString().padStart(4, '0'); + const mm = (d.getMonth() + 1).toString().padStart(2, '0'); + const dd = d.getDate().toString().padStart(2, '0'); + return `${yyyy}${mm}${dd}`; + } + + function pathForToday(): string { + const ds = dateStr(now()); + cachedDate = ds; + return path.join(options.dir, `oauth-${ds}.log`); + } + + function appendOne(event: OAuthTraceEvent): void { + const file = pathForToday(); + const line = JSON.stringify(event) + '\n'; + let fd: number | null = null; + try { + ensureDir(); + fd = fs.openSync(file, 'a', 0o600); + fs.writeSync(fd, line); + } finally { + if (fd !== null) { + try { + fs.closeSync(fd); + } catch { + // ignore + } + } + } + } + + return { + write(event) { + try { + appendOne(event); + } catch (err) { + onError((err as Error).message); + } + }, + async flush() { + // appendSync paths are flushed per-write; no buffer to drain. + void cachedDate; + }, + }; +} diff --git a/src/cliproxy/auth/oauth-trace/sink-memory.ts b/src/cliproxy/auth/oauth-trace/sink-memory.ts new file mode 100644 index 00000000..6a98b773 --- /dev/null +++ b/src/cliproxy/auth/oauth-trace/sink-memory.ts @@ -0,0 +1,31 @@ +import { OAuthTraceEvent, OAuthTraceSink } from './trace-events'; + +/** Default ring-buffer capacity. Keeps latest N events; oldest are dropped. */ +export const MEMORY_SINK_MAX_EVENTS = 1000; + +/** + * In-memory ring buffer sink. Used for diagnose-failure analysis after a flow ends. + * Caps at MAX_EVENTS to bound memory; oldest are dropped when full. + * `droppedCount` tracks how many events were discarded so callers know data loss occurred. + */ +export function createMemorySink( + maxEvents = MEMORY_SINK_MAX_EVENTS +): OAuthTraceSink & { snapshot(): OAuthTraceEvent[]; droppedCount(): number } { + const events: OAuthTraceEvent[] = []; + let dropped = 0; + return { + write(event) { + if (events.length >= maxEvents) { + events.shift(); + dropped++; + } + events.push(event); + }, + snapshot() { + return events.slice(); + }, + droppedCount() { + return dropped; + }, + }; +} diff --git a/src/cliproxy/auth/oauth-trace/sink-verbose-stdout.ts b/src/cliproxy/auth/oauth-trace/sink-verbose-stdout.ts new file mode 100644 index 00000000..b2275453 --- /dev/null +++ b/src/cliproxy/auth/oauth-trace/sink-verbose-stdout.ts @@ -0,0 +1,42 @@ +import { OAuthTraceSink } from './trace-events'; + +/** + * Verbose stdout sink. Writes one ASCII line per event when verbose=true. + * Format: `[oauth-trace] +{elapsedMs}ms {phase} {key=val ...}` + * No emojis (CCS terminal rule). Goes to stderr to avoid mingling with normal stdout. + */ +export function createVerboseStdoutSink(opts: { + enabled: boolean; + out?: (line: string) => void; +}): OAuthTraceSink { + const out = opts.out ?? ((line: string) => process.stderr.write(line + '\n')); + return { + write(event) { + if (!opts.enabled) return; + const parts: string[] = []; + parts.push(`[oauth-trace] +${event.elapsedMs}ms ${event.phase}`); + if (event.data) { + for (const [k, v] of Object.entries(event.data)) { + if (v === undefined) continue; + parts.push(`${k}=${formatValue(v)}`); + } + } + if (event.error) { + parts.push(`error_code=${event.error.code ?? 'unknown'}`); + parts.push(`error_msg="${event.error.message.replace(/"/g, "'")}"`); + } + out(parts.join(' ')); + }, + }; +} + +function formatValue(v: unknown): string { + if (v === null) return 'null'; + if (typeof v === 'string') return v.includes(' ') ? `"${v.replace(/"/g, "'")}"` : v; + if (typeof v === 'number' || typeof v === 'boolean') return String(v); + try { + return JSON.stringify(v); + } catch { + return '[unserializable]'; + } +} diff --git a/src/cliproxy/auth/oauth-trace/trace-events.ts b/src/cliproxy/auth/oauth-trace/trace-events.ts new file mode 100644 index 00000000..b7671d71 --- /dev/null +++ b/src/cliproxy/auth/oauth-trace/trace-events.ts @@ -0,0 +1,63 @@ +/** + * OAuth trace event taxonomy. + * + * Single source of truth for phase IDs that flow through the OAuth pipeline. + * Additive only — never remove or renumber. + */ + +export enum OAuthTracePhase { + // Pre-flight + PreflightStart = 'preflight.start', + PreflightOk = 'preflight.ok', + PreflightPortBlocked = 'preflight.port_blocked', + + // Binary process lifecycle (CLIProxyAPI Go binary) + BinarySpawn = 'binary.spawn', + BinaryStdout = 'binary.stdout', + BinaryStderr = 'binary.stderr', + BinaryExit = 'binary.exit', + + // Browser / URL flow (Authorization Code) + AuthUrlDisplayed = 'auth.url_displayed', + BrowserOpened = 'browser.opened', + CallbackObservedHeuristic = 'callback.observed_heuristic', + + // Paste-callback (CCS-owned end-to-end) + PasteCallbackPrompted = 'paste.prompted', + PasteCallbackReceived = 'paste.received', + PasteCallbackInvalid = 'paste.invalid', + PasteCallbackSubmitted = 'paste.submitted', + + // Token exchange + persistence + TokenExchangePending = 'token.exchange_pending', + TokenFileAppeared = 'token.file_appeared', + TokenFileMissing = 'token.file_missing', + + // Provider-specific gates (Phase 4/5 extend) + ProjectSelectionPrompted = 'project.selection_prompted', + ProjectSelectionResolved = 'project.selection_resolved', + AgyResponsibilityPrompted = 'agy.responsibility_prompted', + AgyResponsibilityResolved = 'agy.responsibility_resolved', + + // Terminal states + Timeout = 'timeout', + Cancelled = 'cancelled', + Error = 'error', +} + +/** A single OAuth trace event. `data` MUST be redacted before construction. */ +export interface OAuthTraceEvent { + sessionId: string; + provider: string; + phase: OAuthTracePhase; + ts: number; // Date.now() + elapsedMs: number; // since recorder.start() + data?: Record; + error?: { code?: string; message: string }; +} + +/** Sink interface — accept events that have already been redacted. */ +export interface OAuthTraceSink { + write(event: OAuthTraceEvent): void; + flush?(): Promise; +} diff --git a/src/cliproxy/auth/oauth-trace/trace-recorder.ts b/src/cliproxy/auth/oauth-trace/trace-recorder.ts new file mode 100644 index 00000000..5cf14c17 --- /dev/null +++ b/src/cliproxy/auth/oauth-trace/trace-recorder.ts @@ -0,0 +1,107 @@ +import { OAuthTraceEvent, OAuthTracePhase, OAuthTraceSink } from './trace-events'; +import { createMemorySink } from './sink-memory'; +import { createVerboseStdoutSink } from './sink-verbose-stdout'; +import { redactJsonShallow } from './redactor'; + +export interface OAuthTraceRecorder { + record( + phase: OAuthTracePhase, + data?: Record, + error?: { code?: string; message: string } | Error + ): void; + snapshot(): OAuthTraceEvent[]; + summary(): { + totalMs: number; + phaseCounts: Record; + lastPhase?: OAuthTracePhase; + }; + flush(): Promise; +} + +export interface OAuthTraceRecorderOptions { + sessionId: string; + provider: string; + verbose: boolean; + fileSink?: OAuthTraceSink; + /** Test seam — defaults to `Date.now`. */ + now?: () => number; + /** Test seam — override verbose sink output channel. */ + verboseOut?: (line: string) => void; +} + +/** + * Create a per-attempt recorder. Always wires: + * - memory sink (read via `snapshot()`) + * - verbose stdout sink (no-op when verbose=false) + * - optional file sink (Phase 8) + * + * All event data passes through the redactor before reaching any sink. + */ +export function createOAuthTraceRecorder(options: OAuthTraceRecorderOptions): OAuthTraceRecorder { + const now = options.now ?? Date.now; + const start = now(); + const memory = createMemorySink(); + const verbose = createVerboseStdoutSink({ enabled: options.verbose, out: options.verboseOut }); + const sinks: OAuthTraceSink[] = [memory, verbose]; + if (options.fileSink) sinks.push(options.fileSink); + + const phaseCounts: Record = {}; + let lastPhase: OAuthTracePhase | undefined; + + function toErrorObj( + err: { code?: string; message: string } | Error | undefined + ): { code?: string; message: string } | undefined { + if (!err) return undefined; + if (err instanceof Error) { + return { message: err.message }; + } + return { code: err.code, message: err.message }; + } + + return { + record(phase, data, error) { + const ts = now(); + const elapsedMs = ts - start; + const redacted = data ? redactJsonShallow(data) : undefined; + const event: OAuthTraceEvent = { + sessionId: options.sessionId, + provider: options.provider, + phase, + ts, + elapsedMs, + data: redacted, + error: toErrorObj(error), + }; + phaseCounts[phase] = (phaseCounts[phase] ?? 0) + 1; + lastPhase = phase; + for (const sink of sinks) { + try { + sink.write(event); + } catch { + // Sinks must never throw out — drop on failure. + } + } + }, + snapshot() { + return memory.snapshot(); + }, + summary() { + return { + totalMs: now() - start, + phaseCounts: { ...phaseCounts }, + lastPhase, + }; + }, + async flush() { + for (const sink of sinks) { + if (sink.flush) { + try { + await sink.flush(); + } catch { + // ignore + } + } + } + }, + }; +}