Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions changelog.d/860.fixed.md
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
**On Windows, a Rust, C/C++ or COBOL program's last line reaches `get_output` even when it has no newline** — the debuggee writes into CodeLLDB's stdio pipes there, and the proxy splits that stream into lines, flushing a trailing fragment only when the pipe closes. CodeLLDB keeps its pipes open until the session is torn down, so a program whose final `printf("result: 42")` had no newline lost that text: the flush came after the exit had been reported and the session had stopped listening. For an adapter that outlives its debuggee the proxy now hands the fragment over when its exit-time drain settles on the pipes going quiet (#856) — before `exited` is forwarded, through the same path as a complete line, and as printed: no newline is added that the program never wrote. Adapters whose pipes close with the program (rdbg) are unchanged (#860)
72 changes: 55 additions & 17 deletions src/proxy/dap-proxy-adapter-manager.ts
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,16 @@ import {
/** Which adapter-process stream a forwarded line came from. */
export type AdapterStdioSource = 'stdout' | 'stderr';

/**
* How a forwarded line ended. Only the fragment handed over by
* AdapterSpawnResult.flushStdio carries `partial: true` (issue #860): the
* program wrote it with no newline, so the forwarder must not add one. A
* complete line is delivered without this argument.
*/
export interface AdapterStdioLineInfo {
partial?: boolean;
}

/**
* Configuration for spawning any debug adapter
*/
Expand All @@ -33,7 +43,7 @@ export interface GenericAdapterConfig {
* the redaction that protects persisted logs must not rewrite what the
* debugging client sees, matching debugpy/js-debug output-event behavior.
*/
onStdioLine?: (source: AdapterStdioSource, line: string) => void;
onStdioLine?: (source: AdapterStdioSource, line: string, info?: AdapterStdioLineInfo) => void;
}

/**
Expand Down Expand Up @@ -148,71 +158,98 @@ export class GenericAdapterManager {
this.logger.info(`[AdapterManager] Spawned adapter process PID: ${adapterProcess.pid} (windowsHide=${!!spawnOptions.windowsHide}, detached=${!!spawnOptions.detached})`);

// Set up error handlers and stderr capture
this.setupProcessHandlers(adapterProcess, config.onStdioLine);
const flushStdio = this.setupProcessHandlers(adapterProcess, config.onStdioLine);

return {
process: adapterProcess,
pid: adapterProcess.pid
pid: adapterProcess.pid,
flushStdio
};
}

/**
* Set up process event handlers
* Set up process event handlers. Returns the early flush of both stdio
* line buffers (AdapterSpawnResult.flushStdio, issue #860).
*/
private setupProcessHandlers(
adapterProcess: ChildProcess,
onStdioLine?: (source: AdapterStdioSource, line: string) => void
): void {
onStdioLine?: (source: AdapterStdioSource, line: string, info?: AdapterStdioLineInfo) => void
): () => void {
adapterProcess.on('error', (err: Error) => {
this.logger.error('[AdapterManager] Adapter process spawn error:', err);
});

const flushes: Array<() => void> = [];

// Capture stderr for diagnostics. Chunks arrive at arbitrary byte
// boundaries, so they are line-buffered before sanitization — a secret
// assignment split across two chunks would otherwise leak its tail past
// the key/value redaction patterns (issues #151/#153).
if (adapterProcess.stderr) {
this.consumeStream(
flushes.push(this.consumeStream(
adapterProcess.stderr,
'stderr',
line => this.logger.error(`[AdapterManager STDERR] ${line}`),
onStdioLine && (line => onStdioLine('stderr', line))
);
onStdioLine
));
}

// stdout is piped but carries no DAP traffic (that goes over TCP); drain
// it through the same sanitized path so a chatty adapter cannot fill the
// pipe buffer and stall, and its diagnostics land in the log at debug.
if (adapterProcess.stdout) {
this.consumeStream(
flushes.push(this.consumeStream(
adapterProcess.stdout,
'stdout',
line => this.logger.debug(`[AdapterManager STDOUT] ${line}`),
onStdioLine && (line => onStdioLine('stdout', line))
);
onStdioLine
));
}

adapterProcess.on('exit', (code: number | null, signal: NodeJS.Signals | null) => {
this.logger.info(`[AdapterManager] Adapter process exited. Code: ${code}, Signal: ${signal}`);
});

return () => {
for (const flush of flushes) {
flush();
}
};
}

/**
* Line-buffer, sanitize, and log a child output stream. The trailing
* partial line is flushed on the stream's own 'end'/'close', never on
* process 'exit' — the pipe can still deliver the rest of a split line
* after exit, which would re-create the straddle leak (issue #151).
*
* Returns that same flush for the caller to run early, marking the lines
* partial (issue #860): an adapter that outlives its debuggee never closes
* the pipes when the program ends, so the worker runs it once its
* exit-time drain has seen the pipes go quiet — the program has exited and
* the fragment is its last word, not half of a line still being written.
* The straddle reasoning above is about process 'exit' with the pipe still
* live; this flush rests on the measured silence instead (issue #856).
* Idempotent: an emptied buffer yields nothing on the later 'end'/'close'.
*/
private consumeStream(
stream: Readable,
source: AdapterStdioSource,
logLine: (line: string) => void,
forwardLine?: (line: string) => void
): void {
forwardLine?: (source: AdapterStdioSource, line: string, info?: AdapterStdioLineInfo) => void
): () => void {
const buffer = new LineBuffer();
const record = (lines: string[]) => {
const record = (lines: string[], info?: AdapterStdioLineInfo) => {
if (forwardLine) {
// Debuggee-output fan-out (issue #222): raw lines, blank lines
// included — they are program output, not log noise.
// included — they are program output, not log noise. Only a flushed
// fragment carries the info argument.
for (const line of lines) {
forwardLine(line);
if (info) {
forwardLine(source, line, info);
} else {
forwardLine(source, line);
}
}
}
for (const line of sanitizeStderr(lines.filter(l => l.trim().length > 0))) {
Expand All @@ -223,6 +260,7 @@ export class GenericAdapterManager {
const flush = () => record(buffer.flush());
stream.on('end', flush);
stream.on('close', flush);
return () => record(buffer.flush(), { partial: true });
}

/**
Expand Down
9 changes: 9 additions & 0 deletions src/proxy/dap-proxy-interfaces.ts
Original file line number Diff line number Diff line change
Expand Up @@ -287,6 +287,15 @@ export interface AdapterConfig {
export interface AdapterSpawnResult {
process: ChildProcess;
pid: number;
/**
* Hand over whatever the line buffers of the adapter's stdio still hold —
* the last line a program printed without a newline — through the same
* onStdioLine path as a complete line, marked partial. For an adapter that
* outlives its debuggee the pipes stay open after the program ends, so
* the worker asks for it when its exit-time drain settles (issue #860).
* Nothing pending, nothing forwarded; a later stream close finds nothing.
*/
flushStdio?: () => void;
}

// ===== State Management =====
Expand Down
29 changes: 24 additions & 5 deletions src/proxy/dap-proxy-worker.ts
Original file line number Diff line number Diff line change
Expand Up @@ -25,7 +25,7 @@ import {
} from './dap-proxy-interfaces.js';
import type { IDapMirrorServer, MirrorEndpoint } from './dap-mirror-server.js';
import { CallbackRequestTracker } from './dap-proxy-request-tracker.js';
import { GenericAdapterManager, AdapterStdioSource } from './dap-proxy-adapter-manager.js';
import { GenericAdapterManager, AdapterStdioSource, AdapterStdioLineInfo } from './dap-proxy-adapter-manager.js';
import { dapTracePathFor, proxyLogPathFor } from './session-log-layout.js';
import { DapConnectionManager } from './dap-proxy-connection-manager.js';
import {
Expand Down Expand Up @@ -131,6 +131,13 @@ export class DapProxyWorker {
* delivers is counted and timed, so the drain can settle on silence.
*/
private adapterStdioActivity: { chunks: number; lastChunkAt: number } | null = null;
/**
* Armed with adapterStdioActivity (issue #860): hands over the last line
* the program printed without a newline, which the adapter manager's line
* buffer would otherwise hold until the pipes close at teardown — after
* the exit has been forwarded. Run once the drain has settled on silence.
*/
private adapterStdioFlush: (() => void) | null = null;
/** When the first terminal signal arrived: the silence that counts is measured from here. */
private firstTerminalSignalAt: number | null = null;
// Terminal signals (exited/terminated DAP events, socket close, adapter
Expand Down Expand Up @@ -549,6 +556,7 @@ export class DapProxyWorker {
this.adapterStdioDrained = this.createStdioDrainBarrier(spawnResult.process);
if (spawnConfig.forwardStdio.adapterOutlivesDebuggee) {
this.adapterStdioActivity = this.trackStdioActivity(spawnResult.process);
this.adapterStdioFlush = spawnResult.flushStdio ?? null;
}
}
this.adapterExitCodeIsDebuggeeExitCode = spawnConfig.adapterExitCodeIsDebuggeeExitCode === true;
Expand Down Expand Up @@ -2474,6 +2482,14 @@ export class DapProxyWorker {
* backstop still bounds both: a pipe that neither closes nor falls silent
* (something the program started is still writing to it) is not waited
* for longer than before. No-op when forwarding is off.
*
* For that same adapter, a last line printed without a newline is still
* in the adapter manager's line buffer when the wait ends on silence or at
* the backstop — the pipes it would be flushed on never closed (issue
* #860). It is asked for here, before the caller forwards the exit, so it
* reaches the session buffer ahead of exited/terminated like a complete
* line does; IPC is FIFO. When the pipes did close the manager flushed on
* its own and this finds nothing.
*/
private async waitForAdapterStdioDrain(): Promise<void> {
if (!this.adapterStdioDrained) {
Expand All @@ -2486,6 +2502,7 @@ export class DapProxyWorker {
const quiet = this.adapterStdioActivity ? this.waitForAdapterStdioQuiet(this.adapterStdioActivity) : undefined;
try {
await Promise.race([this.adapterStdioDrained, backstop, ...(quiet ? [quiet.settled] : [])]);
this.adapterStdioFlush?.();
} finally {
if (timer) {
clearTimeout(timer);
Expand Down Expand Up @@ -2636,19 +2653,21 @@ export class DapProxyWorker {
*/
private buildStdioForwarder(
forwardConfig: { excludeStderrLinePattern?: RegExp } | undefined
): ((source: AdapterStdioSource, line: string) => void) | undefined {
): ((source: AdapterStdioSource, line: string, info?: AdapterStdioLineInfo) => void) | undefined {
if (!forwardConfig) {
return undefined;
}
const exclude = forwardConfig.excludeStderrLinePattern;
return (source, line) => {
return (source, line, info) => {
if (source === 'stderr' && exclude?.test(line)) {
return; // adapter diagnostic banner: log path only
}
try {
// '\n' restores the line ending LineBuffer stripped, and keeps blank
// lines past handleOutput's empty-output drop.
this.sendDapEvent('output', { category: source, output: line + '\n' });
// lines past handleOutput's empty-output drop. A flushed fragment
// (issue #860) had no line ending to restore: it is forwarded as
// printed, and is never blank.
this.sendDapEvent('output', { category: source, output: info?.partial ? line : line + '\n' });
} catch (err) {
// IPC gone during teardown; a stream 'data' handler must never throw.
this.logger?.debug?.('[Worker] Failed to forward adapter stdio line', err);
Expand Down
87 changes: 85 additions & 2 deletions tests/proxy/dap-proxy-worker.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -1978,8 +1978,22 @@ describe('DapProxyWorker', () => {
adapterProcess.kill = vi.fn();
adapterProcess.unref = vi.fn();

// The adapter manager's line buffer, reduced to one fragment: what a
// last line with no newline leaves behind until the pipe closes.
// flushStdio is the worker's way of asking for it (issue #860); the
// stream's own close hands it over as before.
let pendingFragment: string | undefined;
const flushStdio = vi.fn(() => {
if (pendingFragment !== undefined) {
const fragment = pendingFragment;
pendingFragment = undefined;
spawnConfig.onStdioLine('stdout', fragment, { partial: true });
}
});
adapterProcess.stdout.on('close', flushStdio);

const processStub = {
spawn: vi.fn().mockResolvedValue({ process: adapterProcess as ChildProcess, pid: 4245 }),
spawn: vi.fn().mockResolvedValue({ process: adapterProcess as ChildProcess, pid: 4245, flushStdio }),
shutdown: vi.fn().mockResolvedValue(undefined)
};
const connectionStub = {
Expand Down Expand Up @@ -2034,9 +2048,78 @@ describe('DapProxyWorker', () => {
adapterProcess.stdout.emit('data', Buffer.from(`${line}\n`));
spawnConfig.onStdioLine('stdout', line);
};
return { adapterProcess, sent, forwarded, output };
/** A chunk whose last line has no newline: the line is forwarded, the tail stays buffered. */
const outputWithFragment = (line: string, fragment: string) => {
adapterProcess.stdout.emit('data', Buffer.from(`${line}\n${fragment}`));
spawnConfig.onStdioLine('stdout', line);
pendingFragment = fragment;
};
/** Index of the forwarded output event carrying exactly this text, or -1. */
const outputIndex = (text: string) => sent().findIndex(m =>
m.type === 'dapEvent' && m.event === 'output' && isRecord(m.body) && m.body.output === text);
return { adapterProcess, sent, forwarded, output, outputWithFragment, outputIndex, flushStdio };
}

it('forwards a last line without a newline, as printed, before exited (issue #860)', async () => {
const { forwarded, outputWithFragment, outputIndex, sent } = await startWorker({ adapterOutlivesDebuggee: true });
vi.useFakeTimers();
try {
outputWithFragment('first line', 'result: 42');
mockDapClient.emit('exited', { exitCode: 0 });
expect(outputIndex('result: 42')).toBe(-1);

await vi.advanceTimersByTimeAsync(QUIET_MS + 40);
expect(forwarded('exited')).toBe(true);
const fragmentIdx = outputIndex('result: 42');
expect(fragmentIdx).toBeGreaterThan(outputIndex('first line\n'));
expect(fragmentIdx).toBeLessThan(sent().findIndex(m => m.type === 'dapEvent' && m.event === 'exited'));
// No newline the program never printed
expect(outputIndex('result: 42\n')).toBe(-1);
} finally {
vi.useRealTimers();
}
});

it('asks for the fragment once per drain, after the window, not while output still arrives', async () => {
const { output, outputWithFragment, outputIndex, flushStdio } = await startWorker({ adapterOutlivesDebuggee: true });
vi.useFakeTimers();
try {
mockDapClient.emit('exited', { exitCode: 0 });
await vi.advanceTimersByTimeAsync(60);
output('still printing');
expect(flushStdio).not.toHaveBeenCalled();

outputWithFragment('last full line', 'tail');
await vi.advanceTimersByTimeAsync(QUIET_MS + 40);
expect(flushStdio).toHaveBeenCalledTimes(1);
expect(outputIndex('tail')).toBeGreaterThan(outputIndex('last full line\n'));
} finally {
vi.useRealTimers();
}
});

it('leaves the fragment to the pipe close for an adapter whose pipes close with the debuggee', async () => {
// rdbg -c: the pipes close when the program ends, and the manager's
// own close flush delivers the fragment — the worker asks for nothing.
const { adapterProcess, forwarded, outputWithFragment, outputIndex, flushStdio } = await startWorker({});
vi.useFakeTimers();
try {
outputWithFragment('first line', 'result: 42');
mockDapClient.emit('exited', { exitCode: 0 });
await vi.advanceTimersByTimeAsync(10 * QUIET_MS);
expect(forwarded('exited')).toBe(false);
expect(flushStdio).not.toHaveBeenCalled();

adapterProcess.stdout.emit('close');
adapterProcess.stderr.emit('close');
await vi.advanceTimersByTimeAsync(1);
expect(forwarded('exited')).toBe(true);
expect(outputIndex('result: 42')).toBeGreaterThanOrEqual(0);
} finally {
vi.useRealTimers();
}
});

it('forwards exited once the pipes have been quiet for a moment, not at the backstop', async () => {
const { forwarded } = await startWorker({ adapterOutlivesDebuggee: true });
vi.useFakeTimers();
Expand Down
Loading
Loading