Fix issues where logger is defined before ready. Clean up extension lifecycle.

Author: GirlBossRush

package.json

@@ -87,7 +87,6 @@
     "vscode-ripgrep": "^1.12.0",
     "vscode-sqlite3": "4.0.11",
     "vscode-textmate": "5.4.0",
-    "ws": "^8.0.0",
     "xterm": "4.13.0",
     "xterm-addon-search": "0.9.0-beta.3",
     "xterm-addon-unicode11": "0.3.0-beta.5",

src/vs/base/parts/ipc/common/ipc.net.ts

@@ -833,10 +833,7 @@ export class PersistentProtocol implements IMessagePassingProtocol {
 		this._socketReader = new ProtocolReader(this._socket);
 		this._socketDisposables.push(this._socketReader);
 		this._socketDisposables.push(this._socketReader.onMessage(msg => this._receiveMessage(msg)));
-		this._socketDisposables.push(this._socket.onClose((e) => {
-			console.log('SOCKET DISPOSABLE CLOSE RECONNECTION', e?.type || 'unknown');
-			return this._onSocketClose.fire(e);
-		}));
+		this._socketDisposables.push(this._socket.onClose((e) => this._onSocketClose.fire(e)));
 		this._socketReader.acceptChunk(initialDataChunk);
 	}
 

src/vs/base/parts/ipc/node/ipc.cp.ts

@@ -294,6 +294,9 @@ export class Client implements IChannelClient, IDisposable {
 }
 
 export type ExtensionHostMessage = IRemoteConsoleLog | IExtHostReadyMessage;
+/**
+ * Creates an extension host child process with a standard disposable interface.
+ */
 export class ExtensionHost implements IDisposable {
 	private child: ChildProcess | null = null;
 	private readonly _onDidProcessExit = new Emitter<{ code: number, signal: string }>();
@@ -315,7 +318,7 @@ export class ExtensionHost implements IDisposable {
 		this.disposeClient();
 	}
 
-	sendIPCMessage(message: IExtHostMessage, sendHandle?: SendHandle) {
+	sendIPCMessage(message: IExtHostMessage, sendHandle?: SendHandle): boolean {
 		if (this.child && this.child.connected) {
 			return this.child.send(message, sendHandle);
 		}
@@ -327,6 +330,7 @@ export class ExtensionHost implements IDisposable {
 		const args = options && options.args ? this.options.args : [];
 		const forkOpts: ForkOptions = Object.create(null);
 
+		forkOpts.silent = true;
 		forkOpts.env = { ...deepClone(process.env), 'VSCODE_PARENT_PID': String(process.pid) };
 
 		if (this.options && this.options.env) {

src/vs/platform/remote/common/remoteAgentConnection.ts

@@ -25,7 +25,10 @@ export const enum ConnectionType {
 	Tunnel = 3,
 }
 
-function connectionTypeToString(connectionType: ConnectionType): string {
+/**
+ * @coder exported for server side use.
+ */
+export function connectionTypeToString(connectionType: ConnectionType): string {
 	switch (connectionType) {
 		case ConnectionType.Management:
 			return 'Management';
@@ -238,12 +241,9 @@ async function connectToRemoteExtensionHostAgent(options: ISimpleConnectionOptio
 	options.logService.info(`${logPrefix} 1/6. invoking socketFactory.connect().`);
 
 	let socket: ISocket;
+
 	try {
-		/**
-		 * @coder Add connection type to the socket.
-		 * This is so they can be distinguished by the backend.
-		 */
-		socket = await createSocket(options.logService, options.socketFactory, options.host, options.port, `type=${connectionTypeToString(connectionType)}&reconnectionToken=${options.reconnectionToken}&reconnection=${options.reconnectionProtocol ? 'true' : 'false'}`, timeoutCancellationToken);
+		socket = await createSocket(options.logService, options.socketFactory, options.host, options.port, `reconnectionToken=${options.reconnectionToken}&reconnection=${options.reconnectionProtocol ? 'true' : 'false'}`, timeoutCancellationToken);
 	} catch (error) {
 		options.logService.error(`${logPrefix} socketFactory.connect() failed or timed out. Error:`);
 		options.logService.error(error);

src/vs/server/connection/abstractConnection.ts

@@ -18,13 +18,15 @@ export abstract class AbstractConnection {
 	private disposed = false;
 	private _offline: number | undefined;
 
-	protected readonly logService: ConsoleLogger;
+	protected get logPrefix() {
+		return `[${this.name}] ${this.protocol.logPrefix}`;
+	}
 
 	public constructor(
 		protected readonly protocol: ServerProtocol,
+		protected readonly logService: ConsoleLogger,
 		public readonly name: string,
 	) {
-		this.logService = new ConsoleLogger();
 
 		this.logService.debug('Connecting...');
 		this.onClose(() => this.logService.debug('Closed'));
@@ -77,3 +79,42 @@ export abstract class AbstractConnection {
 	 */
 	protected abstract doDispose(): void;
 }
+
+/**
+ * Connection options sent by the client via a remote agent connection.
+ */
+export interface ConnectionOptions {
+	/** The token is how we identify and connect to existing sessions. */
+	readonly reconnectionToken: string,
+	/** Specifies that the client is trying to reconnect. */
+	readonly reconnection: boolean,
+	/** If true assume this is not a web socket (always false for code-server). */
+	readonly skipWebSocketFrames: boolean,
+}
+
+/**
+ * Convenience function to convert a client's query params into a useful object.
+ */
+export function parseQueryConnectionOptions(query: URLSearchParams): ConnectionOptions {
+	const reconnectionToken = query.get('reconnectionToken');
+	const reconnection = query.get('reconnection');
+	const skipWebSocketFrames = query.get('skipWebSocketFrames');
+
+	if (typeof reconnectionToken !== 'string') {
+		throw new Error('`reconnectionToken` not present in query');
+	}
+
+	if (typeof reconnection !== 'string') {
+		throw new Error('`reconnection` not present in query');
+	}
+
+	if (typeof skipWebSocketFrames !== 'string') {
+		throw new Error('`skipWebSocketFrames` not present in query');
+	}
+
+	return {
+		reconnectionToken,
+		reconnection: reconnection === 'true',
+		skipWebSocketFrames: skipWebSocketFrames === 'true',
+	};
+}

src/vs/server/connection/extensionHostConnection.ts

@@ -9,6 +9,8 @@ import { parseExtensionDevOptions } from 'vs/workbench/services/extensions/commo
 import { findFreePort } from 'vs/base/node/ports';
 import { ExtensionHost, IIPCOptions } from 'vs/base/parts/ipc/node/ipc.cp';
 import { VSBuffer } from 'vs/base/common/buffer';
+import { SendHandle } from 'child_process';
+import { ConsoleLogger } from 'vs/platform/log/common/log';
 
 export interface ForkEnvironmentVariables {
 	VSCODE_AMD_ENTRYPOINT: string;
@@ -24,26 +26,28 @@ export interface ForkEnvironmentVariables {
 	VSCODE_CODE_CACHE_PATH?: string;
 }
 
+/**
+ * This complements the client-side `PersistantConnection` in `RemoteExtensionHost`.
+ */
 export class ExtensionHostConnection extends AbstractConnection {
 	private clientProcess?: ExtensionHost;
 
 	/** @TODO Document usage. */
 	public readonly _isExtensionDevHost: boolean;
 	public readonly _isExtensionDevDebug: boolean;
-	public readonly _isExtensionDevDebugBrk: boolean;
 	public readonly _isExtensionDevTestFromCli: boolean;
 
 	public constructor(
 		protocol: ServerProtocol,
+		logService: ConsoleLogger,
 		private readonly startParams: IRemoteExtensionHostStartParams,
 		private readonly _environmentService: INativeEnvironmentService,
 	) {
-		super(protocol, 'exthost');
+		super(protocol, logService, 'ExtensionHost');
 
 		const devOpts = parseExtensionDevOptions(this._environmentService);
 		this._isExtensionDevHost = devOpts.isExtensionDevHost;
 		this._isExtensionDevDebug = devOpts.isExtensionDevDebug;
-		this._isExtensionDevDebugBrk = devOpts.isExtensionDevDebugBrk;
 		this._isExtensionDevTestFromCli = devOpts.isExtensionDevTestFromCli;
 	}
 
@@ -72,11 +76,6 @@ export class ExtensionHostConnection extends AbstractConnection {
 				if (port !== expected) {
 					console.warn(`%c[Extension Host] %cProvided debugging port ${expected} is not free, using ${port} instead.`, 'color: blue', 'color:');
 				}
-				if (this._isExtensionDevDebugBrk) {
-					console.warn(`%c[Extension Host] %cSTOPPED on first line for debugging on port ${port}`, 'color: blue', 'color:');
-				} else {
-					console.info(`%c[Extension Host] %cdebugger listening on port ${port}`, 'color: blue', 'color:');
-				}
 			}
 		}
 
@@ -90,41 +89,44 @@ export class ExtensionHostConnection extends AbstractConnection {
 	}
 
 	protected doReconnect(reconnectionProtocol: ServerProtocol): void {
+		this.logService.info(this.logPrefix, '(Reconnect 1/4)', 'Sending new protocol debug message...');
+		reconnectionProtocol.sendMessage(this.debugMessage);
+
+		this.logService.info(this.logPrefix, '(Reconnect 2/4)', 'Swapping socket references...');
+
 		this.protocol.beginAcceptReconnection(reconnectionProtocol.getSocket(), reconnectionProtocol.readEntireBuffer());
 		this.protocol.endAcceptReconnection();
 
-		this.protocol.sendMessage(this.debugMessage);
+		this.logService.info(this.logPrefix, '(Reconnect 3/4)', 'Pausing socket until we have a chance to forward its data.');
+		const { initialDataChunk, sendHandle } = this.protocol.suspend();
 
-		const { initialDataChunk } = this.protocol;
-
-		// Pause reading on the socket until we have a chance to forward its data.
-		this.protocol.dispose();
-		this.protocol.getSendHandle().pause();
-		this.protocol.getSocket().drain();
+		const messageSent = this.sendInitMessage(initialDataChunk, this.protocol.inflateBytes, sendHandle);
 
+		if (!messageSent) {
+			new Error('Child process did not receive init message. Is their a backlog?');
+		}
 
-		this.sendInitMessage(initialDataChunk, this.protocol.inflateBytes);
+		this.logService.info(this.logPrefix, '(Reconnect 4/4)', 'Child process received init message!');
 	}
 
 	/**
-	 * Sends IPC socket to child process.
+	 * Sends IPC socket to client process.
+	 * @remark This is the complement of `extensionHostProcessSetup.ts#_createExtHostProtocol`
 	 */
-	private sendInitMessage(initialDataChunk: VSBuffer, inflateBytes?: VSBuffer): void {
-		this.logService.info(this.logPrefix, 'Sending socket');
-
-		const foo = this.protocol.getSendHandle();
-
-		if (typeof foo === 'undefined') {
-			throw new Error('SEND HANDLE IS UNDEFINED.');
+	private sendInitMessage(initialDataChunk: VSBuffer, inflateBytes: VSBuffer, sendHandle: SendHandle): boolean {
+		if (!this.clientProcess) {
+			throw new Error(`${this.logPrefix} Client process is not set`);
 		}
 
-		this.clientProcess?.sendIPCMessage({
+		this.logService.info(this.logPrefix, 'Sending init message to client process...');
+
+		return this.clientProcess.sendIPCMessage({
 			type: 'VSCODE_EXTHOST_IPC_SOCKET',
 			initialDataChunk: Buffer.from(initialDataChunk.buffer).toString('base64'),
 			skipWebSocketFrames: this.protocol.skipWebSocketFrames,
 			permessageDeflate: this.protocol.getSocket().permessageDeflate,
 			inflateBytes: inflateBytes ? Buffer.from(inflateBytes.buffer).toString('base64') : '',
-		}, foo);
+		}, sendHandle);
 	}
 
 	private async generateClientOptions(): Promise<IIPCOptions> {
@@ -135,8 +137,8 @@ export class ExtensionHostConnection extends AbstractConnection {
 		return {
 			serverName: 'Server Extension Host',
 			freshExecArgv: true,
-			debugBrk: this._isExtensionDevDebugBrk ? portNumber : undefined,
-			debug: this._isExtensionDevDebugBrk ? undefined : portNumber,
+			debugBrk: this.startParams.break ? portNumber : undefined,
+			debug: this.startParams.break ? undefined : portNumber,
 			args: ['--type=extensionHost', '--skipWorkspaceStorageLock'],
 			env: <ForkEnvironmentVariables>{
 				VSCODE_AMD_ENTRYPOINT: 'vs/workbench/services/extensions/node/extensionHostProcess',
@@ -156,39 +158,45 @@ export class ExtensionHostConnection extends AbstractConnection {
 		};
 	}
 
-	public async spawn() {
-		this.protocol.sendMessage(this.debugMessage);
+	/**
+	 * Creates an extension host child process.
+	 * @remark this is very similar to `LocalProcessExtensionHost`
+	 */
+	public spawn(): Promise<void> {
+		return new Promise(async (resolve, reject) => {
+			this.logService.info(this.logPrefix, '(Spawn 1/7)', 'Sending client initial debug message.');
+			this.protocol.sendMessage(this.debugMessage);
 
-		const { initialDataChunk } = this.protocol;
+			this.logService.info(this.logPrefix, '(Spawn 2/7)', 'Pausing socket until we have a chance to forward its data.');
 
-		// Pause reading on the socket until we have a chance to forward its data.
-		this.protocol.dispose();
-		this.protocol.getSendHandle().pause();
-		this.protocol.getSocket().drain();
+			const { initialDataChunk, sendHandle } = this.protocol.suspend();
 
-		this.logService.debug(this.logPrefix, 'Spawning extension host...');
-		const clientOptions = await this.generateClientOptions();
+			this.logService.info(this.logPrefix, '(Spawn 3/7)', 'Generating IPC client options...');
+			const clientOptions = await this.generateClientOptions();
 
-		// Run Extension Host as fork of current process
-		this.clientProcess = new ExtensionHost(FileAccess.asFileUri('bootstrap-fork', require).fsPath, clientOptions);
+			this.logService.info(this.logPrefix, '(Spawn 4/7)', 'Starting extension host child process...');
+			this.clientProcess = new ExtensionHost(FileAccess.asFileUri('bootstrap-fork', require).fsPath, clientOptions);
 
-		this.clientProcess.onDidProcessExit(({ code, signal }) => {
-			this.dispose();
+			this.clientProcess.onDidProcessExit(({ code, signal }) => {
+				this.dispose();
 
-			if (code !== 0 && signal !== 'SIGTERM') {
-				this.logService.error(`[${this.protocol.reconnectionToken}] Extension host exited with code: ${code} and signal: ${signal}.`);
-			}
-		});
+				if (code !== 0 && signal !== 'SIGTERM') {
+					this.logService.error(`${this.logPrefix} Extension host exited with code: ${code} and signal: ${signal}.`);
+				}
+			});
 
-		this.clientProcess.onReady(() => {
-			this.logService.info(this.logPrefix, 'Handshake completed');
-			this.sendInitMessage(initialDataChunk, this.protocol.inflateBytes);
-		});
+			this.clientProcess.onReady(() => {
+				this.logService.info(this.logPrefix, '(Spawn 5/7)', 'Extension host is ready!');
+				this.logService.info(this.logPrefix, '(Spawn 6/7)', 'Sending init message to child process...');
+				const messageSent = this.sendInitMessage(initialDataChunk, this.protocol.inflateBytes, sendHandle);
 
-		this.logService.info(this.logPrefix, 'Waiting for handshake...');
-	}
+				if (messageSent) {
+					this.logService.info(this.logPrefix, '(Spawn 7/7)', 'Child process received init message!');
+					return resolve();
+				}
 
-	private get logPrefix() {
-		return `[${this.protocol.reconnectionToken}]`;
+				reject(new Error('Child process did not receive init message. Is their a backlog?'));
+			});
+		});
 	}
 }

src/vs/server/connection/index.ts

@@ -3,15 +3,16 @@
 //  *  Licensed under the MIT License. See License.txt in the project root for license information.
 //  *--------------------------------------------------------------------------------------------*/
 
+import { ConsoleLogger } from 'vs/platform/log/common/log';
 import { AbstractConnection } from 'vs/server/connection/abstractConnection';
 import { ServerProtocol } from 'vs/server/protocol';
 
 /**
  * Used for all the IPC channels.
  */
 export class ManagementConnection extends AbstractConnection {
-	public constructor(protocol: ServerProtocol) {
-		super(protocol, 'management');
+	public constructor(protocol: ServerProtocol, logService: ConsoleLogger) {
+		super(protocol, logService, 'management');
 
 		protocol.onDidDispose(() => this.dispose('Explicitly closed'));
 		protocol.onSocketClose(() => this.setOffline()); // Might reconnect.
@@ -23,10 +24,11 @@ export class ManagementConnection extends AbstractConnection {
 		this.protocol.dispose();
 	}
 
-	protected doReconnect(protocol: ServerProtocol): void {
-		protocol.sendMessage({ type: 'ok' });
-		this.protocol.beginAcceptReconnection(protocol.getSocket(), protocol.readEntireBuffer());
+	protected doReconnect(reconnectionProtocol: ServerProtocol): void {
+		reconnectionProtocol.sendMessage({ type: 'ok' });
+
+		this.protocol.beginAcceptReconnection(reconnectionProtocol.getSocket(), reconnectionProtocol.readEntireBuffer());
 		this.protocol.endAcceptReconnection();
-		protocol.dispose();
+		reconnectionProtocol.dispose();
 	}
 }