src/performance/PerformanceStatistics.ts

   1 // Partial Copyright Jerome Benoit. 2021-2023. All Rights Reserved.
   2
   3 import { type PerformanceEntry, PerformanceObserver, performance } from 'node:perf_hooks';
   4 import type { URL } from 'node:url';
   5 import { parentPort } from 'node:worker_threads';
   6
   7 import {
   8   ConfigurationSection,
   9   type IncomingRequestCommand,
  10   type LogConfiguration,
  11   MessageType,
  12   type RequestCommand,
  13   type Statistics,
  14   type StorageConfiguration,
  15   type TimestampedData,
  16 } from '../types';
  17 import {
  18   CircularArray,
  19   Configuration,
  20   Constants,
  21   JSONStringifyWithMapSupport,
  22   buildPerformanceStatisticsMessage,
  23   extractTimeSeriesValues,
  24   formatDurationSeconds,
  25   generateUUID,
  26   logPrefix,
  27   logger,
  28   median,
  29   nthPercentile,
  30   stdDeviation,
  31 } from '../utils';
  32
  33 export class PerformanceStatistics {
  34   private static readonly instances: Map<string, PerformanceStatistics> = new Map<
  35     string,
  36     PerformanceStatistics
  37   >();
  38
  39   private readonly objId: string;
  40   private readonly objName: string;
  41   private performanceObserver!: PerformanceObserver;
  42   private readonly statistics: Statistics;
  43   private displayInterval?: NodeJS.Timeout;
  44
  45   private constructor(objId: string, objName: string, uri: URL) {
  46     this.objId = objId;
  47     this.objName = objName;
  48     this.initializePerformanceObserver();
  49     this.statistics = {
  50       id: this.objId ?? 'Object id not specified',
  51       name: this.objName ?? 'Object name not specified',
  52       uri: uri.toString(),
  53       createdAt: new Date(),
  54       statisticsData: new Map(),
  55     };
  56   }
  57
  58   public static getInstance(
  59     objId: string,
  60     objName: string,
  61     uri: URL,
  62   ): PerformanceStatistics | undefined {
  63     if (!PerformanceStatistics.instances.has(objId)) {
  64       PerformanceStatistics.instances.set(objId, new PerformanceStatistics(objId, objName, uri));
  65     }
  66     return PerformanceStatistics.instances.get(objId);
  67   }
  68
  69   public static beginMeasure(id: string): string {
  70     const markId = `${id.charAt(0).toUpperCase()}${id.slice(1)}~${generateUUID()}`;
  71     performance.mark(markId);
  72     return markId;
  73   }
  74
  75   public static endMeasure(name: string, markId: string): void {
  76     performance.measure(name, markId);
  77     performance.clearMarks(markId);
  78     performance.clearMeasures(name);
  79   }
  80
  81   public addRequestStatistic(
  82     command: RequestCommand | IncomingRequestCommand,
  83     messageType: MessageType,
  84   ): void {
  85     switch (messageType) {
  86       case MessageType.CALL_MESSAGE:
  87         if (
  88           this.statistics.statisticsData.has(command) &&
  89           this.statistics.statisticsData.get(command)?.requestCount
  90         ) {
  91           ++this.statistics.statisticsData.get(command)!.requestCount!;
  92         } else {
  93           this.statistics.statisticsData.set(command, {
  94             ...this.statistics.statisticsData.get(command),
  95             requestCount: 1,
  96           });
  97         }
  98         break;
  99       case MessageType.CALL_RESULT_MESSAGE:
 100         if (
 101           this.statistics.statisticsData.has(command) &&
 102           this.statistics.statisticsData.get(command)?.responseCount
 103         ) {
 104           ++this.statistics.statisticsData.get(command)!.responseCount!;
 105         } else {
 106           this.statistics.statisticsData.set(command, {
 107             ...this.statistics.statisticsData.get(command),
 108             responseCount: 1,
 109           });
 110         }
 111         break;
 112       case MessageType.CALL_ERROR_MESSAGE:
 113         if (
 114           this.statistics.statisticsData.has(command) &&
 115           this.statistics.statisticsData.get(command)?.errorCount
 116         ) {
 117           ++this.statistics.statisticsData.get(command)!.errorCount!;
 118         } else {
 119           this.statistics.statisticsData.set(command, {
 120             ...this.statistics.statisticsData.get(command),
 121             errorCount: 1,
 122           });
 123         }
 124         break;
 125       default:
 126         // eslint-disable-next-line @typescript-eslint/restrict-template-expressions
 127         logger.error(`${this.logPrefix()} wrong message type ${messageType}`);
 128         break;
 129     }
 130   }
 131
 132   public start(): void {
 133     this.startLogStatisticsInterval();
 134     const performanceStorageConfiguration =
 135       Configuration.getConfigurationSection<StorageConfiguration>(
 136         ConfigurationSection.performanceStorage,
 137       );
 138     if (performanceStorageConfiguration.enabled) {
 139       logger.info(
 140         `${this.logPrefix()} storage enabled: type ${performanceStorageConfiguration.type}, uri: ${
 141           performanceStorageConfiguration.uri
 142         }`,
 143       );
 144     }
 145   }
 146
 147   public stop(): void {
 148     this.stopLogStatisticsInterval();
 149     performance.clearMarks();
 150     performance.clearMeasures();
 151     this.performanceObserver?.disconnect();
 152   }
 153
 154   public restart(): void {
 155     this.stop();
 156     this.start();
 157   }
 158
 159   private initializePerformanceObserver(): void {
 160     this.performanceObserver = new PerformanceObserver((performanceObserverList) => {
 161       const lastPerformanceEntry = performanceObserverList.getEntries()[0];
 162       // logger.debug(
 163       //   `${this.logPrefix()} '${lastPerformanceEntry.name}' performance entry: %j`,
 164       //   lastPerformanceEntry,
 165       // );
 166       this.addPerformanceEntryToStatistics(lastPerformanceEntry);
 167     });
 168     this.performanceObserver.observe({ entryTypes: ['measure'] });
 169   }
 170
 171   private logStatistics(): void {
 172     logger.info(`${this.logPrefix()}`, {
 173       ...this.statistics,
 174       statisticsData: JSONStringifyWithMapSupport(this.statistics.statisticsData),
 175     });
 176   }
 177
 178   private startLogStatisticsInterval(): void {
 179     const logConfiguration = Configuration.getConfigurationSection<LogConfiguration>(
 180       ConfigurationSection.log,
 181     );
 182     const logStatisticsInterval = logConfiguration.enabled
 183       ? logConfiguration.statisticsInterval!
 184       : 0;
 185     if (logStatisticsInterval > 0 && !this.displayInterval) {
 186       this.displayInterval = setInterval(() => {
 187         this.logStatistics();
 188       }, logStatisticsInterval * 1000);
 189       logger.info(
 190         `${this.logPrefix()} logged every ${formatDurationSeconds(logStatisticsInterval)}`,
 191       );
 192     } else if (this.displayInterval) {
 193       logger.info(
 194         `${this.logPrefix()} already logged every ${formatDurationSeconds(logStatisticsInterval)}`,
 195       );
 196     } else if (logConfiguration.enabled) {
 197       logger.info(
 198         `${this.logPrefix()} log interval is set to ${logStatisticsInterval}. Not logging statistics`,
 199       );
 200     }
 201   }
 202
 203   private stopLogStatisticsInterval(): void {
 204     if (this.displayInterval) {
 205       clearInterval(this.displayInterval);
 206       delete this.displayInterval;
 207     }
 208   }
 209
 210   private addPerformanceEntryToStatistics(entry: PerformanceEntry): void {
 211     const entryName = entry.name;
 212     // Initialize command statistics
 213     if (!this.statistics.statisticsData.has(entryName)) {
 214       this.statistics.statisticsData.set(entryName, {});
 215     }
 216     // Update current statistics
 217     this.statistics.updatedAt = new Date();
 218     this.statistics.statisticsData.get(entryName)!.timeMeasurementCount =
 219       (this.statistics.statisticsData.get(entryName)?.timeMeasurementCount ?? 0) + 1;
 220     this.statistics.statisticsData.get(entryName)!.currentTimeMeasurement = entry.duration;
 221     this.statistics.statisticsData.get(entryName)!.minTimeMeasurement = Math.min(
 222       entry.duration,
 223       this.statistics.statisticsData.get(entryName)?.minTimeMeasurement ?? Infinity,
 224     );
 225     this.statistics.statisticsData.get(entryName)!.maxTimeMeasurement = Math.max(
 226       entry.duration,
 227       this.statistics.statisticsData.get(entryName)?.maxTimeMeasurement ?? -Infinity,
 228     );
 229     this.statistics.statisticsData.get(entryName)!.totalTimeMeasurement =
 230       (this.statistics.statisticsData.get(entryName)?.totalTimeMeasurement ?? 0) + entry.duration;
 231     this.statistics.statisticsData.get(entryName)!.avgTimeMeasurement =
 232       this.statistics.statisticsData.get(entryName)!.totalTimeMeasurement! /
 233       this.statistics.statisticsData.get(entryName)!.timeMeasurementCount!;
 234     this.statistics.statisticsData.get(entryName)?.measurementTimeSeries instanceof CircularArray
 235       ? this.statistics.statisticsData
 236           .get(entryName)
 237           ?.measurementTimeSeries?.push({ timestamp: entry.startTime, value: entry.duration })
 238       : (this.statistics.statisticsData.get(entryName)!.measurementTimeSeries =
 239           new CircularArray<TimestampedData>(Constants.DEFAULT_CIRCULAR_BUFFER_CAPACITY, {
 240             timestamp: entry.startTime,
 241             value: entry.duration,
 242           }));
 243     this.statistics.statisticsData.get(entryName)!.medTimeMeasurement = median(
 244       extractTimeSeriesValues(
 245         this.statistics.statisticsData.get(entryName)!.measurementTimeSeries as TimestampedData[],
 246       ),
 247     );
 248     this.statistics.statisticsData.get(entryName)!.ninetyFiveThPercentileTimeMeasurement =
 249       nthPercentile(
 250         extractTimeSeriesValues(
 251           this.statistics.statisticsData.get(entryName)!.measurementTimeSeries as TimestampedData[],
 252         ),
 253         95,
 254       );
 255     this.statistics.statisticsData.get(entryName)!.stdDevTimeMeasurement = stdDeviation(
 256       extractTimeSeriesValues(
 257         this.statistics.statisticsData.get(entryName)!.measurementTimeSeries as TimestampedData[],
 258       ),
 259     );
 260     if (
 261       Configuration.getConfigurationSection<StorageConfiguration>(
 262         ConfigurationSection.performanceStorage,
 263       ).enabled
 264     ) {
 265       parentPort?.postMessage(buildPerformanceStatisticsMessage(this.statistics));
 266     }
 267   }
 268
 269   private logPrefix = (): string => {
 270     return logPrefix(` ${this.objName} | Performance statistics`);
 271   };
 272 }