Capture stopwatch results

Introduce `MeasurementResults` that capture a stopwatch execution in a serializable format.
Add `onMeasurementResult` event emitter to stopwatch class and introduce optional 
caching of results.
Add a metrics contribution to `@theia/metrics` that collects all measurement results of frontend and backend processes

Contributed on behalf of STMicroelectronics

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 cache 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.
+     */
+    cacheResults?: 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 cachedResults: MeasurementResult[] = [];
+
+    protected onMeasurementResultEmitter = new Emitter<MeasurementResult>();
+    get onMeasurementResult(): Event<MeasurementResult> {
+        return this.onMeasurementResultEmitter.event;
+    }
+
     constructor(protected readonly defaultLogOptions: LogOptions) {
         if (!defaultLogOptions.defaultLogLevel) {
             defaultLogOptions.defaultLogLevel = DEFAULT_LOG_LEVEL;
         }
+        if (defaultLogOptions.cacheResults === undefined) {
+            defaultLogOptions.cacheResults = true;
+        }
     }
 
     /**
@@ -91,14 +102,17 @@ export abstract class Stopwatch {
         return result;
     }
 
-    protected createMeasurement(name: string, measurement: () => number, options?: MeasurementOptions): Measurement {
+    protected createMeasurement(name: string, measurement: () => { startTime: number, duration: number }, options?: MeasurementOptions): Measurement {
         const logOptions = this.mergeLogOptions(options);
 
         const result: Measurement = {
             name,
             stop: () => {
                 if (result.elapsed === undefined) {
-                    result.elapsed = measurement();
+                    const { startTime, duration } = measurement();
+                    result.elapsed = duration;
+                    this.handleCompletedMeasurement(name, startTime, duration, logOptions);
+
                 }
                 return result.elapsed;
             },
@@ -112,6 +126,19 @@ export abstract class Stopwatch {
         return result;
     }
 
+    protected handleCompletedMeasurement(name: string, startTime: number, elapsed: number, options: LogOptions): void {
+        const result: MeasurementResult = {
+            name,
+            elapsed,
+            startTime,
+            owner: options.owner
+        };
+        if (options.cacheResults) {
+            this.cachedResults.push(result);
+        }
+        this.onMeasurementResultEmitter.fire(result);
+    }
+
     protected mergeLogOptions(logOptions?: Partial<LogOptions>): LogOptions {
         const result: LogOptions = { ...this.defaultLogOptions };
         if (logOptions) {
@@ -154,4 +181,8 @@ export abstract class Stopwatch {
         this.logger.log(level, `${whatWasMeasured}: ${elapsed.toFixed(1)} ms [${timeFromStart}]`, ...(options.arguments ?? []));
     }
 
+    getCachedResults(): MeasurementResult[] {
+        return [...this.cachedResults];
+    }
+
 }

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/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 './metrics-frontend-application-contribution';

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.getCachedResults().forEach(result => this.notify(result));
+        this.stopwatch.onMeasurementResult(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 frontendCounter = 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.getCachedResults().forEach(result => this.onBackendMeasurement(result));
+        this.backendStopwatch.onMeasurementResult(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.frontendCounter.size + 1}`;
+        this.frontendCounter.set(frontendId, counterId);
+        return counterId;
+    }
+
+    protected toCounterId(frontendId: string): string {
+        return this.frontendCounter.get(frontendId) ?? this.createFrontendCounterId(frontendId);
+    }
+
+    onFrontendMeasurement(frontendId: string, result: MeasurementResult): void {
+        this.appendMetricsValue(this.toCounterId(frontendId), result);
+    }
+
+}