src/goDebugFactory: wait before killing the spawned dap server

VSCode disposes the debug adapter as soon as it receives the
disconnect response or reaches timeout. On the other hand,
dlv dap is doing some remaining cleanup after sending a
disconnect response. Allow some time for dlv dap to finish
the cleanup.

And, do not destroy the socket (closing both read/write),
but end the socket (closing write) when the proxy adapter's
dispose is called.
In order to make it clear which side of the socket we
are closing, this CL changes ProxyDebugAdapter.start to take
stream.Readable and stream.Writable instead of a single
duplex stream.

https://nodejs.org/api/stream.html#stream_writable_end_chunk_encoding_callback

Change-Id: I00f5a7685f4cc5ab210496ac7af902a137362d9c
Reviewed-on: https://go-review.googlesource.com/c/vscode-go/+/306589
Trust: Hyang-Ah Hana Kim <hyangah@gmail.com>
Run-TryBot: Hyang-Ah Hana Kim <hyangah@gmail.com>
TryBot-Result: kokoro <noreply+kokoro@google.com>
Reviewed-by: Suzy Mueller <suzmue@golang.org>

Author: hyangah

src/goDebugFactory.ts

@@ -51,8 +51,9 @@ const TWO_CRLF = '\r\n\r\n';
 // start method is called.
 export class ProxyDebugAdapter implements vscode.DebugAdapter {
 	private messageEmitter = new vscode.EventEmitter<vscode.DebugProtocolMessage>();
-	// connection to server.
-	private conn?: stream.Duplex;
+	// connection from/to server (= dlv dap)
+	private readable?: stream.Readable;
+	private writable?: stream.Writable;
 
 	constructor() {
 		this.onDidSendMessage = this.messageEmitter.event;
@@ -63,13 +64,6 @@ export class ProxyDebugAdapter implements vscode.DebugAdapter {
 	// listen on onDidSendMessage to receive messages.
 	onDidSendMessage: vscode.Event<vscode.DebugProtocolMessage>;
 	async handleMessage(message: vscode.DebugProtocolMessage): Promise<void> {
-		// TODO(hyangah): dlv dap often terminates before us
-		// receiving the disconnect response, which causes
-		// vscode to hang forever. Either generate a disconnect
-		// respond after timeout so vscode completes the normal
-		// debug session teardown including the call to this
-		// thin adapter's dispose() or change dlv dap not to
-		// kill itself until the client connection is closed.
 		await this.sendMessageToServer(message);
 	}
 
@@ -79,46 +73,45 @@ export class ProxyDebugAdapter implements vscode.DebugAdapter {
 	}
 	protected sendMessageToServer(message: vscode.DebugProtocolMessage): void {
 		const json = JSON.stringify(message) ?? '';
-		if (this.conn) {
-			this.conn.write(`Content-Length: ${Buffer.byteLength(json, 'utf8')}${TWO_CRLF}${json}`, 'utf8', (err) => {
-				if (err) {
-					console.log(`error sending message: ${err}`);
-					this.sendMessageToClient(new TerminatedEvent());
+		if (this.writable) {
+			this.writable.write(
+				`Content-Length: ${Buffer.byteLength(json, 'utf8')}${TWO_CRLF}${json}`,
+				'utf8',
+				(err) => {
+					if (err) {
+						console.log(`error sending message: ${err}`);
+						this.sendMessageToClient(new TerminatedEvent());
+					}
 				}
-			});
+			);
 		} else {
 			console.log(`stream is closed; dropping ${json}`);
 		}
 	}
 
-	public async start(server: stream.Duplex) {
-		if (this.conn) {
+	public async start(readable: stream.Readable, writable: stream.Writable) {
+		if (this.readable || this.writable) {
 			throw new Error('start was called more than once');
 		}
-		this.conn = server;
-		this.conn.on('data', (data: Buffer) => {
+		this.readable = readable;
+		this.writable = writable;
+		this.readable.on('data', (data: Buffer) => {
 			this.handleDataFromServer(data);
 		});
-		this.conn.once('close', () => {
-			console.log('stream closed');
-			this.conn.destroy();
-			this.conn = undefined;
+		this.readable.once('close', () => {
+			this.readable = undefined;
 		});
-		this.conn.on('error', (err) => {
-			console.log(`stream error: ${err}`);
+		this.readable.on('error', (err) => {
 			if (err) {
+				console.log(`stream error: ${err}`);
 				this.sendMessageToClient(new OutputEvent(`socket to network closed: ${err}`, 'console'));
 			}
 			this.sendMessageToClient(new TerminatedEvent());
 		});
 	}
 
 	async dispose() {
-		if (this.conn) {
-			// TODO(hyangah): not sure if sleep is necessary.
-			await sleep(500);
-			this.conn?.destroy();
-		}
+		this.writable?.end(); // no more write.
 	}
 
 	private rawData = Buffer.alloc(0);
@@ -163,10 +156,6 @@ export class ProxyDebugAdapter implements vscode.DebugAdapter {
 	}
 }
 
-function sleep(ms: number) {
-	return new Promise((resolve) => setTimeout(resolve, ms));
-}
-
 // DelveDAPOutputAdapter is a ProxyDebugAdapter that proxies between
 // VSCode and a dlv dap process spawned and managed by this adapter.
 // It turns the process's stdout/stderrr into OutputEvent.
@@ -189,12 +178,27 @@ export class DelveDAPOutputAdapter extends ProxyDebugAdapter {
 	}
 
 	async dispose() {
-		console.log(`DelveDAPOutputAdapter.dispose ${this.dlvDapServer?.pid}`);
-		super.dispose();
-		if (this.connected) {
-			killProcessTree(this.dlvDapServer);
-			this.connected = undefined;
+		await super.dispose();
+
+		if (this.connected === undefined) {
+			return;
 		}
+		this.connected = undefined;
+		const dlvDapServer = this.dlvDapServer;
+		if (dlvDapServer.exitCode !== null) {
+			return;
+		}
+		await new Promise<void>((resolve) => {
+			const exitTimeoutToken = setTimeout(() => {
+				console.log(`killing dlv dap process(${dlvDapServer.pid}) after 1sec`);
+				killProcessTree(dlvDapServer);
+				resolve();
+			}, 1_000);
+			dlvDapServer.on('exit', () => {
+				clearTimeout(exitTimeoutToken);
+				resolve();
+			});
+		});
 	}
 
 	private async startAndConnectToServer() {
@@ -212,16 +216,14 @@ export class DelveDAPOutputAdapter extends ProxyDebugAdapter {
 			});
 			timer = setTimeout(() => {
 				reject('connection timeout');
-				console.log('failed to connect within 1s');
 				s?.destroy();
-				killProcessTree(dlvDapServer);
 			}, 1000);
 		});
 
 		this.dlvDapServer = dlvDapServer;
 		this.port = port;
 		this.socket = socket;
-		this.start(this.socket);
+		this.start(this.socket, this.socket);
 	}
 
 	stdoutEvent(output: string, data?: any) {
@@ -330,6 +332,12 @@ async function spawnDlvDapServerProcess(
 
 		p.stdout.on('data', (chunk) => {
 			if (!started) {
+				// TODO(hyangah): when --log-dest is specified, the following message
+				// will be written to the log dest file, not stdout/stderr.
+				// Either disable --log-dest, or take advantage of it, i.e.,
+				// always pass a file descriptor to --log-dest, watch the file
+				// descriptor to process the log output, and also swap os.Stdout/os.Stderr
+				// in dlv dap for launch requests to generate proper OutputEvents.
 				if (chunk.toString().startsWith('DAP server listening at:')) {
 					stopWaitingForServerToStart();
 				} else {
@@ -347,13 +355,12 @@ async function spawnDlvDapServerProcess(
 			logErr(chunk.toString());
 		});
 		p.on('close', (code) => {
+			// TODO: should we watch 'exit' instead?
 			if (!started) {
 				stopWaitingForServerToStart(`dlv dap closed with code: '${code}' signal: ${p.killed}`);
 			}
 			if (code) {
 				logErr(`Process exiting with code: ${code} signal: ${p.killed}`);
-			} else {
-				log(`Process exited normally: ${p.killed}`);
 			}
 		});
 		p.on('error', (err) => {