Thread logging through webhooks

thread · Feb 14, 2018 · 0508d5d · 0508d5d
1 parent c54bbaa
commit 0508d5d
Show file tree

Hide file tree

Showing 4 changed files with 31 additions and 9 deletions.
diff --git a/routemaster/logging.py b/routemaster/logging.py
@@ -33,6 +33,14 @@ def process_cron(self, state_machine, state, fn_name):
         """Wraps the processing of a cron job for logging purposes."""
         yield
 
+    @contextlib.contextmanager
+    def process_webhook(self, state_machine, state):
+        """Wraps the processing of a webhook for logging purposes."""
+        yield
+
+    def webhook_response(self, response):
+        pass
+
 
 class PythonLogger(BaseLogger):
     """Routemaster logging interface for Python's logging library."""

diff --git a/routemaster/state_machine/actions.py b/routemaster/state_machine/actions.py
@@ -62,12 +62,14 @@ def process_action(
 
     idempotency_token = _calculate_idempotency_token(label, latest_history)
 
-    result = run_webhook(
-        template_url(action.webhook, state_machine.name, label.name),
-        'application/json',
-        webhook_data,
-        idempotency_token,
-    )
+    with app.logger.process_webhook(state_machine, state):
+        result = run_webhook(
+            template_url(action.webhook, state_machine.name, label.name),
+            'application/json',
+            webhook_data,
+            idempotency_token,
+            app.logger.webhook_response,
+        )
 
     if result != WebhookResult.SUCCESS:
         return False

diff --git a/routemaster/state_machine/tests/test_actions.py b/routemaster/state_machine/tests/test_actions.py
@@ -33,6 +33,7 @@ def test_actions_are_run_and_states_advanced(app_config, create_label, mock_webh
         'application/json',
         b'{"label": "foo", "metadata": {"should_progress": true}}',
         mock.ANY,
+        mock.ANY,
     )
 
     assert_history([
@@ -64,6 +65,7 @@ def test_actions_do_not_advance_state_on_fail(app_config, create_label, mock_web
         'application/json',
         b'{"label": "foo", "metadata": {"should_progress": true}}',
         mock.ANY,
+        mock.ANY,
     )
 
     assert_history([
@@ -77,7 +79,7 @@ def test_actions_retries_use_same_idempotency_token(app_config, create_label, mo
 
     expected = {'token': None}
 
-    def persist_token(url, content_type, data, token):
+    def persist_token(url, content_type, data, token, logger):
         expected['token'] = token
         return WebhookResult.FAIL
 
@@ -96,6 +98,7 @@ def persist_token(url, content_type, data, token):
         'application/json',
         b'{"label": "foo", "metadata": {"should_progress": true}}',
         expected['token'],
+        mock.ANY,
     )
 
     with mock_webhook(WebhookResult.FAIL) as webhook:
@@ -112,6 +115,7 @@ def persist_token(url, content_type, data, token):
         'application/json',
         b'{"label": "foo", "metadata": {"should_progress": true}}',
         expected['token'],
+        mock.ANY,
     )
 
     with mock_webhook(WebhookResult.SUCCESS) as webhook:
@@ -128,6 +132,7 @@ def persist_token(url, content_type, data, token):
         'application/json',
         b'{"label": "foo", "metadata": {"should_progress": true}}',
         expected['token'],
+        mock.ANY,
     )
 
 
@@ -136,7 +141,7 @@ def test_different_actions_use_different_idempotency_tokens(app_config, create_l
 
     seen_tokens = set()
 
-    def persist_token(url, content_type, data, token):
+    def persist_token(url, content_type, data, token, logger):
         seen_tokens.add(token)
         return WebhookResult.SUCCESS
 
@@ -156,18 +161,21 @@ def persist_token(url, content_type, data, token):
             'application/json',
             b'{"label": "foo", "metadata": {"should_progress": true}}',
             mock.ANY,
+            mock.ANY,
         ),
         mock.call(
             'http://localhost/hook/test_machine/bar',
             'application/json',
             b'{"label": "bar", "metadata": {"should_progress": true}}',
             mock.ANY,
+            mock.ANY,
         ),
         mock.call(
             'http://localhost/hook/test_machine/baz',
             'application/json',
             b'{"label": "baz", "metadata": {"should_progress": true}}',
             mock.ANY,
+            mock.ANY,
         ),
     ))
 
@@ -207,6 +215,7 @@ def test_action_retry_trigger_continues_as_far_as_possible(app_config, create_la
         'application/json',
         b'{"label": "foo", "metadata": {"should_progress": true}}',
         mock.ANY,
+        mock.ANY,
     )
 
     assert_history([

diff --git a/routemaster/webhooks.py b/routemaster/webhooks.py
@@ -16,7 +16,8 @@ class WebhookResult(enum.Enum):
     FAIL = 'fail'
 
 
-WebhookRunner = Callable[[str, str, bytes, str], WebhookResult]
+ResponseLogger = Callable[[requests.Response], None]
+WebhookRunner = Callable[[str, str, bytes, str, ResponseLogger], WebhookResult]
 
 
 class RequestsWebhookRunner(object):
@@ -36,6 +37,7 @@ def __call__(
         content_type: str,
         data: bytes,
         idempotency_token: str,
+        log_response: ResponseLogger = lambda x: None,
     ) -> WebhookResult:
         """Run a POST on the given webhook."""
         headers = {
@@ -51,6 +53,7 @@ def __call__(
                 headers=headers,
                 timeout=10,
             )
+            log_response(result)
         except requests.exceptions.RequestException:
             return WebhookResult.RETRY