Ensure performance statistics is started before connection to the OCPP
[e-mobility-charging-stations-simulator.git] / src / utils / PerformanceStatistics.ts
index 0c68fa73027b1169886394abc191a7fc2e73723f..49f75adea6ef7fa12f43b82ad6b1aa967ea0e3ef 100644 (file)
@@ -1,54 +1,67 @@
 import { CircularArray, DEFAULT_CIRCULAR_ARRAY_SIZE } from './CircularArray';
-import CommandStatistics, { CommandStatisticsData, PerfEntry } from '../types/CommandStatistics';
 import { IncomingRequestCommand, RequestCommand } from '../types/ocpp/Requests';
+import { PerformanceEntry, PerformanceObserver, performance } from 'perf_hooks';
+import Statistics, { StatisticsData } from '../types/Statistics';
 
 import Configuration from './Configuration';
 import { MessageType } from '../types/ocpp/MessageType';
-import { PerformanceEntry } from 'perf_hooks';
 import Utils from './Utils';
 import logger from './Logger';
 
 export default class PerformanceStatistics {
   private objId: string;
-  private commandsStatistics: CommandStatistics;
+  private performanceObserver: PerformanceObserver;
+  private statistics: Statistics;
+  private displayInterval: NodeJS.Timeout;
 
   public constructor(objId: string) {
     this.objId = objId;
-    this.commandsStatistics = { id: this.objId ? this.objId : 'Object id not specified', commandsStatisticsData: {} };
+    this.initializePerformanceObserver();
+    this.statistics = { id: this.objId ?? 'Object id not specified', statisticsData: {} };
   }
 
-  public addMessage(command: RequestCommand | IncomingRequestCommand, messageType: MessageType): void {
+  public static beginMeasure(id: string): string {
+    const beginId = 'begin' + id.charAt(0).toUpperCase() + id.slice(1);
+    performance.mark(beginId);
+    return beginId;
+  }
+
+  public static endMeasure(name: string, beginId: string): void {
+    performance.measure(name, beginId);
+  }
+
+  public addRequestStatistic(command: RequestCommand | IncomingRequestCommand, messageType: MessageType): void {
     switch (messageType) {
       case MessageType.CALL_MESSAGE:
-        if (this.commandsStatistics.commandsStatisticsData[command] && this.commandsStatistics.commandsStatisticsData[command].countRequest) {
-          this.commandsStatistics.commandsStatisticsData[command].countRequest++;
+        if (this.statistics.statisticsData[command] && this.statistics.statisticsData[command].countRequest) {
+          this.statistics.statisticsData[command].countRequest++;
         } else {
-          this.commandsStatistics.commandsStatisticsData[command] = {} as CommandStatisticsData;
-          this.commandsStatistics.commandsStatisticsData[command].countRequest = 1;
+          this.statistics.statisticsData[command] = {} as StatisticsData;
+          this.statistics.statisticsData[command].countRequest = 1;
         }
         break;
       case MessageType.CALL_RESULT_MESSAGE:
-        if (this.commandsStatistics.commandsStatisticsData[command]) {
-          if (this.commandsStatistics.commandsStatisticsData[command].countResponse) {
-            this.commandsStatistics.commandsStatisticsData[command].countResponse++;
+        if (this.statistics.statisticsData[command]) {
+          if (this.statistics.statisticsData[command].countResponse) {
+            this.statistics.statisticsData[command].countResponse++;
           } else {
-            this.commandsStatistics.commandsStatisticsData[command].countResponse = 1;
+            this.statistics.statisticsData[command].countResponse = 1;
           }
         } else {
-          this.commandsStatistics.commandsStatisticsData[command] = {} as CommandStatisticsData;
-          this.commandsStatistics.commandsStatisticsData[command].countResponse = 1;
+          this.statistics.statisticsData[command] = {} as StatisticsData;
+          this.statistics.statisticsData[command].countResponse = 1;
         }
         break;
       case MessageType.CALL_ERROR_MESSAGE:
-        if (this.commandsStatistics.commandsStatisticsData[command]) {
-          if (this.commandsStatistics.commandsStatisticsData[command].countError) {
-            this.commandsStatistics.commandsStatisticsData[command].countError++;
+        if (this.statistics.statisticsData[command]) {
+          if (this.statistics.statisticsData[command].countError) {
+            this.statistics.statisticsData[command].countError++;
           } else {
-            this.commandsStatistics.commandsStatisticsData[command].countError = 1;
+            this.statistics.statisticsData[command].countError = 1;
           }
         } else {
-          this.commandsStatistics.commandsStatisticsData[command] = {} as CommandStatisticsData;
-          this.commandsStatistics.commandsStatisticsData[command].countError = 1;
+          this.statistics.statisticsData[command] = {} as StatisticsData;
+          this.statistics.statisticsData[command].countError = 1;
         }
         break;
       default:
@@ -57,31 +70,42 @@ export default class PerformanceStatistics {
     }
   }
 
-  public logPerformance(entry: PerformanceEntry, className: string): void {
-    this.addPerformanceTimer(entry.name as RequestCommand | IncomingRequestCommand, entry.duration);
-    const perfEntry: PerfEntry = {
-      name: entry.name,
-      entryType: entry.entryType,
-      startTime: entry.startTime,
-      duration: entry.duration
-    } ;
-    logger.info(`${this.logPrefix()} ${className} method(s) entry: %j`, perfEntry);
+  public start(): void {
+    this.startDisplayInterval();
   }
 
-  public start(): void {
-    this.displayInterval();
+  public stop(): void {
+    if (this.displayInterval) {
+      clearInterval(this.displayInterval);
+    }
+    performance.clearMarks();
+    this.performanceObserver.disconnect();
+  }
+
+  private initializePerformanceObserver(): void {
+    this.performanceObserver = new PerformanceObserver((list) => {
+      this.logPerformanceEntry(list.getEntries()[0]);
+    });
+    this.performanceObserver.observe({ entryTypes: ['measure'] });
+  }
+
+  private logPerformanceEntry(entry: PerformanceEntry): void {
+    this.addPerformanceStatistic(entry.name, entry.duration);
+    logger.debug(`${this.logPrefix()} '${entry.name}' performance entry: %j`, entry);
   }
 
-  private display(): void {
-    logger.info(this.logPrefix() + ' %j', this.commandsStatistics);
+  private logStatistics(): void {
+    logger.info(this.logPrefix() + ' %j', this.statistics);
   }
 
-  private displayInterval(): void {
+  private startDisplayInterval(): void {
     if (Configuration.getStatisticsDisplayInterval() > 0) {
-      setInterval(() => {
-        this.display();
+      this.displayInterval = setInterval(() => {
+        this.logStatistics();
       }, Configuration.getStatisticsDisplayInterval() * 1000);
       logger.info(this.logPrefix() + ' displayed every ' + Utils.secondsToHHMMSS(Configuration.getStatisticsDisplayInterval()));
+    } else {
+      logger.info(this.logPrefix() + ' display interval is set to ' + Configuration.getStatisticsDisplayInterval().toString() + '. Not displaying statistics');
     }
   }
 
@@ -111,30 +135,26 @@ export default class PerformanceStatistics {
     return Math.sqrt(totalGeometricDeviation / dataSet.length);
   }
 
-  private addPerformanceTimer(command: RequestCommand | IncomingRequestCommand, duration: number): void {
-    // Map to proper command name
-    const MAP_COMMAND = {
-      sendMeterValues: RequestCommand.METER_VALUES,
-      startTransaction: RequestCommand.START_TRANSACTION,
-      stopTransaction: RequestCommand.STOP_TRANSACTION,
-    };
-    if (MAP_COMMAND[command]) {
-      command = MAP_COMMAND[command] as RequestCommand | IncomingRequestCommand;
+  private addPerformanceStatistic(name: string, duration: number): void {
+    // Rename entry name
+    const MAP_NAME = {};
+    if (MAP_NAME[name]) {
+      name = MAP_NAME[name] as string;
     }
     // Initialize command statistics
-    if (!this.commandsStatistics.commandsStatisticsData[command]) {
-      this.commandsStatistics.commandsStatisticsData[command] = {} as CommandStatisticsData;
+    if (!this.statistics.statisticsData[name]) {
+      this.statistics.statisticsData[name] = {} as StatisticsData;
     }
     // Update current statistics timers
-    this.commandsStatistics.commandsStatisticsData[command].countTimeMeasurement = this.commandsStatistics.commandsStatisticsData[command].countTimeMeasurement ? this.commandsStatistics.commandsStatisticsData[command].countTimeMeasurement + 1 : 1;
-    this.commandsStatistics.commandsStatisticsData[command].currentTimeMeasurement = duration;
-    this.commandsStatistics.commandsStatisticsData[command].minTimeMeasurement = this.commandsStatistics.commandsStatisticsData[command].minTimeMeasurement ? (this.commandsStatistics.commandsStatisticsData[command].minTimeMeasurement > duration ? duration : this.commandsStatistics.commandsStatisticsData[command].minTimeMeasurement) : duration;
-    this.commandsStatistics.commandsStatisticsData[command].maxTimeMeasurement = this.commandsStatistics.commandsStatisticsData[command].maxTimeMeasurement ? (this.commandsStatistics.commandsStatisticsData[command].maxTimeMeasurement < duration ? duration : this.commandsStatistics.commandsStatisticsData[command].maxTimeMeasurement) : duration;
-    this.commandsStatistics.commandsStatisticsData[command].totalTimeMeasurement = this.commandsStatistics.commandsStatisticsData[command].totalTimeMeasurement ? this.commandsStatistics.commandsStatisticsData[command].totalTimeMeasurement + duration : duration;
-    this.commandsStatistics.commandsStatisticsData[command].avgTimeMeasurement = this.commandsStatistics.commandsStatisticsData[command].totalTimeMeasurement / this.commandsStatistics.commandsStatisticsData[command].countTimeMeasurement;
-    Array.isArray(this.commandsStatistics.commandsStatisticsData[command].timeMeasurementSeries) ? this.commandsStatistics.commandsStatisticsData[command].timeMeasurementSeries.push(duration) : this.commandsStatistics.commandsStatisticsData[command].timeMeasurementSeries = new CircularArray<number>(DEFAULT_CIRCULAR_ARRAY_SIZE, duration);
-    this.commandsStatistics.commandsStatisticsData[command].medTimeMeasurement = this.median(this.commandsStatistics.commandsStatisticsData[command].timeMeasurementSeries);
-    this.commandsStatistics.commandsStatisticsData[command].stdDevTimeMeasurement = this.stdDeviation(this.commandsStatistics.commandsStatisticsData[command].timeMeasurementSeries);
+    this.statistics.statisticsData[name].countTimeMeasurement = this.statistics.statisticsData[name].countTimeMeasurement ? this.statistics.statisticsData[name].countTimeMeasurement + 1 : 1;
+    this.statistics.statisticsData[name].currentTimeMeasurement = duration;
+    this.statistics.statisticsData[name].minTimeMeasurement = this.statistics.statisticsData[name].minTimeMeasurement ? (this.statistics.statisticsData[name].minTimeMeasurement > duration ? duration : this.statistics.statisticsData[name].minTimeMeasurement) : duration;
+    this.statistics.statisticsData[name].maxTimeMeasurement = this.statistics.statisticsData[name].maxTimeMeasurement ? (this.statistics.statisticsData[name].maxTimeMeasurement < duration ? duration : this.statistics.statisticsData[name].maxTimeMeasurement) : duration;
+    this.statistics.statisticsData[name].totalTimeMeasurement = this.statistics.statisticsData[name].totalTimeMeasurement ? this.statistics.statisticsData[name].totalTimeMeasurement + duration : duration;
+    this.statistics.statisticsData[name].avgTimeMeasurement = this.statistics.statisticsData[name].totalTimeMeasurement / this.statistics.statisticsData[name].countTimeMeasurement;
+    Array.isArray(this.statistics.statisticsData[name].timeMeasurementSeries) ? this.statistics.statisticsData[name].timeMeasurementSeries.push(duration) : this.statistics.statisticsData[name].timeMeasurementSeries = new CircularArray<number>(DEFAULT_CIRCULAR_ARRAY_SIZE, duration);
+    this.statistics.statisticsData[name].medTimeMeasurement = this.median(this.statistics.statisticsData[name].timeMeasurementSeries);
+    this.statistics.statisticsData[name].stdDevTimeMeasurement = this.stdDeviation(this.statistics.statisticsData[name].timeMeasurementSeries);
   }
 
   private logPrefix(): string {