diff --git a/platypush/app/_app.py b/platypush/app/_app.py index 9bcffdba03..4f16e69c29 100644 --- a/platypush/app/_app.py +++ b/platypush/app/_app.py @@ -365,7 +365,13 @@ class Application: elif isinstance(msg, Response): msg.log() elif isinstance(msg, Event): - msg.log() + log.info( + 'Received event: %s.%s[id=%s]', + msg.__class__.__module__, + msg.__class__.__name__, + msg.id, + ) + msg.log(level=logging.DEBUG) self.event_processor.process_event(msg) return _f diff --git a/platypush/message/__init__.py b/platypush/message/__init__.py index 65106da2b4..69c9673f71 100644 --- a/platypush/message/__init__.py +++ b/platypush/message/__init__.py @@ -8,7 +8,7 @@ import logging import inspect import json import time -from typing import Union +from typing import Optional, Union from uuid import UUID _logger = logging.getLogger('platypush') @@ -114,18 +114,19 @@ class Message: self._logger = _logger self._default_log_prefix = '' - def log(self, prefix=''): + def log(self, level: Optional[int] = None, prefix=''): if self.logging_level is None: return # Skip logging log_func = self._logger.info - if self.logging_level == logging.DEBUG: + level = level if level is not None else self.logging_level + if level == logging.DEBUG: log_func = self._logger.debug - elif self.logging_level == logging.WARNING: + elif level == logging.WARNING: log_func = self._logger.warning - elif self.logging_level == logging.ERROR: + elif level == logging.ERROR: log_func = self._logger.error - elif self.logging_level == logging.FATAL: + elif level == logging.FATAL: log_func = self._logger.fatal if not prefix: diff --git a/platypush/message/request/__init__.py b/platypush/message/request/__init__.py index 9e4c20db25..7a55e65429 100644 --- a/platypush/message/request/__init__.py +++ b/platypush/message/request/__init__.py @@ -165,6 +165,11 @@ class Request(Message): context_value = [*context_value] if isinstance(context_value, datetime.date): context_value = context_value.isoformat() + except NameError as e: + logger.warning( + 'Could not expand expression "%s": %s', inner_expr, e + ) + context_value = expr except Exception as e: logger.exception(e) context_value = expr @@ -188,7 +193,13 @@ class Request(Message): response.id = self.id response.target = self.origin response.origin = Config.get('device_id') - response.log() + self._logger.info( + 'Sending response to request[id=%s, action=%s], response_time=%.02fs', + self.id, + self.action, + response.timestamp - self.timestamp, + ) + response.log(level=logging.DEBUG) if self.backend and self.origin: self.backend.send_response(response=response, request=self) @@ -221,7 +232,10 @@ class Request(Message): from platypush.plugins import RunnablePlugin response = None - self.log() + self._logger.info( + 'Executing request[id=%s, action=%s]', self.id, self.action + ) + self.log(level=logging.DEBUG) try: if self.action.startswith('procedure.'): diff --git a/platypush/message/response/__init__.py b/platypush/message/response/__init__.py index f1db626e24..2a16a1cb5d 100644 --- a/platypush/message/response/__init__.py +++ b/platypush/message/response/__init__.py @@ -1,6 +1,7 @@ import json import logging import time +from typing import Optional from platypush.message import Message @@ -99,8 +100,11 @@ class Response(Message): return json.dumps(response_dict, cls=self.Encoder) - def log(self, *args, **kwargs): - self.logging_level = logging.WARNING if self.is_error() else logging.INFO + def log(self, *args, level: Optional[int] = None, **kwargs): + if level is None: + level = logging.WARNING if self.is_error() else logging.INFO + + kwargs['level'] = level super().log(*args, **kwargs)