From 2ee2a1d7b58799a8ccb8e33980fdf4ac4c997a46 Mon Sep 17 00:00:00 2001
From: Fabio Manganiello <fabio@manganiello.tech>
Date: Sun, 11 Dec 2022 11:39:38 +0100
Subject: [PATCH] Replaced `disable_logging` with a more generic
 `logging_level`.

The `disable_logging` attribute was only available on events and
responses, and it could only either entirely disable or enable logging
for all the events of a certain type.

The new flag allows more customization by setting the default logging
level used for any message of a certain type (or `None` to disable
logging). This makes it possible to e.g. set some verbose events to
debug level, and the user can see them if they configure the application
in debug mode.

It also delegates the logging logic to the message itself, instead of
having different parts of the application handling their own logic.
---
 platypush/__init__.py                  |   5 +-
 platypush/message/__init__.py          |  51 ++++++++----
 platypush/message/event/__init__.py    |  16 ++--
 platypush/message/event/camera.py      |  16 ++--
 platypush/message/event/distance.py    |  13 +++-
 platypush/message/event/zwave.py       | 104 ++++++++++++++++++-------
 platypush/message/request/__init__.py  |   9 +--
 platypush/message/response/__init__.py |  43 ++++++----
 8 files changed, 180 insertions(+), 77 deletions(-)

diff --git a/platypush/__init__.py b/platypush/__init__.py
index 78ffb1b3c..831842710 100644
--- a/platypush/__init__.py
+++ b/platypush/__init__.py
@@ -213,10 +213,9 @@ class Daemon:
                 ):
                     self.stop_app()
             elif isinstance(msg, Response):
-                logger.info('Received response: {}'.format(msg))
+                msg.log()
             elif isinstance(msg, Event):
-                if not msg.disable_logging:
-                    logger.info('Received event: {}'.format(msg))
+                msg.log()
                 self.event_processor.process_event(msg)
 
         return _f
diff --git a/platypush/message/__init__.py b/platypush/message/__init__.py
index c32f65b0d..ae8b50c55 100644
--- a/platypush/message/__init__.py
+++ b/platypush/message/__init__.py
@@ -19,7 +19,7 @@ class JSONAble(ABC):
         raise NotImplementedError()
 
 
-class Message(object):
+class Message:
     """
     Message generic class
     """
@@ -45,9 +45,7 @@ class Message(object):
 
         @staticmethod
         def parse_datetime(obj):
-            if isinstance(obj, datetime.datetime) or \
-                    isinstance(obj, datetime.date) or \
-                    isinstance(obj, datetime.time):
+            if isinstance(obj, (datetime.datetime, datetime.date, datetime.time)):
                 return obj.isoformat()
 
         def default(self, obj):
@@ -68,11 +66,33 @@ class Message(object):
             try:
                 return super().default(obj)
             except Exception as e:
-                logger.warning('Could not serialize object type {}: {}: {}'.format(
-                    type(obj), str(e), obj))
+                logger.warning(
+                    'Could not serialize object type {}: {}: {}'.format(
+                        type(obj), str(e), obj
+                    )
+                )
 
-    def __init__(self, timestamp=None, *_, **__):
+    def __init__(self, *_, timestamp=None, logging_level=logging.INFO, **__):
         self.timestamp = timestamp or time.time()
+        self.logging_level = logging_level
+
+    def log(self, prefix=''):
+        if self.logging_level is None:
+            return  # Skip logging
+
+        log_func = logger.info
+        if self.logging_level == logging.DEBUG:
+            log_func = logger.debug
+        elif self.logging_level == logging.WARNING:
+            log_func = logger.warning
+        elif self.logging_level == logging.ERROR:
+            log_func = logger.error
+        elif self.logging_level == logging.FATAL:
+            log_func = logger.fatal
+
+        if not prefix:
+            prefix = f'Received {self.__class__.__name__}: '
+        log_func(f'{prefix}{self}')
 
     def __str__(self):
         """
@@ -80,12 +100,15 @@ class Message(object):
         the message into a UTF-8 JSON string
         """
 
-        return json.dumps({
-            attr: getattr(self, attr)
-            for attr in self.__dir__()
-            if (attr != '_timestamp' or not attr.startswith('_'))
-            and not inspect.ismethod(getattr(self, attr))
-        }, cls=self.Encoder).replace('\n', ' ')
+        return json.dumps(
+            {
+                attr: getattr(self, attr)
+                for attr in self.__dir__()
+                if (attr != '_timestamp' or not attr.startswith('_'))
+                and not inspect.ismethod(getattr(self, attr))
+            },
+            cls=self.Encoder,
+        ).replace('\n', ' ')
 
     def __bytes__(self):
         """
@@ -105,7 +128,7 @@ class Message(object):
 
         if isinstance(msg, cls):
             msg = str(msg)
-        if isinstance(msg, bytes) or isinstance(msg, bytearray):
+        if isinstance(msg, (bytes, bytearray)):
             msg = msg.decode('utf-8')
         if isinstance(msg, str):
             try:
diff --git a/platypush/message/event/__init__.py b/platypush/message/event/__init__.py
index 7cb97bcb3..48c7757d6 100644
--- a/platypush/message/event/__init__.py
+++ b/platypush/message/event/__init__.py
@@ -1,5 +1,6 @@
 import copy
 import json
+import logging
 import random
 import re
 import sys
@@ -11,6 +12,8 @@ from platypush.config import Config
 from platypush.message import Message
 from platypush.utils import get_event_class_by_type
 
+logger = logging.getLogger('platypush')
+
 
 class Event(Message):
     """Event message class"""
@@ -26,7 +29,7 @@ class Event(Message):
         origin=None,
         id=None,
         timestamp=None,
-        disable_logging=False,
+        logging_level=logging.INFO,
         disable_web_clients_notification=False,
         **kwargs
     ):
@@ -36,15 +39,16 @@ class Event(Message):
             origin  -- Origin node (default: current node) [String]
             id      -- Event ID (default: auto-generated)
             kwargs  -- Additional arguments for the event [kwDict]
+            logging_level -- Logging level that should be applied to these
+                events (default: INFO).
         """
 
-        super().__init__(timestamp=timestamp)
+        super().__init__(timestamp=timestamp, logging_level=logging_level)
         self.id = id if id else self._generate_id()
         self.target = target if target else Config.get('device_id')
         self.origin = origin if origin else Config.get('device_id')
         self.type = '{}.{}'.format(self.__class__.__module__, self.__class__.__name__)
         self.args = kwargs
-        self.disable_logging = disable_logging
         self.disable_web_clients_notification = disable_web_clients_notification
 
         for arg, value in self.args.items():
@@ -55,7 +59,7 @@ class Event(Message):
                 'target',
                 'type',
                 'timestamp',
-                'disable_logging',
+                'logging_level',
             ] and not arg.startswith('_'):
                 self.__setattr__(arg, value)
 
@@ -152,7 +156,7 @@ class Event(Message):
                 result.score += 1.5
             elif re.search(condition_token, event_token):
                 m = re.search('({})'.format(condition_token), event_token)
-                if m.group(1):
+                if m and m.group(1):
                     event_tokens.pop(0)
                     result.score += 1.25
 
@@ -214,7 +218,7 @@ class EventMatchResult:
     the match is - in case of multiple event matches, the ones with the
     highest score will win"""
 
-    def __init__(self, is_match, score=0, parsed_args=None):
+    def __init__(self, is_match, score=0.0, parsed_args=None):
         self.is_match = is_match
         self.score = score
         self.parsed_args = parsed_args or {}
diff --git a/platypush/message/event/camera.py b/platypush/message/event/camera.py
index 31186b451..b5e52e129 100644
--- a/platypush/message/event/camera.py
+++ b/platypush/message/event/camera.py
@@ -1,8 +1,10 @@
+import logging
+
 from platypush.message.event import Event
 
 
 class CameraEvent(Event):
-    """ Base class for camera events """
+    """Base class for camera events"""
 
     def __init__(self, *args, **kwargs):
         super().__init__(*args, **kwargs)
@@ -49,13 +51,13 @@ class CameraFrameCapturedEvent(CameraEvent):
     Event triggered when a camera frame has been captured
     """
 
-    disable_logging = True
-
     def __init__(self, filename=None, *args, **kwargs):
-        super().__init__(*args, filename=filename,
-                         disable_logging=kwargs.pop('disable_logging')
-                         if 'disable_logging' in kwargs else self.disable_logging,
-                         **kwargs)
+        super().__init__(
+            *args,
+            filename=filename,
+            logging_level=kwargs.pop('logging_level', logging.DEBUG),
+            **kwargs
+        )
 
 
 # vim:sw=4:ts=4:et:
diff --git a/platypush/message/event/distance.py b/platypush/message/event/distance.py
index 70992dc74..cc2e1438c 100644
--- a/platypush/message/event/distance.py
+++ b/platypush/message/event/distance.py
@@ -1,3 +1,5 @@
+import logging
+
 from platypush.message.event import Event
 
 
@@ -5,9 +7,16 @@ class DistanceSensorEvent(Event):
     """
     Event triggered when a new value is processed by a distance sensor.
     """
+
     def __init__(self, distance: float, unit: str = 'mm', *args, **kwargs):
-        super().__init__(*args, distance=distance, unit=unit, disable_logging=True,
-                         disable_web_clients_notification=True, **kwargs)
+        super().__init__(
+            *args,
+            distance=distance,
+            unit=unit,
+            logging_level=logging.DEBUG,
+            disable_web_clients_notification=True,
+            **kwargs
+        )
 
 
 # vim:sw=4:ts=4:et:
diff --git a/platypush/message/event/zwave.py b/platypush/message/event/zwave.py
index 662539b73..2654f5e2f 100644
--- a/platypush/message/event/zwave.py
+++ b/platypush/message/event/zwave.py
@@ -1,3 +1,4 @@
+import logging
 from typing import Optional, Dict, Any
 
 from platypush.message.event import Event
@@ -12,32 +13,39 @@ class ZwaveNetworkReadyEvent(ZwaveEvent):
     """
     Triggered when the network started on a Z-Wave adapter becomes ready.
     """
-    def __init__(self,
-                 ozw_library_version: str,
-                 python_library_version: str,
-                 zwave_library: str,
-                 node_id: int,
-                 node_version: str,
-                 home_id: int,
-                 nodes_count: int,
-                 device: Optional[str] = None,
-                 *args, **kwargs):
-        super().__init__(*args,
-                         device=device,
-                         ozw_library_version=ozw_library_version,
-                         python_library_version=python_library_version,
-                         zwave_library=zwave_library,
-                         home_id=home_id,
-                         node_id=node_id,
-                         node_version=node_version,
-                         nodes_count=nodes_count,
-                         **kwargs)
+
+    def __init__(
+        self,
+        ozw_library_version: str,
+        python_library_version: str,
+        zwave_library: str,
+        node_id: int,
+        node_version: str,
+        home_id: int,
+        nodes_count: int,
+        device: Optional[str] = None,
+        *args,
+        **kwargs
+    ):
+        super().__init__(
+            *args,
+            device=device,
+            ozw_library_version=ozw_library_version,
+            python_library_version=python_library_version,
+            zwave_library=zwave_library,
+            home_id=home_id,
+            node_id=node_id,
+            node_version=node_version,
+            nodes_count=nodes_count,
+            **kwargs
+        )
 
 
 class ZwaveNetworkStoppedEvent(ZwaveEvent):
     """
     Triggered when a Z-Wave network is stopped.
     """
+
     pass
 
 
@@ -45,6 +53,7 @@ class ZwaveNetworkErrorEvent(ZwaveEvent):
     """
     Triggered when an error occurs on the Z-Wave network.
     """
+
     pass
 
 
@@ -52,6 +61,7 @@ class ZwaveNetworkResetEvent(ZwaveEvent):
     """
     Triggered when a Z-Wave network is reset.
     """
+
     pass
 
 
@@ -59,6 +69,7 @@ class ZwaveNodeEvent(ZwaveEvent):
     """
     Generic Z-Wave node event class.
     """
+
     def __init__(self, node: Dict[str, Any], *args, **kwargs):
         super().__init__(*args, node=node, **kwargs)
 
@@ -67,6 +78,7 @@ class ZwaveNodeAddedEvent(ZwaveNodeEvent):
     """
     Triggered when a node is added to the network.
     """
+
     pass
 
 
@@ -74,6 +86,7 @@ class ZwaveNodeRemovedEvent(ZwaveNodeEvent):
     """
     Triggered when a node is removed from the network.
     """
+
     pass
 
 
@@ -81,6 +94,7 @@ class ZwaveNodeRenamedEvent(ZwaveNodeEvent):
     """
     Triggered when a node is renamed.
     """
+
     pass
 
 
@@ -88,6 +102,7 @@ class ZwaveNodeReadyEvent(ZwaveNodeEvent):
     """
     Triggered when a node is ready.
     """
+
     pass
 
 
@@ -95,6 +110,7 @@ class ZwaveNodeAsleepEvent(ZwaveNodeEvent):
     """
     Triggered when a node goes in sleep mode.
     """
+
     pass
 
 
@@ -102,6 +118,7 @@ class ZwaveNodeAwakeEvent(ZwaveNodeEvent):
     """
     Triggered when a node goes back into awake mode.
     """
+
     pass
 
 
@@ -109,8 +126,11 @@ class ZwaveNodeGroupEvent(ZwaveNodeEvent):
     """
     Triggered when a node is associated/de-associated to a group.
     """
+
     def __init__(self, group_index: Optional[int] = None, *args, **kwargs):
-        kwargs['disable_logging'] = True
+        # ZwaveNodeGroupEvent can be quite verbose, so we only report them if
+        # debug logging is enabled
+        kwargs['logging_level'] = logging.DEBUG
         super().__init__(*args, group_index=group_index, **kwargs)
 
 
@@ -118,6 +138,7 @@ class ZwaveNodeSceneEvent(ZwaveNodeEvent):
     """
     Triggered when a scene is activated on a node.
     """
+
     def __init__(self, scene_id: int, *args, **kwargs):
         super().__init__(*args, scene_id=scene_id, **kwargs)
 
@@ -126,6 +147,7 @@ class ZwaveNodePollingEnabledEvent(ZwaveNodeEvent):
     """
     Triggered when the polling of a node is successfully turned on.
     """
+
     pass
 
 
@@ -133,6 +155,7 @@ class ZwaveNodePollingDisabledEvent(ZwaveNodeEvent):
     """
     Triggered when the polling of a node is successfully turned off.
     """
+
     pass
 
 
@@ -140,6 +163,7 @@ class ZwaveButtonCreatedEvent(ZwaveNodeEvent):
     """
     Triggered when a button is added to the network.
     """
+
     pass
 
 
@@ -147,6 +171,7 @@ class ZwaveButtonRemovedEvent(ZwaveNodeEvent):
     """
     Triggered when a button is removed from the network.
     """
+
     pass
 
 
@@ -154,6 +179,7 @@ class ZwaveButtonOnEvent(ZwaveNodeEvent):
     """
     Triggered when a button is pressed.
     """
+
     pass
 
 
@@ -161,6 +187,7 @@ class ZwaveButtonOffEvent(ZwaveNodeEvent):
     """
     Triggered when a button is released.
     """
+
     pass
 
 
@@ -168,8 +195,11 @@ class ZwaveValueEvent(ZwaveEvent):
     """
     Abstract class for Z-Wave value events.
     """
+
     def __init__(self, node: Dict[str, Any], value: Dict[str, Any], *args, **kwargs):
-        kwargs['disable_logging'] = True
+        # ZwaveValueEvent can be quite verbose, so we only report them if debug
+        # logging is enabled
+        kwargs['logging_level'] = logging.DEBUG
         super().__init__(*args, node=node, value=value, **kwargs)
 
 
@@ -177,6 +207,7 @@ class ZwaveValueAddedEvent(ZwaveValueEvent):
     """
     Triggered when a value is added to a node on the network.
     """
+
     pass
 
 
@@ -184,6 +215,7 @@ class ZwaveValueChangedEvent(ZwaveValueEvent):
     """
     Triggered when a value of a node on the network changes.
     """
+
     pass
 
 
@@ -191,6 +223,7 @@ class ZwaveValueRefreshedEvent(ZwaveValueEvent):
     """
     Triggered when a value of a node on the network is refreshed.
     """
+
     pass
 
 
@@ -198,6 +231,7 @@ class ZwaveValueRemovedEvent(ZwaveValueEvent):
     """
     Triggered when a value of a node on the network is removed.
     """
+
     pass
 
 
@@ -205,6 +239,7 @@ class ZwaveNodeQueryCompletedEvent(ZwaveEvent):
     """
     Triggered when all the nodes on the network have been queried.
     """
+
     pass
 
 
@@ -212,16 +247,33 @@ class ZwaveCommandEvent(ZwaveEvent):
     """
     Triggered when a command is received on the network.
     """
-    def __init__(self, state: str, state_description: str, error: Optional[str] = None,
-                 error_description: Optional[str] = None, node: Optional[Dict[str, Any]] = None, *args, **kwargs):
-        super().__init__(*args, state=state, state_description=state_description,
-                         error=error, error_description=error_description, node=node, **kwargs)
+
+    def __init__(
+        self,
+        state: str,
+        state_description: str,
+        error: Optional[str] = None,
+        error_description: Optional[str] = None,
+        node: Optional[Dict[str, Any]] = None,
+        *args,
+        **kwargs
+    ):
+        super().__init__(
+            *args,
+            state=state,
+            state_description=state_description,
+            error=error,
+            error_description=error_description,
+            node=node,
+            **kwargs
+        )
 
 
 class ZwaveCommandWaitingEvent(ZwaveCommandEvent):
     """
     Triggered when a command is waiting for a message to proceed.
     """
+
     pass
 
 
diff --git a/platypush/message/request/__init__.py b/platypush/message/request/__init__.py
index 7b895fdf3..5ddf2cfb6 100644
--- a/platypush/message/request/__init__.py
+++ b/platypush/message/request/__init__.py
@@ -254,6 +254,7 @@ class Request(Message):
                         action
                     )
                     plugin = get_plugin(module_name)
+                    assert plugin, f'No such plugin: {module_name}'
             except Exception as e:
                 logger.exception(e)
                 msg = 'Uncaught pre-processing exception from action [{}]: {}'.format(
@@ -286,12 +287,8 @@ class Request(Message):
                                 'Response processed with errors from ' + 'action {}: {}'
                             ).format(action, str(response))
                         )
-                    elif not response.disable_logging:
-                        logger.info(
-                            'Processed response from action {}: {}'.format(
-                                action, str(response)
-                            )
-                        )
+                    else:
+                        response.log(action)
             except (AssertionError, TimeoutError) as e:
                 logger.warning(
                     '%s from action [%s]: %s', e.__class__.__name__, action, str(e)
diff --git a/platypush/message/response/__init__.py b/platypush/message/response/__init__.py
index acb44d1a7..6cc3beea8 100644
--- a/platypush/message/response/__init__.py
+++ b/platypush/message/response/__init__.py
@@ -1,14 +1,23 @@
 import json
+import logging
 import time
 
 from platypush.message import Message
 
 
 class Response(Message):
-    """ Response message class """
+    """Response message class"""
 
-    def __init__(self, target=None, origin=None, id=None, output=None, errors=None,
-                 timestamp=None, disable_logging=False):
+    def __init__(
+        self,
+        target=None,
+        origin=None,
+        id=None,
+        output=None,
+        errors=None,
+        timestamp=None,
+        logging_level=logging.INFO,
+    ):
         """
         :param target: Target
         :type target: str
@@ -22,21 +31,20 @@ class Response(Message):
         :type timestamp: float
         """
 
-        super().__init__(timestamp=timestamp)
+        super().__init__(timestamp=timestamp, logging_level=logging_level)
         self.target = target
         self.output = self._parse_msg(output)
         self.errors = self._parse_msg(errors or [])
         self.origin = origin
         self.id = id
-        self.disable_logging = disable_logging
 
     def is_error(self):
-        """ Returns True if the response has errors """
+        """Returns True if the response has errors"""
         return len(self.errors) != 0
 
     @classmethod
     def _parse_msg(cls, msg):
-        if isinstance(msg, bytes) or isinstance(msg, bytearray):
+        if isinstance(msg, (bytes, bytearray)):
             msg = msg.decode('utf-8')
         if isinstance(msg, str):
             try:
@@ -54,7 +62,7 @@ class Response(Message):
             'output': msg['response']['output'],
             'errors': msg['response']['errors'],
             'timestamp': msg['_timestamp'] if '_timestamp' in msg else time.time(),
-            'disable_logging': msg.get('_disable_logging', False),
+            'logging_level': msg.get('_logging_level', logging.INFO),
         }
 
         if 'id' in msg:
@@ -69,9 +77,9 @@ class Response(Message):
         Overrides the ``str()`` operator and converts
         the message into a UTF-8 JSON string
         """
-        output = self.output if self.output is not None else {
-            'success': True if not self.errors else False
-        }
+        output = (
+            self.output if self.output is not None else {'success': bool(self.errors)}
+        )
 
         response_dict = {
             'id': self.id,
@@ -85,10 +93,19 @@ class Response(Message):
             },
         }
 
-        if self.disable_logging:
-            response_dict['_disable_logging'] = self.disable_logging
+        if self.logging_level:
+            response_dict['_logging_level'] = self.logging_level
 
         return json.dumps(response_dict, cls=self.Encoder)
 
+    def log(self, action=None):
+        prefix = (
+            f'Processed response from action {action}: '
+            if action
+            else 'Received response: '
+        )
+
+        super().log(prefix)
+
 
 # vim:sw=4:ts=4:et: