mirror of
https://github.com/tiennm99/ccs.git
synced 2026-07-17 04:17:11 +00:00
feat(cliproxy): add OAuth callback traceability across profiles
Introduces structured per-phase tracing for OAuth flows so users see branch-specific error messages instead of a generic "token not found" fallback. - New oauth-trace/ module: recorder, redactor, three sinks (in-memory ring buffer, verbose stdout, opt-in JSONL file at ~/.ccs/logs/oauth-YYYYMMDD.log mode 0o600 via CCS_OAUTH_LOG_FILE=1) - Branch-specific diagnostics for: URL-not-displayed, callback-not-observed, binary-error, token-exchange-error, session-expired, token-file-missing; UNKNOWN fallback preserves prior UX - Trace recorder threaded through oauth-process.ts spawn/stdout/stderr/ exit lifecycle; SIGINT/SIGTERM cleanup flushes recorder and records Cancelled - Redactor strips code, state, access_token, refresh_token, id_token, client_secret, code_verifier, device_code, assertion, subject_token, plus Authorization: Bearer headers; covers URL fragments, URL-encoded keys, and arrays - 68 new tests including adversarial regression cases for redactor bypass attempts Phases for paste-callback path and cross-profile failure-matrix deferred to follow-up #1207. Closes #1206
This commit is contained in:
@@ -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> = {}): 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);
|
||||
});
|
||||
});
|
||||
@@ -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');
|
||||
});
|
||||
});
|
||||
@@ -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<string, unknown>;
|
||||
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<Record<string, unknown>>;
|
||||
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<Record<string, unknown>>;
|
||||
const inner = (batches[0]['tokens'] as Array<Record<string, unknown>>)[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);
|
||||
});
|
||||
});
|
||||
@@ -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> = {}): 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']);
|
||||
});
|
||||
});
|
||||
@@ -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<AccountInfo | null> {
|
||||
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<Accou
|
||||
// H7: Mutable ref for stdin keepalive interval (set later, needed in cleanup)
|
||||
let stdinKeepalive: ReturnType<typeof setInterval> | 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<Accou
|
||||
cancelManualCallbackPrompt: null,
|
||||
};
|
||||
|
||||
// OAuth trace recorder — opt-in file sink via CCS_OAUTH_LOG_FILE=1
|
||||
const fileSink =
|
||||
process.env['CCS_OAUTH_LOG_FILE'] === '1'
|
||||
? createFileSink({ dir: path.join(getCcsDir(), 'logs') })
|
||||
: undefined;
|
||||
const trace = createOAuthTraceRecorder({
|
||||
sessionId: state.sessionId,
|
||||
provider,
|
||||
verbose,
|
||||
fileSink,
|
||||
});
|
||||
traceRef = trace; // wire late-binding ref for cleanup/handleCancel
|
||||
trace.record(OAuthTracePhase.BinarySpawn, {
|
||||
callbackPort,
|
||||
headless,
|
||||
manualCallback: !!options.manualCallback,
|
||||
flowType,
|
||||
});
|
||||
|
||||
// Register session for cancellation support
|
||||
registerAuthSession(state.sessionId, provider);
|
||||
attachProcessToSession(state.sessionId, authProcess);
|
||||
@@ -732,6 +786,14 @@ export function executeOAuthProcess(options: OAuthProcessOptions): Promise<Accou
|
||||
const handleCancel = (cancelledSessionId: string) => {
|
||||
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<Accou
|
||||
}
|
||||
|
||||
authProcess.stdout?.on('data', async (data: Buffer) => {
|
||||
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<Accou
|
||||
authSessionEvents.removeListener('session:cancelled', handleCancel);
|
||||
unregisterAuthSession(state.sessionId);
|
||||
cancelProjectSelection(state.sessionId);
|
||||
trace.record(OAuthTracePhase.Timeout, { timeoutMs });
|
||||
void trace.flush();
|
||||
killWithEscalation(authProcess);
|
||||
console.log('');
|
||||
console.log(fail(`OAuth timed out after ${timeoutMs / 60000} minutes`));
|
||||
@@ -849,6 +930,10 @@ export function executeOAuthProcess(options: OAuthProcessOptions): Promise<Accou
|
||||
unregisterAuthSession(state.sessionId);
|
||||
cancelProjectSelection(state.sessionId);
|
||||
const elapsed = ((Date.now() - startTime) / 1000).toFixed(1);
|
||||
trace.record(OAuthTracePhase.BinaryExit, {
|
||||
code,
|
||||
stderrTail: redactString(state.stderrData.trim().split('\n').pop() ?? ''),
|
||||
});
|
||||
|
||||
if (code === 0) {
|
||||
const exitAnalysis = analyzeSuccessfulAuthExit({
|
||||
@@ -861,6 +946,8 @@ export function executeOAuthProcess(options: OAuthProcessOptions): Promise<Accou
|
||||
});
|
||||
|
||||
if (exitAnalysis.tokenSnapshot) {
|
||||
trace.record(OAuthTracePhase.TokenFileAppeared, {});
|
||||
await trace.flush();
|
||||
console.log('');
|
||||
console.log(ok(`Authentication successful (${elapsed}s)`));
|
||||
|
||||
@@ -881,6 +968,8 @@ export function executeOAuthProcess(options: OAuthProcessOptions): Promise<Accou
|
||||
});
|
||||
}
|
||||
|
||||
trace.record(OAuthTracePhase.TokenFileMissing, {});
|
||||
await trace.flush();
|
||||
// Try auto-import for Kiro, show error for others
|
||||
const account = await handleTokenNotFound(
|
||||
provider,
|
||||
@@ -889,7 +978,8 @@ export function executeOAuthProcess(options: OAuthProcessOptions): Promise<Accou
|
||||
nickname,
|
||||
expectedAccountId,
|
||||
verbose,
|
||||
exitAnalysis.failureReason || undefined
|
||||
exitAnalysis.failureReason || undefined,
|
||||
trace
|
||||
);
|
||||
resolve(account);
|
||||
}
|
||||
@@ -918,6 +1008,8 @@ export function executeOAuthProcess(options: OAuthProcessOptions): Promise<Accou
|
||||
authSessionEvents.removeListener('session:cancelled', handleCancel);
|
||||
unregisterAuthSession(state.sessionId);
|
||||
cancelProjectSelection(state.sessionId);
|
||||
trace.record(OAuthTracePhase.Error, {}, error);
|
||||
void trace.flush();
|
||||
console.log('');
|
||||
console.log(fail(`Failed to start auth process: ${error.message}`));
|
||||
resolve(null);
|
||||
|
||||
@@ -0,0 +1,214 @@
|
||||
import { OAuthTraceEvent, OAuthTracePhase } from './trace-events';
|
||||
|
||||
export type FailureBranchId =
|
||||
| 'URL_NOT_DISPLAYED'
|
||||
| 'BROWSER_NOT_OPENED'
|
||||
| 'CALLBACK_NEVER_OBSERVED'
|
||||
| 'BINARY_ERROR_EXIT'
|
||||
| 'TOKEN_FILE_MISSING_POST_EXIT'
|
||||
| 'TIMEOUT'
|
||||
| 'SESSION_CANCELLED'
|
||||
| 'TOKEN_EXCHANGE_REJECTED'
|
||||
| 'PASTE_INVALID'
|
||||
| 'GEMINI_PLUS_MISSING_CRED'
|
||||
| 'AGY_RESPONSIBILITY_DECLINED'
|
||||
| 'UNKNOWN';
|
||||
|
||||
export interface DiagnosisResult {
|
||||
branchId: FailureBranchId;
|
||||
data: Record<string, unknown>;
|
||||
}
|
||||
|
||||
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;
|
||||
}
|
||||
@@ -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';
|
||||
@@ -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<string, unknown>): Record<string, unknown> {
|
||||
const out: Record<string, unknown> = {};
|
||||
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<string, unknown>)
|
||||
: item
|
||||
);
|
||||
} else if (value && typeof value === 'object') {
|
||||
out[key] = redactJsonShallow(value as Record<string, unknown>);
|
||||
} 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;
|
||||
@@ -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;
|
||||
},
|
||||
};
|
||||
}
|
||||
@@ -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;
|
||||
},
|
||||
};
|
||||
}
|
||||
@@ -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]';
|
||||
}
|
||||
}
|
||||
@@ -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<string, unknown>;
|
||||
error?: { code?: string; message: string };
|
||||
}
|
||||
|
||||
/** Sink interface — accept events that have already been redacted. */
|
||||
export interface OAuthTraceSink {
|
||||
write(event: OAuthTraceEvent): void;
|
||||
flush?(): Promise<void>;
|
||||
}
|
||||
@@ -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<string, unknown>,
|
||||
error?: { code?: string; message: string } | Error
|
||||
): void;
|
||||
snapshot(): OAuthTraceEvent[];
|
||||
summary(): {
|
||||
totalMs: number;
|
||||
phaseCounts: Record<string, number>;
|
||||
lastPhase?: OAuthTracePhase;
|
||||
};
|
||||
flush(): Promise<void>;
|
||||
}
|
||||
|
||||
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<string, number> = {};
|
||||
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
|
||||
}
|
||||
}
|
||||
}
|
||||
},
|
||||
};
|
||||
}
|
||||
Reference in New Issue
Block a user