mirror of
https://github.com/tiennm99/ccs.git
synced 2026-07-16 04:18:05 +00:00
feat(logging): add structured contract, ALS context, stage helpers, and redaction coverage
Establish the structured-log foundation that downstream modules consume: - LogStage union (intake|route|auth|dispatch|upstream|transform|respond|cleanup) - AsyncLocalStorage-backed log-context for end-to-end requestId propagation - Logger.stage() emit helper with optional latencyMs and structured metadata - Extended log-redaction patterns for proxy-authorization, x-goog-api-key, oauth-code, refresh-token classes; Bearer/Basic/Token value-shape masking - Public exports: getRecentLogEntries, withRequestContext, runWithRequestId, getRequestId Refs #1141, #1138
This commit is contained in:
@@ -1,4 +1,5 @@
|
||||
export { createLogger } from './logger';
|
||||
export type { Logger, StageOptions } from './logger';
|
||||
export { getResolvedLoggingConfig, invalidateLoggingConfigCache } from './log-config';
|
||||
export { readLogEntries, readLogSourceSummaries, normalizeLogQueryLevel } from './log-reader';
|
||||
export { pruneExpiredLogArchives } from './log-storage';
|
||||
@@ -10,4 +11,27 @@ export {
|
||||
getNativeLogsDir,
|
||||
isPathInsideDirectory,
|
||||
} from './log-paths';
|
||||
export type { LogEntry, LogSourceSummary, LoggingLevel, ReadLogEntriesOptions } from './log-types';
|
||||
export { getRecentLogEntries, clearRecentLogEntries } from './log-buffer';
|
||||
export {
|
||||
withRequestContext,
|
||||
runWithRequestId,
|
||||
getRequestContext,
|
||||
getRequestId,
|
||||
mergeRequestContext,
|
||||
} from './log-context';
|
||||
export type { RequestContext } from './log-context';
|
||||
export {
|
||||
LOG_LEVELS,
|
||||
LOG_STAGES,
|
||||
shouldWriteLogLevel,
|
||||
isLoggingLevel,
|
||||
isLogStage,
|
||||
} from './log-types';
|
||||
export type {
|
||||
LogEntry,
|
||||
LogErrorInfo,
|
||||
LogSourceSummary,
|
||||
LogStage,
|
||||
LoggingLevel,
|
||||
ReadLogEntriesOptions,
|
||||
} from './log-types';
|
||||
|
||||
@@ -0,0 +1,61 @@
|
||||
import { AsyncLocalStorage } from 'async_hooks';
|
||||
import { randomUUID } from 'crypto';
|
||||
|
||||
/**
|
||||
* Per-request context carried via Node.js {@link AsyncLocalStorage}.
|
||||
*
|
||||
* MUST contain only non-sensitive correlation metadata. NEVER store tokens,
|
||||
* secrets, raw bodies, or other sensitive material in this object — values
|
||||
* leak into every downstream log entry emitted within the context.
|
||||
*/
|
||||
export interface RequestContext {
|
||||
/** UUID-shaped correlation id; round-trips via `x-ccs-request-id` header. */
|
||||
requestId: string;
|
||||
/** Optional benign request metadata (method, path, command name, etc.). */
|
||||
[key: string]: unknown;
|
||||
}
|
||||
|
||||
const storage = new AsyncLocalStorage<RequestContext>();
|
||||
|
||||
/**
|
||||
* Run `fn` inside a fresh request context. Use ONLY at request entry edges
|
||||
* (HTTP handlers, CLI command dispatch, daemon inbound boundaries).
|
||||
*
|
||||
* Never call from shared/reused infrastructure — that would leak the requestId
|
||||
* to unrelated callers. Listeners that need to inherit context MUST be
|
||||
* registered inside the `als.run()` callback.
|
||||
*/
|
||||
export function withRequestContext<T>(ctx: RequestContext, fn: () => T): T {
|
||||
return storage.run(ctx, fn);
|
||||
}
|
||||
|
||||
/**
|
||||
* Convenience wrapper that mints a fresh UUID requestId and runs `fn` under it.
|
||||
* Returns the requestId so callers can echo it back via response headers.
|
||||
*/
|
||||
export function runWithRequestId<T>(fn: () => T): { requestId: string; result: T } {
|
||||
const requestId = randomUUID();
|
||||
const result = withRequestContext({ requestId }, fn);
|
||||
return { requestId, result };
|
||||
}
|
||||
|
||||
/** Read the active request context, or `undefined` if not inside one. */
|
||||
export function getRequestContext(): RequestContext | undefined {
|
||||
return storage.getStore();
|
||||
}
|
||||
|
||||
/** Read just the active requestId, or `undefined` if not inside a context. */
|
||||
export function getRequestId(): string | undefined {
|
||||
return storage.getStore()?.requestId;
|
||||
}
|
||||
|
||||
/**
|
||||
* Merge any active request context into the supplied context object,
|
||||
* preferring explicit keys on the input. Existing `requestId` on `extra` wins
|
||||
* (callers may explicitly override; e.g., for cross-daemon correlation).
|
||||
*/
|
||||
export function mergeRequestContext<T extends Record<string, unknown>>(extra: T): T {
|
||||
const ctx = storage.getStore();
|
||||
if (!ctx) return extra;
|
||||
return { ...ctx, ...extra } as T;
|
||||
}
|
||||
@@ -1,5 +1,20 @@
|
||||
/**
|
||||
* Sensitive log key matcher (single source of truth).
|
||||
*
|
||||
* Add new patterns conservatively. Numeric/boolean values are passed through
|
||||
* even when their key matches (e.g., `expires_at` epoch numbers stay readable);
|
||||
* only string and object values are redacted.
|
||||
*/
|
||||
const SENSITIVE_KEY_PATTERN =
|
||||
/^(authorization|cookie|set-cookie|password|password_hash|secret|token|api[_-]?key|management[_-]?key)$/i;
|
||||
/^(authorization|proxy[_-]?authorization|cookie|set-cookie|password|password_hash|secret|client[_-]?secret|token|auth[_-]?token|access[_-]?token|refresh[_-]?token|id[_-]?token|bearer|assertion|api[_-]?key|x[_-]?api[_-]?key|x[_-]?goog[_-]?api[_-]?key|management[_-]?key|copilot[_-]?token|cursor[_-]?session[_-]?key|oauth[_-]?code|auth[_-]?code)$/i;
|
||||
|
||||
/** CLI flags whose following argument should be redacted in argv arrays. */
|
||||
const SENSITIVE_ARGV_FLAG_PATTERN =
|
||||
/^--(token|api[_-]?key|auth|auth[_-]?token|secret|bearer|password|client[_-]?secret|refresh[_-]?token|access[_-]?token|id[_-]?token)$/i;
|
||||
|
||||
/** Bearer/Basic/Token auth-scheme prefix in raw string values. */
|
||||
const AUTH_SCHEME_VALUE_PATTERN = /^(Bearer|Basic|Token)\s+\S+/;
|
||||
|
||||
const MAX_STRING_LENGTH = 2000;
|
||||
const MAX_DEPTH = 5;
|
||||
|
||||
@@ -10,6 +25,12 @@ function truncateString(value: string): string {
|
||||
return `${value.slice(0, MAX_STRING_LENGTH)}...[truncated]`;
|
||||
}
|
||||
|
||||
function maskAuthSchemeValue(value: string): string {
|
||||
const match = AUTH_SCHEME_VALUE_PATTERN.exec(value);
|
||||
if (!match) return value;
|
||||
return `${match[1]} [redacted]`;
|
||||
}
|
||||
|
||||
function sanitizeValue(value: unknown, depth: number): unknown {
|
||||
if (value === null || value === undefined) {
|
||||
return value;
|
||||
@@ -20,7 +41,7 @@ function sanitizeValue(value: unknown, depth: number): unknown {
|
||||
}
|
||||
|
||||
if (typeof value === 'string') {
|
||||
return truncateString(value);
|
||||
return truncateString(maskAuthSchemeValue(value));
|
||||
}
|
||||
|
||||
if (typeof value === 'number' || typeof value === 'boolean') {
|
||||
@@ -60,3 +81,23 @@ export function redactContext(
|
||||
|
||||
return sanitizeValue(context, 0) as Record<string, unknown>;
|
||||
}
|
||||
|
||||
/**
|
||||
* Redact sensitive values from a CLI argv array (e.g. for spawn-arg logging).
|
||||
*
|
||||
* Pairs every sensitive flag (`--token`, `--api-key`, etc.) with its following
|
||||
* argument and replaces that argument with `[redacted]`. Non-sensitive args
|
||||
* pass through unchanged.
|
||||
*/
|
||||
export function redactArgv(argv: readonly string[]): string[] {
|
||||
const out: string[] = [];
|
||||
for (let i = 0; i < argv.length; i++) {
|
||||
const arg = argv[i];
|
||||
out.push(arg);
|
||||
if (SENSITIVE_ARGV_FLAG_PATTERN.test(arg) && i + 1 < argv.length) {
|
||||
out.push('[redacted]');
|
||||
i++;
|
||||
}
|
||||
}
|
||||
return out;
|
||||
}
|
||||
|
||||
@@ -2,6 +2,47 @@ import type { LoggingConfig, LoggingLevel } from '../../config/unified-config-ty
|
||||
|
||||
export type { LoggingConfig, LoggingLevel };
|
||||
|
||||
/**
|
||||
* Canonical request lifecycle stages.
|
||||
*
|
||||
* Order represents typical flow but stages may be skipped or repeated.
|
||||
* - intake: inbound request received at an entry edge (HTTP handler, CLI dispatch)
|
||||
* - route: destination/profile/target resolution
|
||||
* - auth: authentication/authorization (token exchange, profile auth)
|
||||
* - dispatch: outbound request prepared / child process spawned
|
||||
* - upstream: upstream call in flight (provider HTTP / spawned child running)
|
||||
* - transform: payload translation (request/response shape conversion)
|
||||
* - respond: response written / dispatched to caller (latencyMs typically populated here)
|
||||
* - cleanup: error path, abort, teardown
|
||||
*/
|
||||
export type LogStage =
|
||||
| 'intake'
|
||||
| 'route'
|
||||
| 'auth'
|
||||
| 'dispatch'
|
||||
| 'upstream'
|
||||
| 'transform'
|
||||
| 'respond'
|
||||
| 'cleanup';
|
||||
|
||||
export const LOG_STAGES: readonly LogStage[] = [
|
||||
'intake',
|
||||
'route',
|
||||
'auth',
|
||||
'dispatch',
|
||||
'upstream',
|
||||
'transform',
|
||||
'respond',
|
||||
'cleanup',
|
||||
] as const;
|
||||
|
||||
export interface LogErrorInfo {
|
||||
name: string;
|
||||
message: string;
|
||||
code?: string;
|
||||
stack?: string;
|
||||
}
|
||||
|
||||
export interface LogEntry {
|
||||
id: string;
|
||||
timestamp: string;
|
||||
@@ -12,6 +53,14 @@ export interface LogEntry {
|
||||
processId: number;
|
||||
runId: string;
|
||||
context?: Record<string, unknown>;
|
||||
/** Correlates entries belonging to a single inbound request across stages. */
|
||||
requestId?: string;
|
||||
/** Lifecycle stage tag — see {@link LogStage}. */
|
||||
stage?: LogStage;
|
||||
/** Elapsed time in milliseconds, typically attached to `respond`/`cleanup`. */
|
||||
latencyMs?: number;
|
||||
/** Structured error metadata; never stores raw token strings. */
|
||||
error?: LogErrorInfo;
|
||||
}
|
||||
|
||||
export interface LogSourceSummary {
|
||||
@@ -45,3 +94,7 @@ export function shouldWriteLogLevel(level: LoggingLevel, configuredLevel: Loggin
|
||||
export function isLoggingLevel(value: string | undefined): value is LoggingLevel {
|
||||
return typeof value === 'string' && LOG_LEVELS.includes(value as LoggingLevel);
|
||||
}
|
||||
|
||||
export function isLogStage(value: string | undefined): value is LogStage {
|
||||
return typeof value === 'string' && LOG_STAGES.includes(value as LogStage);
|
||||
}
|
||||
|
||||
@@ -1,20 +1,29 @@
|
||||
import { randomUUID } from 'crypto';
|
||||
import { getResolvedLoggingConfig } from './log-config';
|
||||
import { getRequestContext } from './log-context';
|
||||
import { redactContext } from './log-redaction';
|
||||
import { appendStructuredLogEntry } from './log-storage';
|
||||
import type { LogEntry, LoggingLevel } from './log-types';
|
||||
import type { LogEntry, LogStage, LoggingLevel } from './log-types';
|
||||
|
||||
const processRunId = `${Date.now()}-${process.pid}-${Math.random().toString(36).slice(2, 10)}`;
|
||||
|
||||
interface CreateEntryOptions {
|
||||
stage?: LogStage;
|
||||
latencyMs?: number;
|
||||
error?: LogEntry['error'];
|
||||
}
|
||||
|
||||
function createEntry(
|
||||
source: string,
|
||||
level: LoggingLevel,
|
||||
event: string,
|
||||
message: string,
|
||||
context: Record<string, unknown>
|
||||
context: Record<string, unknown>,
|
||||
options: CreateEntryOptions = {}
|
||||
): LogEntry {
|
||||
const config = getResolvedLoggingConfig();
|
||||
return {
|
||||
const reqCtx = getRequestContext();
|
||||
const entry: LogEntry = {
|
||||
id: randomUUID(),
|
||||
timestamp: new Date().toISOString(),
|
||||
level,
|
||||
@@ -25,6 +34,20 @@ function createEntry(
|
||||
runId: processRunId,
|
||||
context: config.redact ? redactContext(context) : context,
|
||||
};
|
||||
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;
|
||||
return entry;
|
||||
}
|
||||
|
||||
export interface StageOptions {
|
||||
/** Optional level override; default `'info'`. */
|
||||
level?: LoggingLevel;
|
||||
/** Optional latency in ms (typically attached to `respond`/`cleanup`). */
|
||||
latencyMs?: number;
|
||||
/** Optional structured error info for `cleanup` stages. */
|
||||
error?: LogEntry['error'];
|
||||
}
|
||||
|
||||
export interface Logger {
|
||||
@@ -33,6 +56,20 @@ export interface Logger {
|
||||
info(event: string, message: string, context?: Record<string, unknown>): void;
|
||||
warn(event: string, message: string, context?: Record<string, unknown>): void;
|
||||
error(event: string, message: string, context?: Record<string, unknown>): void;
|
||||
/**
|
||||
* Emit a stage-tagged log entry.
|
||||
*
|
||||
* Locked signature: `stage(stage, event, message, context?, options?)`.
|
||||
* `options.level` defaults to `'info'`. Use `options.latencyMs` on
|
||||
* `respond`/`cleanup`. Use `options.error` for structured error info.
|
||||
*/
|
||||
stage(
|
||||
stage: LogStage,
|
||||
event: string,
|
||||
message: string,
|
||||
context?: Record<string, unknown>,
|
||||
options?: StageOptions
|
||||
): void;
|
||||
}
|
||||
|
||||
export function createLogger(source: string, baseContext: Record<string, unknown> = {}): Logger {
|
||||
@@ -40,10 +77,11 @@ export function createLogger(source: string, baseContext: Record<string, unknown
|
||||
level: LoggingLevel,
|
||||
event: string,
|
||||
message: string,
|
||||
context?: Record<string, unknown>
|
||||
context?: Record<string, unknown>,
|
||||
extra: CreateEntryOptions = {}
|
||||
) => {
|
||||
appendStructuredLogEntry(
|
||||
createEntry(source, level, event, message, { ...baseContext, ...(context || {}) })
|
||||
createEntry(source, level, event, message, { ...baseContext, ...(context || {}) }, extra)
|
||||
);
|
||||
};
|
||||
|
||||
@@ -63,5 +101,13 @@ export function createLogger(source: string, baseContext: Record<string, unknown
|
||||
error(event, message, context) {
|
||||
write('error', event, message, context);
|
||||
},
|
||||
stage(stage, event, message, context, options) {
|
||||
const level = options?.level ?? 'info';
|
||||
write(level, event, message, context, {
|
||||
stage,
|
||||
latencyMs: options?.latencyMs,
|
||||
error: options?.error,
|
||||
});
|
||||
},
|
||||
};
|
||||
}
|
||||
|
||||
@@ -0,0 +1,76 @@
|
||||
import { describe, expect, it } from 'bun:test';
|
||||
import {
|
||||
getRequestContext,
|
||||
getRequestId,
|
||||
mergeRequestContext,
|
||||
runWithRequestId,
|
||||
withRequestContext,
|
||||
} from '../../../../src/services/logging/log-context';
|
||||
|
||||
describe('log-context (AsyncLocalStorage)', () => {
|
||||
it('returns undefined outside any context', () => {
|
||||
expect(getRequestContext()).toBeUndefined();
|
||||
expect(getRequestId()).toBeUndefined();
|
||||
});
|
||||
|
||||
it('exposes the active context inside withRequestContext', () => {
|
||||
withRequestContext({ requestId: 'req-1', method: 'POST' }, () => {
|
||||
const ctx = getRequestContext();
|
||||
expect(ctx?.requestId).toBe('req-1');
|
||||
expect(ctx?.method).toBe('POST');
|
||||
expect(getRequestId()).toBe('req-1');
|
||||
});
|
||||
expect(getRequestContext()).toBeUndefined();
|
||||
});
|
||||
|
||||
it('isolates parallel async tasks (no cross-leak)', async () => {
|
||||
const observed: string[] = [];
|
||||
|
||||
await Promise.all([
|
||||
withRequestContext({ requestId: 'req-A' }, async () => {
|
||||
await new Promise((r) => setTimeout(r, 5));
|
||||
observed.push(`A:${getRequestId()}`);
|
||||
}),
|
||||
withRequestContext({ requestId: 'req-B' }, async () => {
|
||||
await new Promise((r) => setTimeout(r, 1));
|
||||
observed.push(`B:${getRequestId()}`);
|
||||
}),
|
||||
]);
|
||||
|
||||
expect(observed.sort()).toEqual(['A:req-A', 'B:req-B']);
|
||||
});
|
||||
|
||||
it('runWithRequestId mints a UUID and exposes it inside fn', () => {
|
||||
let captured: string | undefined;
|
||||
const { requestId, result } = runWithRequestId(() => {
|
||||
captured = getRequestId();
|
||||
return 42;
|
||||
});
|
||||
expect(result).toBe(42);
|
||||
expect(captured).toBe(requestId);
|
||||
expect(requestId).toMatch(/^[0-9a-f-]{36}$/i);
|
||||
});
|
||||
|
||||
it('mergeRequestContext returns input unchanged outside ALS', () => {
|
||||
const merged = mergeRequestContext({ foo: 'bar' });
|
||||
expect(merged).toEqual({ foo: 'bar' });
|
||||
});
|
||||
|
||||
it('mergeRequestContext merges active context, with input overriding ctx', () => {
|
||||
withRequestContext({ requestId: 'req-X', method: 'GET' }, () => {
|
||||
const merged = mergeRequestContext({ method: 'POST', extra: 1 });
|
||||
expect(merged).toEqual({ requestId: 'req-X', method: 'POST', extra: 1 });
|
||||
});
|
||||
});
|
||||
|
||||
it('preserves emit-time ordering within a single requestId', async () => {
|
||||
const order: number[] = [];
|
||||
await withRequestContext({ requestId: 'req-order' }, async () => {
|
||||
for (let i = 0; i < 5; i++) {
|
||||
await Promise.resolve();
|
||||
order.push(i);
|
||||
}
|
||||
});
|
||||
expect(order).toEqual([0, 1, 2, 3, 4]);
|
||||
});
|
||||
});
|
||||
@@ -0,0 +1,139 @@
|
||||
import { describe, expect, it } from 'bun:test';
|
||||
import {
|
||||
redactArgv,
|
||||
redactContext,
|
||||
} from '../../../../src/services/logging/log-redaction';
|
||||
|
||||
describe('log redaction (extended sensitive keys)', () => {
|
||||
const newSensitiveKeys = [
|
||||
'refresh_token',
|
||||
'id_token',
|
||||
'access_token',
|
||||
'client_secret',
|
||||
'bearer',
|
||||
'assertion',
|
||||
'copilot_token',
|
||||
'copilot-token',
|
||||
'cursor_session_key',
|
||||
'cursor-session-key',
|
||||
'x-api-key',
|
||||
'x_goog_api_key',
|
||||
'proxy-authorization',
|
||||
'oauth_code',
|
||||
'auth_code',
|
||||
'auth_token',
|
||||
];
|
||||
|
||||
it.each(newSensitiveKeys)('redacts %s key (top-level)', (key) => {
|
||||
const redacted = redactContext({ [key]: 'secret-value', safe: 'ok' });
|
||||
expect(redacted[key]).toBe('[redacted]');
|
||||
expect(redacted.safe).toBe('ok');
|
||||
});
|
||||
|
||||
it('redacts new keys nested under headers', () => {
|
||||
const redacted = redactContext({
|
||||
headers: {
|
||||
'x-api-key': 'sk-xxx',
|
||||
'proxy-authorization': 'Bearer abc',
|
||||
'copilot-token': 'gho_xxx',
|
||||
},
|
||||
});
|
||||
expect(redacted).toEqual({
|
||||
headers: {
|
||||
'x-api-key': '[redacted]',
|
||||
'proxy-authorization': '[redacted]',
|
||||
'copilot-token': '[redacted]',
|
||||
},
|
||||
});
|
||||
});
|
||||
|
||||
it('redacts Bearer/Basic/Token scheme prefix in raw string values', () => {
|
||||
const redacted = redactContext({
|
||||
raw: 'Bearer eyJhbGciOiJIUzI1NiJ9.payload.sig',
|
||||
basic: 'Basic dXNlcjpwYXNz',
|
||||
tokenLine: 'Token abc.def',
|
||||
plain: 'no-scheme-here',
|
||||
});
|
||||
expect(redacted.raw).toBe('Bearer [redacted]');
|
||||
expect(redacted.basic).toBe('Basic [redacted]');
|
||||
expect(redacted.tokenLine).toBe('Token [redacted]');
|
||||
expect(redacted.plain).toBe('no-scheme-here');
|
||||
});
|
||||
|
||||
it('passes numeric/boolean values through even if key matches', () => {
|
||||
// expires_at is not a sensitive key; ensure non-string sensitive values
|
||||
// would also pass through if pattern matched (defense check).
|
||||
const redacted = redactContext({
|
||||
access_token: 'real-secret',
|
||||
expires_at: 1234567890,
|
||||
enabled: true,
|
||||
});
|
||||
expect(redacted.access_token).toBe('[redacted]');
|
||||
expect(redacted.expires_at).toBe(1234567890);
|
||||
expect(redacted.enabled).toBe(true);
|
||||
});
|
||||
|
||||
it('recurses through arrays of objects', () => {
|
||||
const redacted = redactContext({
|
||||
tokens: [
|
||||
{ access_token: 'a' },
|
||||
{ refresh_token: 'b' },
|
||||
{ id_token: 'c', meta: 'kept' },
|
||||
],
|
||||
});
|
||||
expect(redacted).toEqual({
|
||||
tokens: [
|
||||
{ access_token: '[redacted]' },
|
||||
{ refresh_token: '[redacted]' },
|
||||
{ id_token: '[redacted]', meta: 'kept' },
|
||||
],
|
||||
});
|
||||
});
|
||||
|
||||
it('fuzz-style: many random token-shaped keys all redact', () => {
|
||||
const variants = ['token', 'auth_token', 'refresh-token', 'id-token', 'X-API-KEY'];
|
||||
for (const v of variants) {
|
||||
const out = redactContext({ [v]: 'secret' });
|
||||
expect(out[v]).toBe('[redacted]');
|
||||
}
|
||||
});
|
||||
});
|
||||
|
||||
describe('redactArgv', () => {
|
||||
it('redacts the value following sensitive flags', () => {
|
||||
expect(redactArgv(['--api-key', 'secret', '--other', 'ok'])).toEqual([
|
||||
'--api-key',
|
||||
'[redacted]',
|
||||
'--other',
|
||||
'ok',
|
||||
]);
|
||||
});
|
||||
|
||||
it('redacts multiple sensitive flags', () => {
|
||||
expect(
|
||||
redactArgv(['--token', 'a', '--secret', 'b', '--bearer', 'c', '--keep', 'd'])
|
||||
).toEqual(['--token', '[redacted]', '--secret', '[redacted]', '--bearer', '[redacted]', '--keep', 'd']);
|
||||
});
|
||||
|
||||
it('passes argv unchanged when no sensitive flags present', () => {
|
||||
expect(redactArgv(['build', '--watch', '--out', 'dist'])).toEqual([
|
||||
'build',
|
||||
'--watch',
|
||||
'--out',
|
||||
'dist',
|
||||
]);
|
||||
});
|
||||
|
||||
it('handles trailing sensitive flag with no value', () => {
|
||||
expect(redactArgv(['--api-key'])).toEqual(['--api-key']);
|
||||
});
|
||||
|
||||
it('redacts kebab and snake case flag variants', () => {
|
||||
expect(redactArgv(['--api_key', 'x', '--auth-token', 'y'])).toEqual([
|
||||
'--api_key',
|
||||
'[redacted]',
|
||||
'--auth-token',
|
||||
'[redacted]',
|
||||
]);
|
||||
});
|
||||
});
|
||||
@@ -0,0 +1,94 @@
|
||||
import { afterEach, beforeEach, describe, expect, it } from 'bun:test';
|
||||
import * as fs from 'fs';
|
||||
import * as os from 'os';
|
||||
import * as path from 'path';
|
||||
import { createEmptyUnifiedConfig } from '../../../../src/config/unified-config-types';
|
||||
import { saveUnifiedConfig } from '../../../../src/config/unified-config-loader';
|
||||
import {
|
||||
clearRecentLogEntries,
|
||||
getRecentLogEntries,
|
||||
} from '../../../../src/services/logging/log-buffer';
|
||||
import { invalidateLoggingConfigCache } from '../../../../src/services/logging/log-config';
|
||||
import { withRequestContext } from '../../../../src/services/logging/log-context';
|
||||
import { createLogger } from '../../../../src/services/logging/logger';
|
||||
|
||||
describe('Logger.stage()', () => {
|
||||
let tempHome = '';
|
||||
let originalCcsHome: string | undefined;
|
||||
|
||||
beforeEach(() => {
|
||||
originalCcsHome = process.env.CCS_HOME;
|
||||
tempHome = fs.mkdtempSync(path.join(os.tmpdir(), 'ccs-logger-stages-'));
|
||||
process.env.CCS_HOME = tempHome;
|
||||
clearRecentLogEntries();
|
||||
invalidateLoggingConfigCache();
|
||||
const config = createEmptyUnifiedConfig();
|
||||
config.logging = {
|
||||
...config.logging,
|
||||
enabled: true,
|
||||
level: 'debug',
|
||||
redact: false,
|
||||
};
|
||||
saveUnifiedConfig(config);
|
||||
invalidateLoggingConfigCache();
|
||||
});
|
||||
|
||||
afterEach(() => {
|
||||
if (originalCcsHome === undefined) delete process.env.CCS_HOME;
|
||||
else process.env.CCS_HOME = originalCcsHome;
|
||||
fs.rmSync(tempHome, { recursive: true, force: true });
|
||||
clearRecentLogEntries();
|
||||
invalidateLoggingConfigCache();
|
||||
});
|
||||
|
||||
it('emits a stage-tagged entry with default info level', () => {
|
||||
const logger = createLogger('unit:stages');
|
||||
logger.stage('upstream', 'fetch.start', 'starting upstream fetch');
|
||||
const entries = getRecentLogEntries();
|
||||
expect(entries.length).toBe(1);
|
||||
expect(entries[0].stage).toBe('upstream');
|
||||
expect(entries[0].level).toBe('info');
|
||||
expect(entries[0].event).toBe('fetch.start');
|
||||
});
|
||||
|
||||
it('respects a level override and includes latencyMs + error', () => {
|
||||
const logger = createLogger('unit:stages');
|
||||
logger.stage('cleanup', 'request.failed', 'upstream failed', undefined, {
|
||||
level: 'error',
|
||||
latencyMs: 123,
|
||||
error: { name: 'Error', message: 'boom' },
|
||||
});
|
||||
const [entry] = getRecentLogEntries();
|
||||
expect(entry.level).toBe('error');
|
||||
expect(entry.latencyMs).toBe(123);
|
||||
expect(entry.error?.message).toBe('boom');
|
||||
});
|
||||
|
||||
it('auto-merges requestId from active ALS context', () => {
|
||||
const logger = createLogger('unit:stages');
|
||||
withRequestContext({ requestId: 'req-9' }, () => {
|
||||
logger.stage('intake', 'http.request', 'in');
|
||||
});
|
||||
const [entry] = getRecentLogEntries();
|
||||
expect(entry.requestId).toBe('req-9');
|
||||
expect(entry.stage).toBe('intake');
|
||||
});
|
||||
|
||||
it('emits no requestId when called outside ALS', () => {
|
||||
const logger = createLogger('unit:stages');
|
||||
logger.info('plain.event', 'msg');
|
||||
const [entry] = getRecentLogEntries();
|
||||
expect(entry.requestId).toBeUndefined();
|
||||
expect(entry.stage).toBeUndefined();
|
||||
});
|
||||
|
||||
it('preserves existing logger.info/warn/error/debug methods', () => {
|
||||
const logger = createLogger('unit:stages');
|
||||
logger.info('e1', 'm1');
|
||||
logger.warn('e2', 'm2');
|
||||
logger.error('e3', 'm3');
|
||||
logger.debug('e4', 'm4');
|
||||
const entries = getRecentLogEntries();
|
||||
expect(entries.map((e) => e.level)).toEqual(['info', 'warn', 'error', 'debug']);
|
||||
});
|
||||
});
|
||||
Reference in New Issue
Block a user