diff --git a/packages/core/src/browser/performance/frontend-stopwatch.ts b/packages/core/src/browser/performance/frontend-stopwatch.ts index 396c9fb9e7f19..f8759d011ff46 100644 --- a/packages/core/src/browser/performance/frontend-stopwatch.ts +++ b/packages/core/src/browser/performance/frontend-stopwatch.ts @@ -40,6 +40,7 @@ export class FrontendStopwatch extends Stopwatch { performance.mark(endMarker); let duration: number; + let startTime: number; try { performance.measure(name, startMarker, endMarker); @@ -47,16 +48,18 @@ export class FrontendStopwatch extends Stopwatch { const entries = performance.getEntriesByName(name); // If no entries, then performance measurement was disabled or failed, so // signal that with a `NaN` result - duration = entries.length > 0 ? entries[0].duration : Number.NaN; + duration = entries[0].duration ?? Number.NaN; + startTime = entries[0].startTime ?? Number.NaN; } catch (e) { console.warn(e); duration = Number.NaN; + startTime = Number.NaN; } performance.clearMeasures(name); performance.clearMarks(startMarker); performance.clearMarks(endMarker); - return duration; + return { startTime, duration }; }, options); } }; diff --git a/packages/core/src/common/performance/measurement.ts b/packages/core/src/common/performance/measurement.ts index db3e547779459..8647071d7d6c2 100644 --- a/packages/core/src/common/performance/measurement.ts +++ b/packages/core/src/common/performance/measurement.ts @@ -101,4 +101,30 @@ export interface MeasurementOptions { * @see {@link thresholdLogLevel} */ thresholdMillis?: number; + + /** + * Flag to indicate whether the stopwatch should store measurement results for later retrieval. + * For example the cache can be used to retrieve measurements which were taken during startup before a listener had a chance to register. + */ + storeResults?: boolean +} + +/** + * Captures the result of a {@link Measurement} in a serializable format. + */ +export interface MeasurementResult { + /** The measurement name. This may show up in the performance measurement framework appropriate to the application context. */ + name: string; + + /** The time when the measurement recording has been started */ + startTime: number; + + /** + * The elapsed time measured, if it has been {@link stop stopped} and measured, or `NaN` if the platform disabled + * performance measurement. + */ + elapsed: number; + + /** An optional label for the application the start of which (in real time) is the basis of all measurements. */ + owner?: string; } diff --git a/packages/core/src/common/performance/stopwatch.ts b/packages/core/src/common/performance/stopwatch.ts index 4475bef57a78a..a86e0d6cd6742 100644 --- a/packages/core/src/common/performance/stopwatch.ts +++ b/packages/core/src/common/performance/stopwatch.ts @@ -19,7 +19,8 @@ import { inject, injectable } from 'inversify'; import { ILogger, LogLevel } from '../logger'; import { MaybePromise } from '../types'; -import { Measurement, MeasurementOptions } from './measurement'; +import { Measurement, MeasurementOptions, MeasurementResult } from './measurement'; +import { Emitter, Event } from '../event'; /** The default log level for measurements that are not otherwise configured with a default. */ const DEFAULT_LOG_LEVEL = LogLevel.INFO; @@ -50,10 +51,20 @@ export abstract class Stopwatch { @inject(ILogger) protected readonly logger: ILogger; + protected _storedMeasurements: MeasurementResult[] = []; + + protected onDidAddMeasurementResultEmitter = new Emitter(); + get onDidAddMeasurementResult(): Event { + return this.onDidAddMeasurementResultEmitter.event; + } + constructor(protected readonly defaultLogOptions: LogOptions) { if (!defaultLogOptions.defaultLogLevel) { defaultLogOptions.defaultLogLevel = DEFAULT_LOG_LEVEL; } + if (defaultLogOptions.storeResults === undefined) { + defaultLogOptions.storeResults = true; + } } /** @@ -91,25 +102,36 @@ export abstract class Stopwatch { return result; } - protected createMeasurement(name: string, measurement: () => number, options?: MeasurementOptions): Measurement { + protected createMeasurement(name: string, measure: () => { startTime: number, duration: number }, options?: MeasurementOptions): Measurement { const logOptions = this.mergeLogOptions(options); - const result: Measurement = { + const measurement: Measurement = { name, stop: () => { - if (result.elapsed === undefined) { - result.elapsed = measurement(); + if (measurement.elapsed === undefined) { + const { startTime, duration } = measure(); + measurement.elapsed = duration; + const result: MeasurementResult = { + name, + elapsed: duration, + startTime, + owner: logOptions.owner + }; + if (logOptions.storeResults) { + this._storedMeasurements.push(result); + } + this.onDidAddMeasurementResultEmitter.fire(result); } - return result.elapsed; + return measurement.elapsed; }, - log: (activity: string, ...optionalArgs: any[]) => this.log(result, activity, this.atLevel(logOptions, undefined, optionalArgs)), - debug: (activity: string, ...optionalArgs: any[]) => this.log(result, activity, this.atLevel(logOptions, LogLevel.DEBUG, optionalArgs)), - info: (activity: string, ...optionalArgs: any[]) => this.log(result, activity, this.atLevel(logOptions, LogLevel.INFO, optionalArgs)), - warn: (activity: string, ...optionalArgs: any[]) => this.log(result, activity, this.atLevel(logOptions, LogLevel.WARN, optionalArgs)), - error: (activity: string, ...optionalArgs: any[]) => this.log(result, activity, this.atLevel(logOptions, LogLevel.ERROR, optionalArgs)), + log: (activity: string, ...optionalArgs: any[]) => this.log(measurement, activity, this.atLevel(logOptions, undefined, optionalArgs)), + debug: (activity: string, ...optionalArgs: any[]) => this.log(measurement, activity, this.atLevel(logOptions, LogLevel.DEBUG, optionalArgs)), + info: (activity: string, ...optionalArgs: any[]) => this.log(measurement, activity, this.atLevel(logOptions, LogLevel.INFO, optionalArgs)), + warn: (activity: string, ...optionalArgs: any[]) => this.log(measurement, activity, this.atLevel(logOptions, LogLevel.WARN, optionalArgs)), + error: (activity: string, ...optionalArgs: any[]) => this.log(measurement, activity, this.atLevel(logOptions, LogLevel.ERROR, optionalArgs)), }; - return result; + return measurement; } protected mergeLogOptions(logOptions?: Partial): LogOptions { @@ -154,4 +176,8 @@ export abstract class Stopwatch { this.logger.log(level, `${whatWasMeasured}: ${elapsed.toFixed(1)} ms [${timeFromStart}]`, ...(options.arguments ?? [])); } + get storedMeasurements(): ReadonlyArray { + return this._storedMeasurements; + } + } diff --git a/packages/core/src/node/performance/node-stopwatch.ts b/packages/core/src/node/performance/node-stopwatch.ts index 57f33286c1681..42db4b6feb3e6 100644 --- a/packages/core/src/node/performance/node-stopwatch.ts +++ b/packages/core/src/node/performance/node-stopwatch.ts @@ -33,7 +33,7 @@ export class NodeStopwatch extends Stopwatch { return this.createMeasurement(name, () => { const duration = performance.now() - startTime; - return duration; + return { duration, startTime }; }, options); } diff --git a/packages/metrics/package.json b/packages/metrics/package.json index ac54923c66beb..4a833c1492295 100644 --- a/packages/metrics/package.json +++ b/packages/metrics/package.json @@ -11,6 +11,7 @@ }, "theiaExtensions": [ { + "frontend": "lib/browser/metrics-frontend-module", "backend": "lib/node/metrics-backend-module" } ], diff --git a/packages/metrics/src/browser/metrics-frontend-application-contribution.ts b/packages/metrics/src/browser/metrics-frontend-application-contribution.ts new file mode 100644 index 0000000000000..177ad53f37ad6 --- /dev/null +++ b/packages/metrics/src/browser/metrics-frontend-application-contribution.ts @@ -0,0 +1,51 @@ +// ***************************************************************************** +// Copyright (C) 2023 STMicroelectronics and others. +// +// This program and the accompanying materials are made available under the +// terms of the Eclipse Public License v. 2.0 which is available at +// http://www.eclipse.org/legal/epl-2.0. +// +// This Source Code may also be made available under the following Secondary +// Licenses when the conditions for such availability set forth in the Eclipse +// Public License v. 2.0 are satisfied: GNU General Public License, version 2 +// with the GNU Classpath Exception which is available at +// https://www.gnu.org/software/classpath/license.html. +// +// SPDX-License-Identifier: EPL-2.0 OR GPL-2.0-only WITH Classpath-exception-2.0 +// ***************************************************************************** +import { inject, injectable } from '@theia/core/shared/inversify'; +import { FrontendApplicationContribution } from '@theia/core/lib/browser'; +import { ILogger, LogLevel, MeasurementResult, Stopwatch } from '@theia/core'; +import { UUID } from '@theia/core/shared/@phosphor/coreutils'; +import { MeasurementNotificationService } from '../common'; + +@injectable() +export class MetricsFrontendApplicationContribution implements FrontendApplicationContribution { + @inject(Stopwatch) + protected stopwatch: Stopwatch; + + @inject(MeasurementNotificationService) + protected notificationService: MeasurementNotificationService; + + @inject(ILogger) + protected logger: ILogger; + + readonly id = UUID.uuid4(); + + initialize(): void { + this.doInitialize(); + } + + protected async doInitialize(): Promise { + const logLevel = await this.logger.getLogLevel(); + if (logLevel !== LogLevel.DEBUG) { + return; + } + this.stopwatch.storedMeasurements.forEach(result => this.notify(result)); + this.stopwatch.onDidAddMeasurementResult(result => this.notify(result)); + } + + protected notify(result: MeasurementResult): void { + this.notificationService.onFrontendMeasurement(this.id, result); + } +} diff --git a/packages/metrics/src/browser/metrics-frontend-module.ts b/packages/metrics/src/browser/metrics-frontend-module.ts new file mode 100644 index 0000000000000..453b9ead52dad --- /dev/null +++ b/packages/metrics/src/browser/metrics-frontend-module.ts @@ -0,0 +1,28 @@ +// ***************************************************************************** +// Copyright (C) 2023 STMicroelectronics and others. +// +// This program and the accompanying materials are made available under the +// terms of the Eclipse Public License v. 2.0 which is available at +// http://www.eclipse.org/legal/epl-2.0. +// +// This Source Code may also be made available under the following Secondary +// Licenses when the conditions for such availability set forth in the Eclipse +// Public License v. 2.0 are satisfied: GNU General Public License, version 2 +// with the GNU Classpath Exception which is available at +// https://www.gnu.org/software/classpath/license.html. +// +// SPDX-License-Identifier: EPL-2.0 OR GPL-2.0-only WITH Classpath-exception-2.0 +// ***************************************************************************** + +import { ContainerModule } from '@theia/core/shared/inversify'; +import { MetricsFrontendApplicationContribution } from './metrics-frontend-application-contribution'; +import { MeasurementNotificationService, measurementNotificationServicePath } from '../common'; +import { FrontendApplicationContribution, WebSocketConnectionProvider } from '@theia/core/lib/browser'; + +export default new ContainerModule(bind => { + bind(FrontendApplicationContribution).to(MetricsFrontendApplicationContribution).inSingletonScope(); + bind(MeasurementNotificationService).toDynamicValue(ctx => { + const connection = ctx.container.get(WebSocketConnectionProvider); + return connection.createProxy(measurementNotificationServicePath); + }); +}); diff --git a/packages/metrics/src/common/index.ts b/packages/metrics/src/common/index.ts new file mode 100644 index 0000000000000..e661e62e7f703 --- /dev/null +++ b/packages/metrics/src/common/index.ts @@ -0,0 +1,17 @@ +// ***************************************************************************** +// Copyright (C) 2023 STMicroelectronics and others. +// +// This program and the accompanying materials are made available under the +// terms of the Eclipse Public License v. 2.0 which is available at +// http://www.eclipse.org/legal/epl-2.0. +// +// This Source Code may also be made available under the following Secondary +// Licenses when the conditions for such availability set forth in the Eclipse +// Public License v. 2.0 are satisfied: GNU General Public License, version 2 +// with the GNU Classpath Exception which is available at +// https://www.gnu.org/software/classpath/license.html. +// +// SPDX-License-Identifier: EPL-2.0 OR GPL-2.0-only WITH Classpath-exception-2.0 +// ***************************************************************************** + +export * from './measurement-notification-service'; diff --git a/packages/metrics/src/common/measurement-notification-service.ts b/packages/metrics/src/common/measurement-notification-service.ts new file mode 100644 index 0000000000000..084297d536703 --- /dev/null +++ b/packages/metrics/src/common/measurement-notification-service.ts @@ -0,0 +1,29 @@ +// ***************************************************************************** +// Copyright (C) 2023 STMicroelectronics and others. +// +// This program and the accompanying materials are made available under the +// terms of the Eclipse Public License v. 2.0 which is available at +// http://www.eclipse.org/legal/epl-2.0. +// +// This Source Code may also be made available under the following Secondary +// Licenses when the conditions for such availability set forth in the Eclipse +// Public License v. 2.0 are satisfied: GNU General Public License, version 2 +// with the GNU Classpath Exception which is available at +// https://www.gnu.org/software/classpath/license.html. +// +// SPDX-License-Identifier: EPL-2.0 OR GPL-2.0-only WITH Classpath-exception-2.0 +// ***************************************************************************** + +import { MeasurementResult } from '@theia/core'; + +export const measurementNotificationServicePath = '/services/measurement-notification'; + +export const MeasurementNotificationService = Symbol('MeasurementNotificationService'); +export interface MeasurementNotificationService { + /** + * Notify the backend when a fronted stopwatch provides a new measurement. + * @param frontendId The unique id associated with the frontend that sends the notification + * @param result The new measurement result + */ + onFrontendMeasurement(frontendId: string, result: MeasurementResult): void; +} diff --git a/packages/metrics/src/node/measurement-metrics-contribution.ts b/packages/metrics/src/node/measurement-metrics-contribution.ts new file mode 100644 index 0000000000000..0cb8ca6b09db2 --- /dev/null +++ b/packages/metrics/src/node/measurement-metrics-contribution.ts @@ -0,0 +1,75 @@ +// ***************************************************************************** +// Copyright (C) 2023 STMicroelectronics and others. +// +// This program and the accompanying materials are made available under the +// terms of the Eclipse Public License v. 2.0 which is available at +// http://www.eclipse.org/legal/epl-2.0. +// +// This Source Code may also be made available under the following Secondary +// Licenses when the conditions for such availability set forth in the Eclipse +// Public License v. 2.0 are satisfied: GNU General Public License, version 2 +// with the GNU Classpath Exception which is available at +// https://www.gnu.org/software/classpath/license.html. +// +// SPDX-License-Identifier: EPL-2.0 OR GPL-2.0-only WITH Classpath-exception-2.0 +// ***************************************************************************** +import { inject, injectable, } from '@theia/core/shared/inversify'; +import { MetricsContribution } from './metrics-contribution'; +import { LogLevel, MeasurementResult, Stopwatch } from '@theia/core'; +import { MeasurementNotificationService } from '../common'; +import { LogLevelCliContribution } from '@theia/core/lib/node/logger-cli-contribution'; + +const backendId = 'backend'; +const metricsName = 'theia_measurements'; + +@injectable() +export class MeasurementMetricsBackendContribution implements MetricsContribution, MeasurementNotificationService { + @inject(Stopwatch) + protected backendStopwatch: Stopwatch; + + @inject(LogLevelCliContribution) + protected logLevelCli: LogLevelCliContribution; + + protected metrics = ''; + protected frontendCounters = new Map(); + + startCollecting(): void { + if (this.logLevelCli.defaultLogLevel !== LogLevel.DEBUG) { + return; + } + this.metrics += `# HELP ${metricsName} Theia stopwatch measurement results.\n`; + this.metrics += `# TYPE ${metricsName} gauge\n`; + this.backendStopwatch.storedMeasurements.forEach(result => this.onBackendMeasurement(result)); + this.backendStopwatch.onDidAddMeasurementResult(result => this.onBackendMeasurement(result)); + } + + getMetrics(): string { + return this.metrics; + } + + protected appendMetricsValue(id: string, result: MeasurementResult): void { + const { name, elapsed, startTime, owner } = result; + const labels: string = `id="${id}", name="${name}", startTime="${startTime}", owner="${owner}"`; + const metricsValue = `${metricsName}{${labels}} ${elapsed}`; + this.metrics += (metricsValue + '\n'); + } + + protected onBackendMeasurement(result: MeasurementResult): void { + this.appendMetricsValue(backendId, result); + } + + protected createFrontendCounterId(frontendId: string): string { + const counterId = `frontend-${this.frontendCounters.size + 1}`; + this.frontendCounters.set(frontendId, counterId); + return counterId; + } + + protected toCounterId(frontendId: string): string { + return this.frontendCounters.get(frontendId) ?? this.createFrontendCounterId(frontendId); + } + + onFrontendMeasurement(frontendId: string, result: MeasurementResult): void { + this.appendMetricsValue(this.toCounterId(frontendId), result); + } + +} diff --git a/packages/metrics/src/node/metrics-backend-module.ts b/packages/metrics/src/node/metrics-backend-module.ts index 9ef1dbb1997ba..2a4e7e90633a8 100644 --- a/packages/metrics/src/node/metrics-backend-module.ts +++ b/packages/metrics/src/node/metrics-backend-module.ts @@ -16,17 +16,25 @@ import { ContainerModule } from '@theia/core/shared/inversify'; import { BackendApplicationContribution } from '@theia/core/lib/node'; -import { bindContributionProvider } from '@theia/core/lib/common'; +import { ConnectionHandler, RpcConnectionHandler, bindContributionProvider } from '@theia/core/lib/common'; import { MetricsContribution } from './metrics-contribution'; import { NodeMetricsContribution } from './node-metrics-contribution'; import { ExtensionMetricsContribution } from './extensions-metrics-contribution'; import { MetricsBackendApplicationContribution } from './metrics-backend-application-contribution'; +import { measurementNotificationServicePath } from '../common'; +import { MeasurementMetricsBackendContribution } from './measurement-metrics-contribution'; export default new ContainerModule(bind => { bindContributionProvider(bind, MetricsContribution); bind(MetricsContribution).to(NodeMetricsContribution).inSingletonScope(); bind(MetricsContribution).to(ExtensionMetricsContribution).inSingletonScope(); + bind(MeasurementMetricsBackendContribution).toSelf().inSingletonScope(); + bind(MetricsContribution).toService(MeasurementMetricsBackendContribution); + bind(ConnectionHandler).toDynamicValue(ctx => + new RpcConnectionHandler(measurementNotificationServicePath, + () => ctx.container.get(MeasurementMetricsBackendContribution))); + bind(BackendApplicationContribution).to(MetricsBackendApplicationContribution).inSingletonScope(); });