Further robustness checks to the on_register_report logic

Signed-off-by: Stan Janssen <stan.janssen@elaad.nl>

openleadr/service/report_service.py

@@ -112,30 +112,37 @@ class ReportService(VTNService):
                 if iscoroutine(result[0]):
                     result = await gather(*result)
                 for i, r in enumerate(result):
+                    if r is None:
+                        continue
                     if not isinstance(r, tuple):
-                        logger.error(f"Your on_register_report handler must return a tuple; it returned '{r}' ({r.__class__.__name__}).")
+                        logger.error("Your on_register_report handler must return a tuple; "
+                                     f"it returned '{r}' ({r.__class__.__name__}).")
                         result[i] = None
                 result = [(report['report_descriptions'][i]['r_id'], *result[i])
                           for i in range(len(report['report_descriptions'])) if isinstance(result[i], tuple)]
                 report_requests.append(result)
+            utils.validate_report_request_tuples(report_requests)
         else:
             # Use the 'full' mode for openADR reporting
             result = [self.on_register_report(report) for report in payload['reports']]
             if iscoroutine(result[0]):
                 result = await gather(*result)      # Now we have r_id, callback, sampling_rate
             for i, r in enumerate(result):
+                if r is None:
+                    continue
                 if not isinstance(r, list):
-                    logger.error(f"Your on_register_report handler must return a list of tuples. It returned '{r}' ({r.__class__.__name__}).")
+                    logger.error("Your on_register_report handler must return a list of tuples. "
+                                 f"It returned '{r}' ({r.__class__.__name__}).")
                     result[i] = None
             report_requests = result
+            utils.validate_report_request_tuples(report_requests, full_mode=True)
+
 
-        # Validate the report requests for being of the proper type and lengs
-        utils.validate_report_request_tuples(report_requests)
         for i, report_request in enumerate(report_requests):
-            if report_request is None or len(report_request) == 0:
+            if report_request is None or len(report_request) == 0 or all(rrq is None for rrq in report_request):
                 continue
             # Check if all sampling rates per report_request are the same
-            sampling_interval = min(rrq[2] for rrq in report_request if rrq is not None)
+            sampling_interval = min(rrq[2] for rrq in report_request if isinstance(rrq, tuple))
             if not all(rrq is not None and report_request[0][2] == sampling_interval for rrq in report_request):
                 logger.error("OpenADR does not support multiple different sampling rates per "
                              "report. OpenLEADR will set all sampling rates to "
@@ -144,7 +151,7 @@ class ReportService(VTNService):
         # Form the report request
         oadr_report_requests = []
         for i, report_request in enumerate(report_requests):
-            if report_request is None or len(report_request) == 0:
+            if report_request is None or len(report_request) == 0 or all(rrq is None for rrq in report_request):
                 continue
 
             orig_report = payload['reports'][i]

openleadr/utils.py

@@ -647,7 +647,8 @@ def get_next_event_from_deque(deque):
     deque.extend(unused_elements)
     return event
 
-def validate_report_request_tuples(list_of_report_requests):
+
+def validate_report_request_tuples(list_of_report_requests, full_mode=False):
     if len(list_of_report_requests) == 0:
         return
     for report_requests in list_of_report_requests:
@@ -660,37 +661,69 @@ def validate_report_request_tuples(list_of_report_requests):
             # Check if it is a tuple
             elif not isinstance(rrq, tuple):
                 report_requests[i] = None
-                logger.error(f"Your on_register_report did not return a tuple. It returned '{rrq}'.")
+                if full_mode:
+                    logger.error("Your on_register_report handler did not return a list of tuples. "
+                                 f"The first item from the list was '{rrq}' ({rrq.__class__.__name__}).")
+                else:
+                    logger.error("Your on_register_report handler did not return a tuple. "
+                                 f"It returned '{rrq}'. Please see the documentation for the correct format.")
 
             # Check if it has the correct length
             elif not len(rrq) in (3, 4):
                 report_requests[i] = None
-                logger.error("Your on_register_report returned a tuple of the wrong length. "
-                             f"It should be 2 or 3. It returned '{rrq}'.")
+                if full_mode:
+                    logger.error("Your on_register_report handler returned tuples of the wrong length. "
+                                 f"It should be 3 or 4. It returned: '{rrq}'.")
+                else:
+                    logger.error("Your on_register_report handler returned a tuple of the wrong length. "
+                                 f"It should be 2 or 3. It returned: '{rrq[1:]}'.")
 
             # Check if the first element is callable
             elif not callable(rrq[1]):
                 report_requests[i] = None
-                logger.error(f"Your on_register_report did not return the correct tuple. "
-                             "It should return a (callback, sampling_interval) or "
-                             "(callback, sampling_interval, reporting_interval) tuple, where "
-                             "sampling_interval and reporting_interval are of type datetime.timedelta. "
-                             f"It returned: '{rrq}'. The first element was not callable.")
+                if full_mode:
+                    logger.error(f"Your on_register_report handler did not return the correct tuple. "
+                                 "It should return a list of (r_id, callback, sampling_interval) or "
+                                 "(r_id, callback, sampling_interval, reporting_interval) tuples, where "
+                                 "the r_id is a string, callback is a callable function or coroutine, and "
+                                 "sampling_interval and reporting_interval are of type datetime.timedelta. "
+                                 f"It returned: '{rrq}'. The second element was not callable.")
+                else:
+                    logger.error(f"Your on_register_report handler did not return the correct tuple. "
+                                 "It should return a (callback, sampling_interval) or "
+                                 "(callback, sampling_interval, reporting_interval) tuple, where "
+                                 "the callback is a callable function or coroutine, and "
+                                 "sampling_interval and reporting_interval are of type datetime.timedelta. "
+                                 f"It returned: '{rrq[1:]}'. The first element was not callable.")
 
             # Check if the second element is a timedelta
             elif not isinstance(rrq[2], timedelta):
                 report_requests[i] = None
-                logger.error(f"Your on_register_report did not return the correct tuple. "
-                             "It should return a (callback, sampling_interval) or "
-                             "(callback, sampling_interval, reporting_interval) tuple, where "
-                             "sampling_interval and reporting_interval are of type datetime.timedelta. "
-                             f"It returned: '{rrq}'. The second element was not of type timedelta.")
+                if full_mode:
+                    logger.error(f"Your on_register_report handler did not return the correct tuple. "
+                                 "It should return a list of (r_id, callback, sampling_interval) or "
+                                 "(r_id, callback, sampling_interval, reporting_interval) tuples, where "
+                                 "sampling_interval and reporting_interval are of type datetime.timedelta. "
+                                 f"It returned: '{rrq}'. The third element was not of type timedelta.")
+                else:
+                    logger.error(f"Your on_register_report handler did not return the correct tuple. "
+                                 "It should return a (callback, sampling_interval) or "
+                                 "(callback, sampling_interval, reporting_interval) tuple, where "
+                                 "sampling_interval and reporting_interval are of type datetime.timedelta. "
+                                 f"It returned: '{rrq[1:]}'. The second element was not of type timedelta.")
 
             # Check if the third element is a timedelta (if it exists)
             elif len(rrq) == 4 and not isinstance(rrq[3], timedelta):
                 report_requests[i] = None
-                logger.error(f"Your on_register_report did not return the correct tuple. "
-                             "It should return a (callback, sampling_interval) or "
-                             "(callback, sampling_interval, reporting_interval) tuple, where "
-                             "sampling_interval and reporting_interval are of type datetime.timedelta. "
-                             f"It returned: '{rrq}'. The third element was not of type timedelta.")
+                if full_mode:
+                    logger.error(f"Your on_register_report handler did not return the correct tuple. "
+                                 "It should return a list of (r_id, callback, sampling_interval) or "
+                                 "(r_id, callback, sampling_interval, reporting_interval) tuples, where "
+                                 "sampling_interval and reporting_interval are of type datetime.timedelta. "
+                                 f"It returned: '{rrq}'. The fourth element was not of type timedelta.")
+                else:
+                    logger.error(f"Your on_register_report handler did not return the correct tuple. "
+                                 "It should return a (callback, sampling_interval) or "
+                                 "(callback, sampling_interval, reporting_interval) tuple, where "
+                                 "sampling_interval and reporting_interval are of type datetime.timedelta. "
+                                 f"It returned: '{rrq[1:]}'. The third element was not of type timedelta.")

test/test_reports.py

@@ -508,7 +508,165 @@ def test_add_report_non_standard_measurement():
     assert client.reports[0].report_descriptions[0].measurement.description == 'rainbows'
 
 
-async def test_report_registration_broken_handlers(caplog):
+@pytest.mark.asyncio
+async def test_different_on_register_report_handlers(caplog):
+    def on_create_party_registration(registration_info):
+        return 'ven123', 'reg123'
+
+    def get_value():
+        return 123.456
+
+    def report_callback(data):
+        pass
+
+    def on_register_report_returning_none(ven_id, resource_id, measurement, unit, scale, min_sampling_interval, max_sampling_interval):
+        return None
+
+    def on_register_report_returning_string(ven_id, resource_id, measurement, unit, scale, min_sampling_interval, max_sampling_interval):
+        return "Hello There"
+
+    def on_register_report_returning_uncallable_first_element(ven_id, resource_id, measurement, unit, scale, min_sampling_interval, max_sampling_interval):
+        return ("Hello", "There")
+
+    def on_register_report_returning_non_datetime_second_element(ven_id, resource_id, measurement, unit, scale, min_sampling_interval, max_sampling_interval):
+        return (report_callback, "Hello There")
+
+    def on_register_report_returning_non_datetime_third_element(ven_id, resource_id, measurement, unit, scale, min_sampling_interval, max_sampling_interval):
+        return (report_callback, timedelta(minutes=10), "Hello There")
+
+    def on_register_report_returning_too_long_tuple(ven_id, resource_id, measurement, unit, scale, min_sampling_interval, max_sampling_interval):
+        return (report_callback, timedelta(minutes=10), timedelta(minutes=10), "Hello")
+
+    def on_register_report_full_returning_string(report):
+        return "Hello There"
+
+    def on_register_report_full_returning_list_of_strings(report):
+        return ["Hello", "There"]
+
+    def on_register_report_full_returning_list_of_tuples_of_wrong_length(report):
+        return [("Hello", "There")]
+
+    def on_register_report_full_returning_list_of_tuples_with_no_callable(report):
+        return [("Hello", "There", "World")]
+
+    def on_register_report_full_returning_list_of_tuples_with_no_timedelta(report):
+        return [(report_callback, "Hello There")]
+
+    server = OpenADRServer(vtn_id='myvtn')
+    server.add_handler('on_create_party_registration', on_create_party_registration)
+
+    client = OpenADRClient(ven_name='myven',
+                           vtn_url='http://localhost:8080/OpenADR2/Simple/2.0b')
+    client.add_report(resource_id='Device001',
+                      measurement='voltage',
+                      sampling_rate=timedelta(minutes=10),
+                      callback=get_value)
+
+    await server.run()
+    await client.create_party_registration()
+    assert client.ven_id == 'ven123'
+
+    await client.register_reports(client.reports)
+    assert len(client.report_requests) == 0
+    messages = [rec.message for rec in caplog.records if rec.levelno == logging.ERROR]
+    assert len(messages) == 0
+    caplog.clear()
+
+    server.add_handler('on_register_report', on_register_report_returning_none)
+    await client.register_reports(client.reports)
+    assert len(client.report_requests) == 0
+    messages = [rec.message for rec in caplog.records if rec.levelno == logging.ERROR]
+    assert len(messages) == 0
+    caplog.clear()
+
+    server.add_handler('on_register_report', on_register_report_returning_string)
+    await client.register_reports(client.reports)
+    assert len(client.report_requests) == 0
+    assert "Your on_register_report handler must return a tuple; it returned 'Hello There' (str)." in caplog.messages
+    caplog.clear()
+
+    server.add_handler('on_register_report', on_register_report_returning_uncallable_first_element)
+    await client.register_reports(client.reports)
+    assert len(client.report_requests) == 0
+    assert(f"Your on_register_report handler did not return the correct tuple. "
+           "It should return a (callback, sampling_interval) or "
+           "(callback, sampling_interval, reporting_interval) tuple, where "
+           "the callback is a callable function or coroutine, and "
+           "sampling_interval and reporting_interval are of type datetime.timedelta. "
+           "It returned: '('Hello', 'There')'. The first element was not callable.") in caplog.messages
+    caplog.clear()
+
+    server.add_handler('on_register_report', on_register_report_returning_non_datetime_second_element)
+    await client.register_reports(client.reports)
+    assert len(client.report_requests) == 0
+    assert (f"Your on_register_report handler did not return the correct tuple. "
+            "It should return a (callback, sampling_interval) or "
+            "(callback, sampling_interval, reporting_interval) tuple, where "
+            "sampling_interval and reporting_interval are of type datetime.timedelta. "
+            f"It returned: '{(report_callback, 'Hello There')}'. The second element was not of type timedelta.") in caplog.messages
+    caplog.clear()
+
+    server.add_handler('on_register_report', on_register_report_returning_non_datetime_third_element)
+    await client.register_reports(client.reports)
+    assert len(client.report_requests) == 0
+    assert ("Your on_register_report handler did not return the correct tuple. "
+            "It should return a (callback, sampling_interval) or "
+            "(callback, sampling_interval, reporting_interval) tuple, where "
+            "sampling_interval and reporting_interval are of type datetime.timedelta. "
+            f"It returned: '{(report_callback, timedelta(minutes=10), 'Hello There')}'. The third element was not of type timedelta.") in caplog.messages
+    caplog.clear()
+
+    server.add_handler('on_register_report', on_register_report_returning_too_long_tuple)
+    await client.register_reports(client.reports)
+    assert len(client.report_requests) == 0
+    assert ("Your on_register_report handler returned a tuple of the wrong length. "
+            "It should be 2 or 3. "
+            f"It returned: '{(report_callback, timedelta(minutes=10), timedelta(minutes=10), 'Hello')}'.") in caplog.messages
+    caplog.clear()
+
+    server.add_handler('on_register_report', on_register_report_full_returning_string)
+    await client.register_reports(client.reports)
+    assert len(client.report_requests) == 0
+    assert "Your on_register_report handler must return a list of tuples. It returned 'Hello There' (str)." in caplog.messages
+    caplog.clear()
+
+    server.add_handler('on_register_report', on_register_report_full_returning_list_of_strings)
+    await client.register_reports(client.reports)
+    assert len(client.report_requests) == 0
+    assert ("Your on_register_report handler did not return a list of tuples. "
+            f"The first item from the list was 'Hello' (str).") in caplog.messages
+    caplog.clear()
+
+    server.add_handler('on_register_report', on_register_report_full_returning_list_of_tuples_of_wrong_length)
+    await client.register_reports(client.reports)
+    assert len(client.report_requests) == 0
+    assert ("Your on_register_report handler returned tuples of the wrong length. "
+            "It should be 3 or 4. It returned: '('Hello', 'There')'.") in caplog.messages
+    caplog.clear()
+
+    server.add_handler('on_register_report', on_register_report_full_returning_list_of_tuples_with_no_callable)
+    await client.register_reports(client.reports)
+    assert len(client.report_requests) == 0
+    assert ("Your on_register_report handler did not return the correct tuple. "
+            "It should return a list of (r_id, callback, sampling_interval) or "
+            "(r_id, callback, sampling_interval, reporting_interval) tuples, "
+            "where the r_id is a string, callback is a callable function or "
+            "coroutine, and sampling_interval and reporting_interval are of "
+            "type datetime.timedelta. It returned: '('Hello', 'There', 'World')'. "
+            "The second element was not callable.") in caplog.messages
+    caplog.clear()
+
+    server.add_handler('on_register_report', on_register_report_full_returning_list_of_tuples_with_no_timedelta)
+    await client.register_reports(client.reports)
+    assert len(client.report_requests) == 0
+    assert ("Your on_register_report handler returned tuples of the wrong length. "
+            f"It should be 3 or 4. It returned: '({report_callback}, 'Hello There')'.") in caplog.messages
+    await server.stop()
+    await client.stop()
+
+
+@pytest.mark.asyncio
+async def test_report_registration_broken_handlers_raw_message(caplog):
     msg = """<?xml version="1.0" encoding="UTF-8" standalone="no" ?>
 <p1:oadrPayload xmlns:p1="http://openadr.org/oadr-2.0b/2012/07">
   <p1:oadrSignedObject>
@@ -630,6 +788,3 @@ async def test_report_registration_broken_handlers(caplog):
     assert f"Your on_register_report handler must return a list of tuples. It returned 'Hello There Again' (str)." in caplog.messages
 
     await server.stop()
-
-if __name__ == "__main__":
-    asyncio.run(test_update_reports())