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.

src/copilot/copilot-executor.ts

@@ -35,7 +35,7 @@ import {
   resolveImageAnalysisRuntimeStatus,
 } from '../utils/hooks';
 import { stripClaudeCodeEnv } from '../utils/shell-executor';
-import { createLogger } from '../services/logging';
+import { createLogger, forwardRequestIdEnv } from '../services/logging';
 import { getGlobalEnvConfig } from '../config/config-loader-facade';
 
 const logger = createLogger('copilot:executor');
@@ -324,7 +324,7 @@ export async function executeCopilotProfile(
 
     const proc = spawn(claudeCliPath, launchArgs, {
       stdio: 'inherit',
-      env: { ...env, ...traceEnv },
+      env: { ...env, ...traceEnv, ...forwardRequestIdEnv() },
       shell: process.platform === 'win32',
     });
 

src/cursor/cursor-daemon-entry.ts

@@ -7,6 +7,7 @@
 import * as http from 'http';
 import { Readable } from 'stream';
 import { CursorExecutor } from './cursor-executor';
+import { runWithRequestId } from '../services/logging';
 import {
   createAnthropicErrorResponse,
   createAnthropicProxyResponse,
@@ -417,13 +418,18 @@ export function startCursorDaemonServer(options: DaemonRuntimeOptions): http.Ser
 }
 
 if (require.main === module) {
-  const options = parseArgs(process.argv.slice(2));
-  const server = startCursorDaemonServer(options);
+  // Re-anchor to a requestId forwarded by the spawning CLI (CCS_REQUEST_ID env)
+  // so daemon startup logs correlate with the parent invocation. AsyncLocalStorage
+  // does not cross the spawn boundary, so the env bridge is mandatory here.
+  runWithRequestId(() => {
+    const options = parseArgs(process.argv.slice(2));
+    const server = startCursorDaemonServer(options);
 
-  const shutdown = () => {
-    server.close();
-  };
+    const shutdown = () => {
+      server.close();
+    };
 
-  process.on('SIGTERM', shutdown);
-  process.on('SIGINT', shutdown);
+    process.on('SIGTERM', shutdown);
+    process.on('SIGINT', shutdown);
+  });
 }

src/cursor/cursor-daemon.ts

@@ -13,7 +13,7 @@ import * as http from 'http';
 import type { CursorDaemonConfig, CursorDaemonStatus } from './types';
 import { getPidFromFile, writePidToFile, removePidFile } from './cursor-daemon-pid';
 import { verifyDaemonOwnership } from './daemon-process-ownership';
-import { createLogger } from '../services/logging';
+import { createLogger, forwardRequestIdEnv } from '../services/logging';
 export { getPidFromFile, writePidToFile, removePidFile } from './cursor-daemon-pid';
 
 const logger = createLogger('cursor:daemon');
@@ -226,6 +226,7 @@ export async function startDaemon(
         detached: true,
         env: {
           ...process.env,
+          ...forwardRequestIdEnv(),
           CCS_CURSOR_DAEMON_TOKEN: effectiveConfig.daemon_token || '',
         },
       });

src/cursor/cursor-profile-executor.ts

@@ -3,6 +3,7 @@ import { spawn } from 'child_process';
 import type { CursorConfig } from '../config/unified-config-types';
 
 import { ensureCliproxyService } from '../cliproxy';
+import { forwardRequestIdEnv } from '../services/logging';
 import { resolveLifecyclePort } from '../cliproxy/config/port-manager';
 import { fail, info, ok } from '../utils/ui';
 import {
@@ -194,7 +195,7 @@ export async function executeCursorProfile(
 
     const proc = spawn(claudeCliPath, launchArgs, {
       stdio: 'inherit',
-      env: { ...env, ...traceEnv },
+      env: { ...env, ...traceEnv, ...forwardRequestIdEnv() },
       shell: process.platform === 'win32',
     });
 

src/delegation/headless-executor.ts

@@ -8,6 +8,7 @@
 import { spawn } from 'child_process';
 import * as path from 'path';
 import { killWithEscalation } from '../utils/process-utils';
+import { forwardRequestIdEnv } from '../services/logging';
 import * as fs from 'fs';
 import { SessionManager } from './session-manager';
 import { SettingsParser } from './settings-parser';
@@ -432,6 +433,7 @@ export class HeadlessExecutor {
         ...imageAnalysisEnv,
         ...traceEnv,
         ...(claudeConfigDir ? { CLAUDE_CONFIG_DIR: claudeConfigDir } : {}),
+        ...forwardRequestIdEnv(),
         CCS_PROFILE_TYPE: 'settings',
       });
 

src/delegation/session-manager.ts

@@ -7,6 +7,9 @@
 import * as fs from 'fs';
 import * as path from 'path';
 import { getCcsDir } from '../config/config-loader-facade';
+import { createLogger } from '../services/logging';
+
+const logger = createLogger('delegation:session-manager');
 
 interface SessionData {
   sessionId: string;
@@ -145,9 +148,12 @@ class SessionManager {
       const content = fs.readFileSync(this.sessionsPath, 'utf8');
       return JSON.parse(content) as SessionsRegistry;
     } catch (error) {
-      if (process.env.CCS_DEBUG) {
-        console.warn(`[!] Failed to load sessions: ${(error as Error).message}`);
-      }
+      logger.warn('session.load.failed', 'Failed to load delegation sessions', {
+        err:
+          error instanceof Error
+            ? { name: error.name, message: error.message }
+            : { message: String(error) },
+      });
       return {};
     }
   }
@@ -163,7 +169,12 @@ class SessionManager {
       }
       fs.writeFileSync(this.sessionsPath, JSON.stringify(sessions, null, 2), { mode: 0o600 });
     } catch (error) {
-      console.error(`[!] Failed to save sessions: ${(error as Error).message}`);
+      logger.error('session.save.failed', 'Failed to save delegation sessions', {
+        err:
+          error instanceof Error
+            ? { name: error.name, message: error.message }
+            : { message: String(error) },
+      });
     }
   }
 }

src/docker/supervisord-lifecycle.ts

@@ -10,9 +10,11 @@
 import * as fs from 'fs';
 import { execSync } from 'child_process';
 import { CLIPROXY_DEFAULT_PORT } from '../cliproxy/config/port-manager';
+import { createLogger } from '../services/logging';
 
 const SUPERVISOR_SOCK = '/var/run/supervisor.sock';
 const SUPERVISOR_CONF = '/etc/supervisord.conf';
+const logger = createLogger('docker:supervisord-lifecycle');
 
 /** True when running inside a supervisord-managed container. */
 export function isRunningUnderSupervisord(): boolean {
@@ -30,7 +32,9 @@ export function restartCliproxyViaSupervisord(): {
     return { success: true, port: CLIPROXY_DEFAULT_PORT };
   } catch (err) {
     const detail = err instanceof Error ? err.message : String(err);
-    console.error(`[cliproxy] supervisorctl restart failed: ${detail}`);
+    logger.error('cliproxy.restart.failed', 'supervisorctl restart failed', {
+      detail,
+    });
     return { success: false, error: 'supervisorctl restart failed' };
   }
 }

src/services/logging/index.ts

@@ -18,6 +18,11 @@ export {
   getRequestContext,
   getRequestId,
   mergeRequestContext,
+  resolveRequestIdFromEnv,
+  forwardRequestIdEnv,
+  REQUEST_ID_HEADER,
+  REQUEST_ID_ENV,
+  REQUEST_ID_PATTERN,
 } from './log-context';
 export type { RequestContext } from './log-context';
 export {

src/services/logging/log-context.ts

@@ -1,6 +1,13 @@
 import { AsyncLocalStorage } from 'async_hooks';
 import { randomUUID } from 'crypto';
 
+/** Header name used to echo the requestId back on HTTP responses. */
+export const REQUEST_ID_HEADER = 'x-ccs-request-id';
+/** Env var used to forward the requestId across process boundaries (child daemons, spawned CLI). */
+export const REQUEST_ID_ENV = 'CCS_REQUEST_ID';
+// Loose UUID-ish guard: accepts UUIDs and opaque ids; rejects empty / control chars.
+export const REQUEST_ID_PATTERN = /^[A-Za-z0-9._-]{8,128}$/;
+
 /**
  * Per-request context carried via Node.js {@link AsyncLocalStorage}.
  *
@@ -30,11 +37,29 @@ export function withRequestContext<T>(ctx: RequestContext, fn: () => T): T {
 }
 
 /**
- * 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.
+ * Resolve a requestId forwarded across a process boundary (spawned CLI child,
+ * daemon). Returns the env value when well-formed, otherwise `undefined` so the
+ * caller mints a fresh id. AsyncLocalStorage does NOT cross child_process.spawn,
+ * so forwarding via CCS_REQUEST_ID env and re-anchoring at the child entry is
+ * the only cross-process bridge.
+ */
+export function resolveRequestIdFromEnv(): string | undefined {
+  const raw = process.env[REQUEST_ID_ENV];
+  if (typeof raw === 'string') {
+    const trimmed = raw.trim();
+    if (REQUEST_ID_PATTERN.test(trimmed)) return trimmed;
+  }
+  return undefined;
+}
+
+/**
+ * Entry-edge wrapper. Reuses a requestId forwarded via CCS_REQUEST_ID when
+ * present and well-formed (so a spawned child re-anchors to the parent's id);
+ * otherwise mints a fresh UUID. Use at CLI main, daemon inbound boundaries, and
+ * spawned CLI children. Returns the requestId so callers can echo it via headers.
  */
 export function runWithRequestId<T>(fn: () => T): { requestId: string; result: T } {
-  const requestId = randomUUID();
+  const requestId = resolveRequestIdFromEnv() ?? randomUUID();
   const result = withRequestContext({ requestId }, fn);
   return { requestId, result };
 }
@@ -49,6 +74,20 @@ export function getRequestId(): string | undefined {
   return storage.getStore()?.requestId;
 }
 
+/**
+ * Build the env fragment that forwards the active requestId to a child process
+ * (spawned CLI child, daemon). Returns `{ [REQUEST_ID_ENV]: id }` when a context
+ * is active, otherwise `{}`. Spread into the `child_process.spawn` env object.
+ *
+ * AsyncLocalStorage does not cross process boundaries; this is the parent half
+ * of the bridge. The child re-anchors via {@link runWithRequestId}, which reads
+ * the same env var.
+ */
+export function forwardRequestIdEnv(): Record<string, string> {
+  const requestId = getRequestId();
+  return requestId ? { [REQUEST_ID_ENV]: requestId } : {};
+}
+
 /**
  * Merge any active request context into the supplied context object,
  * preferring explicit keys on the input. Existing `requestId` on `extra` wins

src/web-server/middleware/request-logging-middleware.ts

@@ -1,6 +1,6 @@
 import { randomUUID } from 'crypto';
 import type { Request, Response, NextFunction } from 'express';
-import { createLogger } from '../../services/logging';
+import { createLogger, withRequestContext } from '../../services/logging';
 
 const logger = createLogger('web-server:http');
 
@@ -26,5 +26,8 @@ export function requestLoggingMiddleware(req: Request, res: Response, next: Next
     });
   });
 
-  next();
+  // Wrap the downstream handler chain so structured logs emitted by route
+  // handlers carry the requestId (the logger auto-attaches it from the active
+  // request context). Mirrors src/proxy/server/proxy-server.ts.
+  withRequestContext({ requestId }, () => next());
 }

tests/unit/services/logging/request-id-forwarding.test.ts

@@ -0,0 +1,65 @@
+import { afterEach, describe, expect, test } from 'bun:test';
+import {
+  REQUEST_ID_ENV,
+  forwardRequestIdEnv,
+  getRequestId,
+  resolveRequestIdFromEnv,
+  runWithRequestId,
+} from '../../../../src/services/logging';
+
+describe('requestId cross-process forwarding', () => {
+  const originalEnv = process.env[REQUEST_ID_ENV];
+
+  afterEach(() => {
+    if (originalEnv === undefined) delete process.env[REQUEST_ID_ENV];
+    else process.env[REQUEST_ID_ENV] = originalEnv;
+  });
+
+  test('resolveRequestIdFromEnv returns a well-formed forwarded id', () => {
+    process.env[REQUEST_ID_ENV] = '12345678-1234-1234-1234-1234567890ab';
+    expect(resolveRequestIdFromEnv()).toBe('12345678-1234-1234-1234-1234567890ab');
+  });
+
+  test('resolveRequestIdFromEnv trims surrounding whitespace', () => {
+    process.env[REQUEST_ID_ENV] = '  abcdef123456  ';
+    expect(resolveRequestIdFromEnv()).toBe('abcdef123456');
+  });
+
+  test('resolveRequestIdFromEnv rejects garbage (too short, spaces, control chars)', () => {
+    process.env[REQUEST_ID_ENV] = 'short';
+    expect(resolveRequestIdFromEnv()).toBeUndefined();
+    process.env[REQUEST_ID_ENV] = 'has spaces here';
+    expect(resolveRequestIdFromEnv()).toBeUndefined();
+  });
+
+  test('resolveRequestIdFromEnv returns undefined when unset', () => {
+    delete process.env[REQUEST_ID_ENV];
+    expect(resolveRequestIdFromEnv()).toBeUndefined();
+  });
+
+  test('runWithRequestId reuses a forwarded env id (child re-anchor)', () => {
+    process.env[REQUEST_ID_ENV] = 'forwarded-id-1234';
+    const { requestId } = runWithRequestId(() => getRequestId());
+    expect(requestId).toBe('forwarded-id-1234');
+  });
+
+  test('runWithRequestId mints a fresh id when no env id is present', () => {
+    delete process.env[REQUEST_ID_ENV];
+    const { requestId } = runWithRequestId(() => undefined);
+    expect(requestId).toMatch(/^[0-9a-f]{8}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{12}$/);
+    expect(requestId).not.toBe('forwarded-id-1234');
+  });
+
+  test('forwardRequestIdEnv emits the active id for a child spawn env', () => {
+    delete process.env[REQUEST_ID_ENV];
+    runWithRequestId(() => {
+      const envFragment = forwardRequestIdEnv();
+      expect(envFragment[REQUEST_ID_ENV]).toBe(getRequestId());
+    });
+  });
+
+  test('forwardRequestIdEnv is empty when no context is active', () => {
+    delete process.env[REQUEST_ID_ENV];
+    expect(forwardRequestIdEnv()).toEqual({});
+  });
+});

tests/unit/web-server/request-context-middleware.test.ts

@@ -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();
+  });
+});