Add action exception handler

opwen_email_server/actions.py

@@ -1,3 +1,4 @@
+from abc import ABC
 from typing import Callable
 from typing import Iterable
 from typing import Tuple
@@ -21,20 +22,34 @@
 Response = Union[dict, Tuple[str, int]]
 
 
-class Ping(object):
-    def __call__(self) -> Response:
+class _Action(ABC, LogMixin):
+    def __call__(self, *args, **kwargs) -> Response:
+        try:
+            return self._action(*args, **kwargs)
+        except Exception as ex:
+            self.log_exception(ex, 'error in action %s',
+                               self.__class__.__name__)
+            raise ex
+
+    def _action(self, *args, **kwargs) -> Response:
+        raise NotImplementedError
+
+
+class Ping(_Action):
+    # noinspection PyMethodMayBeStatic
+    def _action(self):  # type: ignore
         return 'OK', 200
 
 
-class SendOutboundEmails(LogMixin):
+class SendOutboundEmails(_Action):
     def __init__(self,
                  email_storage: AzureObjectStorage,
                  send_email: SendSendgridEmail):
 
         self._email_storage = email_storage
         self._send_email = send_email
 
-    def __call__(self, resource_id: str) -> Response:
+    def _action(self, resource_id):  # type: ignore
         email = self._email_storage.fetch_object(resource_id)
 
         success = self._send_email(email)
@@ -45,7 +60,7 @@ def __call__(self, resource_id: str) -> Response:
         return 'OK', 200
 
 
-class StoreInboundEmails(LogMixin):
+class StoreInboundEmails(_Action):
     def __init__(self,
                  raw_email_storage: AzureTextStorage,
                  email_storage: AzureObjectStorage,
@@ -57,7 +72,7 @@ def __init__(self,
         self._pending_factory = pending_factory
         self._email_parser = email_parser or self._parse_mime_email
 
-    def __call__(self, resource_id: str) -> Response:
+    def _action(self, resource_id):  # type: ignore
         mime_email = self._raw_email_storage.fetch_text(resource_id)
 
         email = self._email_parser(mime_email)
@@ -85,7 +100,7 @@ def _parse_mime_email(cls, mime_email: str) -> dict:
         return email
 
 
-class StoreWrittenClientEmails(LogMixin):
+class StoreWrittenClientEmails(_Action):
     def __init__(self,
                  client_storage: AzureObjectsStorage,
                  email_storage: AzureObjectStorage,
@@ -95,7 +110,7 @@ def __init__(self,
         self._email_storage = email_storage
         self._next_task = next_task
 
-    def __call__(self, resource_id: str) -> Response:
+    def _action(self, resource_id):  # type: ignore
         emails = self._client_storage.fetch_objects(
             resource_id, sync.EMAILS_FILE)
 
@@ -116,7 +131,7 @@ def __call__(self, resource_id: str) -> Response:
         return 'OK', 200
 
 
-class ReceiveInboundEmail(LogMixin):
+class ReceiveInboundEmail(_Action):
     def __init__(self,
                  auth: AzureAuth,
                  raw_email_storage: AzureTextStorage,
@@ -128,7 +143,7 @@ def __init__(self,
         self._next_task = next_task
         self._email_id_source = email_id_source or self._new_email_id
 
-    def __call__(self, client_id: str, email: str) -> Response:
+    def _action(self, client_id, email):  # type: ignore
         domain = self._auth.domain_for(client_id)
         if not domain:
             self.log_event(events.UNREGISTERED_CLIENT, {'client_id': client_id})  # noqa: E501
@@ -148,7 +163,7 @@ def _new_email_id(cls) -> str:
         return str(uuid4())
 
 
-class DownloadClientEmails(LogMixin):
+class DownloadClientEmails(_Action):
     def __init__(self,
                  auth: AzureAuth,
                  client_storage: AzureObjectsStorage,
@@ -160,7 +175,7 @@ def __init__(self,
         self._email_storage = email_storage
         self._pending_factory = pending_factory
 
-    def __call__(self, client_id: str, compression: str) -> Response:
+    def _action(self, client_id, compression):  # type: ignore
         domain = self._auth.domain_for(client_id)
         if not domain:
             self.log_event(events.UNREGISTERED_CLIENT, {'client_id': client_id})  # noqa: E501
@@ -202,15 +217,15 @@ def _mark_emails_as_delivered(cls, pending_storage: AzureTextStorage,
             pending_storage.delete(email_id)
 
 
-class UploadClientEmails(LogMixin):
+class UploadClientEmails(_Action):
     def __init__(self,
                  auth: AzureAuth,
                  next_task: Callable[[str], None]):
 
         self._auth = auth
         self._next_task = next_task
 
-    def __call__(self, client_id: str, upload_info: dict) -> Response:
+    def _action(self, client_id, upload_info):  # type: ignore
         domain = self._auth.domain_for(client_id)
         if not domain:
             self.log_event(events.UNREGISTERED_CLIENT, {'client_id': client_id})  # noqa: E501
@@ -224,7 +239,7 @@ def __call__(self, client_id: str, upload_info: dict) -> Response:
         return 'uploaded', 200
 
 
-class RegisterClient(LogMixin):
+class RegisterClient(_Action):
     def __init__(self,
                  auth: AzureAuth,
                  client_storage: AzureObjectsStorage,
@@ -238,7 +253,7 @@ def __init__(self,
         self._setup_mx_records = setup_mx_records
         self._client_id_source = client_id_source or self._new_client_id
 
-    def __call__(self, client: dict) -> Response:
+    def _action(self, client):  # type: ignore
         domain = client['domain']
         if self._auth.client_id_for(domain) is not None:
             return 'client already exists', 409

opwen_email_server/integration/wsgi.py

@@ -1,13 +1,8 @@
 #!/usr/bin/env python3
 
-from applicationinsights.flask.ext import AppInsights
-from applicationinsights.flask.ext import CONF_KEY
 from connexion import App
-from connexion.apps.flask_app import flask
 
-from opwen_email_server.config import APPINSIGHTS_KEY
 from opwen_email_server.utils.imports import can_import
-from opwen_email_server.utils.log import LogMixin
 
 _servers = list(filter(can_import, ('tornado', 'gevent', 'flask')))
 _hosts = ['127.0.0.1', '0.0.0.0']  # nosec
@@ -18,21 +13,10 @@
 _ui = False
 
 
-def _get_flask(app: App) -> flask.Flask:
-    return app.app
-
-
 def build_app(apis, host=_host, port=_port, server=_server, ui=_ui):
     app = App(__name__, host=host, port=port, server=server,
               options={'swagger_ui': ui})
 
-    flask_app = _get_flask(app)
-    flask_app.config[CONF_KEY] = APPINSIGHTS_KEY
-    appinsights = AppInsights(flask_app)
-
-    # noinspection PyProtectedMember
-    LogMixin.inject(flask_app.logger, appinsights._channel)
-
     for api in apis:
         app.add_api(api)
 

opwen_email_server/services/sendgrid.py

@@ -47,14 +47,14 @@ def _send_email(self, email: Mail, email_id: str) -> bool:
         request = email.get()
         try:
             status = self._client(request)
-        except HTTPError as exception:
-            status = exception.code
-            self.log_exception('error sending email %s:%r:%r',
-                               email_id, exception, request)
-        except URLError as exception:
+        except HTTPError as ex:
+            status = ex.code
+            self.log_exception(ex, 'error sending email %s:%r',
+                               email_id, request)
+        except URLError as ex:
             status = -1
-            self.log_exception('error sending email %s:%r:%r',
-                               email_id, exception, request)
+            self.log_exception(ex, 'error sending email %s:%r',
+                               email_id, request)
         else:
             self.log_debug('sent email %s', email_id)
 

opwen_email_server/utils/collections.py

@@ -24,3 +24,9 @@ def chunks(iterable: Iterable[T], chunk_size: int) -> Iterable[Iterable[T]]:
 
 def singleton(func: Callable) -> Callable:
     return lru_cache(maxsize=1)(func)
+
+
+def append(iterable: Iterable[T], next_item: T) -> Iterable[T]:
+    for item in iterable:
+        yield item
+    yield next_item

opwen_email_server/utils/log.py

@@ -8,7 +8,6 @@
 from typing import Optional
 
 from applicationinsights import TelemetryClient
-from applicationinsights.channel import TelemetryChannel
 from applicationinsights.logging import LoggingHandler
 from cached_property import cached_property
 
@@ -18,18 +17,10 @@
 from opwen_email_server.constants.logging import STDERR
 from opwen_email_server.constants.logging import TELEMETRY_QUEUE_ITEMS
 from opwen_email_server.constants.logging import TELEMETRY_QUEUE_SECONDS
+from opwen_email_server.utils.collections import append
 
 
 class LogMixin(object):
-    __logger = None  # type: Optional[Logger]
-    __telemetry_channel = None  # type: Optional[TelemetryChannel]
-
-    @classmethod
-    def inject(cls, logger: Logger, channel: TelemetryChannel):
-        logger.setLevel(LOG_LEVEL)
-        cls.__logger = logger
-        cls.__telemetry_channel = channel
-
     @classmethod
     def _default_log_handlers(cls) -> Iterable[Handler]:
         handlers = []
@@ -44,10 +35,10 @@ def _default_log_handlers(cls) -> Iterable[Handler]:
 
         return handlers
 
-    @classmethod
-    def _default_logger(cls) -> Logger:
+    @cached_property
+    def _logger(self) -> Logger:
         log = getLogger()
-        for handler in cls._default_log_handlers():
+        for handler in self._default_log_handlers():
             log.addHandler(handler)
         log.setLevel(LOG_LEVEL)
         return log
@@ -57,19 +48,14 @@ def _telemetry_client(self) -> Optional[TelemetryClient]:
         if not APPINSIGHTS_KEY:
             return None
 
-        telemetry_client = TelemetryClient(
-            APPINSIGHTS_KEY, self.__telemetry_channel)
+        telemetry_client = TelemetryClient(APPINSIGHTS_KEY)
         telemetry_client.channel.sender.send_interval_in_milliseconds = \
             TELEMETRY_QUEUE_SECONDS * 1000
         telemetry_client.channel.sender.max_queue_item_count = \
             TELEMETRY_QUEUE_ITEMS
 
         return telemetry_client
 
-    @cached_property
-    def _logger(self) -> Logger:
-        return self.__logger or self._default_logger()
-
     def log_debug(self, message: str, *args: Any):
         self._log('debug', message, args)
 
@@ -79,8 +65,15 @@ def log_info(self, message: str, *args: Any):
     def log_warning(self, message: str, *args: Any):
         self._log('warning', message, args)
 
-    def log_exception(self, message: str, *args: Any):
-        self._log('exception', message, args)
+    def log_exception(self, ex: Exception, message: str, *args: Any):
+        self._log('exception', message + ' (%r)', append(args, ex))
+
+        if self._telemetry_client:
+            # noinspection PyBroadException
+            try:
+                raise ex
+            except Exception:
+                self._telemetry_client.track_exception()
 
     def _log(self, level: str, log_message: str, log_args: Iterable[Any]):
         message_parts = ['%s']

tests/opwen_email_server/test_actions.py

@@ -2,13 +2,28 @@
 from unittest import TestCase
 from unittest.mock import MagicMock
 from unittest.mock import Mock
+from unittest.mock import patch
 from uuid import uuid4
 
 from opwen_email_server import actions
 from opwen_email_server.constants import sync
 from opwen_email_server.services.storage import AccessInfo
 
 
+class ActionTests(TestCase):
+    @patch.object(actions._Action, '_telemetry_client')
+    def test_logs_exception(self, telemetry_mock):
+        class TestAction(actions._Action):
+            def _action(self):
+                int('not-a-number')
+
+        with self.assertRaises(ValueError):
+            action = TestAction()
+            action()
+
+        telemetry_mock.track_exception.assert_called_once_with()
+
+
 class PingTests(TestCase):
     def test_200(self):
         action = actions.Ping()

tests/opwen_email_server/utils/test_collections.py

@@ -57,3 +57,10 @@ def function1(self):
     def function2(self):
         self.call_counts['function2'] += 1
         return 'some-other-value'
+
+
+class AppendTests(TestCase):
+    def test_yields_item_after_items(self):
+        collection = collections.append([1, 2, 3], 4)
+
+        self.assertSequenceEqual(list(collection), [1, 2, 3, 4])