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