[DVI-509] OCPP Validation logging (#384)

In case an OCPP validation fails TypeConstraint or Format, we should log which message caused the validation to fail.

We noticed a reproducible TypeConstraintViolation as a reaction to an OCPP message from Etrel Chargers.

A (OCPP) response from the Etrel chargers leads to a a) problem in data type conversion/parsing, b) a debug message that a transmitted string may be too long.

Author: klimaschkas

ocpp/messages.py

@@ -1,10 +1,12 @@
 """ Module containing classes that model the several OCPP messages types. It
 also contain some helper functions for packing and unpacking messages.  """
+from __future__ import annotations
+
 import decimal
 import json
 import os
 from dataclasses import asdict, is_dataclass
-from typing import Callable, Dict
+from typing import Callable, Dict, Union
 
 from jsonschema import Draft4Validator
 from jsonschema import _validators as SchemaValidators
@@ -75,7 +77,9 @@ def unpack(msg):
     try:
         msg = json.loads(msg)
     except json.JSONDecodeError:
-        raise FormatViolationError(details={"cause": "Message is not valid JSON"})
+        raise FormatViolationError(
+            details={"cause": "Message is not valid JSON", "ocpp_message": msg}
+        )
 
     if not isinstance(msg, list):
         raise ProtocolError(
@@ -100,7 +104,7 @@ def unpack(msg):
             raise ProtocolError(details={"cause": "Message is missing elements."})
 
     raise PropertyConstraintViolationError(
-        details={f"MessageTypeId '{msg[0]}' isn't valid"}
+        details={"cause": f"MessageTypeId '{msg[0]}' isn't valid"}
     )
 
 
@@ -160,7 +164,7 @@ def get_validator(
     return _validators[cache_key]
 
 
-def validate_payload(message, ocpp_version):
+def validate_payload(message: Union[Call, CallResult], ocpp_version: str) -> None:
     """Validate the payload of the message using JSON schemas."""
     if type(message) not in [Call, CallResult]:
         raise ValidationError(
@@ -217,18 +221,25 @@ def validate_payload(message, ocpp_version):
         validator.validate(message.payload)
     except SchemaValidationError as e:
         if e.validator == SchemaValidators.type.__name__:
-            raise TypeConstraintViolationError(details={"cause": e.message})
+            raise TypeConstraintViolationError(
+                details={"cause": e.message, "ocpp_message": message}
+            )
         elif e.validator == SchemaValidators.additionalProperties.__name__:
-            raise FormatViolationError(details={"cause": e.message})
+            raise FormatViolationError(
+                details={"cause": e.message, "ocpp_message": message}
+            )
         elif e.validator == SchemaValidators.required.__name__:
             raise ProtocolError(details={"cause": e.message})
         elif e.validator == "maxLength":
-            raise TypeConstraintViolationError(details={"cause": e.message}) from e
+            raise TypeConstraintViolationError(
+                details={"cause": e.message, "ocpp_message": message}
+            ) from e
         else:
             raise FormatViolationError(
                 details={
                     "cause": f"Payload '{message.payload} for action "
-                    f"'{message.action}' is not valid: {e}"
+                    f"'{message.action}' is not valid: {e}",
+                    "ocpp_message": message,
                 }
             )
 
@@ -317,7 +328,7 @@ def __repr__(self):
 class CallResult:
     """
     A CallResult is a message indicating that a Call has been handled
-    succesfully.
+    successfully.
 
     From the specification:
 

tests/test_exceptions.py

@@ -1,4 +1,11 @@
-from ocpp.exceptions import ProtocolError
+import pytest
+
+from ocpp.exceptions import (
+    FormatViolationError,
+    ProtocolError,
+    TypeConstraintViolationError,
+)
+from ocpp.messages import Call, validate_payload
 
 
 def test_exception_with_error_details():
@@ -13,3 +20,39 @@ def test_exception_without_error_details():
 
     assert exception.description == "Payload for Action is incomplete"
     assert exception.details == {}
+
+
+def test_exception_show_triggered_message_type_constraint():
+    # chargePointVendor should be a string, not an integer,
+    # so this should raise a TypeConstraintViolationError
+    call = Call(
+        unique_id=123456,
+        action="BootNotification",
+        payload={"chargePointVendor": 1, "chargePointModel": "SingleSocketCharger"},
+    )
+    ocpp_message = (
+        "'ocpp_message': <Call - unique_id=123456, action=BootNotification, "
+        "payload={'chargePointVendor': 1, 'chargePointModel': 'SingleSocketCharger'}"
+    )
+
+    with pytest.raises(TypeConstraintViolationError) as exception_info:
+        validate_payload(call, "1.6")
+    assert ocpp_message in str(exception_info.value)
+
+
+def test_exception_show_triggered_message_format():
+    # The payload is syntactically incorrect, should trigger a FormatViolationError
+    call = Call(
+        unique_id=123457,
+        action="BootNotification",
+        payload={"syntactically": "incorrect"},
+    )
+
+    ocpp_message = (
+        "'ocpp_message': <Call - unique_id=123457, action=BootNotification, "
+        "payload={'syntactically': 'incorrect'}"
+    )
+
+    with pytest.raises(FormatViolationError) as exception_info:
+        validate_payload(call, "1.6")
+    assert ocpp_message in str(exception_info.value)