From 1462823be8c67895e81009aab0259263ae8b4097 Mon Sep 17 00:00:00 2001 From: Tam Nhu Tran Date: Thu, 18 Jun 2026 18:48:13 -0400 Subject: [PATCH] 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. --- docs/hardening-debt-burndown.md | 10 +- eslint-rules/throw-error-baseline.json | 16 +- src/cursor/cursor-daemon-entry.ts | 369 ++++++++++-------- src/delegation/headless-executor.ts | 27 +- src/services/logging/log-redaction.ts | 10 + src/services/logging/logger.ts | 4 +- .../middleware/request-logging-middleware.ts | 18 +- ...ursor-daemon-entry-request-context.test.ts | 73 ++++ .../unit/delegation/headless-executor.test.ts | 32 ++ .../hotpath-redaction-regression.test.ts | 24 +- .../request-context-middleware.test.ts | 30 ++ 11 files changed, 421 insertions(+), 192 deletions(-) create mode 100644 tests/unit/cursor/cursor-daemon-entry-request-context.test.ts diff --git a/docs/hardening-debt-burndown.md b/docs/hardening-debt-burndown.md index 9003a3f2..e2cbfe5b 100644 --- a/docs/hardening-debt-burndown.md +++ b/docs/hardening-debt-burndown.md @@ -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. diff --git a/eslint-rules/throw-error-baseline.json b/eslint-rules/throw-error-baseline.json index 62680ec3..44743d23 100644 --- a/eslint-rules/throw-error-baseline.json +++ b/eslint-rules/throw-error-baseline.json @@ -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", diff --git a/src/cursor/cursor-daemon-entry.ts b/src/cursor/cursor-daemon-entry.ts index 5fa89aa6..a22a2a0a 100644 --- a/src/cursor/cursor-daemon-entry.ts +++ b/src/cursor/cursor-daemon-entry.ts @@ -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( + 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; diff --git a/src/delegation/headless-executor.ts b/src/delegation/headless-executor.ts index 61513011..085fe30e 100644 --- a/src/delegation/headless-executor.ts +++ b/src/delegation/headless-executor.ts @@ -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 { + 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 diff --git a/src/services/logging/log-redaction.ts b/src/services/logging/log-redaction.ts index 52a7d83d..79a65dd7 100644 --- a/src/services/logging/log-redaction.ts +++ b/src/services/logging/log-redaction.ts @@ -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; } +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). * diff --git a/src/services/logging/logger.ts b/src/services/logging/logger.ts index 2d6a98a5..280d5a1c 100644 --- a/src/services/logging/logger.ts +++ b/src/services/logging/logger.ts @@ -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; } diff --git a/src/web-server/middleware/request-logging-middleware.ts b/src/web-server/middleware/request-logging-middleware.ts index 1c846623..94b65bcf 100644 --- a/src/web-server/middleware/request-logging-middleware.ts +++ b/src/web-server/middleware/request-logging-middleware.ts @@ -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, + }); }); }); diff --git a/tests/unit/cursor/cursor-daemon-entry-request-context.test.ts b/tests/unit/cursor/cursor-daemon-entry-request-context.test.ts new file mode 100644 index 00000000..d90f073d --- /dev/null +++ b/tests/unit/cursor/cursor-daemon-entry-request-context.test.ts @@ -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 { + 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((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'); + }); +}); diff --git a/tests/unit/delegation/headless-executor.test.ts b/tests/unit/delegation/headless-executor.test.ts index 14479d27..e974a237 100644 --- a/tests/unit/delegation/headless-executor.test.ts +++ b/tests/unit/delegation/headless-executor.test.ts @@ -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: { diff --git a/tests/unit/services/logging/hotpath-redaction-regression.test.ts b/tests/unit/services/logging/hotpath-redaction-regression.test.ts index c3705a77..784390d2 100644 --- a/tests/unit/services/logging/hotpath-redaction-regression.test.ts +++ b/tests/unit/services/logging/hotpath-redaction-regression.test.ts @@ -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)?.provider).toBe('codex'); diff --git a/tests/unit/web-server/request-context-middleware.test.ts b/tests/unit/web-server/request-context-middleware.test.ts index 1fb2a1e9..67215984 100644 --- a/tests/unit/web-server/request-context-middleware.test.ts +++ b/tests/unit/web-server/request-context-middleware.test.ts @@ -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, + 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[1]; + const req = { + originalUrl: '/api/anything', + method: 'POST', + headers: { 'user-agent': 'test-agent' }, + socket: { remoteAddress: '127.0.0.1' }, + } as unknown as Parameters[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)?.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');