Collect and deliver perf marks from extension hosts (#112552)

This commit is contained in:
Alexandru Dima 2020-12-15 21:47:59 +01:00
parent 691a2ce4ec
commit fbe4aa28ff
No known key found for this signature in database
GPG key ID: 6E58D7B045760DA0
15 changed files with 102 additions and 29 deletions

View file

@ -8,6 +8,7 @@
const loader = require('./vs/loader');
const bootstrap = require('./bootstrap');
const performance = require('./vs/base/common/performance');
// Bootstrap: NLS
const nlsConfig = bootstrap.setupNLS();
@ -55,5 +56,6 @@ exports.load = function (entrypoint, onLoad, onError) {
onLoad = onLoad || function () { };
onError = onError || function (err) { console.error(err); };
performance.mark(`fork/willLoadCode`);
loader([entrypoint], onLoad, onError);
};

View file

@ -6,6 +6,9 @@
//@ts-check
'use strict';
const performance = require('./vs/base/common/performance');
performance.mark('fork/start');
const bootstrap = require('./bootstrap');
const bootstrapNode = require('./bootstrap-node');

View file

@ -7,7 +7,7 @@ import { SerializedError } from 'vs/base/common/errors';
import Severity from 'vs/base/common/severity';
import { extHostNamedCustomer } from 'vs/workbench/api/common/extHostCustomers';
import { IExtHostContext, MainContext, MainThreadExtensionServiceShape } from 'vs/workbench/api/common/extHost.protocol';
import { IExtensionService, ExtensionActivationError } from 'vs/workbench/services/extensions/common/extensions';
import { IExtensionService, ExtensionActivationError, ExtensionHostKind } from 'vs/workbench/services/extensions/common/extensions';
import { ExtensionIdentifier, IExtensionDescription } from 'vs/platform/extensions/common/extensions';
import { INotificationService } from 'vs/platform/notification/common/notification';
import { localize } from 'vs/nls';
@ -19,29 +19,23 @@ import { IExtensionsWorkbenchService } from 'vs/workbench/contrib/extensions/com
import { CancellationToken } from 'vs/base/common/cancellation';
import { ILocalExtension } from 'vs/platform/extensionManagement/common/extensionManagement';
import { ExtensionActivationReason } from 'vs/workbench/api/common/extHostExtensionActivator';
import { ITimerService } from 'vs/workbench/services/timer/browser/timerService';
@extHostNamedCustomer(MainContext.MainThreadExtensionService)
export class MainThreadExtensionService implements MainThreadExtensionServiceShape {
private readonly _extensionService: IExtensionService;
private readonly _notificationService: INotificationService;
private readonly _extensionsWorkbenchService: IExtensionsWorkbenchService;
private readonly _hostService: IHostService;
private readonly _extensionEnablementService: IWorkbenchExtensionEnablementService;
private readonly _extensionHostKind: ExtensionHostKind;
constructor(
extHostContext: IExtHostContext,
@IExtensionService extensionService: IExtensionService,
@INotificationService notificationService: INotificationService,
@IExtensionsWorkbenchService extensionsWorkbenchService: IExtensionsWorkbenchService,
@IHostService hostService: IHostService,
@IWorkbenchExtensionEnablementService extensionEnablementService: IWorkbenchExtensionEnablementService
@IExtensionService private readonly _extensionService: IExtensionService,
@INotificationService private readonly _notificationService: INotificationService,
@IExtensionsWorkbenchService private readonly _extensionsWorkbenchService: IExtensionsWorkbenchService,
@IHostService private readonly _hostService: IHostService,
@IWorkbenchExtensionEnablementService private readonly _extensionEnablementService: IWorkbenchExtensionEnablementService,
@ITimerService private readonly _timerService: ITimerService,
) {
this._extensionService = extensionService;
this._notificationService = notificationService;
this._extensionsWorkbenchService = extensionsWorkbenchService;
this._hostService = hostService;
this._extensionEnablementService = extensionEnablementService;
this._extensionHostKind = extHostContext.extensionHostKind;
}
public dispose(): void {
@ -131,4 +125,14 @@ export class MainThreadExtensionService implements MainThreadExtensionServiceSha
async $onExtensionHostExit(code: number): Promise<void> {
this._extensionService._onExtensionHostExit(code);
}
async $setPerformanceMarks(marks: PerformanceMark[]): Promise<void> {
if (this._extensionHostKind === ExtensionHostKind.LocalProcess) {
this._timerService.setPerformanceMarks('localExtHost', marks);
} else if (this._extensionHostKind === ExtensionHostKind.LocalWebWorker) {
this._timerService.setPerformanceMarks('workerExtHost', marks);
} else {
this._timerService.setPerformanceMarks('remoteExtHost', marks);
}
}
}

View file

@ -3,6 +3,7 @@
* Licensed under the MIT License. See License.txt in the project root for license information.
*--------------------------------------------------------------------------------------------*/
import * as performance from 'vs/base/common/performance';
import { VSBuffer } from 'vs/base/common/buffer';
import { CancellationToken } from 'vs/base/common/cancellation';
import { IRemoteConsoleLog } from 'vs/base/common/console';
@ -41,7 +42,7 @@ import { IRevealOptions, ITreeItem } from 'vs/workbench/common/views';
import { IAdapterDescriptor, IConfig, IDebugSessionReplMode } from 'vs/workbench/contrib/debug/common/debug';
import { ITextQueryBuilderOptions } from 'vs/workbench/contrib/search/common/queryBuilder';
import { ITerminalDimensions, IShellLaunchConfig, ITerminalLaunchError } from 'vs/workbench/contrib/terminal/common/terminal';
import { ActivationKind, ExtensionActivationError } from 'vs/workbench/services/extensions/common/extensions';
import { ActivationKind, ExtensionActivationError, ExtensionHostKind } from 'vs/workbench/services/extensions/common/extensions';
import { createExtHostContextProxyIdentifier as createExtId, createMainContextProxyIdentifier as createMainId, IRPCProtocol } from 'vs/workbench/services/extensions/common/proxyIdentifier';
import * as search from 'vs/workbench/services/search/common/search';
import { EditorGroupColumn, SaveReason } from 'vs/workbench/common/editor';
@ -108,7 +109,8 @@ export interface IConfigurationInitData extends IConfigurationData {
}
export interface IExtHostContext extends IRPCProtocol {
remoteAuthority: string | null;
readonly remoteAuthority: string | null;
readonly extensionHostKind: ExtensionHostKind;
}
export interface IMainContext extends IRPCProtocol {
@ -853,6 +855,7 @@ export interface MainThreadExtensionServiceShape extends IDisposable {
$onExtensionActivationError(extensionId: ExtensionIdentifier, error: ExtensionActivationError): Promise<void>;
$onExtensionRuntimeError(extensionId: ExtensionIdentifier, error: SerializedError): void;
$onExtensionHostExit(code: number): Promise<void>;
$setPerformanceMarks(marks: performance.PerformanceMark[]): Promise<void>;
}
export interface SCMProviderFeatures {

View file

@ -5,6 +5,7 @@
import * as nls from 'vs/nls';
import * as path from 'vs/base/common/path';
import * as performance from 'vs/base/common/performance';
import { originalFSPath, joinPath } from 'vs/base/common/resources';
import { Barrier, timeout } from 'vs/base/common/async';
import { dispose, toDisposable, DisposableStore, Disposable } from 'vs/base/common/lifecycle';
@ -184,6 +185,7 @@ export abstract class AbstractExtHostExtensionService extends Disposable impleme
this._almostReadyToRunExtensions.open();
await this._extHostWorkspace.waitForInitializeCall();
performance.mark('extHost/ready');
this._readyToStartExtensionHost.open();
if (this._initData.autoStart) {
@ -362,10 +364,14 @@ export abstract class AbstractExtHostExtensionService extends Disposable impleme
const activationTimesBuilder = new ExtensionActivationTimesBuilder(reason.startup);
return Promise.all([
this._loadCommonJSModule<IExtensionModule>(joinPath(extensionDescription.extensionLocation, entryPoint), activationTimesBuilder),
this._loadCommonJSModule<IExtensionModule>(extensionDescription.identifier, joinPath(extensionDescription.extensionLocation, entryPoint), activationTimesBuilder),
this._loadExtensionContext(extensionDescription)
]).then(values => {
performance.mark(`extHost/willActivateExtension/${extensionDescription.identifier.value}`);
return AbstractExtHostExtensionService._callActivate(this._logService, extensionDescription.identifier, values[0], values[1], activationTimesBuilder);
}).then((activatedExtension) => {
performance.mark(`extHost/didActivateExtension/${extensionDescription.identifier.value}`);
return activatedExtension;
});
}
@ -456,6 +462,18 @@ export abstract class AbstractExtHostExtensionService extends Disposable impleme
}
private _activateAllStartupFinished(): void {
// startup is considered finished
const marks = performance.getMarks().map((entry) => {
if (entry.name.startsWith('fork/')) {
return {
name: `extHost/` + entry.name.substr('fork/'.length),
startTime: entry.startTime
};
}
return entry;
});
this._mainThreadExtensionsProxy.$setPerformanceMarks(marks);
for (const desc of this._registry.getAllExtensionDescriptions()) {
if (desc.activationEvents) {
for (const activationEvent of desc.activationEvents) {
@ -541,7 +559,7 @@ export abstract class AbstractExtHostExtensionService extends Disposable impleme
let testRunner: ITestRunner | INewTestRunner | undefined;
let requireError: Error | undefined;
try {
testRunner = await this._loadCommonJSModule(URI.file(extensionTestsPath), new ExtensionActivationTimesBuilder(false));
testRunner = await this._loadCommonJSModule(null, URI.file(extensionTestsPath), new ExtensionActivationTimesBuilder(false));
} catch (error) {
requireError = error;
}
@ -644,7 +662,9 @@ export abstract class AbstractExtHostExtensionService extends Disposable impleme
}
try {
performance.mark(`extHost/willResolveAuthority/${authorityPrefix}`);
const result = await resolver.resolve(remoteAuthority, { resolveAttempt });
performance.mark(`extHost/didResolveAuthorityOK/${authorityPrefix}`);
this._disposables.add(await this._extHostTunnelService.setTunnelExtensionFunctions(resolver));
// Split merged API result into separate authority/options
@ -667,6 +687,7 @@ export abstract class AbstractExtHostExtensionService extends Disposable impleme
}
};
} catch (err) {
performance.mark(`extHost/didResolveAuthorityError/${authorityPrefix}`);
if (err instanceof RemoteAuthorityResolverError) {
return {
type: 'error',
@ -754,7 +775,7 @@ export abstract class AbstractExtHostExtensionService extends Disposable impleme
protected abstract _beforeAlmostReadyToRunExtensions(): Promise<void>;
protected abstract _getEntryPoint(extensionDescription: IExtensionDescription): string | undefined;
protected abstract _loadCommonJSModule<T>(module: URI, activationTimesBuilder: ExtensionActivationTimesBuilder): Promise<T>;
protected abstract _loadCommonJSModule<T>(extensionId: ExtensionIdentifier | null, module: URI, activationTimesBuilder: ExtensionActivationTimesBuilder): Promise<T>;
public abstract $setRemoteEnvironment(env: { [key: string]: string | null }): Promise<void>;
}

View file

@ -3,6 +3,7 @@
* Licensed under the MIT License. See License.txt in the project root for license information.
*--------------------------------------------------------------------------------------------*/
import * as performance from 'vs/base/common/performance';
import { TernarySearchTree } from 'vs/base/common/map';
import { URI } from 'vs/base/common/uri';
import { MainThreadTelemetryShape, MainContext } from 'vs/workbench/api/common/extHost.protocol';
@ -52,7 +53,9 @@ export abstract class RequireInterceptor {
this._installInterceptor();
performance.mark('extHost/willWaitForConfig');
const configProvider = await this._extHostConfiguration.getConfigProvider();
performance.mark('extHost/didWaitForConfig');
const extensionPaths = await this._extHostExtensionService.getExtensionPathIndex();
this.register(new VSCodeNodeModuleFactory(this._apiFactory, extensionPaths, this._extensionRegistry, configProvider, this._logService));

View file

@ -3,6 +3,7 @@
* Licensed under the MIT License. See License.txt in the project root for license information.
*--------------------------------------------------------------------------------------------*/
import * as performance from 'vs/base/common/performance';
import { createApiFactoryAndRegisterActors } from 'vs/workbench/api/common/extHost.api.impl';
import { RequireInterceptor } from 'vs/workbench/api/common/extHostRequireInterceptor';
import { MainContext } from 'vs/workbench/api/common/extHost.protocol';
@ -13,7 +14,7 @@ import { ExtHostDownloadService } from 'vs/workbench/api/node/extHostDownloadSer
import { CLIServer } from 'vs/workbench/api/node/extHostCLIServer';
import { URI } from 'vs/base/common/uri';
import { Schemas } from 'vs/base/common/network';
import { IExtensionDescription } from 'vs/platform/extensions/common/extensions';
import { ExtensionIdentifier, IExtensionDescription } from 'vs/platform/extensions/common/extensions';
import { ExtensionRuntime } from 'vs/workbench/api/common/extHostTypes';
class NodeModuleRequireInterceptor extends RequireInterceptor {
@ -62,10 +63,12 @@ export class ExtHostExtensionService extends AbstractExtHostExtensionService {
// Module loading tricks
const interceptor = this._instaService.createInstance(NodeModuleRequireInterceptor, extensionApiFactory, this._registry);
await interceptor.install();
performance.mark('extHost/didInitAPI');
// Do this when extension service exists, but extensions are not being activated yet.
const configProvider = await this._extHostConfiguration.getConfigProvider();
await connectProxyResolver(this._extHostWorkspace, configProvider, this, this._logService, this._mainThreadTelemetryProxy, this._initData);
performance.mark('extHost/didInitProxyResolver');
// Use IPC messages to forward console-calls, note that the console is
// already patched to use`process.send()`
@ -84,7 +87,7 @@ export class ExtHostExtensionService extends AbstractExtHostExtensionService {
return extensionDescription.main;
}
protected _loadCommonJSModule<T>(module: URI, activationTimesBuilder: ExtensionActivationTimesBuilder): Promise<T> {
protected _loadCommonJSModule<T>(extensionId: ExtensionIdentifier | null, module: URI, activationTimesBuilder: ExtensionActivationTimesBuilder): Promise<T> {
if (module.scheme !== Schemas.file) {
throw new Error(`Cannot load URI: '${module}', must be of file-scheme`);
}
@ -93,10 +96,16 @@ export class ExtHostExtensionService extends AbstractExtHostExtensionService {
this._logService.info(`ExtensionService#loadCommonJSModule ${module.toString(true)}`);
this._logService.flush();
try {
if (extensionId) {
performance.mark(`extHost/willLoadExtensionCode/${extensionId.value}`);
}
r = require.__$__nodeRequire<T>(module.fsPath);
} catch (e) {
return Promise.reject(e);
} finally {
if (extensionId) {
performance.mark(`extHost/didLoadExtensionCode/${extensionId.value}`);
}
activationTimesBuilder.codeLoadingStop();
}
return Promise.resolve(r);

View file

@ -8,7 +8,7 @@ import { ExtensionActivationTimesBuilder } from 'vs/workbench/api/common/extHost
import { AbstractExtHostExtensionService } from 'vs/workbench/api/common/extHostExtensionService';
import { URI } from 'vs/base/common/uri';
import { RequireInterceptor } from 'vs/workbench/api/common/extHostRequireInterceptor';
import { IExtensionDescription } from 'vs/platform/extensions/common/extensions';
import { ExtensionIdentifier, IExtensionDescription } from 'vs/platform/extensions/common/extensions';
import { ExtensionRuntime } from 'vs/workbench/api/common/extHostTypes';
import { timeout } from 'vs/base/common/async';
@ -42,6 +42,8 @@ export class ExtHostExtensionService extends AbstractExtHostExtensionService {
const apiFactory = this._instaService.invokeFunction(createApiFactoryAndRegisterActors);
this._fakeModules = this._instaService.createInstance(WorkerRequireInterceptor, apiFactory, this._registry);
await this._fakeModules.install();
performance.mark('extHost/didInitAPI');
await this._waitForDebuggerAttachment();
}
@ -49,10 +51,16 @@ export class ExtHostExtensionService extends AbstractExtHostExtensionService {
return extensionDescription.browser;
}
protected async _loadCommonJSModule<T>(module: URI, activationTimesBuilder: ExtensionActivationTimesBuilder): Promise<T> {
protected async _loadCommonJSModule<T>(extensionId: ExtensionIdentifier | null, module: URI, activationTimesBuilder: ExtensionActivationTimesBuilder): Promise<T> {
module = module.with({ path: ensureSuffix(module.path, '.js') });
if (extensionId) {
performance.mark(`extHost/willFetchExtensionCode/${extensionId.value}`);
}
const response = await fetch(module.toString(true));
if (extensionId) {
performance.mark(`extHost/didFetchExtensionCode/${extensionId.value}`);
}
if (response.status !== 200) {
throw new Error(response.statusText);
@ -78,9 +86,15 @@ export class ExtHostExtensionService extends AbstractExtHostExtensionService {
try {
activationTimesBuilder.codeLoadingStart();
if (extensionId) {
performance.mark(`extHost/willLoadExtensionCode/${extensionId.value}`);
}
initFn(_module, _exports, _require);
return <T>(_module.exports !== _exports ? _module.exports : _exports);
} finally {
if (extensionId) {
performance.mark(`extHost/didLoadExtensionCode/${extensionId.value}`);
}
activationTimesBuilder.codeLoadingStop();
}
}

View file

@ -5,6 +5,7 @@
import { timeout } from 'vs/base/common/async';
import * as errors from 'vs/base/common/errors';
import * as performance from 'vs/base/common/performance';
import { DisposableStore } from 'vs/base/common/lifecycle';
import { URI } from 'vs/base/common/uri';
import { IURITransformer } from 'vs/base/common/uriIpc';
@ -67,6 +68,7 @@ export class ExtensionHostMain {
const logService = instaService.invokeFunction(accessor => accessor.get(ILogService));
this._disposables.add(logService);
performance.mark(`extHost/didCreateServices`);
logService.info('extension host started');
logService.trace('initData', initData);

View file

@ -182,6 +182,7 @@ export class ExtensionHostManager extends Disposable {
this._register(this._rpcProtocol.onDidChangeResponsiveState((responsiveState: ResponsiveState) => this._onDidChangeResponsiveState.fire(responsiveState)));
const extHostContext: IExtHostContext = {
remoteAuthority: this._extensionHost.remoteAuthority,
extensionHostKind: this.kind,
getProxy: <T>(identifier: ProxyIdentifier<T>): T => this._rpcProtocol!.getProxy(identifier),
set: <T, R extends T>(identifier: ProxyIdentifier<T>, instance: R): R => this._rpcProtocol!.set(identifier, instance),
assertRegistered: (identifiers: ProxyIdentifier<any>[]): void => this._rpcProtocol!.assertRegistered(identifiers),

View file

@ -6,6 +6,7 @@
import * as nativeWatchdog from 'native-watchdog';
import * as net from 'net';
import * as minimist from 'minimist';
import * as performance from 'vs/base/common/performance';
import { onUnexpectedError } from 'vs/base/common/errors';
import { Event } from 'vs/base/common/event';
import { IMessagePassingProtocol } from 'vs/base/parts/ipc/common/ipc';
@ -295,9 +296,11 @@ function connectToRenderer(protocol: IMessagePassingProtocol): Promise<IRenderer
}
export async function startExtensionHostProcess(): Promise<void> {
performance.mark(`extHost/willConnectToRenderer`);
const protocol = await createExtHostProtocol();
performance.mark(`extHost/didConnectToRenderer`);
const renderer = await connectToRenderer(protocol);
performance.mark(`extHost/didWaitForInitData`);
const { initData } = renderer;
// setup things
patchProcess(!!initData.environment.extensionTestsLocationURI); // to support other test frameworks like Jasmin that use process.exit (https://github.com/microsoft/vscode/issues/37708)

View file

@ -12,6 +12,7 @@ import { ExtensionHostMain } from 'vs/workbench/services/extensions/common/exten
import { IHostUtils } from 'vs/workbench/api/common/extHostExtensionService';
import { NestedWorker } from 'vs/workbench/services/extensions/worker/polyfillNestedWorker';
import * as path from 'vs/base/common/path';
import * as performance from 'vs/base/common/performance';
import 'vs/workbench/api/common/extHost.common.services';
import 'vs/workbench/api/worker/extHost.worker.services';
@ -150,9 +151,9 @@ let onTerminate = nativeClose;
(function create(): void {
const res = new ExtensionWorker();
performance.mark(`extHost/willConnectToRenderer`);
connectToRenderer(res.protocol).then(data => {
performance.mark(`extHost/didWaitForInitData`);
const extHostMain = new ExtensionHostMain(
data.protocol,
data.initData,

View file

@ -10,6 +10,7 @@ import { URI } from 'vs/base/common/uri';
import { IExtHostContext } from 'vs/workbench/api/common/extHost.protocol';
import { mock } from 'vs/workbench/test/common/workbenchTestServices';
import { IUriIdentityService } from 'vs/workbench/services/uriIdentity/common/uriIdentity';
import { ExtensionHostKind } from 'vs/workbench/services/extensions/common/extensions';
suite('MainThreadDiagnostics', function () {
@ -25,6 +26,7 @@ suite('MainThreadDiagnostics', function () {
let diag = new MainThreadDiagnostics(
new class implements IExtHostContext {
remoteAuthority = '';
extensionHostKind = ExtensionHostKind.LocalProcess;
assertRegistered() { }
set(v: any): any { return null; }
getProxy(): any {

View file

@ -17,6 +17,7 @@ import { SyncDescriptor } from 'vs/platform/instantiation/common/descriptors';
import { TestInstantiationService } from 'vs/platform/instantiation/test/common/instantiationServiceMock';
import { ViewDescriptorService } from 'vs/workbench/services/views/browser/viewDescriptorService';
import { CustomTreeView } from 'vs/workbench/browser/parts/views/treeView';
import { ExtensionHostKind } from 'vs/workbench/services/extensions/common/extensions';
suite('MainThreadHostTreeView', function () {
const testTreeViewId = 'testTreeView';
@ -61,6 +62,7 @@ suite('MainThreadHostTreeView', function () {
mainThreadTreeViews = new MainThreadTreeViews(
new class implements IExtHostContext {
remoteAuthority = '';
extensionHostKind = ExtensionHostKind.LocalProcess;
assertRegistered() { }
set(v: any): any { return null; }
getProxy(): any {

View file

@ -8,6 +8,7 @@ import { CharCode } from 'vs/base/common/charCode';
import { IExtHostContext } from 'vs/workbench/api/common/extHost.protocol';
import { isThenable } from 'vs/base/common/async';
import { IExtHostRpcService } from 'vs/workbench/api/common/extHostRpcService';
import { ExtensionHostKind } from 'vs/workbench/services/extensions/common/extensions';
export function SingleProxyRPCProtocol(thing: any): IExtHostContext & IExtHostRpcService {
return {
@ -20,7 +21,8 @@ export function SingleProxyRPCProtocol(thing: any): IExtHostContext & IExtHostRp
return value;
},
assertRegistered: undefined!,
drain: undefined!
drain: undefined!,
extensionHostKind: ExtensionHostKind.LocalProcess
};
}
@ -28,6 +30,7 @@ export class TestRPCProtocol implements IExtHostContext, IExtHostRpcService {
public _serviceBrand: undefined;
public remoteAuthority = null!;
public extensionHostKind = ExtensionHostKind.LocalProcess;
private _callCountValue: number = 0;
private _idle?: Promise<any>;