feat(logging): P2 traceability foundation - requestId wrap, daemon forwarding (#NNN)

Epic P2. Closes the three real traceability gaps so every diagnostic log can
carry a requestId from origin (ccs.ts main) through HTTP edges and spawned
daemons.

- log-context: add REQUEST_ID_HEADER/ENV/PATTERN, resolveRequestIdFromEnv,
  forwardRequestIdEnv. runWithRequestId now reuses a forwarded CCS_REQUEST_ID
  when well-formed (child re-anchor), else mints fresh.
- request-logging-middleware: wrap the Express dashboard handler chain in
  withRequestContext so downstream route-handler logs carry requestId (mirrors
  src/proxy/server/proxy-server.ts, which is untouched prior art).
- forward CCS_REQUEST_ID at the 4 child-daemon spawn sites: delegation
  headless-executor, cursor-daemon, cursor-profile-executor, copilot-executor.
- cursor-daemon-entry: re-anchor via runWithRequestId so daemon startup logs
  correlate with the spawning CLI invocation (ALS does not cross spawn).
- logger adoption toe-hold: delegation/session-manager (load/save failures) and
  docker/supervisord-lifecycle (restart failure) now use createLogger.

api/channels/shared have no touchable diagnostic console.error (CLI-UX only or
pure data); dispatcher's only diagnostic is in pre-dispatch.ts, owned by plan
#1165. Those defer to P3's full per-site sweep.

Tests: request-context-middleware (handler log requestId === header),
request-id-forwarding (env resolve/reject, re-anchor, forwardRequestIdEnv).
validate + validate:ci-parity green.
This commit is contained in:
Tam Nhu Tran committed 2026-06-18 18:48:12 -04:00
1 parent 95a2864ef3
commit 5e1b8640ab
12 files changed
+234 -21

No files matched your search

@@ -0,0 +1,76 @@
import { afterEach, beforeEach, describe, expect, test } 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,
createLogger,
getRecentLogEntries,
invalidateLoggingConfigCache,
} from '../../../src/services/logging';
import { requestLoggingMiddleware } from '../../../src/web-server/middleware/request-logging-middleware';
describe('request-logging-middleware requestId propagation', () => {
let tempHome = '';
let originalCcsHome: string | undefined;
beforeEach(() => {
originalCcsHome = process.env.CCS_HOME;
tempHome = fs.mkdtempSync(path.join(os.tmpdir(), 'ccs-req-ctx-mw-'));
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();
});
test('downstream handler log requestId === response x-ccs-request-id header', () => {
const handlerLogger = createLogger('test:downstream-handler');
let headerRequestId = '';
const res = {
locals: {} as Record<string, unknown>,
setHeader: (_name: string, value: string) => {
headerRequestId = value;
},
on: () => {},
statusCode: 200,
socket: { remoteAddress: null },
} as unknown as Parameters<typeof requestLoggingMiddleware>[1];
const req = {
originalUrl: '/api/anything',
method: 'GET',
headers: {},
socket: { remoteAddress: null },
} as unknown as Parameters<typeof requestLoggingMiddleware>[0];
requestLoggingMiddleware(req, res, () => {
// Simulate a downstream route handler emitting a structured log inside the chain.
handlerLogger.info('test.handler.ran', 'downstream handler executed');
});
const entries = getRecentLogEntries();
const handlerEntry = entries.find((e) => e.event === 'test.handler.ran');
expect(handlerEntry).toBeDefined();
expect(headerRequestId).toMatch(/^[A-Za-z0-9._-]{8,128}$/);
expect(handlerEntry?.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');
const entry = getRecentLogEntries().find((e) => e.event === 'test.bare.ran');
expect(entry?.requestId).toBeUndefined();
});
});