WIP Fix issues surrounding net socket lifecycle, and frequent restarts.

Author: GirlBossRush

resources/web/code-web.js

@@ -491,19 +491,19 @@ async function handleRoot(req, res) {
  * @param webConfigJSON {import('../../src/vs/workbench/workbench.web.api').IServerWorkbenchConstructionOptions}
  */
 async function handleRootFromServer(req, res, webConfigJSON) {
-	const { extensions: builtInExtensions } = await builtInExtensionsPromise;
-	const { extensions: additionalBuiltinExtensions, locations: staticLocations } = await commandlineProvidedExtensionsPromise;
+	// const { extensions: builtInExtensions } = await builtInExtensionsPromise;
+	// const { extensions: additionalBuiltinExtensions, locations: staticLocations } = await commandlineProvidedExtensionsPromise;
 
-	const dedupedBuiltInExtensions = [];
-	for (const builtInExtension of builtInExtensions) {
-		const extensionId = `${builtInExtension.packageJSON.publisher}.${builtInExtension.packageJSON.name}`;
-		if (staticLocations[extensionId]) {
-			fancyLog(`${ansiColors.magenta('BuiltIn extensions')}: Ignoring built-in ${extensionId} because it was overridden via --extension argument`);
-			continue;
-		}
+	// const dedupedBuiltInExtensions = [];
+	// for (const builtInExtension of builtInExtensions) {
+	// 	const extensionId = `${builtInExtension.packageJSON.publisher}.${builtInExtension.packageJSON.name}`;
+	// 	if (staticLocations[extensionId]) {
+	// 		fancyLog(`${ansiColors.magenta('BuiltIn extensions')}: Ignoring built-in ${extensionId} because it was overridden via --extension argument`);
+	// 		continue;
+	// 	}
 
-		dedupedBuiltInExtensions.push(builtInExtension);
-	}
+	// 	dedupedBuiltInExtensions.push(builtInExtension);
+	// }
 
 	if (args.verbose) {
 		fancyLog(`${ansiColors.magenta('BuiltIn extensions')}: ${dedupedBuiltInExtensions.map(e => path.basename(e.extensionPath)).join(', ')}`);
@@ -518,7 +518,7 @@ async function handleRootFromServer(req, res, webConfigJSON) {
 
 	const data = (await readFile(WEB_MAIN)).toString()
 		.replace('{{WORKBENCH_WEB_CONFIGURATION}}', () => escapeAttribute(JSON.stringify(webConfigJSON))) // use a replace function to avoid that regexp replace patterns ($&, $0, ...) are applied
-		.replace('{{WORKBENCH_BUILTIN_EXTENSIONS}}', () => escapeAttribute(JSON.stringify(dedupedBuiltInExtensions)))
+		// .replace('{{WORKBENCH_BUILTIN_EXTENSIONS}}', () => escapeAttribute(JSON.stringify(dedupedBuiltInExtensions)))
 		.replace('{{WORKBENCH_AUTH_SESSION}}', () => authSessionInfo ? escapeAttribute(JSON.stringify(authSessionInfo)) : '')
 		.replace('{{WEBVIEW_ENDPOINT}}', '');
 

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

@@ -715,7 +715,10 @@ 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) => this._onSocketClose.fire(e)));
+		this._socketDisposables.push(this._socket.onClose((e) => {
+			console.log('SOCKET DISPOSABLE CLOSE', (e as WebSocketCloseEvent).reason);
+			return this._onSocketClose.fire(e);
+		}));
 		if (initialChunk) {
 			this._socketReader.acceptChunk(initialChunk);
 		}
@@ -804,6 +807,11 @@ export class PersistentProtocol implements IMessagePassingProtocol {
 		return this._socket;
 	}
 
+	// NOTE@coder: add setSocket
+	public setSocket(socket: ISocket) {
+		this._socket = socket;
+	}
+
 	public getMillisSinceLastIncomingData(): number {
 		return Date.now() - this._socketReader.lastReadTime;
 	}
@@ -825,7 +833,10 @@ 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) => this._onSocketClose.fire(e)));
+		this._socketDisposables.push(this._socket.onClose((e) => {
+			console.log('SOCKET DISPOSABLE CLOSE RECONNECTION', e?.type || 'unknown');
+			return this._onSocketClose.fire(e);
+		}));
 		this._socketReader.acceptChunk(initialDataChunk);
 	}
 

src/vs/platform/log/node/spdlogLog.ts

@@ -14,7 +14,9 @@ async function createSpdLogLogger(name: string, logfilePath: string, filesize: n
 		_spdlog.setFlushOn(LogLevel.Trace);
 		return _spdlog.createAsyncRotatingLogger(name, logfilePath, filesize, filecount);
 	} catch (e) {
-		console.error(e);
+		// console.error(e);
+		// TODO@coder enable
+		console.error('generic log failure');
 	}
 	return null;
 }

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

@@ -63,7 +63,17 @@ export interface OKMessage {
 	type: 'ok';
 }
 
-export type HandshakeMessage = AuthRequest | SignRequest | ConnectionTypeRequest | ErrorMessage | OKMessage;
+/**
+ * Expected response from `CodeServer` connection.
+ * @coder Moved from inline type for use outside this module.
+ */
+export interface DebugMessage {
+	type: 'debug';
+	debugPort?: NonNullable<IRemoteExtensionHostStartParams['port']>;
+}
+
+
+export type HandshakeMessage = AuthRequest | SignRequest | ConnectionTypeRequest | ErrorMessage | OKMessage | DebugMessage;
 
 
 interface ISimpleConnectionOptions {
@@ -225,20 +235,22 @@ function raceWithTimeoutCancellation<T>(promise: Promise<T>, timeoutCancellation
 async function connectToRemoteExtensionHostAgent(options: ISimpleConnectionOptions, connectionType: ConnectionType, args: any | undefined, timeoutCancellationToken: CancellationToken): Promise<{ protocol: PersistentProtocol; ownsProtocol: boolean; }> {
 	const logPrefix = connectLogPrefix(options, connectionType);
 
-	options.logService.trace(`${logPrefix} 1/6. invoking socketFactory.connect().`);
+	options.logService.info(`${logPrefix} 1/6. invoking socketFactory.connect().`);
 
 	let socket: ISocket;
 	try {
-		// NOTE@coder: Add connection type to the socket. This is so they can be
-		// distinguished by the backend.
+		/**
+		 * @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);
 	} catch (error) {
 		options.logService.error(`${logPrefix} socketFactory.connect() failed or timed out. Error:`);
 		options.logService.error(error);
 		throw error;
 	}
 
-	options.logService.trace(`${logPrefix} 2/6. socketFactory.connect() was successful.`);
+	options.logService.info(`${logPrefix} 2/6. socketFactory.connect() was successful.`);
 
 	let protocol: PersistentProtocol;
 	let ownsProtocol: boolean;
@@ -251,7 +263,7 @@ async function connectToRemoteExtensionHostAgent(options: ISimpleConnectionOptio
 		ownsProtocol = true;
 	}
 
-	options.logService.trace(`${logPrefix} 3/6. sending AuthRequest control message.`);
+	options.logService.info(`${logPrefix} 3/6. sending AuthRequest control message.`);
 	const authRequest: AuthRequest = {
 		type: 'auth',
 		auth: options.connectionToken || '00000000000000000000'
@@ -267,7 +279,7 @@ async function connectToRemoteExtensionHostAgent(options: ISimpleConnectionOptio
 			throw error;
 		}
 
-		options.logService.trace(`${logPrefix} 4/6. received SignRequest control message.`);
+		options.logService.info(`${logPrefix} 4/6. received SignRequest control message.`);
 
 		const signed = await raceWithTimeoutCancellation(options.signService.sign(msg.data), timeoutCancellationToken);
 		const connTypeRequest: ConnectionTypeRequest = {
@@ -280,7 +292,7 @@ async function connectToRemoteExtensionHostAgent(options: ISimpleConnectionOptio
 			connTypeRequest.args = args;
 		}
 
-		options.logService.trace(`${logPrefix} 5/6. sending ConnectionTypeRequest control message.`);
+		options.logService.info(`${logPrefix} 5/6. sending ConnectionTypeRequest control message.`);
 		protocol.sendControl(VSBuffer.fromString(JSON.stringify(connTypeRequest)));
 
 		return { protocol, ownsProtocol };
@@ -324,7 +336,7 @@ async function connectToRemoteExtensionHostAgentAndReadOneMessage<T>(options: IS
 			if (options.reconnectionProtocol) {
 				options.reconnectionProtocol.endAcceptReconnection();
 			}
-			options.logService.trace(`${logPrefix} 6/6. handshake finished, connection is up and running after ${logElapsed(startTime)}!`);
+			options.logService.info(`${logPrefix} 6/6. handshake finished, connection is up and running after ${logElapsed(startTime)}!`);
 			result.resolve({ protocol, firstMessage: msg });
 		}
 	}));
@@ -350,7 +362,9 @@ interface IExtensionHostConnectionResult {
 }
 
 async function doConnectRemoteAgentExtensionHost(options: ISimpleConnectionOptions, startArguments: IRemoteExtensionHostStartParams, timeoutCancellationToken: CancellationToken): Promise<IExtensionHostConnectionResult> {
-	const { protocol, firstMessage } = await connectToRemoteExtensionHostAgentAndReadOneMessage<{ debugPort?: number; }>(options, ConnectionType.ExtensionHost, startArguments, timeoutCancellationToken);
+	console.log('>>> READING ONE MESSAGE', options, startArguments);
+	const { protocol, firstMessage } = await connectToRemoteExtensionHostAgentAndReadOneMessage<DebugMessage>(options, ConnectionType.ExtensionHost, startArguments, timeoutCancellationToken);
+	console.log('>>> READ ONE MESSAGE', JSON.stringify(firstMessage));
 	const debugPort = firstMessage && firstMessage.debugPort;
 	return { protocol, debugPort };
 }
@@ -363,7 +377,7 @@ async function doConnectRemoteAgentTunnel(options: ISimpleConnectionOptions, sta
 	const startTime = Date.now();
 	const logPrefix = connectLogPrefix(options, ConnectionType.Tunnel);
 	const { protocol } = await connectToRemoteExtensionHostAgent(options, ConnectionType.Tunnel, startParams, timeoutCancellationToken);
-	options.logService.trace(`${logPrefix} 6/6. handshake finished, connection is up and running after ${logElapsed(startTime)}!`);
+	options.logService.info(`${logPrefix} 6/6. handshake finished, connection is up and running after ${logElapsed(startTime)}!`);
 	return protocol;
 }
 
@@ -553,7 +567,7 @@ abstract class PersistentConnection extends Disposable {
 		}));
 		this._register(protocol.onSocketTimeout(() => {
 			const logPrefix = commonLogPrefix(this._connectionType, this.reconnectionToken, true);
-			this._options.logService.trace(`${logPrefix} received socket timeout event.`);
+			this._options.logService.info(`${logPrefix} received socket timeout event.`);
 			this._beginReconnecting();
 		}));
 
@@ -632,19 +646,19 @@ abstract class PersistentConnection extends Disposable {
 				}
 				if (RemoteAuthorityResolverError.isTemporarilyNotAvailable(err)) {
 					this._options.logService.info(`${logPrefix} A temporarily not available error occurred while trying to reconnect, will try again...`);
-					this._options.logService.trace(err);
+					this._options.logService.info(err);
 					// try again!
 					continue;
 				}
 				if ((err.code === 'ETIMEDOUT' || err.code === 'ENETUNREACH' || err.code === 'ECONNREFUSED' || err.code === 'ECONNRESET') && err.syscall === 'connect') {
 					this._options.logService.info(`${logPrefix} A network error occurred while trying to reconnect, will try again...`);
-					this._options.logService.trace(err);
+					this._options.logService.info(err);
 					// try again!
 					continue;
 				}
 				if (isPromiseCanceledError(err)) {
 					this._options.logService.info(`${logPrefix} A promise cancelation error occurred while trying to reconnect, will try again...`);
-					this._options.logService.trace(err);
+					this._options.logService.info(err);
 					// try again!
 					continue;
 				}

src/vs/platform/remote/node/serverWebSocket.ts renamed to src/vs/platform/remote/node/serverSocket.ts

@@ -3,6 +3,7 @@
  *  Licensed under the MIT License. See License.txt in the project root for license information.
  *--------------------------------------------------------------------------------------------*/
 
+import * as net from 'net';
 import * as WebSocket from 'ws';
 import { Disposable, IDisposable } from 'vs/base/common/lifecycle';
 import { Event, Emitter } from 'vs/base/common/event';
@@ -18,7 +19,6 @@ import { VSBuffer } from 'vs/base/common/buffer';
  * by `ServerSocket`. This allows IPC-style protocol handlers to interact with it.
  */
 class ServerWebSocket extends Disposable implements IWebSocket {
-
 	private readonly _onData = new Emitter<ArrayBuffer>();
 	public readonly onData = this._onData.event;
 
@@ -117,10 +117,12 @@ class ServerWebSocket extends Disposable implements IWebSocket {
 }
 
 export class ServerSocket implements ISocket {
+	public readonly socket: net.Socket;
 	public readonly ws: ServerWebSocket;
 
-	constructor(ws: WebSocket) {
+	constructor(ws: WebSocket, socket: net.Socket) {
 		this.ws = new ServerWebSocket(ws);
+		this.socket = socket;
 	}
 
 	public dispose(): void {
@@ -136,15 +138,17 @@ export class ServerSocket implements ISocket {
 			if (typeof e === 'undefined') {
 				listener(e);
 			} else {
+				console.log('SERVER CLOSE');
 				listener({
 					type: SocketCloseEventType.WebSocketCloseEvent,
 					code: e.code,
-					reason: e.reason,
+					reason: e.reason || getStatusCodeLabel(e.code),
 					wasClean: e.wasClean,
 					event: e.event
 				});
 			}
 		};
+
 		return this.ws.onClose(adapter);
 	}
 
@@ -164,3 +168,40 @@ export class ServerSocket implements ISocket {
 		return Promise.resolve();
 	}
 }
+
+const specificStatusCodeMappings: { [code: string]: string | undefined } = {
+	'1000': 'Normal Closure',
+	'1001': 'Going Away',
+	'1002': 'Protocol Error',
+	'1003': 'Unsupported Data',
+	'1004': '(For future)',
+	'1005': 'No Status Received',
+	'1006': 'Abnormal Closure',
+	'1007': 'Invalid frame payload data',
+	'1008': 'Policy Violation',
+	'1009': 'Message too big',
+	'1010': 'Missing Extension',
+	'1011': 'Internal Error',
+	'1012': 'Service Restart',
+	'1013': 'Try Again Later',
+	'1014': 'Bad Gateway',
+	'1015': 'TLS Handshake'
+};
+
+function getStatusCodeLabel(code: number) {
+	if (code >= 0 && code <= 999) {
+		return '(Unused)';
+	} else if (code >= 1016) {
+		if (code <= 1999) {
+			return '(For WebSocket standard)';
+		} else if (code <= 2999) {
+			return '(For WebSocket extensions)';
+		} else if (code <= 3999) {
+			return '(For libraries and frameworks)';
+		} else if (code <= 4999) {
+			return '(For applications)';
+		}
+	}
+
+	return specificStatusCodeMappings[code] || '(Unknown)';
+}

src/vs/server/connection/abstractConnection.ts

@@ -34,13 +34,13 @@ export abstract class AbstractConnection {
 	}
 
 	public reconnect(protocol: ServerProtocol): void {
-		// this.logger.debug(`${this.protocol.options.reconnectionToken} Reconnecting...`);
+		this.logger.debug(`${this.protocol.reconnectionToken} Reconnecting...`);
 		this._offline = undefined;
 		this.doReconnect(protocol);
 	}
 
 	public dispose(reason?: string): void {
-		// this.logger.debug(`${this.protocol.options.reconnectionToken} Disposing...`, reason);
+		this.logger.debug(`${this.protocol.reconnectionToken} Disposing...`, reason);
 		if (!this.disposed) {
 			this.disposed = true;
 			this.doDispose();