Add logging for calls of process.exit in the extension host

src/vs/workbench/api/common/extHostExtensionService.ts

@@ -51,7 +51,7 @@ export const IHostUtils = createDecorator<IHostUtils>('IHostUtils');
 
 export interface IHostUtils {
 	readonly _serviceBrand: undefined;
-	exit(code?: number): void;
+	exit(code: number): void;
 	exists(path: string): Promise<boolean>;
 	realpath(path: string): Promise<string>;
 }
@@ -610,11 +610,17 @@ export abstract class AbstractExtHostExtensionService extends Disposable impleme
 	}
 
 	private _testRunnerExit(code: number): void {
+		this._logService.info(`extension host terminating: test runner requested exit with code ${code}`);
+		this._logService.flush();
+
 		// wait at most 5000ms for the renderer to confirm our exit request and for the renderer socket to drain
 		// (this is to ensure all outstanding messages reach the renderer)
 		const exitPromise = this._mainThreadExtensionsProxy.$onExtensionHostExit(code);
 		const drainPromise = this._extHostContext.drain();
 		Promise.race([Promise.all([exitPromise, drainPromise]), timeout(5000)]).then(() => {
+			this._logService.info(`exiting with code ${code}`);
+			this._logService.flush();
+
 			this._hostUtils.exit(code);
 		});
 	}

src/vs/workbench/services/extensions/common/extensionHostMain.ts

@@ -37,6 +37,7 @@ export class ExtensionHostMain {
 	private _isTerminating: boolean;
 	private readonly _hostUtils: IHostUtils;
 	private readonly _extensionService: IExtHostExtensionService;
+	private readonly _logService: ILogService;
 	private readonly _disposables = new DisposableStore();
 
 	constructor(
@@ -65,12 +66,11 @@ export class ExtensionHostMain {
 		const terminalService = instaService.invokeFunction(accessor => accessor.get(IExtHostTerminalService));
 		this._disposables.add(terminalService);
 
-		const logService = instaService.invokeFunction(accessor => accessor.get(ILogService));
-		this._disposables.add(logService);
+		this._logService = instaService.invokeFunction(accessor => accessor.get(ILogService));
 
 		performance.mark(`extHost/didCreateServices`);
-		logService.info('extension host started');
-		logService.trace('initData', initData);
+		this._logService.info('extension host started');
+		this._logService.trace('initData', initData);
 
 		// ugly self - inject
 		// must call initialize *after* creating the extension service
@@ -112,12 +112,14 @@ export class ExtensionHostMain {
 		});
 	}
 
-	terminate(): void {
+	terminate(reason: string): void {
 		if (this._isTerminating) {
 			// we are already shutting down...
 			return;
 		}
 		this._isTerminating = true;
+		this._logService.info(`extension host terminating: ${reason}`);
+		this._logService.flush();
 
 		this._disposables.dispose();
 
@@ -129,7 +131,12 @@ export class ExtensionHostMain {
 
 		// Give extensions 1 second to wrap up any async dispose, then exit in at most 4 seconds
 		setTimeout(() => {
-			Promise.race([timeout(4000), extensionsDeactivated]).finally(() => this._hostUtils.exit());
+			Promise.race([timeout(4000), extensionsDeactivated]).finally(() => {
+				this._logService.info(`exiting with code 0`);
+				this._logService.flush();
+				this._logService.dispose();
+				this._hostUtils.exit(0);
+			});
 		}, 1000);
 	}
 

src/vs/workbench/services/extensions/node/extensionHostProcessSetup.ts

@@ -93,7 +93,7 @@ interface IRendererConnection {
 
 // This calls exit directly in case the initialization is not finished and we need to exit
 // Otherwise, if initialization completed we go to extensionHostMain.terminate()
-let onTerminate = function () {
+let onTerminate = function (reason: string) {
 	nativeExit();
 };
 
@@ -110,8 +110,8 @@ function _createExtHostProtocol(): Promise<PersistentProtocol> {
 
 			const reconnectionGraceTime = ProtocolConstants.ReconnectionGraceTime;
 			const reconnectionShortGraceTime = ProtocolConstants.ReconnectionShortGraceTime;
-			const disconnectRunner1 = new RunOnceScheduler(() => onTerminate(), reconnectionGraceTime);
-			const disconnectRunner2 = new RunOnceScheduler(() => onTerminate(), reconnectionShortGraceTime);
+			const disconnectRunner1 = new RunOnceScheduler(() => onTerminate('renderer disconnected for too long (1)'), reconnectionGraceTime);
+			const disconnectRunner2 = new RunOnceScheduler(() => onTerminate('renderer disconnected for too long (2)'), reconnectionShortGraceTime);
 
 			process.on('message', (msg: IExtHostSocketMessage | IExtHostReduceGraceTimeMessage, handle: net.Socket) => {
 				if (msg && msg.type === 'VSCODE_EXTHOST_IPC_SOCKET') {
@@ -131,7 +131,7 @@ function _createExtHostProtocol(): Promise<PersistentProtocol> {
 					} else {
 						clearTimeout(timer);
 						protocol = new PersistentProtocol(socket, initialDataChunk);
-						protocol.onDidDispose(() => onTerminate());
+						protocol.onDidDispose(() => onTerminate('renderer disconnected'));
 						resolve(protocol);
 
 						// Wait for rich client to reconnect
@@ -192,7 +192,7 @@ async function createExtHostProtocol(): Promise<IMessagePassingProtocol> {
 			protocol.onMessage((msg) => {
 				if (isMessageOfType(msg, MessageType.Terminate)) {
 					this._terminating = true;
-					onTerminate();
+					onTerminate('received terminate message from renderer');
 				} else {
 					this._onMessage.fire(msg);
 				}
@@ -268,7 +268,7 @@ function connectToRenderer(protocol: IMessagePassingProtocol): Promise<IRenderer
 				try {
 					process.kill(initData.parentPid, 0); // throws an exception if the main process doesn't exist anymore.
 				} catch (e) {
-					onTerminate();
+					onTerminate(`parent process ${initData.parentPid} does not exist anymore`);
 				}
 			}, 1000);
 
@@ -334,5 +334,5 @@ export async function startExtensionHostProcess(): Promise<void> {
 	);
 
 	// rewrite onTerminate-function to be a proper shutdown
-	onTerminate = () => extensionHostMain.terminate();
+	onTerminate = (reason: string) => extensionHostMain.terminate(reason);
 }

src/vs/workbench/services/extensions/worker/extensionHostWorker.ts

@@ -111,7 +111,7 @@ class ExtensionWorker {
 			if (isMessageOfType(msg, MessageType.Terminate)) {
 				// handle terminate-message right here
 				terminating = true;
-				onTerminate();
+				onTerminate('received terminate message from renderer');
 				return;
 			}
 
@@ -147,7 +147,7 @@ function connectToRenderer(protocol: IMessagePassingProtocol): Promise<IRenderer
 	});
 }
 
-let onTerminate = nativeClose;
+let onTerminate = (reason: string) => nativeClose();
 
 (function create(): void {
 	const res = new ExtensionWorker();
@@ -161,6 +161,6 @@ let onTerminate = nativeClose;
 			null,
 		);
 
-		onTerminate = () => extHostMain.terminate();
+		onTerminate = (reason: string) => extHostMain.terminate(reason);
 	});
 })();