Simplify performance measurement API
authorJérôme Benoit <jerome.benoit@sap.com>
Thu, 12 Aug 2021 22:11:19 +0000 (00:11 +0200)
committerJérôme Benoit <jerome.benoit@sap.com>
Thu, 12 Aug 2021 22:11:19 +0000 (00:11 +0200)
Signed-off-by: Jérôme Benoit <jerome.benoit@sap.com>
src/charging-station/AutomaticTransactionGenerator.ts
src/charging-station/ChargingStation.ts
src/utils/PerformanceStatistics.ts

index 0f923a96dfe71b20ce27e005b4ca2fa1d1d4ef70..f8183b8b41470a9135609b5cc08f23d63486be1d 100644 (file)
@@ -2,7 +2,6 @@ import { AuthorizationStatus, AuthorizeResponse, StartTransactionResponse, StopT
 
 import ChargingStation from './ChargingStation';
 import Constants from '../utils/Constants';
-import { PerformanceObserver } from 'perf_hooks';
 import PerformanceStatistics from '../utils/PerformanceStatistics';
 import Utils from '../utils/Utils';
 import logger from '../utils/Logger';
@@ -10,15 +9,10 @@ import logger from '../utils/Logger';
 export default class AutomaticTransactionGenerator {
   public timeToStop: boolean;
   private chargingStation: ChargingStation;
-  private performanceObserver!: PerformanceObserver;
 
   constructor(chargingStation: ChargingStation) {
     this.chargingStation = chargingStation;
     this.timeToStop = true;
-    if (this.chargingStation.getEnableStatistics()) {
-      this.performanceObserver = PerformanceStatistics.initPerformanceObserver(Constants.ENTITY_AUTOMATIC_TRANSACTION_GENERATOR, this.chargingStation.performanceStatistics,
-        this.performanceObserver);
-    }
   }
 
   public async start(): Promise<void> {
@@ -84,13 +78,13 @@ export default class AutomaticTransactionGenerator {
       let skip = 0;
       if (start < this.chargingStation.stationInfo.AutomaticTransactionGenerator.probabilityOfStart) {
         // Start transaction
-        let startTransaction: (connectorId: number, self: AutomaticTransactionGenerator) => Promise<StartTransactionResponse | AuthorizeResponse>;
+        let startATGTransaction: (connectorId: number, self: AutomaticTransactionGenerator) => Promise<StartTransactionResponse | AuthorizeResponse>;
         if (this.chargingStation.getEnableStatistics()) {
-          startTransaction = PerformanceStatistics.timedFunction(this.startTransaction.bind(this), this.performanceObserver);
+          startATGTransaction = PerformanceStatistics.timedFunction(this.startATGTransaction.bind(this));
         } else {
-          startTransaction = this.startTransaction.bind(this);
+          startATGTransaction = this.startATGTransaction.bind(this);
         }
-        const startResponse = await startTransaction(connectorId, this);
+        const startResponse = await startATGTransaction(connectorId, this);
         if (startResponse?.idTagInfo?.status !== AuthorizationStatus.ACCEPTED) {
           logger.warn(this.logPrefix(connectorId) + ' transaction rejected');
           await Utils.sleep(Constants.CHARGING_STATION_ATG_WAIT_TIME);
@@ -103,13 +97,13 @@ export default class AutomaticTransactionGenerator {
           // Stop transaction
           if (this.chargingStation.getConnector(connectorId)?.transactionStarted) {
             logger.info(this.logPrefix(connectorId) + ' stop transaction ' + this.chargingStation.getConnector(connectorId).transactionId.toString());
-            let stopTransaction: (connectorId: number, self: AutomaticTransactionGenerator) => Promise<StopTransactionResponse>;
+            let stopATGTransaction: (connectorId: number, self: AutomaticTransactionGenerator) => Promise<StopTransactionResponse>;
             if (this.chargingStation.getEnableStatistics()) {
-              stopTransaction = PerformanceStatistics.timedFunction(this.stopTransaction.bind(this), this.performanceObserver);
+              stopATGTransaction = PerformanceStatistics.timedFunction(this.stopATGTransaction.bind(this));
             } else {
-              stopTransaction = this.stopTransaction.bind(this);
+              stopATGTransaction = this.stopATGTransaction.bind(this);
             }
-            await stopTransaction(connectorId, this);
+            await stopATGTransaction(connectorId, this);
           }
         }
       } else {
@@ -121,7 +115,7 @@ export default class AutomaticTransactionGenerator {
   }
 
   // eslint-disable-next-line consistent-this
-  private async startTransaction(connectorId: number, self: AutomaticTransactionGenerator): Promise<StartTransactionResponse | AuthorizeResponse> {
+  private async startATGTransaction(connectorId: number, self: AutomaticTransactionGenerator): Promise<StartTransactionResponse | AuthorizeResponse> {
     if (self.chargingStation.hasAuthorizedTags()) {
       const tagId = self.chargingStation.getRandomTagId();
       if (self.chargingStation.getAutomaticTransactionGeneratorRequireAuthorize()) {
@@ -143,7 +137,7 @@ export default class AutomaticTransactionGenerator {
   }
 
   // eslint-disable-next-line consistent-this
-  private async stopTransaction(connectorId: number, self: AutomaticTransactionGenerator): Promise<StopTransactionResponse> {
+  private async stopATGTransaction(connectorId: number, self: AutomaticTransactionGenerator): Promise<StopTransactionResponse> {
     const transactionId = self.chargingStation.getConnector(connectorId).transactionId;
     return self.chargingStation.ocppRequestService.sendStopTransaction(transactionId, self.chargingStation.getEnergyActiveImportRegisterByTransactionId(transactionId),
       self.chargingStation.getTransactionIdTag(transactionId));
index aed980c8df47c6c9d0204a2077419e0a0e3f9f04..4b6243731fc26689bcfd22ee883dbd235075f3be 100644 (file)
@@ -22,7 +22,6 @@ import OCPPError from './OCPPError';
 import OCPPIncomingRequestService from './ocpp/OCPPIncomingRequestService';
 import OCPPRequestService from './ocpp/OCPPRequestService';
 import { OCPPVersion } from '../types/ocpp/OCPPVersion';
-import { PerformanceObserver } from 'perf_hooks';
 import PerformanceStatistics from '../utils/PerformanceStatistics';
 import { StopTransactionReason } from '../types/ocpp/Transaction';
 import { URL } from 'url';
@@ -55,7 +54,6 @@ export default class ChargingStation {
   private hasSocketRestarted: boolean;
   private autoReconnectRetryCount: number;
   private automaticTransactionGeneration!: AutomaticTransactionGenerator;
-  private performanceObserver!: PerformanceObserver;
   private webSocketPingSetInterval!: NodeJS.Timeout;
 
   constructor(index: number, stationTemplateFile: string) {
@@ -551,7 +549,7 @@ export default class ChargingStation {
     this.stationInfo.powerDivider = this.getPowerDivider();
     if (this.getEnableStatistics()) {
       this.performanceStatistics = new PerformanceStatistics(this.stationInfo.chargingStationId);
-      this.performanceObserver = PerformanceStatistics.initPerformanceObserver(Constants.ENTITY_CHARGING_STATION, this.performanceStatistics, this.performanceObserver);
+      PerformanceStatistics.initFunctionPerformanceObserver(this.performanceStatistics);
     }
   }
 
@@ -593,7 +591,7 @@ export default class ChargingStation {
   }
 
   private async onOpen(): Promise<void> {
-    logger.info(`${this.logPrefix()} Connected to server through ${this.wsConnectionUrl.toString()}`);
+    logger.info(`${this.logPrefix()} Connected to OCPP server through ${this.wsConnectionUrl.toString()}`);
     if (!this.isRegistered()) {
       // Send BootNotification
       let registrationRetryCount = 0;
@@ -954,7 +952,7 @@ export default class ChargingStation {
         break;
     }
     this.wsConnection = new WebSocket(this.wsConnectionUrl, protocol, options);
-    logger.info(this.logPrefix() + ' Open connection to URL ' + this.wsConnectionUrl.toString());
+    logger.info(this.logPrefix() + ' Open OCPP connection to URL ' + this.wsConnectionUrl.toString());
   }
 
   private stopMeterValues(connectorId: number) {
index fe17f040e363c98e76269a50a227b5c1c82a7f21..1e666fe9a025a41aa3cdce5dc6bbff6f24c6fb1f 100644 (file)
@@ -17,16 +17,16 @@ export default class PerformanceStatistics {
     this.commandsStatistics = { id: this.objId ? this.objId : 'Object id not specified', commandsStatisticsData: {} };
   }
 
-  public static initPerformanceObserver(entity: string, performanceStatistics: PerformanceStatistics, performanceObserver: PerformanceObserver): PerformanceObserver {
-    return new PerformanceObserver((list) => {
-      const entry = list.getEntries()[0];
-      performanceStatistics.logPerformance(entry, entity);
-      performanceObserver && performanceObserver.disconnect();
+  public static initFunctionPerformanceObserver(performanceStatistics: PerformanceStatistics): PerformanceObserver {
+    const performanceObserver = new PerformanceObserver((list, observer) => {
+      performanceStatistics.logPerformance(list.getEntries()[0]);
+      observer.disconnect();
     });
+    performanceObserver.observe({ entryTypes: ['function'] });
+    return performanceObserver;
   }
 
-  public static timedFunction(method: (...optionalParams: any[]) => any, performanceObserver: PerformanceObserver): (...optionalParams: any[]) => any {
-    performanceObserver.observe({ entryTypes: ['function'] });
+  public static timedFunction(method: (...optionalParams: any[]) => any): (...optionalParams: any[]) => any {
     return performance.timerify(method);
   }
 
@@ -70,15 +70,15 @@ export default class PerformanceStatistics {
     }
   }
 
-  public logPerformance(entry: PerformanceEntry, className: string): void {
-    this.addPerformanceTimer(entry.name as RequestCommand | IncomingRequestCommand, entry.duration);
+  public logPerformance(entry: PerformanceEntry): void {
+    this.addPerformanceTimer(entry.name, 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);
+    logger.debug(`${this.logPrefix()} Method or function '${entry.name}' performance entry: %j`, perfEntry);
   }
 
   public start(): void {
@@ -124,30 +124,29 @@ 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,
+  private addPerformanceTimer(name: string, duration: number): void {
+    // Rename entry name
+    const MAP_NAME = {
+      startATGTransaction: 'StartATGTransaction',
+      stopATGTransaction: 'StartATGTransaction'
     };
-    if (MAP_COMMAND[command]) {
-      command = MAP_COMMAND[command] as RequestCommand | IncomingRequestCommand;
+    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.commandsStatistics.commandsStatisticsData[name]) {
+      this.commandsStatistics.commandsStatisticsData[name] = {} as CommandStatisticsData;
     }
     // 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.commandsStatistics.commandsStatisticsData[name].countTimeMeasurement = this.commandsStatistics.commandsStatisticsData[name].countTimeMeasurement ? this.commandsStatistics.commandsStatisticsData[name].countTimeMeasurement + 1 : 1;
+    this.commandsStatistics.commandsStatisticsData[name].currentTimeMeasurement = duration;
+    this.commandsStatistics.commandsStatisticsData[name].minTimeMeasurement = this.commandsStatistics.commandsStatisticsData[name].minTimeMeasurement ? (this.commandsStatistics.commandsStatisticsData[name].minTimeMeasurement > duration ? duration : this.commandsStatistics.commandsStatisticsData[name].minTimeMeasurement) : duration;
+    this.commandsStatistics.commandsStatisticsData[name].maxTimeMeasurement = this.commandsStatistics.commandsStatisticsData[name].maxTimeMeasurement ? (this.commandsStatistics.commandsStatisticsData[name].maxTimeMeasurement < duration ? duration : this.commandsStatistics.commandsStatisticsData[name].maxTimeMeasurement) : duration;
+    this.commandsStatistics.commandsStatisticsData[name].totalTimeMeasurement = this.commandsStatistics.commandsStatisticsData[name].totalTimeMeasurement ? this.commandsStatistics.commandsStatisticsData[name].totalTimeMeasurement + duration : duration;
+    this.commandsStatistics.commandsStatisticsData[name].avgTimeMeasurement = this.commandsStatistics.commandsStatisticsData[name].totalTimeMeasurement / this.commandsStatistics.commandsStatisticsData[name].countTimeMeasurement;
+    Array.isArray(this.commandsStatistics.commandsStatisticsData[name].timeMeasurementSeries) ? this.commandsStatistics.commandsStatisticsData[name].timeMeasurementSeries.push(duration) : this.commandsStatistics.commandsStatisticsData[name].timeMeasurementSeries = new CircularArray<number>(DEFAULT_CIRCULAR_ARRAY_SIZE, duration);
+    this.commandsStatistics.commandsStatisticsData[name].medTimeMeasurement = this.median(this.commandsStatistics.commandsStatisticsData[name].timeMeasurementSeries);
+    this.commandsStatistics.commandsStatisticsData[name].stdDevTimeMeasurement = this.stdDeviation(this.commandsStatistics.commandsStatisticsData[name].timeMeasurementSeries);
   }
 
   private logPrefix(): string {