fix(logging): log debuggee output events by shape, not text, at the default level (#852) (#870)

Every DAP output event was logged with its full body at info: by the
worker's MinimalDapClient (a redirectable logger, so into the per-session
proxy log too) and twice by the server (ProxyManager.handleDapEvent and
the functional core's log command). A program that printed a credential
left it in plain text in two files under the temp directory that outlive
the session, while get_output masked the same value (#237), and the logs
grew with everything a chatty program printed.

describeDapEventBodyForLog (shared, next to sanitizePayloadForLogging)
reduces an output body to { category, outputLength } and passes every
other event body through the request-payload sanitizer; the three info
sites use it. The worker's existing debug-level copy of the output body
is now sanitized too, so even --log-level debug logs mask token-shaped
values the way get_output does. The events themselves are untouched.

Measured (Windows 11, JavaScript session printing a fake ghp_ token and
500 stderr lines): before, the proxy log held the token once and 78 lines
of program text, the per-pid server log held it twice in 156 lines
(143 KB); after, neither file contains the token or any program line, and
the server log is 60 KB.

Co-authored-by: JF <john.franklin@gmail.com>
Co-authored-by: Claude Fable 5.1 <noreply@anthropic.com>

Author: 3 people

changelog.d/852.fixed.md

@@ -0,0 +1 @@
+**Debuggee output is no longer copied verbatim into the server and proxy logs at the default level** — every DAP `output` event was written with its full body, at `info`, to the per-process server log (twice) and to the per-session proxy log, two files under the temp directory that outlive the session; a program that printed a credential left it there in plain text while `get_output` masked the same value, and the logs grew with everything a chatty program printed (one 480-line debuggee: 1.3 MB of log). Those records now carry the output's category and length only; the one verbatim copy is at `debug` level and masked like `get_output` is. Other event bodies (`process`, `stopped`, …) are logged after the same sanitization as request payloads — environment blocks counted, token-shaped values masked (#852)

docs/tool-reference.md

@@ -750,6 +750,8 @@ Results that had values masked carry a `redaction` field (`{ masked, notice }` o
 
 **Opting out**: start the server with `DEBUG_MCP_NO_REDACT=1` to disable redaction entirely (e.g. when debugging credential-handling code itself). Adapter stderr sanitization (unconditional, whole-line) is unaffected by this flag.
 
+**Logs**: the server's per-process log and the per-session proxy log (both under the temp directory, outliving the session) record a debuggee output event by its category and length only; the text itself is written only at `--log-level debug`, masked the same way `get_output` is. Other DAP event bodies are logged after the same sanitization as request payloads (environment blocks counted, token-shaped values masked).
+
 **Limitations**: redaction is display-level protection against credentials leaking into transcripts, not a security boundary against a hostile agent — an agent can still compute over secrets via `evaluate_expression` side effects. Secrets split across separate output chunks, and generic high-entropy strings with no recognizable shape or name, are not detected. The [`expose_session`](#expose_session) IDE mirror shows **raw, unredacted** values — it serves a human's IDE, not the agent.
 
 ### Least-privilege mode

packages/shared/src/index.ts

@@ -257,6 +257,7 @@ export type { DebugProtocol } from '@vscode/debugprotocol';
 export {
   sanitizeEnvForLogging,
   sanitizePayloadForLogging,
+  describeDapEventBodyForLog,
   sanitizeStderr,
   sanitizeStderrTail
 } from './utils/env-sanitizer.js';

packages/shared/src/utils/env-sanitizer.ts

@@ -79,6 +79,27 @@ export function sanitizePayloadForLogging(payload: unknown): unknown {
   return redactEnvDeep(payload, new WeakSet());
 }
 
+/**
+ * The log-safe view of a DAP event body (issue #852). An `output` event's
+ * body is the debuggee's own text: logged as it came, at the default level,
+ * a program that prints a credential left it in plain text in two files
+ * that outlive the session (the per-pid server log and the per-session
+ * proxy log) while `get_output` masked the same value, and the logs grew
+ * with everything a chatty program printed. The default-level record keeps
+ * only the shape of the output — its category and length — and every other
+ * event body goes through the same sanitizer as a request payload.
+ */
+export function describeDapEventBodyForLog(event: string, body: unknown): unknown {
+  if (event === 'output') {
+    const fields = body && typeof body === 'object' ? (body as Record<string, unknown>) : {};
+    return {
+      category: typeof fields.category === 'string' ? fields.category : 'console',
+      outputLength: typeof fields.output === 'string' ? fields.output.length : 0
+    };
+  }
+  return sanitizePayloadForLogging(body);
+}
+
 function redactEnvDeep(value: unknown, ancestors: WeakSet<object>): unknown {
   // Value-shape masking on string leaves (issue #237): DAP response payloads
   // (variables/evaluate bodies) flow through here on their way to proxy debug

packages/shared/tests/unit/env-sanitizer.test.ts

@@ -6,7 +6,8 @@ import {
   sanitizeEnvForLogging,
   sanitizePayloadForLogging,
   sanitizeStderr,
-  sanitizeStderrTail
+  sanitizeStderrTail,
+  describeDapEventBodyForLog
 } from '../../src/utils/env-sanitizer.js';
 
 describe('sanitizeEnvForLogging', () => {
@@ -341,3 +342,35 @@ describe('sanitizeStderrTail', () => {
     expect(sanitizeStderrTail('  \n \r\n')).toBe('');
   });
 });
+
+describe('describeDapEventBodyForLog (issue #852)', () => {
+  const token = 'ghp_A1b2C3d4E5f6G7h8I9j0K1l2M3n4O5p6Q7r8S9t0';
+
+  it('keeps only the shape of an output event: category and length, never the text', () => {
+    const output = `token=${token}\n`;
+    const described = describeDapEventBodyForLog('output', { category: 'stdout', output });
+    expect(described).toEqual({ category: 'stdout', outputLength: output.length });
+    expect(JSON.stringify(described)).not.toContain('ghp_');
+  });
+
+  it('defaults a missing category to console and a missing text to length 0', () => {
+    expect(describeDapEventBodyForLog('output', {})).toEqual({ category: 'console', outputLength: 0 });
+    expect(describeDapEventBodyForLog('output', undefined)).toEqual({ category: 'console', outputLength: 0 });
+  });
+
+  it('sanitizes every other event body like a request payload', () => {
+    const described = describeDapEventBodyForLog('process', {
+      name: 'app',
+      env: { SECRET: 'x' },
+      note: `bearer ${token}`
+    }) as Record<string, unknown>;
+    expect(described.env).toBe('<1 env vars redacted>');
+    expect(String(described.note)).not.toContain(token);
+    expect(described.name).toBe('app');
+  });
+
+  it('passes a stopped body through unchanged in shape', () => {
+    expect(describeDapEventBodyForLog('stopped', { reason: 'breakpoint', threadId: 1 }))
+      .toEqual({ reason: 'breakpoint', threadId: 1 });
+  });
+});

src/dap-core/handlers.ts

@@ -18,6 +18,7 @@ import {
   getPendingRequest,
   removePendingRequest
 } from './state.js';
+import { describeDapEventBodyForLog } from '@debugmcp/shared';
 
 /**
  * Main handler for proxy messages
@@ -132,7 +133,8 @@ function handleDapEvent(
       type: 'log', 
       level: 'info', 
       message: `[ProxyManager] DAP event: ${message.event}`,
-      data: message.body
+      // Debuggee output by shape only, other bodies sanitized (issue #852)
+      data: describeDapEventBodyForLog(message.event, message.body)
     }
   ];
 

src/proxy/dap-proxy-worker.ts

@@ -46,7 +46,8 @@ import {
   DotnetAdapterPolicy,
   MockAdapterPolicy,
   getPolicyForLanguage,
-  resolveExceptionFilters
+  resolveExceptionFilters,
+  sanitizePayloadForLogging
 } from '@debugmcp/shared';
 
 export type DapProxyWorkerHooks = {
@@ -1011,7 +1012,9 @@ export class DapProxyWorker {
         }
       },
       onOutput: (body) => {
-        this.logger!.debug('[Worker] DAP event: output', body);
+        // The one verbatim copy of debuggee output in the logs, at debug
+        // level only and masked like get_output is (issue #852).
+        this.logger!.debug('[Worker] DAP event: output', sanitizePayloadForLogging(body));
         this.noteDebuggeeExitCodeFromOutput(body);
         this.sendDapEvent('output', body);
       },

src/proxy/minimal-dap.ts

@@ -18,7 +18,8 @@ import {
   type ParentStart,
   type ChildSessionConfig,
   buildNoDebugTargetError,
-  sanitizePayloadForLogging
+  sanitizePayloadForLogging,
+  describeDapEventBodyForLog
 } from '@debugmcp/shared';
 import { ChildSessionManager, type ChildSessionOptions } from './child-session-manager.js';
 import { sendSetBreakpointsStamping } from './breakpoint-condition-errors.js';
@@ -257,9 +258,12 @@ export class MinimalDapClient extends EventEmitter implements IDapClient {
       });
     } else if (message.type === 'event') {
       const evt = message as DebugProtocol.Event;
+      // An output event's body is the debuggee's own text, and this logger
+      // also writes the per-session proxy log: only its shape is recorded,
+      // and other bodies are sanitized like request payloads (issue #852).
       logger.info(`[MinimalDapClient] Event: ${evt.event}`, {
         event: evt.event,
-        body: evt.body
+        body: describeDapEventBodyForLog(evt.event, evt.body)
       });
     }
 

src/proxy/proxy-manager.ts

@@ -37,6 +37,7 @@ import {
   IDebugAdapter,
   AdapterLaunchBarrier,
   sanitizePayloadForLogging,
+  describeDapEventBodyForLog,
   sanitizeStderr,
   LineBuffer
 } from '@debugmcp/shared';
@@ -1346,7 +1347,8 @@ export class ProxyManager extends EventEmitter implements IProxyManager {
       message.body as DebugProtocol.Event['body'] | undefined
     );
 
-    this.logger.info(`[ProxyManager] DAP event: ${message.event}`, message.body);
+    // Debuggee output is logged by shape only (issue #852); see describeDapEventBodyForLog.
+    this.logger.info(`[ProxyManager] DAP event: ${message.event}`, describeDapEventBodyForLog(message.event, message.body));
 
     switch (message.event) {
       case 'stopped':

tests/unit/dap-core/handlers.test.ts

@@ -242,6 +242,30 @@ describe('DAP Core Handlers', () => {
         });
       });
 
+      it('logs an output event as category and length, never its text (issue #852)', () => {
+        const message: ProxyDapEventMessage = {
+          type: 'dapEvent',
+          sessionId: 'test-session-123',
+          event: 'output',
+          body: { category: 'stdout', output: 'token=ghp_A1b2C3d4E5f6G7h8I9j0K1l2M3n4O5p6Q7r8S9t0\n' }
+        };
+
+        const result = handleProxyMessage(state, message);
+
+        expect(result.commands[0]).toEqual({
+          type: 'log',
+          level: 'info',
+          message: '[ProxyManager] DAP event: output',
+          data: { category: 'stdout', outputLength: (message.body as { output: string }).output.length }
+        });
+        // The event itself still carries the real text to the session buffer
+        expect(result.commands[1]).toEqual({
+          type: 'emitEvent',
+          event: 'output',
+          args: [message.body]
+        });
+      });
+
       it('should forward unknown DAP events', () => {
         const message: ProxyDapEventMessage = {
           type: 'dapEvent',