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     if (
 135       Configuration.getConfigurationSection<StorageConfiguration>(
 136         ConfigurationSection.performanceStorage,
 137       ).enabled
 138     ) {
 139       logger.info(
 140         `${this.logPrefix()} storage enabled: type ${
 141           Configuration.getConfigurationSection<StorageConfiguration>(
 142             ConfigurationSection.performanceStorage,
 143           ).type
 144         }, uri: ${
 145           Configuration.getConfigurationSection<StorageConfiguration>(
 146             ConfigurationSection.performanceStorage,
 147           ).uri
 148         }`,
 149       );
 150     }
 151   }
 152
 153   public stop(): void {
 154     this.stopLogStatisticsInterval();
 155     performance.clearMarks();
 156     performance.clearMeasures();
 157     this.performanceObserver?.disconnect();
 158   }
 159
 160   public restart(): void {
 161     this.stop();
 162     this.start();
 163   }
 164
 165   private initializePerformanceObserver(): void {
 166     this.performanceObserver = new PerformanceObserver((performanceObserverList) => {
 167       const lastPerformanceEntry = performanceObserverList.getEntries()[0];
 168       // logger.debug(
 169       //   `${this.logPrefix()} '${lastPerformanceEntry.name}' performance entry: %j`,
 170       //   lastPerformanceEntry,
 171       // );
 172       this.addPerformanceEntryToStatistics(lastPerformanceEntry);
 173     });
 174     this.performanceObserver.observe({ entryTypes: ['measure'] });
 175   }
 176
 177   private logStatistics(): void {
 178     logger.info(`${this.logPrefix()}`, {
 179       ...this.statistics,
 180       statisticsData: JSONStringifyWithMapSupport(this.statistics.statisticsData),
 181     });
 182   }
 183
 184   private startLogStatisticsInterval(): void {
 185     const logStatisticsInterval = Configuration.getConfigurationSection<LogConfiguration>(
 186       ConfigurationSection.log,
 187     ).enabled
 188       ? Configuration.getConfigurationSection<LogConfiguration>(ConfigurationSection.log)
 189           .statisticsInterval!
 190       : 0;
 191     if (logStatisticsInterval > 0 && !this.displayInterval) {
 192       this.displayInterval = setInterval(() => {
 193         this.logStatistics();
 194       }, logStatisticsInterval * 1000);
 195       logger.info(
 196         `${this.logPrefix()} logged every ${formatDurationSeconds(logStatisticsInterval)}`,
 197       );
 198     } else if (this.displayInterval) {
 199       logger.info(
 200         `${this.logPrefix()} already logged every ${formatDurationSeconds(logStatisticsInterval)}`,
 201       );
 202     } else if (
 203       Configuration.getConfigurationSection<LogConfiguration>(ConfigurationSection.log).enabled
 204     ) {
 205       logger.info(
 206         `${this.logPrefix()} log interval is set to ${logStatisticsInterval?.toString()}. Not logging statistics`,
 207       );
 208     }
 209   }
 210
 211   private stopLogStatisticsInterval(): void {
 212     if (this.displayInterval) {
 213       clearInterval(this.displayInterval);
 214       delete this.displayInterval;
 215     }
 216   }
 217
 218   private addPerformanceEntryToStatistics(entry: PerformanceEntry): void {
 219     const entryName = entry.name;
 220     // Initialize command statistics
 221     if (!this.statistics.statisticsData.has(entryName)) {
 222       this.statistics.statisticsData.set(entryName, {});
 223     }
 224     // Update current statistics
 225     this.statistics.updatedAt = new Date();
 226     this.statistics.statisticsData.get(entryName)!.timeMeasurementCount =
 227       (this.statistics.statisticsData.get(entryName)?.timeMeasurementCount ?? 0) + 1;
 228     this.statistics.statisticsData.get(entryName)!.currentTimeMeasurement = entry.duration;
 229     this.statistics.statisticsData.get(entryName)!.minTimeMeasurement = Math.min(
 230       entry.duration,
 231       this.statistics.statisticsData.get(entryName)?.minTimeMeasurement ?? Infinity,
 232     );
 233     this.statistics.statisticsData.get(entryName)!.maxTimeMeasurement = Math.max(
 234       entry.duration,
 235       this.statistics.statisticsData.get(entryName)?.maxTimeMeasurement ?? -Infinity,
 236     );
 237     this.statistics.statisticsData.get(entryName)!.totalTimeMeasurement =
 238       (this.statistics.statisticsData.get(entryName)?.totalTimeMeasurement ?? 0) + entry.duration;
 239     this.statistics.statisticsData.get(entryName)!.avgTimeMeasurement =
 240       this.statistics.statisticsData.get(entryName)!.totalTimeMeasurement! /
 241       this.statistics.statisticsData.get(entryName)!.timeMeasurementCount!;
 242     this.statistics.statisticsData.get(entryName)?.measurementTimeSeries instanceof CircularArray
 243       ? this.statistics.statisticsData
 244           .get(entryName)
 245           ?.measurementTimeSeries?.push({ timestamp: entry.startTime, value: entry.duration })
 246       : (this.statistics.statisticsData.get(entryName)!.measurementTimeSeries =
 247           new CircularArray<TimestampedData>(Constants.DEFAULT_CIRCULAR_BUFFER_CAPACITY, {
 248             timestamp: entry.startTime,
 249             value: entry.duration,
 250           }));
 251     this.statistics.statisticsData.get(entryName)!.medTimeMeasurement = median(
 252       extractTimeSeriesValues(
 253         this.statistics.statisticsData.get(entryName)!.measurementTimeSeries as TimestampedData[],
 254       ),
 255     );
 256     this.statistics.statisticsData.get(entryName)!.ninetyFiveThPercentileTimeMeasurement =
 257       nthPercentile(
 258         extractTimeSeriesValues(
 259           this.statistics.statisticsData.get(entryName)!.measurementTimeSeries as TimestampedData[],
 260         ),
 261         95,
 262       );
 263     this.statistics.statisticsData.get(entryName)!.stdDevTimeMeasurement = stdDeviation(
 264       extractTimeSeriesValues(
 265         this.statistics.statisticsData.get(entryName)!.measurementTimeSeries as TimestampedData[],
 266       ),
 267     );
 268     if (
 269       Configuration.getConfigurationSection<StorageConfiguration>(
 270         ConfigurationSection.performanceStorage,
 271       ).enabled
 272     ) {
 273       parentPort?.postMessage(buildPerformanceStatisticsMessage(this.statistics));
 274     }
 275   }
 276
 277   private logPrefix = (): string => {
 278     return logPrefix(` ${this.objName} | Performance statistics`);
 279   };
 280 }