Skip to content

Commit 5dfec6e

Browse files
debugmcpdevcynarlabclaude
authored
fix(proxy): forward a program's last line without a newline before its exit on Windows (#860) (#869)
On Windows the debuggee of a CodeLLDB-based adapter (rust, cpp, cobol) writes into the adapter's stdio pipes, and GenericAdapterManager splits that stream into lines with a LineBuffer: complete lines are forwarded as they arrive, the trailing fragment on the stream's end/close. CodeLLDB keeps its pipes open until teardown, so a last line printed without a newline was flushed after exited/terminated had been forwarded and the session had stopped listening — `result: 42` never reached get_output. AdapterSpawnResult gains an optional flushStdio(): the early flush of both stdio line buffers, delivering what they hold through onStdioLine marked `{ partial: true }`. The worker keeps it for an adapter that outlives its debuggee and runs it when waitForAdapterStdioDrain settles — on the measured quiet window or the backstop (#856) — before every caller forwards its terminal signal, so the fragment lands ahead of exited on the FIFO IPC channel. The forwarder leaves a partial line without the '\n' it restores for complete lines: the fragment arrives as printed. When the pipes did close, the manager's own close flush ran first and the early flush finds nothing; rdbg (pipes close with the program) is unchanged. Measured on Windows 11 through the dev server, cpp adapter: before, get_output ended at `first line\n`; after, `result: 42` follows 103 ms later (the quiet window), with no added newline, and a 2000-char stdout fragment plus a stderr fragment arrive intact with exit code 3. Co-authored-by: JF <john.franklin@gmail.com> Co-authored-by: Claude Fable 5.1 <noreply@anthropic.com>
1 parent 6cb0c52 commit 5dfec6e

6 files changed

Lines changed: 239 additions & 24 deletions

File tree

‎changelog.d/860.fixed.md‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1 @@
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)

‎src/proxy/dap-proxy-adapter-manager.ts‎

Lines changed: 55 additions & 17 deletions
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,16 @@ import {
1616
/** Which adapter-process stream a forwarded line came from. */
1717
export type AdapterStdioSource = 'stdout' | 'stderr';
1818

19+
/**
20+
* How a forwarded line ended. Only the fragment handed over by
21+
* AdapterSpawnResult.flushStdio carries `partial: true` (issue #860): the
22+
* program wrote it with no newline, so the forwarder must not add one. A
23+
* complete line is delivered without this argument.
24+
*/
25+
export interface AdapterStdioLineInfo {
26+
partial?: boolean;
27+
}
28+
1929
/**
2030
* Configuration for spawning any debug adapter
2131
*/
@@ -33,7 +43,7 @@ export interface GenericAdapterConfig {
3343
* the redaction that protects persisted logs must not rewrite what the
3444
* debugging client sees, matching debugpy/js-debug output-event behavior.
3545
*/
36-
onStdioLine?: (source: AdapterStdioSource, line: string) => void;
46+
onStdioLine?: (source: AdapterStdioSource, line: string, info?: AdapterStdioLineInfo) => void;
3747
}
3848

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

150160
// Set up error handlers and stderr capture
151-
this.setupProcessHandlers(adapterProcess, config.onStdioLine);
161+
const flushStdio = this.setupProcessHandlers(adapterProcess, config.onStdioLine);
152162

153163
return {
154164
process: adapterProcess,
155-
pid: adapterProcess.pid
165+
pid: adapterProcess.pid,
166+
flushStdio
156167
};
157168
}
158169

159170
/**
160-
* Set up process event handlers
171+
* Set up process event handlers. Returns the early flush of both stdio
172+
* line buffers (AdapterSpawnResult.flushStdio, issue #860).
161173
*/
162174
private setupProcessHandlers(
163175
adapterProcess: ChildProcess,
164-
onStdioLine?: (source: AdapterStdioSource, line: string) => void
165-
): void {
176+
onStdioLine?: (source: AdapterStdioSource, line: string, info?: AdapterStdioLineInfo) => void
177+
): () => void {
166178
adapterProcess.on('error', (err: Error) => {
167179
this.logger.error('[AdapterManager] Adapter process spawn error:', err);
168180
});
169181

182+
const flushes: Array<() => void> = [];
183+
170184
// Capture stderr for diagnostics. Chunks arrive at arbitrary byte
171185
// boundaries, so they are line-buffered before sanitization — a secret
172186
// assignment split across two chunks would otherwise leak its tail past
173187
// the key/value redaction patterns (issues #151/#153).
174188
if (adapterProcess.stderr) {
175-
this.consumeStream(
189+
flushes.push(this.consumeStream(
176190
adapterProcess.stderr,
191+
'stderr',
177192
line => this.logger.error(`[AdapterManager STDERR] ${line}`),
178-
onStdioLine && (line => onStdioLine('stderr', line))
179-
);
193+
onStdioLine
194+
));
180195
}
181196

182197
// stdout is piped but carries no DAP traffic (that goes over TCP); drain
183198
// it through the same sanitized path so a chatty adapter cannot fill the
184199
// pipe buffer and stall, and its diagnostics land in the log at debug.
185200
if (adapterProcess.stdout) {
186-
this.consumeStream(
201+
flushes.push(this.consumeStream(
187202
adapterProcess.stdout,
203+
'stdout',
188204
line => this.logger.debug(`[AdapterManager STDOUT] ${line}`),
189-
onStdioLine && (line => onStdioLine('stdout', line))
190-
);
205+
onStdioLine
206+
));
191207
}
192208

193209
adapterProcess.on('exit', (code: number | null, signal: NodeJS.Signals | null) => {
194210
this.logger.info(`[AdapterManager] Adapter process exited. Code: ${code}, Signal: ${signal}`);
195211
});
212+
213+
return () => {
214+
for (const flush of flushes) {
215+
flush();
216+
}
217+
};
196218
}
197219

198220
/**
199221
* Line-buffer, sanitize, and log a child output stream. The trailing
200222
* partial line is flushed on the stream's own 'end'/'close', never on
201223
* process 'exit' — the pipe can still deliver the rest of a split line
202224
* after exit, which would re-create the straddle leak (issue #151).
225+
*
226+
* Returns that same flush for the caller to run early, marking the lines
227+
* partial (issue #860): an adapter that outlives its debuggee never closes
228+
* the pipes when the program ends, so the worker runs it once its
229+
* exit-time drain has seen the pipes go quiet — the program has exited and
230+
* the fragment is its last word, not half of a line still being written.
231+
* The straddle reasoning above is about process 'exit' with the pipe still
232+
* live; this flush rests on the measured silence instead (issue #856).
233+
* Idempotent: an emptied buffer yields nothing on the later 'end'/'close'.
203234
*/
204235
private consumeStream(
205236
stream: Readable,
237+
source: AdapterStdioSource,
206238
logLine: (line: string) => void,
207-
forwardLine?: (line: string) => void
208-
): void {
239+
forwardLine?: (source: AdapterStdioSource, line: string, info?: AdapterStdioLineInfo) => void
240+
): () => void {
209241
const buffer = new LineBuffer();
210-
const record = (lines: string[]) => {
242+
const record = (lines: string[], info?: AdapterStdioLineInfo) => {
211243
if (forwardLine) {
212244
// Debuggee-output fan-out (issue #222): raw lines, blank lines
213-
// included — they are program output, not log noise.
245+
// included — they are program output, not log noise. Only a flushed
246+
// fragment carries the info argument.
214247
for (const line of lines) {
215-
forwardLine(line);
248+
if (info) {
249+
forwardLine(source, line, info);
250+
} else {
251+
forwardLine(source, line);
252+
}
216253
}
217254
}
218255
for (const line of sanitizeStderr(lines.filter(l => l.trim().length > 0))) {
@@ -223,6 +260,7 @@ export class GenericAdapterManager {
223260
const flush = () => record(buffer.flush());
224261
stream.on('end', flush);
225262
stream.on('close', flush);
263+
return () => record(buffer.flush(), { partial: true });
226264
}
227265

228266
/**

‎src/proxy/dap-proxy-interfaces.ts‎

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -287,6 +287,15 @@ export interface AdapterConfig {
287287
export interface AdapterSpawnResult {
288288
process: ChildProcess;
289289
pid: number;
290+
/**
291+
* Hand over whatever the line buffers of the adapter's stdio still hold —
292+
* the last line a program printed without a newline — through the same
293+
* onStdioLine path as a complete line, marked partial. For an adapter that
294+
* outlives its debuggee the pipes stay open after the program ends, so
295+
* the worker asks for it when its exit-time drain settles (issue #860).
296+
* Nothing pending, nothing forwarded; a later stream close finds nothing.
297+
*/
298+
flushStdio?: () => void;
290299
}
291300

292301
// ===== State Management =====

‎src/proxy/dap-proxy-worker.ts‎

Lines changed: 24 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -25,7 +25,7 @@ import {
2525
} from './dap-proxy-interfaces.js';
2626
import type { IDapMirrorServer, MirrorEndpoint } from './dap-mirror-server.js';
2727
import { CallbackRequestTracker } from './dap-proxy-request-tracker.js';
28-
import { GenericAdapterManager, AdapterStdioSource } from './dap-proxy-adapter-manager.js';
28+
import { GenericAdapterManager, AdapterStdioSource, AdapterStdioLineInfo } from './dap-proxy-adapter-manager.js';
2929
import { dapTracePathFor, proxyLogPathFor } from './session-log-layout.js';
3030
import { DapConnectionManager } from './dap-proxy-connection-manager.js';
3131
import {
@@ -131,6 +131,13 @@ export class DapProxyWorker {
131131
* delivers is counted and timed, so the drain can settle on silence.
132132
*/
133133
private adapterStdioActivity: { chunks: number; lastChunkAt: number } | null = null;
134+
/**
135+
* Armed with adapterStdioActivity (issue #860): hands over the last line
136+
* the program printed without a newline, which the adapter manager's line
137+
* buffer would otherwise hold until the pipes close at teardown — after
138+
* the exit has been forwarded. Run once the drain has settled on silence.
139+
*/
140+
private adapterStdioFlush: (() => void) | null = null;
134141
/** When the first terminal signal arrived: the silence that counts is measured from here. */
135142
private firstTerminalSignalAt: number | null = null;
136143
// Terminal signals (exited/terminated DAP events, socket close, adapter
@@ -549,6 +556,7 @@ export class DapProxyWorker {
549556
this.adapterStdioDrained = this.createStdioDrainBarrier(spawnResult.process);
550557
if (spawnConfig.forwardStdio.adapterOutlivesDebuggee) {
551558
this.adapterStdioActivity = this.trackStdioActivity(spawnResult.process);
559+
this.adapterStdioFlush = spawnResult.flushStdio ?? null;
552560
}
553561
}
554562
this.adapterExitCodeIsDebuggeeExitCode = spawnConfig.adapterExitCodeIsDebuggeeExitCode === true;
@@ -2474,6 +2482,14 @@ export class DapProxyWorker {
24742482
* backstop still bounds both: a pipe that neither closes nor falls silent
24752483
* (something the program started is still writing to it) is not waited
24762484
* for longer than before. No-op when forwarding is off.
2485+
*
2486+
* For that same adapter, a last line printed without a newline is still
2487+
* in the adapter manager's line buffer when the wait ends on silence or at
2488+
* the backstop — the pipes it would be flushed on never closed (issue
2489+
* #860). It is asked for here, before the caller forwards the exit, so it
2490+
* reaches the session buffer ahead of exited/terminated like a complete
2491+
* line does; IPC is FIFO. When the pipes did close the manager flushed on
2492+
* its own and this finds nothing.
24772493
*/
24782494
private async waitForAdapterStdioDrain(): Promise<void> {
24792495
if (!this.adapterStdioDrained) {
@@ -2486,6 +2502,7 @@ export class DapProxyWorker {
24862502
const quiet = this.adapterStdioActivity ? this.waitForAdapterStdioQuiet(this.adapterStdioActivity) : undefined;
24872503
try {
24882504
await Promise.race([this.adapterStdioDrained, backstop, ...(quiet ? [quiet.settled] : [])]);
2505+
this.adapterStdioFlush?.();
24892506
} finally {
24902507
if (timer) {
24912508
clearTimeout(timer);
@@ -2636,19 +2653,21 @@ export class DapProxyWorker {
26362653
*/
26372654
private buildStdioForwarder(
26382655
forwardConfig: { excludeStderrLinePattern?: RegExp } | undefined
2639-
): ((source: AdapterStdioSource, line: string) => void) | undefined {
2656+
): ((source: AdapterStdioSource, line: string, info?: AdapterStdioLineInfo) => void) | undefined {
26402657
if (!forwardConfig) {
26412658
return undefined;
26422659
}
26432660
const exclude = forwardConfig.excludeStderrLinePattern;
2644-
return (source, line) => {
2661+
return (source, line, info) => {
26452662
if (source === 'stderr' && exclude?.test(line)) {
26462663
return; // adapter diagnostic banner: log path only
26472664
}
26482665
try {
26492666
// '\n' restores the line ending LineBuffer stripped, and keeps blank
2650-
// lines past handleOutput's empty-output drop.
2651-
this.sendDapEvent('output', { category: source, output: line + '\n' });
2667+
// lines past handleOutput's empty-output drop. A flushed fragment
2668+
// (issue #860) had no line ending to restore: it is forwarded as
2669+
// printed, and is never blank.
2670+
this.sendDapEvent('output', { category: source, output: info?.partial ? line : line + '\n' });
26522671
} catch (err) {
26532672
// IPC gone during teardown; a stream 'data' handler must never throw.
26542673
this.logger?.debug?.('[Worker] Failed to forward adapter stdio line', err);

‎tests/proxy/dap-proxy-worker.test.ts‎

Lines changed: 85 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1978,8 +1978,22 @@ describe('DapProxyWorker', () => {
19781978
adapterProcess.kill = vi.fn();
19791979
adapterProcess.unref = vi.fn();
19801980

1981+
// The adapter manager's line buffer, reduced to one fragment: what a
1982+
// last line with no newline leaves behind until the pipe closes.
1983+
// flushStdio is the worker's way of asking for it (issue #860); the
1984+
// stream's own close hands it over as before.
1985+
let pendingFragment: string | undefined;
1986+
const flushStdio = vi.fn(() => {
1987+
if (pendingFragment !== undefined) {
1988+
const fragment = pendingFragment;
1989+
pendingFragment = undefined;
1990+
spawnConfig.onStdioLine('stdout', fragment, { partial: true });
1991+
}
1992+
});
1993+
adapterProcess.stdout.on('close', flushStdio);
1994+
19811995
const processStub = {
1982-
spawn: vi.fn().mockResolvedValue({ process: adapterProcess as ChildProcess, pid: 4245 }),
1996+
spawn: vi.fn().mockResolvedValue({ process: adapterProcess as ChildProcess, pid: 4245, flushStdio }),
19831997
shutdown: vi.fn().mockResolvedValue(undefined)
19841998
};
19851999
const connectionStub = {
@@ -2034,9 +2048,78 @@ describe('DapProxyWorker', () => {
20342048
adapterProcess.stdout.emit('data', Buffer.from(`${line}\n`));
20352049
spawnConfig.onStdioLine('stdout', line);
20362050
};
2037-
return { adapterProcess, sent, forwarded, output };
2051+
/** A chunk whose last line has no newline: the line is forwarded, the tail stays buffered. */
2052+
const outputWithFragment = (line: string, fragment: string) => {
2053+
adapterProcess.stdout.emit('data', Buffer.from(`${line}\n${fragment}`));
2054+
spawnConfig.onStdioLine('stdout', line);
2055+
pendingFragment = fragment;
2056+
};
2057+
/** Index of the forwarded output event carrying exactly this text, or -1. */
2058+
const outputIndex = (text: string) => sent().findIndex(m =>
2059+
m.type === 'dapEvent' && m.event === 'output' && isRecord(m.body) && m.body.output === text);
2060+
return { adapterProcess, sent, forwarded, output, outputWithFragment, outputIndex, flushStdio };
20382061
}
20392062

2063+
it('forwards a last line without a newline, as printed, before exited (issue #860)', async () => {
2064+
const { forwarded, outputWithFragment, outputIndex, sent } = await startWorker({ adapterOutlivesDebuggee: true });
2065+
vi.useFakeTimers();
2066+
try {
2067+
outputWithFragment('first line', 'result: 42');
2068+
mockDapClient.emit('exited', { exitCode: 0 });
2069+
expect(outputIndex('result: 42')).toBe(-1);
2070+
2071+
await vi.advanceTimersByTimeAsync(QUIET_MS + 40);
2072+
expect(forwarded('exited')).toBe(true);
2073+
const fragmentIdx = outputIndex('result: 42');
2074+
expect(fragmentIdx).toBeGreaterThan(outputIndex('first line\n'));
2075+
expect(fragmentIdx).toBeLessThan(sent().findIndex(m => m.type === 'dapEvent' && m.event === 'exited'));
2076+
// No newline the program never printed
2077+
expect(outputIndex('result: 42\n')).toBe(-1);
2078+
} finally {
2079+
vi.useRealTimers();
2080+
}
2081+
});
2082+
2083+
it('asks for the fragment once per drain, after the window, not while output still arrives', async () => {
2084+
const { output, outputWithFragment, outputIndex, flushStdio } = await startWorker({ adapterOutlivesDebuggee: true });
2085+
vi.useFakeTimers();
2086+
try {
2087+
mockDapClient.emit('exited', { exitCode: 0 });
2088+
await vi.advanceTimersByTimeAsync(60);
2089+
output('still printing');
2090+
expect(flushStdio).not.toHaveBeenCalled();
2091+
2092+
outputWithFragment('last full line', 'tail');
2093+
await vi.advanceTimersByTimeAsync(QUIET_MS + 40);
2094+
expect(flushStdio).toHaveBeenCalledTimes(1);
2095+
expect(outputIndex('tail')).toBeGreaterThan(outputIndex('last full line\n'));
2096+
} finally {
2097+
vi.useRealTimers();
2098+
}
2099+
});
2100+
2101+
it('leaves the fragment to the pipe close for an adapter whose pipes close with the debuggee', async () => {
2102+
// rdbg -c: the pipes close when the program ends, and the manager's
2103+
// own close flush delivers the fragment — the worker asks for nothing.
2104+
const { adapterProcess, forwarded, outputWithFragment, outputIndex, flushStdio } = await startWorker({});
2105+
vi.useFakeTimers();
2106+
try {
2107+
outputWithFragment('first line', 'result: 42');
2108+
mockDapClient.emit('exited', { exitCode: 0 });
2109+
await vi.advanceTimersByTimeAsync(10 * QUIET_MS);
2110+
expect(forwarded('exited')).toBe(false);
2111+
expect(flushStdio).not.toHaveBeenCalled();
2112+
2113+
adapterProcess.stdout.emit('close');
2114+
adapterProcess.stderr.emit('close');
2115+
await vi.advanceTimersByTimeAsync(1);
2116+
expect(forwarded('exited')).toBe(true);
2117+
expect(outputIndex('result: 42')).toBeGreaterThanOrEqual(0);
2118+
} finally {
2119+
vi.useRealTimers();
2120+
}
2121+
});
2122+
20402123
it('forwards exited once the pipes have been quiet for a moment, not at the backstop', async () => {
20412124
const { forwarded } = await startWorker({ adapterOutlivesDebuggee: true });
20422125
vi.useFakeTimers();

0 commit comments

Comments
 (0)