mirror of
https://github.com/tiennm99/ccs.git
synced 2026-10-15 22:14:40 +00:00
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:
1 parent
2d48488475
commit
1462823be8
11 files changed
+250
-21
No files matched your search
@@ -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 (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 |
|
| 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 |
|
| 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) |
|
| files > 400 LOC | 95 | 89 | <60 | partial (P6 deferred 4 targets) |
|
||||||
| hardening report freshness | stale | <30d gate | gate | met (P1) |
|
| hardening report freshness | stale | <30d gate | gate | met (P1) |
|
||||||
| ESLint `no-new-throw-error` | not enforced | error + allowlist | enforced | met (P7) |
|
| 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
|
### 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.
|
- 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)
|
### 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.
|
||||||
|
|
||||||
@@ -158,17 +158,17 @@
|
|||||||
"src/cursor/cursor-client-policy.ts:33",
|
"src/cursor/cursor-client-policy.ts:33",
|
||||||
"src/cursor/cursor-client-policy.ts:81",
|
"src/cursor/cursor-client-policy.ts:81",
|
||||||
"src/cursor/cursor-client-policy.ts:85",
|
"src/cursor/cursor-client-policy.ts:85",
|
||||||
"src/cursor/cursor-daemon-entry.ts:148",
|
"src/cursor/cursor-daemon-entry.ts:183",
|
||||||
"src/cursor/cursor-daemon-entry.ts:153",
|
"src/cursor/cursor-daemon-entry.ts:188",
|
||||||
"src/cursor/cursor-daemon-entry.ts:158",
|
"src/cursor/cursor-daemon-entry.ts:193",
|
||||||
"src/cursor/cursor-daemon-entry.ts:168",
|
"src/cursor/cursor-daemon-entry.ts:203",
|
||||||
"src/cursor/cursor-executor.ts:206",
|
"src/cursor/cursor-executor.ts:206",
|
||||||
"src/cursor/cursor-protobuf.ts:50",
|
"src/cursor/cursor-protobuf.ts:50",
|
||||||
"src/cursor/cursor-translator.ts:189",
|
"src/cursor/cursor-translator.ts:189",
|
||||||
"src/delegation/headless-executor.ts:107",
|
"src/delegation/headless-executor.ts:126",
|
||||||
"src/delegation/headless-executor.ts:122",
|
"src/delegation/headless-executor.ts:141",
|
||||||
"src/delegation/headless-executor.ts:251",
|
"src/delegation/headless-executor.ts:270",
|
||||||
"src/delegation/headless-executor.ts:654",
|
"src/delegation/headless-executor.ts:679",
|
||||||
"src/dispatcher/cli-argument-parser.ts:310",
|
"src/dispatcher/cli-argument-parser.ts:310",
|
||||||
"src/dispatcher/cli-argument-parser.ts:314",
|
"src/dispatcher/cli-argument-parser.ts:314",
|
||||||
"src/dispatcher/cli-argument-parser.ts:324",
|
"src/dispatcher/cli-argument-parser.ts:324",
|
||||||
|
|||||||
@@ -5,9 +5,15 @@
|
|||||||
*/
|
*/
|
||||||
|
|
||||||
import * as http from 'http';
|
import * as http from 'http';
|
||||||
|
import { randomUUID } from 'crypto';
|
||||||
import { Readable } from 'stream';
|
import { Readable } from 'stream';
|
||||||
import { CursorExecutor } from './cursor-executor';
|
import { CursorExecutor } from './cursor-executor';
|
||||||
import { runWithRequestId } from '../services/logging';
|
import {
|
||||||
|
REQUEST_ID_HEADER,
|
||||||
|
REQUEST_ID_PATTERN,
|
||||||
|
runWithRequestId,
|
||||||
|
withRequestContext,
|
||||||
|
} from '../services/logging';
|
||||||
import {
|
import {
|
||||||
createAnthropicErrorResponse,
|
createAnthropicErrorResponse,
|
||||||
createAnthropicProxyResponse,
|
createAnthropicProxyResponse,
|
||||||
@@ -143,6 +149,35 @@ function hasValidDaemonToken(req: http.IncomingMessage): boolean {
|
|||||||
|
|
||||||
return false;
|
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[] {
|
function normalizeMessages(raw: unknown): NormalizedOpenAIMessage[] {
|
||||||
if (!Array.isArray(raw)) {
|
if (!Array.isArray(raw)) {
|
||||||
throw new Error('messages must be an array');
|
throw new Error('messages must be an array');
|
||||||
@@ -229,7 +264,8 @@ function parseArgs(argv: string[]): DaemonRuntimeOptions {
|
|||||||
export function startCursorDaemonServer(options: DaemonRuntimeOptions): http.Server {
|
export function startCursorDaemonServer(options: DaemonRuntimeOptions): http.Server {
|
||||||
const executor = new CursorExecutor();
|
const executor = new CursorExecutor();
|
||||||
|
|
||||||
const server = http.createServer(async (req, res) => {
|
const server = http.createServer((req, res) =>
|
||||||
|
withCursorDaemonRequestContext(req, res, async () => {
|
||||||
const method = req.method || 'GET';
|
const method = req.method || 'GET';
|
||||||
const requestUrl = req.url || '/';
|
const requestUrl = req.url || '/';
|
||||||
const isOpenAiRoute = method === 'POST' && requestUrl === '/v1/chat/completions';
|
const isOpenAiRoute = method === 'POST' && requestUrl === '/v1/chat/completions';
|
||||||
@@ -411,7 +447,8 @@ export function startCursorDaemonServer(options: DaemonRuntimeOptions): http.Ser
|
|||||||
});
|
});
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
});
|
})
|
||||||
|
);
|
||||||
|
|
||||||
server.listen(options.port, '127.0.0.1');
|
server.listen(options.port, '127.0.0.1');
|
||||||
return server;
|
return server;
|
||||||
|
|||||||
@@ -66,6 +66,25 @@ export type { ExecutionOptions, ExecutionResult, StreamMessage } from './executo
|
|||||||
|
|
||||||
const logger = createLogger('delegation:headless-executor');
|
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
|
* Headless executor for Claude CLI delegation
|
||||||
*/
|
*/
|
||||||
@@ -338,6 +357,7 @@ export class HeadlessExecutor {
|
|||||||
|
|
||||||
// Passthrough extra args (catch-all for new/unknown flags)
|
// Passthrough extra args (catch-all for new/unknown flags)
|
||||||
// Filter out duplicates of explicitly handled flags
|
// Filter out duplicates of explicitly handled flags
|
||||||
|
let filteredExtraArgCount = 0;
|
||||||
if (extraArgs.length > 0) {
|
if (extraArgs.length > 0) {
|
||||||
const explicitFlags = new Set(['--max-turns', '--fallback-model', '--agents', '--betas']);
|
const explicitFlags = new Set(['--max-turns', '--fallback-model', '--agents', '--betas']);
|
||||||
const filteredExtras: string[] = [];
|
const filteredExtras: string[] = [];
|
||||||
@@ -353,6 +373,7 @@ export class HeadlessExecutor {
|
|||||||
}
|
}
|
||||||
if (filteredExtras.length > 0) {
|
if (filteredExtras.length > 0) {
|
||||||
args.push(...filteredExtras);
|
args.push(...filteredExtras);
|
||||||
|
filteredExtraArgCount = filteredExtras.length;
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
@@ -371,7 +392,11 @@ export class HeadlessExecutor {
|
|||||||
});
|
});
|
||||||
|
|
||||||
if (process.env.CCS_DEBUG) {
|
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
|
// Initialize UI before spawning
|
||||||
|
|||||||
@@ -1,3 +1,5 @@
|
|||||||
|
import type { LogErrorInfo } from './log-types';
|
||||||
|
|
||||||
/**
|
/**
|
||||||
* Sensitive log key matcher (single source of truth).
|
* Sensitive log key matcher (single source of truth).
|
||||||
*
|
*
|
||||||
@@ -105,6 +107,14 @@ export function redactContext(
|
|||||||
return sanitizeValue(context, 0) as Record<string, unknown>;
|
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).
|
* Redact sensitive values from a CLI argv array (e.g. for spawn-arg logging).
|
||||||
*
|
*
|
||||||
|
|||||||
@@ -1,7 +1,7 @@
|
|||||||
import { randomUUID } from 'crypto';
|
import { randomUUID } from 'crypto';
|
||||||
import { getResolvedLoggingConfig } from './log-config';
|
import { getResolvedLoggingConfig } from './log-config';
|
||||||
import { getRequestContext } from './log-context';
|
import { getRequestContext } from './log-context';
|
||||||
import { maskSecretTokens, redactContext } from './log-redaction';
|
import { maskSecretTokens, redactContext, redactErrorInfo } from './log-redaction';
|
||||||
import { appendStructuredLogEntry } from './log-storage';
|
import { appendStructuredLogEntry } from './log-storage';
|
||||||
import type { LogEntry, LogStage, LoggingLevel } from './log-types';
|
import type { LogEntry, LogStage, LoggingLevel } from './log-types';
|
||||||
|
|
||||||
@@ -37,7 +37,7 @@ function createEntry(
|
|||||||
if (reqCtx?.requestId) entry.requestId = reqCtx.requestId;
|
if (reqCtx?.requestId) entry.requestId = reqCtx.requestId;
|
||||||
if (options.stage) entry.stage = options.stage;
|
if (options.stage) entry.stage = options.stage;
|
||||||
if (typeof options.latencyMs === 'number') entry.latencyMs = options.latencyMs;
|
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;
|
return entry;
|
||||||
}
|
}
|
||||||
|
|
||||||
|
|||||||
@@ -15,6 +15,7 @@ export function requestLoggingMiddleware(req: Request, res: Response, next: Next
|
|||||||
if (shouldSkipLogging) {
|
if (shouldSkipLogging) {
|
||||||
return;
|
return;
|
||||||
}
|
}
|
||||||
|
withRequestContext({ requestId }, () => {
|
||||||
logger.info('request.completed', 'Dashboard request completed', {
|
logger.info('request.completed', 'Dashboard request completed', {
|
||||||
requestId,
|
requestId,
|
||||||
method: req.method,
|
method: req.method,
|
||||||
@@ -25,6 +26,7 @@ export function requestLoggingMiddleware(req: Request, res: Response, next: Next
|
|||||||
userAgent: req.headers['user-agent'] || null,
|
userAgent: req.headers['user-agent'] || null,
|
||||||
});
|
});
|
||||||
});
|
});
|
||||||
|
});
|
||||||
|
|
||||||
// Wrap the downstream handler chain so structured logs emitted by route
|
// Wrap the downstream handler chain so structured logs emitted by route
|
||||||
// handlers carry the requestId (the logger auto-attaches it from the active
|
// handlers carry the requestId (the logger auto-attaches it from the active
|
||||||
|
|||||||
@@ -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 { describe, it, expect } from 'bun:test';
|
||||||
|
import { summarizeClaudeLaunchArgsForLog } from '../../../src/delegation/headless-executor';
|
||||||
|
|
||||||
describe('HeadlessExecutor flag construction', () => {
|
describe('HeadlessExecutor flag construction', () => {
|
||||||
// Test the flag construction logic by simulating the filtering behavior
|
// 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', () => {
|
describe('Flag undefined vs truthy checks', () => {
|
||||||
// Simulate the flag construction logic
|
// Simulate the flag construction logic
|
||||||
function buildArgs(options: {
|
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)`, () => {
|
test(`scrubs ${name} token in a context value (under a non-sensitive key)`, () => {
|
||||||
const token = buildToken();
|
const token = buildToken();
|
||||||
const logger = createLogger('test:redaction');
|
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');
|
const entry = getRecentLogEntries().find((e) => e.event === 'test.token.in.value');
|
||||||
expect(entry).toBeDefined();
|
expect(entry).toBeDefined();
|
||||||
expect(JSON.stringify(entry)).not.toContain(token);
|
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);
|
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)', () => {
|
test('scrubs token shapes that leak into the message string (defense-in-depth)', () => {
|
||||||
const token = anthropicToken();
|
const token = anthropicToken();
|
||||||
const logger = createLogger('test:redaction');
|
const logger = createLogger('test:redaction');
|
||||||
@@ -118,7 +136,9 @@ describe('hotpath redaction regression (token-laden payloads)', () => {
|
|||||||
|
|
||||||
test('preserves non-sensitive prose messages unchanged', () => {
|
test('preserves non-sensitive prose messages unchanged', () => {
|
||||||
const logger = createLogger('test:redaction');
|
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');
|
const entry = getRecentLogEntries().find((e) => e.event === 'test.prose');
|
||||||
expect(entry?.message).toBe('Delegation failed: target adapter not found');
|
expect(entry?.message).toBe('Delegation failed: target adapter not found');
|
||||||
expect((entry?.context as Record<string, unknown>)?.provider).toBe('codex');
|
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);
|
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', () => {
|
test('control: a bare handler log (no middleware) carries no requestId', () => {
|
||||||
const handlerLogger = createLogger('test:bare-handler');
|
const handlerLogger = createLogger('test:bare-handler');
|
||||||
handlerLogger.info('test.bare.ran', 'no middleware wrap');
|
handlerLogger.info('test.bare.ran', 'no middleware wrap');
|
||||||
|
|||||||
Reference in new issue
Block a user