first cut of auto extension profiler, #60332

src/vs/workbench/parts/extensions/electron-browser/extensions.contribution.ts

@@ -45,6 +45,7 @@ import { RuntimeExtensionsInput } from 'vs/workbench/services/extensions/electro
 import { URI } from 'vs/base/common/uri';
 import { ContextKeyExpr } from 'vs/platform/contextkey/common/contextkey';
 import { ExtensionActivationProgress } from 'vs/workbench/parts/extensions/electron-browser/extensionsActivationProgress';
+import { ExtensionsAutoProfiler } from 'vs/workbench/parts/extensions/electron-browser/extensionsAutoProfiler';
 
 // Singletons
 registerSingleton(IExtensionsWorkbenchService, ExtensionsWorkbenchService);
@@ -58,6 +59,7 @@ workbenchRegistry.registerWorkbenchContribution(ConfigureRecommendedExtensionsCo
 workbenchRegistry.registerWorkbenchContribution(KeymapExtensions, LifecyclePhase.Running);
 workbenchRegistry.registerWorkbenchContribution(ExtensionsViewletViewsContribution, LifecyclePhase.Starting);
 workbenchRegistry.registerWorkbenchContribution(ExtensionActivationProgress, LifecyclePhase.Eventually);
+workbenchRegistry.registerWorkbenchContribution(ExtensionsAutoProfiler, LifecyclePhase.Eventually);
 
 Registry.as<IOutputChannelRegistry>(OutputExtensions.OutputChannels)
 	.registerChannel({ id: ExtensionsChannelId, label: ExtensionsLabel, log: false });

src/vs/workbench/parts/extensions/electron-browser/extensionsAutoProfiler.ts

+/*---------------------------------------------------------------------------------------------
+ *  Copyright (c) Microsoft Corporation. All rights reserved.
+ *  Licensed under the MIT License. See License.txt in the project root for license information.
+ *--------------------------------------------------------------------------------------------*/
+
+import { IWorkbenchContribution } from 'vs/workbench/common/contributions';
+import { IExtensionService, IResponsiveStateChangeEvent, ICpuProfilerTarget, IExtensionHostProfile } from 'vs/workbench/services/extensions/common/extensions';
+import { ITelemetryService } from 'vs/platform/telemetry/common/telemetry';
+import { Disposable } from 'vs/base/common/lifecycle';
+import { timeout } from 'vs/base/common/async';
+import { onUnexpectedError } from 'vs/base/common/errors';
+import { ILogService } from 'vs/platform/log/common/log';
+
+export class ExtensionsAutoProfiler extends Disposable implements IWorkbenchContribution {
+
+	private _activeProfilingSessions = new Map<ICpuProfilerTarget, boolean>();
+
+	constructor(
+		@IExtensionService extensionService: IExtensionService,
+		@ITelemetryService private readonly _telemetryService: ITelemetryService,
+		@ILogService private readonly _logService: ILogService,
+	) {
+		super();
+		this._register(extensionService.onDidChangeResponsiveChange(this._onDidChangeResponsiveChange, this));
+	}
+
+	private _onDidChangeResponsiveChange(event: IResponsiveStateChangeEvent): void {
+		const { target } = event;
+
+		if (!target.canProfileExtensionHost()) {
+			return;
+		}
+
+		if (!this._activeProfilingSessions.has(target)) {
+			this._activeProfilingSessions.set(target, true);
+			this._profileNSeconds(target).then(profile => {
+				this._processCpuProfile(profile);
+				this._activeProfilingSessions.delete(target);
+			}).catch(err => {
+				onUnexpectedError(err);
+				this._activeProfilingSessions.delete(target);
+			});
+		}
+	}
+
+	private _profileNSeconds(target: ICpuProfilerTarget, seconds: number = 5): Promise<IExtensionHostProfile> {
+		return target.startExtensionHostProfile().then(session => {
+			return timeout(seconds * 1000).then(() => session.stop());
+		}).catch(err => {
+			return Promise.reject(err);
+		});
+	}
+
+	private _processCpuProfile(profile: IExtensionHostProfile) {
+
+		interface NamedSlice {
+			id: string;
+			total: number;
+			percentage: number;
+		}
+
+		let data: NamedSlice[] = [];
+		for (let i = 0; i < profile.ids.length; i++) {
+			let id = profile.ids[i];
+			let total = profile.deltas[i];
+			data.push({ id, total, percentage: 0 });
+		}
+
+		// merge data by identifier
+		let anchor = 0;
+		data.sort((a, b) => a.id.localeCompare(b.id));
+		for (let i = 1; i < data.length; i++) {
+			if (data[anchor].id === data[i].id) {
+				data[anchor].total += data[i].total;
+			} else {
+				anchor += 1;
+				data[anchor] = data[i];
+			}
+		}
+		data = data.slice(0, anchor + 1);
+
+		let percentage = (profile.endTime - profile.startTime) / 100;
+		let top: NamedSlice;
+		for (const slice of data) {
+			slice.percentage = Math.round(slice.total / percentage);
+			if (!top || top.percentage < slice.percentage) {
+				top = slice;
+			}
+		}
+
+		this._logService.warn(`UNRESPONSIVE extension host, '${top.id}' took ${top.percentage}% of ${(profile.endTime - profile.startTime) / 1e3}ms`, data);
+
+		this._telemetryService.publicLog('extensionsAutoProfile', data);
+	}
+}

src/vs/workbench/services/commands/test/common/commandService.test.ts

@@ -20,6 +20,7 @@ class SimpleExtensionService implements IExtensionService {
 	}
 	onDidChangeExtensionsStatus = null;
 	onWillActivateByEvent = null;
+	onDidChangeResponsiveChange = null;
 	activateByEvent(activationEvent: string): Promise<void> {
 		return this.whenInstalledExtensionsRegistered().then(() => { });
 	}

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

@@ -132,7 +132,12 @@ export interface IWillActivateEvent {
 	readonly activation: Thenable<void>;
 }
 
-export interface IExtensionService {
+export interface IResponsiveStateChangeEvent {
+	target: ICpuProfilerTarget;
+	isResponsive: boolean;
+}
+
+export interface IExtensionService extends ICpuProfilerTarget {
 	_serviceBrand: any;
 
 	/**
@@ -156,6 +161,12 @@ export interface IExtensionService {
 	 */
 	onWillActivateByEvent: Event<IWillActivateEvent>;
 
+	/**
+	 * An event that is fired when an extension host changes its
+	 * responsive-state.
+	 */
+	onDidChangeResponsiveChange: Event<IResponsiveStateChangeEvent>;
+
 	/**
 	 * Send an activation event and activate interested extensions.
 	 */
@@ -182,16 +193,6 @@ export interface IExtensionService {
 	 */
 	getExtensionsStatus(): { [id: string]: IExtensionsStatus };
 
-	/**
-	 * Check if the extension host can be profiled.
-	 */
-	canProfileExtensionHost(): boolean;
-
-	/**
-	 * Begin an extension host process profile session.
-	 */
-	startExtensionHostProfile(): Promise<ProfileSession>;
-
 	/**
 	 * Return the inspect port or 0.
 	 */
@@ -213,6 +214,19 @@ export interface IExtensionService {
 	stopExtensionHost(): void;
 }
 
+export interface ICpuProfilerTarget {
+
+	/**
+	 * Check if the extension host can be profiled.
+	 */
+	canProfileExtensionHost(): boolean;
+
+	/**
+	 * Begin an extension host process profile session.
+	 */
+	startExtensionHostProfile(): Promise<ProfileSession>;
+}
+
 export interface ProfileSession {
 	stop(): Promise<IExtensionHostProfile>;
 }

src/vs/workbench/services/extensions/electron-browser/extensionService.ts

@@ -36,7 +36,7 @@ import { IWindowService, IWindowsService } from 'vs/platform/windows/common/wind
 import { ExtHostCustomersRegistry } from 'vs/workbench/api/electron-browser/extHostCustomers';
 import { ExtHostContext, ExtHostExtensionServiceShape, IExtHostContext, MainContext } from 'vs/workbench/api/node/extHost.protocol';
 import { IEditorService } from 'vs/workbench/services/editor/common/editorService';
-import { ActivationTimes, ExtensionPointContribution, IExtensionDescription, IExtensionService, IExtensionsStatus, IMessage, ProfileSession, IWillActivateEvent } from 'vs/workbench/services/extensions/common/extensions';
+import { ActivationTimes, ExtensionPointContribution, IExtensionDescription, IExtensionService, IExtensionsStatus, IMessage, ProfileSession, IWillActivateEvent, IResponsiveStateChangeEvent } from 'vs/workbench/services/extensions/common/extensions';
 import { ExtensionMessageCollector, ExtensionPoint, ExtensionsRegistry, IExtensionPoint, IExtensionPointUser, schema } from 'vs/workbench/services/extensions/common/extensionsRegistry';
 import { ExtensionHostProcessWorker, IExtensionHostStarter } from 'vs/workbench/services/extensions/electron-browser/extensionHost';
 import { ExtensionHostProfiler } from 'vs/workbench/services/extensions/electron-browser/extensionHostProfiler';
@@ -281,6 +281,9 @@ export class ExtensionService extends Disposable implements IExtensionService {
 	private _onWillActivateByEvent = new Emitter<IWillActivateEvent>();
 	readonly onWillActivateByEvent: Event<IWillActivateEvent> = this._onWillActivateByEvent.event;
 
+	private readonly _onDidChangeResponsiveChange = new Emitter<IResponsiveStateChangeEvent>();
+	readonly onDidChangeResponsiveChange: Event<IResponsiveStateChangeEvent> = this._onDidChangeResponsiveChange.event;
+
 	private _unresponsiveNotificationHandle: INotificationHandle;
 
 	// --- Members used per extension host process
@@ -347,6 +350,8 @@ export class ExtensionService extends Disposable implements IExtensionService {
 
 	public dispose(): void {
 		super.dispose();
+		this._onWillActivateByEvent.dispose();
+		this._onDidChangeResponsiveChange.dispose();
 	}
 
 	public get onDidRegisterExtensions(): Event<void> {
@@ -387,7 +392,7 @@ export class ExtensionService extends Disposable implements IExtensionService {
 		const extHostProcessWorker = this._instantiationService.createInstance(ExtensionHostProcessWorker, this.getExtensions(), this._extensionHostLogsLocation);
 		const extHostProcessManager = this._instantiationService.createInstance(ExtensionHostProcessManager, extHostProcessWorker, null, initialActivationEvents);
 		extHostProcessManager.onDidCrash(([code, signal]) => this._onExtensionHostCrashed(code, signal));
-		extHostProcessManager.onDidChangeResponsiveState((responsiveState) => this._onResponsiveStateChanged(responsiveState));
+		extHostProcessManager.onDidChangeResponsiveState((responsiveState) => this._onResponsiveStateChanged(responsiveState, extHostProcessManager));
 		this._extensionHostProcessManagers.push(extHostProcessManager);
 	}
 
@@ -429,7 +434,15 @@ export class ExtensionService extends Disposable implements IExtensionService {
 		);
 	}
 
-	private _onResponsiveStateChanged(state: ResponsiveState): void {
+	private _onResponsiveStateChanged(state: ResponsiveState, manager: ExtensionHostProcessManager): void {
+
+		// fire an event when an extension host is changing its state.
+		this._onDidChangeResponsiveChange.fire({
+			target: manager,
+			isResponsive: state === ResponsiveState.Responsive
+		});
+
+
 		// Do not show the notification anymore
 		// See https://github.com/Microsoft/vscode/issues/60318
 		const DISABLE_PROMPT = true;

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

@@ -128,7 +128,7 @@ const noop = () => { };
 
 export class RPCProtocol extends Disposable implements IRPCProtocol {
 
-	private static UNRESPONSIVE_TIME = 10 * 1000; // 10s
+	private static UNRESPONSIVE_TIME = 3 * 1000; // 3s
 
 	private readonly _onDidChangeResponsiveState: Emitter<ResponsiveState> = this._register(new Emitter<ResponsiveState>());
 	public readonly onDidChangeResponsiveState: Event<ResponsiveState> = this._onDidChangeResponsiveState.event;

src/vs/workbench/test/workbenchTestServices.ts

@@ -58,7 +58,7 @@ import { Range } from 'vs/editor/common/core/range';
 import { IConfirmation, IConfirmationResult, IDialogService, IDialogOptions, IPickAndOpenOptions, ISaveDialogOptions, IOpenDialogOptions, IFileDialogService } from 'vs/platform/dialogs/common/dialogs';
 import { INotificationService } from 'vs/platform/notification/common/notification';
 import { TestNotificationService } from 'vs/platform/notification/test/common/testNotificationService';
-import { IExtensionService, ProfileSession, IExtensionsStatus, ExtensionPointContribution, IExtensionDescription, IWillActivateEvent } from '../services/extensions/common/extensions';
+import { IExtensionService, ProfileSession, IExtensionsStatus, ExtensionPointContribution, IExtensionDescription, IWillActivateEvent, IResponsiveStateChangeEvent } from '../services/extensions/common/extensions';
 import { IExtensionPoint } from 'vs/workbench/services/extensions/common/extensionsRegistry';
 import { IKeybindingService } from 'vs/platform/keybinding/common/keybinding';
 import { IDecorationsService, IResourceDecorationChangeEvent, IDecoration, IDecorationData, IDecorationsProvider } from 'vs/workbench/services/decorations/browser/decorations';
@@ -311,6 +311,7 @@ export class TestExtensionService implements IExtensionService {
 	onDidRegisterExtensions: Event<void> = Event.None;
 	onDidChangeExtensionsStatus: Event<string[]> = Event.None;
 	onWillActivateByEvent: Event<IWillActivateEvent> = Event.None;
+	onDidChangeResponsiveChange: Event<IResponsiveStateChangeEvent> = Event.None;
 	activateByEvent(_activationEvent: string): Thenable<void> { return Promise.resolve(void 0); }
 	whenInstalledExtensionsRegistered(): Promise<boolean> { return Promise.resolve(true); }
 	getExtensions(): Promise<IExtensionDescription[]> { return Promise.resolve([]); }