From e9017bfcbb2853db238c1aa18c2696bc0cbc56cc Mon Sep 17 00:00:00 2001 From: =?utf8?q?J=C3=A9r=C3=B4me=20Benoit?= Date: Fri, 13 Aug 2021 00:11:19 +0200 Subject: [PATCH] Simplify performance measurement API MIME-Version: 1.0 Content-Type: text/plain; charset=utf8 Content-Transfer-Encoding: 8bit Signed-off-by: Jérôme Benoit --- .../AutomaticTransactionGenerator.ts | 26 ++++----- src/charging-station/ChargingStation.ts | 8 +-- src/utils/PerformanceStatistics.ts | 57 +++++++++---------- 3 files changed, 41 insertions(+), 50 deletions(-) diff --git a/src/charging-station/AutomaticTransactionGenerator.ts b/src/charging-station/AutomaticTransactionGenerator.ts index 0f923a96..f8183b8b 100644 --- a/src/charging-station/AutomaticTransactionGenerator.ts +++ b/src/charging-station/AutomaticTransactionGenerator.ts @@ -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 { @@ -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; + let startATGTransaction: (connectorId: number, self: AutomaticTransactionGenerator) => Promise; 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; + let stopATGTransaction: (connectorId: number, self: AutomaticTransactionGenerator) => Promise; 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 { + private async startATGTransaction(connectorId: number, self: AutomaticTransactionGenerator): Promise { 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 { + private async stopATGTransaction(connectorId: number, self: AutomaticTransactionGenerator): Promise { const transactionId = self.chargingStation.getConnector(connectorId).transactionId; return self.chargingStation.ocppRequestService.sendStopTransaction(transactionId, self.chargingStation.getEnergyActiveImportRegisterByTransactionId(transactionId), self.chargingStation.getTransactionIdTag(transactionId)); diff --git a/src/charging-station/ChargingStation.ts b/src/charging-station/ChargingStation.ts index aed980c8..4b624373 100644 --- a/src/charging-station/ChargingStation.ts +++ b/src/charging-station/ChargingStation.ts @@ -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 { - 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) { diff --git a/src/utils/PerformanceStatistics.ts b/src/utils/PerformanceStatistics.ts index fe17f040..1e666fe9 100644 --- a/src/utils/PerformanceStatistics.ts +++ b/src/utils/PerformanceStatistics.ts @@ -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(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(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 { -- 2.34.1