From d4b540dd671d355150fe557aec22e308acee8825 Mon Sep 17 00:00:00 2001 From: Fabio Manganiello 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 | 21 ++++- 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, 163 insertions(+), 64 deletions(-) diff --git a/platypush/__init__.py b/platypush/__init__.py index c112d0f13e..dd58d98f04 100644 --- a/platypush/__init__.py +++ b/platypush/__init__.py @@ -216,10 +216,9 @@ class Daemon: ): self.stop_app() elif isinstance(msg, Response): - log.info('Received response: {}'.format(msg)) + msg.log() elif isinstance(msg, Event): - if not msg.disable_logging: - log.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 41caa37bd8..7c7a009fdb 100644 --- a/platypush/message/__init__.py +++ b/platypush/message/__init__.py @@ -75,8 +75,27 @@ class Message: ) ) - 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): """ diff --git a/platypush/message/event/__init__.py b/platypush/message/event/__init__.py index 7cb97bcb39..48c7757d6a 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 31186b451c..b5e52e1292 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 70992dc744..cc2e1438c0 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 662539b732..2654f5e2f4 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 7b895fdf33..5ddf2cfb68 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 acb44d1a72..6cc3beea86 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: