fix(logging): harden structured trace redaction

Redact StageOptions error payloads and summarize debug launch args.

Propagate request IDs through Cursor daemon and dashboard completion logs.

Mark remaining P2/P3 maintainability targets as partial instead of overclaiming.
This commit is contained in:
Tam Nhu Tran committed 2026-06-18 18:48:13 -04:00
1 parent 2d48488475
commit 1462823be8
11 files changed
+421 -192

No files matched your search

+5 -5
View File
@@ -93,8 +93,9 @@ Metrics are grep-based and approximate (not a contract). Comments and string/tem
|---|---:|---:|---:|---|
| typed-error adoption (locked subdomains) | 0.0% (0/23) | 91.3% (21/23) | >40% | met |
| typed-error adoption (overall) | 0.9% (5/431) | 8.6% (37/431) | rise | met |
| hotpath `console.error`/`warn` | 928 | 267 | <10 (diagnostics) | diagnostics fully structured; residual is user-facing CLI output (see P3 note) |
| hotpath `console.error`/`warn` | 928 | 267 | <10 | partial; high-risk diagnostics migrated + redaction gate closed, but metric target unmet (see P3 note) |
| files with `createLogger` | 35 | 64 | rise | met |
| subdomains with zero `createLogger` | 20 | 15 | 0 in named set | partial; logger toe-holds improved coverage but P2 zero-subdomain target unmet |
| files > 400 LOC | 95 | 89 | <60 | partial (P6 deferred 4 targets) |
| hardening report freshness | stale | <30d gate | gate | met (P1) |
| ESLint `no-new-throw-error` | not enforced | error + allowlist | enforced | met (P7) |
@@ -102,11 +103,10 @@ Metrics are grep-based and approximate (not a contract). Comments and string/tem
### Deferred follow-ups
- P2 remaining zero-logger subdomains (`api`, `channels`, `config`, `dispatcher`, `shared`, and others): add lightweight logger toe-holds when those subdomains next receive behavior work. This epic improved coverage but did not satisfy the original `0` target.
- P3 remaining 267 non-exempt `console.error`/`warn` call sites: split into true user-facing terminal output vs diagnostics, then either migrate diagnostics to structured logs or update the metric method to exempt confirmed CLI display helpers.
- P6 remaining 4 targets (`oauth-handler.ts`, `cursor-executor.ts`, `tool-sanitization-proxy.ts`, +1): need dedicated characterization-test work before splitting (the plan's characterization-first hard gate). Each has a clean seam identified in the epic plan.
- P3 residual ~267 user-facing `console.error` -> `process.stderr.write`: mechanical, no traceability value; continues incrementally.
### P3 residual note (2026-06-18)
The remaining ~267 `console.error`/`warn` are user-facing CLI output (interactive flows, arg-parser usage errors, installers, prompts, adapter launch failures, error-display helpers) routed via `fail()`/`info()`/`warn()` from `utils/ui`. They are legitimate stderr output, not diagnostics. The plan's `<10` target assumed these were diagnostics; in practice the diagnostic subset is fully converted to structured logs. Migrating the residual `console.error` -> `process.stderr.write` is mechanical (near-zero behavior change, no traceability value) and continues incrementally; it does not block P4-P7. The redaction gate makes any further conversion safe.
The remaining 267 non-exempt `console.error`/`warn` occurrences are not fully resolved by this epic. Many are user-facing terminal display paths (interactive flows, arg-parser usage errors, installers, prompts, adapter launch failures, error-display helpers), but the generated metric still counts them because its exemption list is intentionally conservative. Treat P3 as partial until the residual list is classified file-by-file and either migrated to structured logs or explicitly moved into the CLI-UX exemption method. The redaction gate now covers structured message, context, `Error.message`, and `StageOptions.error` metadata so further diagnostic migration is safe.
+8 -8
View File
@@ -158,17 +158,17 @@
"src/cursor/cursor-client-policy.ts:33",
"src/cursor/cursor-client-policy.ts:81",
"src/cursor/cursor-client-policy.ts:85",
"src/cursor/cursor-daemon-entry.ts:148",
"src/cursor/cursor-daemon-entry.ts:153",
"src/cursor/cursor-daemon-entry.ts:158",
"src/cursor/cursor-daemon-entry.ts:168",
"src/cursor/cursor-daemon-entry.ts:183",
"src/cursor/cursor-daemon-entry.ts:188",
"src/cursor/cursor-daemon-entry.ts:193",
"src/cursor/cursor-daemon-entry.ts:203",
"src/cursor/cursor-executor.ts:206",
"src/cursor/cursor-protobuf.ts:50",
"src/cursor/cursor-translator.ts:189",
"src/delegation/headless-executor.ts:107",
"src/delegation/headless-executor.ts:122",
"src/delegation/headless-executor.ts:251",
"src/delegation/headless-executor.ts:654",
"src/delegation/headless-executor.ts:126",
"src/delegation/headless-executor.ts:141",
"src/delegation/headless-executor.ts:270",
"src/delegation/headless-executor.ts:679",
"src/dispatcher/cli-argument-parser.ts:310",
"src/dispatcher/cli-argument-parser.ts:314",
"src/dispatcher/cli-argument-parser.ts:324",
+203 -166
View File
@@ -5,9 +5,15 @@
*/
import * as http from 'http';
import { randomUUID } from 'crypto';
import { Readable } from 'stream';
import { CursorExecutor } from './cursor-executor';
import { runWithRequestId } from '../services/logging';
import {
REQUEST_ID_HEADER,
REQUEST_ID_PATTERN,
runWithRequestId,
withRequestContext,
} from '../services/logging';
import {
createAnthropicErrorResponse,
createAnthropicProxyResponse,
@@ -143,6 +149,35 @@ function hasValidDaemonToken(req: http.IncomingMessage): boolean {
return false;
}
function resolveInboundRequestId(req: http.IncomingMessage): string | undefined {
const raw = req.headers[REQUEST_ID_HEADER];
const value = Array.isArray(raw) ? raw[0] : raw;
if (typeof value !== 'string') {
return undefined;
}
const requestId = value.trim();
return REQUEST_ID_PATTERN.test(requestId) ? requestId : undefined;
}
function withCursorDaemonRequestContext<T>(
req: http.IncomingMessage,
res: http.ServerResponse,
fn: () => T
): T {
const requestId = resolveInboundRequestId(req) ?? randomUUID();
res.setHeader(REQUEST_ID_HEADER, requestId);
return withRequestContext(
{
requestId,
method: req.method || 'GET',
path: req.url || '/',
},
fn
);
}
function normalizeMessages(raw: unknown): NormalizedOpenAIMessage[] {
if (!Array.isArray(raw)) {
throw new Error('messages must be an array');
@@ -229,189 +264,191 @@ function parseArgs(argv: string[]): DaemonRuntimeOptions {
export function startCursorDaemonServer(options: DaemonRuntimeOptions): http.Server {
const executor = new CursorExecutor();
const server = http.createServer(async (req, res) => {
const method = req.method || 'GET';
const requestUrl = req.url || '/';
const isOpenAiRoute = method === 'POST' && requestUrl === '/v1/chat/completions';
const isAnthropicRoute = method === 'POST' && requestUrl === '/v1/messages';
const server = http.createServer((req, res) =>
withCursorDaemonRequestContext(req, res, async () => {
const method = req.method || 'GET';
const requestUrl = req.url || '/';
const isOpenAiRoute = method === 'POST' && requestUrl === '/v1/chat/completions';
const isAnthropicRoute = method === 'POST' && requestUrl === '/v1/messages';
try {
if (method === 'GET' && requestUrl === '/health') {
if (!hasValidDaemonToken(req)) {
writeJson(res, 401, { error: 'Unauthorized' });
return;
}
writeJson(res, 200, { ok: true, service: 'cursor-daemon' });
return;
}
if (method === 'GET' && requestUrl === '/v1/models') {
const authStatus = checkAuthStatus();
const models = await getModelsForDaemon({
credentials:
authStatus.authenticated && !authStatus.expired && authStatus.credentials
? {
accessToken: authStatus.credentials.accessToken,
machineId: authStatus.credentials.machineId,
ghostMode: options.ghostMode,
}
: null,
});
const data = models.map((model) => ({
id: model.id,
object: 'model',
created: 0,
owned_by: model.provider,
}));
writeJson(res, 200, { object: 'list', data });
return;
}
if (!isOpenAiRoute && !isAnthropicRoute) {
writeJson(res, 404, { error: 'Not found' });
return;
}
try {
if (method === 'GET' && requestUrl === '/health') {
if (!hasValidDaemonToken(req)) {
writeJson(res, 401, { error: 'Unauthorized' });
return;
}
writeJson(res, 200, { ok: true, service: 'cursor-daemon' });
return;
}
if (method === 'GET' && requestUrl === '/v1/models') {
const rawBody = await readJsonBody(req);
const anthropicBody = isAnthropicRoute ? translateAnthropicRequest(rawBody) : undefined;
const parsedBody = anthropicBody ?? ((rawBody as OpenAIChatRequest) || {});
const messages = anthropicBody
? anthropicBody.messages
: normalizeMessages(parsedBody.messages);
const requestedModel =
typeof parsedBody.model === 'string' && parsedBody.model.trim().length > 0
? parsedBody.model.trim()
: undefined;
const stream = parsedBody.stream === true;
const authStatus = checkAuthStatus();
const models = await getModelsForDaemon({
credentials:
authStatus.authenticated && !authStatus.expired && authStatus.credentials
? {
accessToken: authStatus.credentials.accessToken,
machineId: authStatus.credentials.machineId,
ghostMode: options.ghostMode,
}
: null,
});
const data = models.map((model) => ({
id: model.id,
object: 'model',
created: 0,
owned_by: model.provider,
}));
writeJson(res, 200, { object: 'list', data });
return;
}
if (!isOpenAiRoute && !isAnthropicRoute) {
writeJson(res, 404, { error: 'Not found' });
return;
}
if (!hasValidDaemonToken(req)) {
writeJson(res, 401, { error: 'Unauthorized' });
return;
}
const rawBody = await readJsonBody(req);
const anthropicBody = isAnthropicRoute ? translateAnthropicRequest(rawBody) : undefined;
const parsedBody = anthropicBody ?? ((rawBody as OpenAIChatRequest) || {});
const messages = anthropicBody
? anthropicBody.messages
: normalizeMessages(parsedBody.messages);
const requestedModel =
typeof parsedBody.model === 'string' && parsedBody.model.trim().length > 0
? parsedBody.model.trim()
: undefined;
const stream = parsedBody.stream === true;
const authStatus = checkAuthStatus();
if (!authStatus.authenticated || !authStatus.credentials) {
const message = 'Cursor credentials not found. Run `ccs legacy cursor auth` first.';
if (isAnthropicRoute) {
await pipeWebResponseToNode(
createAnthropicErrorResponse(401, 'authentication_error', message),
res
);
} else {
writeJson(res, 401, {
error: {
type: 'authentication_error',
message,
},
});
}
return;
}
if (authStatus.expired) {
const message = 'Cursor credentials expired. Run `ccs legacy cursor auth` again.';
if (isAnthropicRoute) {
await pipeWebResponseToNode(
createAnthropicErrorResponse(401, 'authentication_error', message),
res
);
} else {
writeJson(res, 401, {
error: {
type: 'authentication_error',
message,
},
});
}
return;
}
if (isAnthropicRoute) {
const expectedToken = (process.env.ANTHROPIC_AUTH_TOKEN || 'cursor-managed').trim();
const requestToken = getAnthropicRequestToken(req.headers);
if (!expectedToken || requestToken !== expectedToken) {
await pipeWebResponseToNode(
createAnthropicErrorResponse(
401,
'authentication_error',
'Invalid Anthropic auth token. Set ANTHROPIC_AUTH_TOKEN and send it via x-api-key or Authorization Bearer.'
),
res
);
if (!authStatus.authenticated || !authStatus.credentials) {
const message = 'Cursor credentials not found. Run `ccs legacy cursor auth` first.';
if (isAnthropicRoute) {
await pipeWebResponseToNode(
createAnthropicErrorResponse(401, 'authentication_error', message),
res
);
} else {
writeJson(res, 401, {
error: {
type: 'authentication_error',
message,
},
});
}
return;
}
}
const daemonCredentials = {
accessToken: authStatus.credentials.accessToken,
machineId: authStatus.credentials.machineId,
ghostMode: options.ghostMode,
};
const availableModels = await getModelsForDaemon({
credentials: daemonCredentials,
});
const model = resolveCursorRequestModel(requestedModel, availableModels);
if (
requestedModel &&
requestedModel !== model &&
(process.env.CCS_DEBUG === '1' || process.env.CCS_DEBUG === 'true')
) {
console.error(
`[cursor] Requested model "${requestedModel}" is unavailable; falling back to "${model}".`
);
}
const abortController = new AbortController();
const abortOnDisconnect = () => {
if (!abortController.signal.aborted && !res.writableEnded) {
abortController.abort();
if (authStatus.expired) {
const message = 'Cursor credentials expired. Run `ccs legacy cursor auth` again.';
if (isAnthropicRoute) {
await pipeWebResponseToNode(
createAnthropicErrorResponse(401, 'authentication_error', message),
res
);
} else {
writeJson(res, 401, {
error: {
type: 'authentication_error',
message,
},
});
}
return;
}
};
req.on('aborted', abortOnDisconnect);
req.on('close', abortOnDisconnect);
res.on('close', abortOnDisconnect);
if (isAnthropicRoute) {
const expectedToken = (process.env.ANTHROPIC_AUTH_TOKEN || 'cursor-managed').trim();
const requestToken = getAnthropicRequestToken(req.headers);
if (!expectedToken || requestToken !== expectedToken) {
await pipeWebResponseToNode(
createAnthropicErrorResponse(
401,
'authentication_error',
'Invalid Anthropic auth token. Set ANTHROPIC_AUTH_TOKEN and send it via x-api-key or Authorization Bearer.'
),
res
);
return;
}
}
const result = await executor.execute({
model,
stream,
signal: abortController.signal,
credentials: daemonCredentials,
body: {
messages,
tools: Array.isArray(parsedBody.tools) ? parsedBody.tools : undefined,
reasoning_effort:
typeof parsedBody.reasoning_effort === 'string'
? parsedBody.reasoning_effort
: undefined,
},
});
const daemonCredentials = {
accessToken: authStatus.credentials.accessToken,
machineId: authStatus.credentials.machineId,
ghostMode: options.ghostMode,
};
const availableModels = await getModelsForDaemon({
credentials: daemonCredentials,
});
const model = resolveCursorRequestModel(requestedModel, availableModels);
if (
requestedModel &&
requestedModel !== model &&
(process.env.CCS_DEBUG === '1' || process.env.CCS_DEBUG === 'true')
) {
console.error(
`[cursor] Requested model "${requestedModel}" is unavailable; falling back to "${model}".`
);
}
const outgoingResponse = isAnthropicRoute
? await createAnthropicProxyResponse(result.response)
: result.response;
const abortController = new AbortController();
const abortOnDisconnect = () => {
if (!abortController.signal.aborted && !res.writableEnded) {
abortController.abort();
}
};
await pipeWebResponseToNode(outgoingResponse, res);
} catch (error) {
const message = error instanceof Error ? error.message : 'Unknown error';
const isPayloadTooLarge = message.includes('Request body too large');
const status = isPayloadTooLarge ? 413 : 400;
if (isAnthropicRoute) {
await pipeWebResponseToNode(
createAnthropicErrorResponse(status, 'invalid_request_error', message),
res
);
} else {
writeJson(res, status, {
error: {
type: 'invalid_request_error',
message,
req.on('aborted', abortOnDisconnect);
req.on('close', abortOnDisconnect);
res.on('close', abortOnDisconnect);
const result = await executor.execute({
model,
stream,
signal: abortController.signal,
credentials: daemonCredentials,
body: {
messages,
tools: Array.isArray(parsedBody.tools) ? parsedBody.tools : undefined,
reasoning_effort:
typeof parsedBody.reasoning_effort === 'string'
? parsedBody.reasoning_effort
: undefined,
},
});
const outgoingResponse = isAnthropicRoute
? await createAnthropicProxyResponse(result.response)
: result.response;
await pipeWebResponseToNode(outgoingResponse, res);
} catch (error) {
const message = error instanceof Error ? error.message : 'Unknown error';
const isPayloadTooLarge = message.includes('Request body too large');
const status = isPayloadTooLarge ? 413 : 400;
if (isAnthropicRoute) {
await pipeWebResponseToNode(
createAnthropicErrorResponse(status, 'invalid_request_error', message),
res
);
} else {
writeJson(res, status, {
error: {
type: 'invalid_request_error',
message,
},
});
}
}
}
});
})
);
server.listen(options.port, '127.0.0.1');
return server;
+26 -1
View File
@@ -66,6 +66,25 @@ export type { ExecutionOptions, ExecutionResult, StreamMessage } from './executo
const logger = createLogger('delegation:headless-executor');
export function summarizeClaudeLaunchArgsForLog(
args: readonly string[],
filteredExtraArgCount: number
): Record<string, unknown> {
return {
argCount: args.length,
hasPrompt: args.includes('-p'),
hasSettings: args.includes('--settings'),
outputFormat: args.includes('--output-format') ? 'configured' : 'default',
verbose: args.includes('--verbose'),
hasResume: args.includes('--resume'),
hasPermissionMode: args.includes('--permission-mode'),
bypassPermissions: args.includes('--dangerously-skip-permissions'),
hasAllowedTools: args.includes('--allowedTools'),
hasDisallowedTools: args.includes('--disallowedTools'),
filteredExtraArgCount,
};
}
/**
* Headless executor for Claude CLI delegation
*/
@@ -338,6 +357,7 @@ export class HeadlessExecutor {
// Passthrough extra args (catch-all for new/unknown flags)
// Filter out duplicates of explicitly handled flags
let filteredExtraArgCount = 0;
if (extraArgs.length > 0) {
const explicitFlags = new Set(['--max-turns', '--fallback-model', '--agents', '--betas']);
const filteredExtras: string[] = [];
@@ -353,6 +373,7 @@ export class HeadlessExecutor {
}
if (filteredExtras.length > 0) {
args.push(...filteredExtras);
filteredExtraArgCount = filteredExtras.length;
}
}
@@ -371,7 +392,11 @@ export class HeadlessExecutor {
});
if (process.env.CCS_DEBUG) {
logger.info('claude_cli_args', 'Claude CLI args', { args: launchArgs });
logger.info(
'claude_cli_args',
'Claude CLI args prepared',
summarizeClaudeLaunchArgsForLog(launchArgs, filteredExtraArgCount)
);
}
// Initialize UI before spawning
+10
View File
@@ -1,3 +1,5 @@
import type { LogErrorInfo } from './log-types';
/**
* Sensitive log key matcher (single source of truth).
*
@@ -105,6 +107,14 @@ export function redactContext(
return sanitizeValue(context, 0) as Record<string, unknown>;
}
export function redactErrorInfo(error: LogErrorInfo | undefined): LogErrorInfo | undefined {
if (!error) {
return undefined;
}
return sanitizeValue(error, 0) as LogErrorInfo;
}
/**
* Redact sensitive values from a CLI argv array (e.g. for spawn-arg logging).
*
+2 -2
View File
@@ -1,7 +1,7 @@
import { randomUUID } from 'crypto';
import { getResolvedLoggingConfig } from './log-config';
import { getRequestContext } from './log-context';
import { maskSecretTokens, redactContext } from './log-redaction';
import { maskSecretTokens, redactContext, redactErrorInfo } from './log-redaction';
import { appendStructuredLogEntry } from './log-storage';
import type { LogEntry, LogStage, LoggingLevel } from './log-types';
@@ -37,7 +37,7 @@ function createEntry(
if (reqCtx?.requestId) entry.requestId = reqCtx.requestId;
if (options.stage) entry.stage = options.stage;
if (typeof options.latencyMs === 'number') entry.latencyMs = options.latencyMs;
if (options.error) entry.error = options.error;
if (options.error) entry.error = redactErrorInfo(options.error);
return entry;
}
@@ -15,14 +15,16 @@ export function requestLoggingMiddleware(req: Request, res: Response, next: Next
if (shouldSkipLogging) {
return;
}
logger.info('request.completed', 'Dashboard request completed', {
requestId,
method: req.method,
path: req.originalUrl,
statusCode: res.statusCode,
durationMs: Date.now() - startTime,
remoteAddress: req.socket.remoteAddress || null,
userAgent: req.headers['user-agent'] || null,
withRequestContext({ requestId }, () => {
logger.info('request.completed', 'Dashboard request completed', {
requestId,
method: req.method,
path: req.originalUrl,
statusCode: res.statusCode,
durationMs: Date.now() - startTime,
remoteAddress: req.socket.remoteAddress || null,
userAgent: req.headers['user-agent'] || null,
});
});
});
@@ -0,0 +1,73 @@
import { afterEach, beforeEach, describe, expect, test } from 'bun:test';
import * as http from 'http';
import { startCursorDaemonServer } from '../../../src/cursor/cursor-daemon-entry';
import { REQUEST_ID_HEADER } from '../../../src/services/logging';
function listenAddress(server: http.Server): { port: number } {
const address = server.address();
if (!address || typeof address === 'string') {
throw new Error('Unable to resolve test server address');
}
return { port: address.port };
}
async function requestHealth(port: number, requestId?: string): Promise<http.IncomingMessage> {
return new Promise((resolve, reject) => {
const req = http.request(
{
host: '127.0.0.1',
port,
path: '/health',
method: 'GET',
headers: {
'x-ccs-cursor-token': 'test-token',
...(requestId ? { [REQUEST_ID_HEADER]: requestId } : {}),
},
},
(res) => {
res.resume();
res.on('end', () => resolve(res));
}
);
req.on('error', reject);
req.end();
});
}
describe('cursor daemon request context', () => {
let originalToken: string | undefined;
let server: http.Server | undefined;
beforeEach(() => {
originalToken = process.env.CCS_CURSOR_DAEMON_TOKEN;
process.env.CCS_CURSOR_DAEMON_TOKEN = 'test-token';
});
afterEach(async () => {
if (server) {
await new Promise<void>((resolve) => server?.close(() => resolve()));
server = undefined;
}
if (originalToken === undefined) delete process.env.CCS_CURSOR_DAEMON_TOKEN;
else process.env.CCS_CURSOR_DAEMON_TOKEN = originalToken;
});
test('echoes a valid inbound requestId header', async () => {
server = startCursorDaemonServer({ port: 0, ghostMode: true });
const { port } = listenAddress(server);
const res = await requestHealth(port, 'req-cursor-123');
expect(res.statusCode).toBe(200);
expect(res.headers[REQUEST_ID_HEADER]).toBe('req-cursor-123');
});
test('mints a requestId when no valid inbound header exists', async () => {
server = startCursorDaemonServer({ port: 0, ghostMode: true });
const { port } = listenAddress(server);
const res = await requestHealth(port, 'bad id with spaces');
expect(res.statusCode).toBe(200);
expect(res.headers[REQUEST_ID_HEADER]).toMatch(/^[A-Za-z0-9._-]{8,128}$/);
expect(res.headers[REQUEST_ID_HEADER]).not.toBe('bad id with spaces');
});
});
@@ -4,6 +4,7 @@
*/
import { describe, it, expect } from 'bun:test';
import { summarizeClaudeLaunchArgsForLog } from '../../../src/delegation/headless-executor';
describe('HeadlessExecutor flag construction', () => {
// Test the flag construction logic by simulating the filtering behavior
@@ -88,6 +89,37 @@ describe('HeadlessExecutor flag construction', () => {
});
});
describe('Debug launch-arg logging', () => {
it('summarizes launch args without persisting prompt text or passthrough secret values', () => {
const prompt = 'please analyze api_key=plainsecretvalue in this prompt';
const args = [
'-p',
prompt,
'--settings',
'/tmp/settings.json',
'--output-format',
'stream-json',
'--verbose',
'--api-key',
'plainsecretvalue',
];
const summary = summarizeClaudeLaunchArgsForLog(args, 2);
const serialized = JSON.stringify(summary);
expect(serialized).not.toContain(prompt);
expect(serialized).not.toContain('plainsecretvalue');
expect(summary).toMatchObject({
argCount: args.length,
hasPrompt: true,
hasSettings: true,
outputFormat: 'configured',
verbose: true,
filteredExtraArgCount: 2,
});
});
});
describe('Flag undefined vs truthy checks', () => {
// Simulate the flag construction logic
function buildArgs(options: {
@@ -90,7 +90,9 @@ describe('hotpath redaction regression (token-laden payloads)', () => {
test(`scrubs ${name} token in a context value (under a non-sensitive key)`, () => {
const token = buildToken();
const logger = createLogger('test:redaction');
logger.error('test.token.in.value', `token shape ${name}`, { detail: `request failed: ${token}` });
logger.error('test.token.in.value', `token shape ${name}`, {
detail: `request failed: ${token}`,
});
const entry = getRecentLogEntries().find((e) => e.event === 'test.token.in.value');
expect(entry).toBeDefined();
expect(JSON.stringify(entry)).not.toContain(token);
@@ -107,6 +109,22 @@ describe('hotpath redaction regression (token-laden payloads)', () => {
expect(JSON.stringify(entry)).not.toContain(token);
});
test('scrubs token embedded in stage options.error metadata', () => {
const token = anthropicToken();
const logger = createLogger('test:redaction');
logger.stage('cleanup', 'test.stage.error', 'structured error carrying token', undefined, {
level: 'error',
error: {
name: 'Error',
message: `Auth failed: ${token}`,
stack: `Error: Auth failed: ${token}\n at test`,
},
});
const entry = getRecentLogEntries().find((e) => e.event === 'test.stage.error');
expect(entry).toBeDefined();
expect(JSON.stringify(entry)).not.toContain(token);
});
test('scrubs token shapes that leak into the message string (defense-in-depth)', () => {
const token = anthropicToken();
const logger = createLogger('test:redaction');
@@ -118,7 +136,9 @@ describe('hotpath redaction regression (token-laden payloads)', () => {
test('preserves non-sensitive prose messages unchanged', () => {
const logger = createLogger('test:redaction');
logger.error('test.prose', 'Delegation failed: target adapter not found', { provider: 'codex' });
logger.error('test.prose', 'Delegation failed: target adapter not found', {
provider: 'codex',
});
const entry = getRecentLogEntries().find((e) => e.event === 'test.prose');
expect(entry?.message).toBe('Delegation failed: target adapter not found');
expect((entry?.context as Record<string, unknown>)?.provider).toBe('codex');
@@ -67,6 +67,36 @@ describe('request-logging-middleware requestId propagation', () => {
expect(handlerEntry?.requestId).toBe(headerRequestId);
});
test('completion log carries top-level requestId for trace grouping', () => {
let finishHandler: (() => void) | undefined;
let headerRequestId = '';
const res = {
locals: {} as Record<string, unknown>,
setHeader: (_name: string, value: string) => {
headerRequestId = value;
},
on: (event: string, handler: () => void) => {
if (event === 'finish') finishHandler = handler;
},
statusCode: 204,
socket: { remoteAddress: '127.0.0.1' },
} as unknown as Parameters<typeof requestLoggingMiddleware>[1];
const req = {
originalUrl: '/api/anything',
method: 'POST',
headers: { 'user-agent': 'test-agent' },
socket: { remoteAddress: '127.0.0.1' },
} as unknown as Parameters<typeof requestLoggingMiddleware>[0];
requestLoggingMiddleware(req, res, () => {});
finishHandler?.();
const entry = getRecentLogEntries().find((e) => e.event === 'request.completed');
expect(entry).toBeDefined();
expect(entry?.requestId).toBe(headerRequestId);
expect((entry?.context as Record<string, unknown>)?.requestId).toBe(headerRequestId);
});
test('control: a bare handler log (no middleware) carries no requestId', () => {
const handlerLogger = createLogger('test:bare-handler');
handlerLogger.info('test.bare.ran', 'no middleware wrap');