Improve OCPP logging.
authorJérôme Benoit <jerome.benoit@sap.com>
Tue, 3 Nov 2020 12:10:37 +0000 (13:10 +0100)
committerJérôme Benoit <jerome.benoit@sap.com>
Tue, 3 Nov 2020 12:10:37 +0000 (13:10 +0100)
Signed-off-by: Jérôme Benoit <jerome.benoit@sap.com>
src/charging-station/ChargingStation.ts
src/charging-station/OcppError.ts
src/utils/Constants.ts
src/utils/Statistics.ts

index f7754b6486c94e669f8a36d40e333d0f80c6a1a3..94ffc12a2481edca965765d1f669fff60902d9f4 100644 (file)
@@ -29,7 +29,7 @@ export default class ChargingStation {
   private _autoReconnectMaxRetries: number;
   private _autoReconnectTimeout: number;
   private _requests;
-  private _messageQueue;
+  private _messageQueue: any[];
   private _automaticTransactionGeneration: AutomaticTransactionGenerator;
   private _authorizedTags: string[];
   private _heartbeatInterval: number;
@@ -406,9 +406,9 @@ export default class ChargingStation {
       return;
     }
     if (interval > 0) {
+      // eslint-disable-next-line @typescript-eslint/no-this-alias
+      const self = this;
       this.getConnector(connectorId).transactionSetInterval = setInterval(async () => {
-        // eslint-disable-next-line @typescript-eslint/no-this-alias
-        const self = this;
         if (this.getEnableStatistics()) {
           const sendMeterValues = performance.timerify(this.sendMeterValues);
           this._performanceObserver.observe({
@@ -542,6 +542,9 @@ export default class ChargingStation {
       switch (messageType) {
         // Incoming Message
         case Constants.OCPP_JSON_CALL_MESSAGE:
+          if (this.getEnableStatistics()) {
+            this._statistics.addMessage(commandName, messageType);
+          }
           // Process the call
           await this.handleRequest(messageId, commandName, commandPayload);
           break;
@@ -580,13 +583,16 @@ export default class ChargingStation {
           break;
         // Error
         default:
-          throw new Error(`Wrong message type ${messageType}`);
+          // eslint-disable-next-line no-case-declarations
+          const errMsg = `${this._logPrefix()} Wrong message type ${messageType}`;
+          logger.error(errMsg);
+          throw new Error(errMsg);
       }
     } catch (error) {
       // Log
-      logger.error('%s Incoming message %j processing error %s on request content %s', this._logPrefix(), message, error, this._requests[messageId]);
+      logger.error('%s Incoming message %j processing error %s on request content type %s', this._logPrefix(), message, error, this._requests[messageId]);
       // Send error
-      await this.sendError(messageId, error);
+      await this.sendError(messageId, error, commandName);
     }
   }
 
@@ -680,12 +686,13 @@ export default class ChargingStation {
           }
         // Voltage measurand
         } else if (meterValuesTemplate[index].measurand && meterValuesTemplate[index].measurand === 'Voltage' && self._getConfigurationKey('MeterValuesSampledData').value.includes('Voltage')) {
+          const voltageMeasurandValue = Utils.getRandomFloatRounded(self._getVoltageOut() + self._getVoltageOut() * 0.1, self._getVoltageOut() - self._getVoltageOut() * 0.1);
           sampledValues.sampledValue.push({
             ...!Utils.isUndefined(meterValuesTemplate[index].unit) ? { unit: meterValuesTemplate[index].unit } : { unit: 'V' },
             ...!Utils.isUndefined(meterValuesTemplate[index].context) && { context: meterValuesTemplate[index].context },
             measurand: meterValuesTemplate[index].measurand,
             ...!Utils.isUndefined(meterValuesTemplate[index].location) && { location: meterValuesTemplate[index].location },
-            ...!Utils.isUndefined(meterValuesTemplate[index].value) ? { value: meterValuesTemplate[index].value } : { value: self._getVoltageOut() },
+            ...!Utils.isUndefined(meterValuesTemplate[index].value) ? { value: meterValuesTemplate[index].value } : { value: voltageMeasurandValue },
           });
           for (let phase = 1; self._getNumberOfPhases() === 3 && phase <= self._getNumberOfPhases(); phase++) {
             const voltageValue = sampledValues.sampledValue[sampledValues.sampledValue.length - 1].value;
@@ -700,7 +707,7 @@ export default class ChargingStation {
               ...!Utils.isUndefined(meterValuesTemplate[index].context) && { context: meterValuesTemplate[index].context },
               measurand: meterValuesTemplate[index].measurand,
               ...!Utils.isUndefined(meterValuesTemplate[index].location) && { location: meterValuesTemplate[index].location },
-              ...!Utils.isUndefined(meterValuesTemplate[index].value) ? { value: meterValuesTemplate[index].value } : { value: self._getVoltageOut() },
+              ...!Utils.isUndefined(meterValuesTemplate[index].value) ? { value: meterValuesTemplate[index].value } : { value: voltageMeasurandValue },
               phase: phaseValue,
             });
           }
@@ -876,14 +883,14 @@ export default class ChargingStation {
     }
   }
 
-  sendError(messageId, err) {
-    // Check exception: only OCPP error are accepted
-    const error = err instanceof OCPPError ? err : new OCPPError(Constants.OCPP_ERROR_INTERNAL_ERROR, err.message);
+  sendError(messageId, err: Error|OCPPError, commandName) {
+    // Check exception type: only OCPP error are accepted
+    const error = err instanceof OCPPError ? err : new OCPPError(Constants.OCPP_ERROR_INTERNAL_ERROR, err.message, err.stack && err.stack);
     // Send error
-    return this.sendMessage(messageId, error, Constants.OCPP_JSON_CALL_ERROR_MESSAGE);
+    return this.sendMessage(messageId, error, Constants.OCPP_JSON_CALL_ERROR_MESSAGE, commandName);
   }
 
-  sendMessage(messageId, command, messageType = Constants.OCPP_JSON_CALL_RESULT_MESSAGE, commandName = '') {
+  sendMessage(messageId, commandParams, messageType = Constants.OCPP_JSON_CALL_RESULT_MESSAGE, commandName: string) {
     const self = this;
     // Send a message through wsConnection
     return new Promise((resolve, reject) => {
@@ -892,39 +899,44 @@ export default class ChargingStation {
       switch (messageType) {
         // Request
         case Constants.OCPP_JSON_CALL_MESSAGE:
-          if (this.getEnableStatistics()) {
-            this._statistics.addMessage(commandName);
-          }
           // Build request
-          this._requests[messageId] = [responseCallback, rejectCallback, command];
-          messageToSend = JSON.stringify([messageType, messageId, commandName, command]);
+          this._requests[messageId] = [responseCallback, rejectCallback, commandParams];
+          messageToSend = JSON.stringify([messageType, messageId, commandName, commandParams]);
           break;
         // Response
         case Constants.OCPP_JSON_CALL_RESULT_MESSAGE:
-          if (this.getEnableStatistics()) {
-            this._statistics.addMessage(commandName);
-          }
           // Build response
-          messageToSend = JSON.stringify([messageType, messageId, command]);
+          messageToSend = JSON.stringify([messageType, messageId, commandParams]);
           break;
         // Error Message
         case Constants.OCPP_JSON_CALL_ERROR_MESSAGE:
-          if (this.getEnableStatistics()) {
-            this._statistics.addMessage(commandName + ' error');
-          }
           // Build Error Message
-          messageToSend = JSON.stringify([messageType, messageId, command.code ? command.code : Constants.OCPP_ERROR_GENERIC_ERROR, command.message ? command.message : '', command.details ? command.details : {}]);
+          messageToSend = JSON.stringify([messageType, messageId, commandParams.code ? commandParams.code : Constants.OCPP_ERROR_GENERIC_ERROR, commandParams.message ? commandParams.message : '', commandParams.details ? commandParams.details : {}]);
           break;
       }
       // Check if wsConnection is ready
       if (this._wsConnection && this._wsConnection.readyState === WebSocket.OPEN) {
+        if (this.getEnableStatistics()) {
+          this._statistics.addMessage(commandName, messageType);
+        }
         // Yes: Send Message
         this._wsConnection.send(messageToSend);
       } else {
-        // Buffer message until connection is back
-        this._messageQueue.push(messageToSend);
+        let dups = false;
+        // Handle dups in buffer
+        for (const message of this._messageQueue) {
+          // Same message
+          if (JSON.stringify(messageToSend) === JSON.stringify(message)) {
+            dups = true;
+            break;
+          }
+        }
+        if (!dups) {
+          // Buffer message
+          this._messageQueue.push(messageToSend);
+        }
         // Reject it
-        return rejectCallback(new OCPPError(command.code ? command.code : Constants.OCPP_ERROR_GENERIC_ERROR, command.message ? command.message : `Web socket closed for message id '${messageId}' with content '${messageToSend}', buffer it`, command.details ? command.details : {}));
+        return rejectCallback(new OCPPError(commandParams.code ? commandParams.code : Constants.OCPP_ERROR_GENERIC_ERROR, commandParams.message ? commandParams.message : `Web socket closed for message id '${messageId}' with content '${messageToSend}', message buffered`, commandParams.details ? commandParams.details : {}));
       }
       // Response?
       if (messageType === Constants.OCPP_JSON_CALL_RESULT_MESSAGE) {
@@ -932,22 +944,25 @@ export default class ChargingStation {
         resolve();
       } else if (messageType === Constants.OCPP_JSON_CALL_ERROR_MESSAGE) {
         // Send timeout
-        setTimeout(() => rejectCallback(new OCPPError(command.code ? command.code : Constants.OCPP_ERROR_GENERIC_ERROR, command.message ? command.message : `Timeout for message id '${messageId}' with content '${messageToSend}'`, command.details ? command.details : {})), Constants.OCPP_SOCKET_TIMEOUT);
+        setTimeout(() => rejectCallback(new OCPPError(commandParams.code ? commandParams.code : Constants.OCPP_ERROR_GENERIC_ERROR, commandParams.message ? commandParams.message : `Timeout for message id '${messageId}' with content '${messageToSend}'`, commandParams.details ? commandParams.details : {})), Constants.OCPP_SOCKET_TIMEOUT);
       }
 
       // Function that will receive the request's response
-      function responseCallback(payload, requestPayload) {
+      function responseCallback(payload, requestPayload): void {
+        if (self.getEnableStatistics()) {
+          self._statistics.addMessage(commandName, messageType);
+        }
         // Send the response
         self.handleResponse(commandName, payload, requestPayload);
         resolve(payload);
       }
 
       // Function that will receive the request's rejection
-      function rejectCallback(error: OCPPError) {
-        logger.debug(`${self._logPrefix()} Error %j on commandName %s command %j`, error, commandName, command);
+      function rejectCallback(error: OCPPError): void {
         if (self.getEnableStatistics()) {
-          self._statistics.addMessage(`${commandName} error`, true);
+          self._statistics.addMessage(commandName, messageType);
         }
+        logger.debug(`${self._logPrefix()} Error %j occurred when calling command %s with parameters %j`, error, commandName, commandParams);
         // Build Exception
         // eslint-disable-next-line no-empty-function
         self._requests[messageId] = [() => { }, () => { }, '']; // Properly format the request
@@ -957,10 +972,7 @@ export default class ChargingStation {
     });
   }
 
-  handleResponse(commandName, payload, requestPayload) {
-    if (this.getEnableStatistics()) {
-      this._statistics.addMessage(commandName, true);
-    }
+  handleResponse(commandName: string, payload, requestPayload) {
     const responseCallbackFn = 'handleResponse' + commandName;
     if (typeof this[responseCallbackFn] === 'function') {
       this[responseCallbackFn](payload, requestPayload);
@@ -1070,9 +1082,6 @@ export default class ChargingStation {
   }
 
   async handleRequest(messageId, commandName, commandPayload) {
-    if (this.getEnableStatistics()) {
-      this._statistics.addMessage(commandName, true);
-    }
     let response;
     // Call
     if (typeof this['handleRequest' + commandName] === 'function') {
@@ -1083,15 +1092,16 @@ export default class ChargingStation {
         // Log
         logger.error(this._logPrefix() + ' Handle request error: ' + error);
         // Send back response to inform backend
-        await this.sendError(messageId, error);
+        await this.sendError(messageId, error, commandName);
+        throw error;
       }
     } else {
       // Throw exception
-      await this.sendError(messageId, new OCPPError(Constants.OCPP_ERROR_NOT_IMPLEMENTED, 'Not implemented', {}));
+      await this.sendError(messageId, new OCPPError(Constants.OCPP_ERROR_NOT_IMPLEMENTED, `${commandName} not implemented`, {}), commandName);
       throw new Error(`${commandName} is not implemented ${JSON.stringify(commandPayload, null, ' ')}`);
     }
     // Send response
-    await this.sendMessage(messageId, response, Constants.OCPP_JSON_CALL_RESULT_MESSAGE);
+    await this.sendMessage(messageId, response, Constants.OCPP_JSON_CALL_RESULT_MESSAGE, commandName);
   }
 
   // Simulate charging station restart
index 1f384783a90e428c12bdb48ea7b05f8189ab4373..3de71eb539125bc22de51da613948a7ea6b8e444 100644 (file)
@@ -2,7 +2,7 @@ import Constants from '../utils/Constants';
 
 export default class OCPPError extends Error {
   code: string;
-  details;
+  details: any;
 
   constructor(code: string, message:string , details?) {
     super(message);
index cdc4dc75146a6e828d918bc4165ea77f691c50af..0057f066e34dcf5efcb233e85a26888232e97e45 100644 (file)
@@ -105,9 +105,9 @@ export default class Constants {
   static OCPP_RESPONSE_REJECTED = { status: 'Rejected' };
   static OCPP_RESPONSE_REBOOT_REQUIRED = { status: 'RebootRequired' };
   static OCPP_SOCKET_TIMEOUT = 60000; // 60 sec
-  static OCPP_JSON_CALL_MESSAGE = 2; // Client-to-Server
-  static OCPP_JSON_CALL_RESULT_MESSAGE = 3; // Server-to-Client
-  static OCPP_JSON_CALL_ERROR_MESSAGE = 4; // Server-to-Client
+  static OCPP_JSON_CALL_MESSAGE = 2; // Caller to callee
+  static OCPP_JSON_CALL_RESULT_MESSAGE = 3; // Callee to caller
+  static OCPP_JSON_CALL_ERROR_MESSAGE = 4; // Callee to caller
   // Requested Action is not known by receiver
   static OCPP_ERROR_NOT_IMPLEMENTED = 'NotImplemented';
   // Requested Action is recognized but not supported by the receiver
@@ -122,7 +122,7 @@ export default class Constants {
   static OCPP_ERROR_FORMATION_VIOLATION = 'FormationViolation';
   // Payload is syntactically correct but at least one field contains an invalid value
   static OCPP_ERROR_PROPERTY_RAINT_VIOLATION = 'PropertyraintViolation';
-  // Payload for Action is syntactically correct but at least one of the fields violates occurence raints
+  // Payload for Action is syntactically correct but at least one of the fields violates occurrence raints
   static OCPP_ERROR_OCCURENCE_RAINT_VIOLATION = 'OccurenceraintViolation';
   // Payload for Action is syntactically correct but at least one of the fields violates data type raints (e.g. “somestring” = 12)
   static OCPP_ERROR_TYPERAINT_VIOLATION = 'TyperaintViolation';
index a2e0d030f009221fe5bf69cef6a8aee51353c75e..67bbf49e337bd03ec357ce0f2bbb530a960c9b6f 100644 (file)
@@ -1,4 +1,5 @@
 import Configuration from './Configuration';
+import Constants from './Constants';
 import Utils from './Utils';
 import logger from './Logger';
 
@@ -22,23 +23,43 @@ export default class Statistics {
     return Statistics.instance;
   }
 
-  addMessage(command, response = false) {
-    if (response) {
-      if (this._statistics[command]) {
-        if (this._statistics[command].countResponse) {
-          this._statistics[command].countResponse++;
+  addMessage(command: string, messageType: number): void {
+    switch (messageType) {
+      case Constants.OCPP_JSON_CALL_MESSAGE:
+        if (this._statistics[command] && this._statistics[command].count) {
+          this._statistics[command].countRequest++;
         } else {
+          this._statistics[command] = {};
+          this._statistics[command].countRequest = 1;
+        }
+        break;
+      case Constants.OCPP_JSON_CALL_RESULT_MESSAGE:
+        if (this._statistics[command]) {
+          if (this._statistics[command].countResponse) {
+            this._statistics[command].countResponse++;
+          } else {
+            this._statistics[command].countResponse = 1;
+          }
+        } else {
+          this._statistics[command] = {};
           this._statistics[command].countResponse = 1;
         }
-      } else {
-        this._statistics[command] = {};
-        this._statistics[command].countResponse = 1;
-      }
-    } else if (this._statistics[command] && this._statistics[command].count) {
-      this._statistics[command].count++;
-    } else {
-      this._statistics[command] = {};
-      this._statistics[command].count = 1;
+        break;
+      case Constants.OCPP_JSON_CALL_ERROR_MESSAGE:
+        if (this._statistics[command]) {
+          if (this._statistics[command].countError) {
+            this._statistics[command].countError++;
+          } else {
+            this._statistics[command].countError = 1;
+          }
+        } else {
+          this._statistics[command] = {};
+          this._statistics[command].countError = 1;
+        }
+        break;
+      default:
+        logger.error(`${this._logPrefix()} Wrong message type ${messageType}`);
+        break;
     }
   }