Capture stopwatch results

packages/core/src/browser/performance/frontend-stopwatch.ts

@@ -40,23 +40,26 @@ export class FrontendStopwatch extends Stopwatch {
             performance.mark(endMarker);
 
             let duration: number;
+            let startTime: number;
 
             try {
                 performance.measure(name, startMarker, endMarker);
 
                 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);
     }
 };

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;
 }

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<MeasurementResult>();
+    get onDidAddMeasurementResult(): Event<MeasurementResult> {
+        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>): LogOptions {
@@ -154,4 +176,8 @@ export abstract class Stopwatch {
         this.logger.log(level, `${whatWasMeasured}: ${elapsed.toFixed(1)} ms [${timeFromStart}]`, ...(options.arguments ?? []));
     }
 
+    get storedMeasurements(): ReadonlyArray<MeasurementResult> {
+        return this._storedMeasurements;
+    }
+
 }

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);
     }
 

packages/metrics/package.json

@@ -11,6 +11,7 @@
   },
   "theiaExtensions": [
     {
+      "frontend": "lib/browser/metrics-frontend-module",
       "backend": "lib/node/metrics-backend-module"
     }
   ],

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<void> {
+        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);
+    }
+}

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<MeasurementNotificationService>(measurementNotificationServicePath);
+    });
+});

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';

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;
+}

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<string, string>();
+
+    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);
+    }
+
+}

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();
 
 });