DRY-up logging and metrics for sending SMS

This avoids duplicating it as we add a new provider and means we
can test it all in one place (although it wasn't tested before).

I'm not sure why the previous code did "super(..)__init__" in a
non-init function - it's a bit late! - so I've just replaced it
with a call to the new "init_app" function in the parent class.

app/clients/sms/__init__.py

@@ -1,3 +1,5 @@
+from time import monotonic
+
 from app.clients import Client, ClientException
 
 
@@ -18,6 +20,10 @@ class SmsClient(Client):
     Base Sms client for sending smss.
     '''
 
+    def init_app(self, current_app, statsd_client):
+        self.current_app = current_app
+        self.statsd_client = statsd_client
+
     def record_outcome(self, success):
         log_message = "Provider request for {} {}".format(
             self.name,
@@ -31,7 +37,23 @@ class SmsClient(Client):
             self.statsd_client.incr(f"clients.{self.name}.error")
             self.current_app.logger.warning(log_message)
 
-    def send_sms(self, *args, **kwargs):
+    def send_sms(self, to, content, reference, international, sender=None):
+        start_time = monotonic()
+
+        try:
+            response = self.try_send_sms(to, content, reference, international, sender)
+            self.record_outcome(True)
+        except SmsClientResponseException as e:
+            self.record_outcome(False)
+            raise e
+        finally:
+            elapsed_time = monotonic() - start_time
+            self.statsd_client.timing(f"clients.{self.name}.request-time", elapsed_time)
+            self.current_app.logger.info("Reach request for {} finished in {}".format(reference, elapsed_time))
+
+        return response
+
+    def try_send_sms(self, *args, **kwargs):
         raise NotImplementedError('TODO Need to implement.')
 
     @property

app/clients/sms/firetext.py

@@ -1,6 +1,5 @@
 import json
 import logging
-from time import monotonic
 
 from requests import RequestException, request
 
@@ -62,20 +61,18 @@ class FiretextClient(SmsClient):
     FireText sms client.
     '''
 
-    def init_app(self, current_app, statsd_client, *args, **kwargs):
+    def init_app(self, *args, **kwargs):
-        super(SmsClient, self).__init__(*args, **kwargs)
+        super().init_app(*args, **kwargs)
-        self.current_app = current_app
+        self.api_key = self.current_app.config.get('FIRETEXT_API_KEY')
-        self.api_key = current_app.config.get('FIRETEXT_API_KEY')
+        self.international_api_key = self.current_app.config.get('FIRETEXT_INTERNATIONAL_API_KEY')
-        self.international_api_key = current_app.config.get('FIRETEXT_INTERNATIONAL_API_KEY')
+        self.from_number = self.current_app.config.get('FROM_NUMBER')
-        self.from_number = current_app.config.get('FROM_NUMBER')
+        self.url = self.current_app.config.get('FIRETEXT_URL')
-        self.url = current_app.config.get('FIRETEXT_URL')
-        self.statsd_client = statsd_client
 
     @property
     def name(self):
         return 'firetext'
 
-    def send_sms(self, to, content, reference, international, sender=None):
+    def try_send_sms(self, to, content, reference, international, sender=None):
         data = {
             "apiKey": self.international_api_key if international else self.api_key,
             "from": self.from_number if sender is None else sender,
@@ -84,7 +81,6 @@ class FiretextClient(SmsClient):
             "reference": reference
         }
 
-        start_time = monotonic()
         try:
             response = request(
                 "POST",
@@ -98,14 +94,8 @@ class FiretextClient(SmsClient):
                 if response.json()['code'] != 0:
                     raise ValueError()
             except (ValueError, AttributeError) as e:
-                self.record_outcome(False)
                 raise FiretextClientResponseException(response=response, exception=e)
-            self.record_outcome(True)
         except RequestException as e:
-            self.record_outcome(False)
             raise FiretextClientResponseException(response=e.response, exception=e)
-        finally:
+
-            elapsed_time = monotonic() - start_time
-            self.current_app.logger.info("Firetext request for {} finished in {}".format(reference, elapsed_time))
-            self.statsd_client.timing("clients.firetext.request-time", elapsed_time)
         return response

app/clients/sms/mmg.py

@@ -1,5 +1,4 @@
 import json
-from time import monotonic
 
 from requests import RequestException, request
 
@@ -69,19 +68,17 @@ class MMGClient(SmsClient):
     MMG sms client
     '''
 
-    def init_app(self, current_app, statsd_client, *args, **kwargs):
+    def init_app(self, *args, **kwargs):
-        super(SmsClient, self).__init__(*args, **kwargs)
+        super().init_app(*args, **kwargs)
-        self.current_app = current_app
+        self.api_key = self.current_app.config.get('MMG_API_KEY')
-        self.api_key = current_app.config.get('MMG_API_KEY')
+        self.from_number = self.current_app.config.get('FROM_NUMBER')
-        self.from_number = current_app.config.get('FROM_NUMBER')
+        self.mmg_url = self.current_app.config.get('MMG_URL')
-        self.statsd_client = statsd_client
-        self.mmg_url = current_app.config.get('MMG_URL')
 
     @property
     def name(self):
         return 'mmg'
 
-    def send_sms(self, to, content, reference, international, sender=None):
+    def try_send_sms(self, to, content, reference, international, sender=None):
         data = {
             "reqType": "BULK",
             "MSISDN": to,
@@ -91,7 +88,6 @@ class MMGClient(SmsClient):
             "multi": True
         }
 
-        start_time = monotonic()
         try:
             response = request(
                 "POST",
@@ -108,15 +104,8 @@ class MMGClient(SmsClient):
             try:
                 json.loads(response.text)
             except (ValueError, AttributeError) as e:
-                self.record_outcome(False)
                 raise MMGClientResponseException(response=response, exception=e)
-            self.record_outcome(True)
         except RequestException as e:
-            self.record_outcome(False)
             raise MMGClientResponseException(response=e.response, exception=e)
-        finally:
-            elapsed_time = monotonic() - start_time
-            self.statsd_client.timing("clients.mmg.request-time", elapsed_time)
-            self.current_app.logger.info("MMG request for {} finished in {}".format(reference, elapsed_time))
 
         return response

tests/app/clients/test_firetext.py

@@ -36,7 +36,7 @@ def test_get_firetext_responses_raises_KeyError_if_unrecognised_status_code():
     assert '99' in str(e.value)
 
 
-def test_send_sms_successful_returns_firetext_response(mocker, mock_firetext_client):
+def test_try_send_sms_successful_returns_firetext_response(mocker, mock_firetext_client):
     to = content = reference = 'foo'
     response_dict = {
         'data': [],
@@ -47,7 +47,7 @@ def test_send_sms_successful_returns_firetext_response(mocker, mock_firetext_cli
 
     with requests_mock.Mocker() as request_mock:
         request_mock.post('https://example.com/firetext', json=response_dict, status_code=200)
-        response = mock_firetext_client.send_sms(to, content, reference, False)
+        response = mock_firetext_client.try_send_sms(to, content, reference, False)
 
     response_json = response.json()
     assert response.status_code == 200
@@ -55,7 +55,7 @@ def test_send_sms_successful_returns_firetext_response(mocker, mock_firetext_cli
     assert response_json['description'] == 'SMS successfully queued'
 
 
-def test_send_sms_calls_firetext_correctly(mocker, mock_firetext_client):
+def test_try_send_sms_calls_firetext_correctly(mocker, mock_firetext_client):
     to = '+447234567890'
     content = 'my message'
     reference = 'my reference'
@@ -65,7 +65,7 @@ def test_send_sms_calls_firetext_correctly(mocker, mock_firetext_client):
 
     with requests_mock.Mocker() as request_mock:
         request_mock.post('https://example.com/firetext', json=response_dict, status_code=200)
-        mock_firetext_client.send_sms(to, content, reference, False)
+        mock_firetext_client.try_send_sms(to, content, reference, False)
 
     assert request_mock.call_count == 1
     assert request_mock.request_history[0].url == 'https://example.com/firetext'
@@ -79,7 +79,7 @@ def test_send_sms_calls_firetext_correctly(mocker, mock_firetext_client):
     assert request_args['reference'][0] == reference
 
 
-def test_send_sms_calls_firetext_correctly_for_international(mocker, mock_firetext_client):
+def test_try_send_sms_calls_firetext_correctly_for_international(mocker, mock_firetext_client):
     to = '+607234567890'
     content = 'my message'
     reference = 'my reference'
@@ -89,7 +89,7 @@ def test_send_sms_calls_firetext_correctly_for_international(mocker, mock_firete
 
     with requests_mock.Mocker() as request_mock:
         request_mock.post('https://example.com/firetext', json=response_dict, status_code=200)
-        mock_firetext_client.send_sms(to, content, reference, True)
+        mock_firetext_client.try_send_sms(to, content, reference, True)
 
     assert request_mock.call_count == 1
     assert request_mock.request_history[0].url == 'https://example.com/firetext'
@@ -103,7 +103,7 @@ def test_send_sms_calls_firetext_correctly_for_international(mocker, mock_firete
     assert request_args['reference'][0] == reference
 
 
-def test_send_sms_raises_if_firetext_rejects(mocker, mock_firetext_client):
+def test_try_send_sms_raises_if_firetext_rejects(mocker, mock_firetext_client):
     to = content = reference = 'foo'
     response_dict = {
         'data': [],
@@ -114,27 +114,27 @@ def test_send_sms_raises_if_firetext_rejects(mocker, mock_firetext_client):
 
     with pytest.raises(SmsClientResponseException) as exc, requests_mock.Mocker() as request_mock:
         request_mock.post('https://example.com/firetext', json=response_dict, status_code=200)
-        mock_firetext_client.send_sms(to, content, reference, False)
+        mock_firetext_client.try_send_sms(to, content, reference, False)
 
     assert exc.value.status_code == 200
     assert '"description": "Some kind of error"' in exc.value.text
     assert '"code": 1' in exc.value.text
 
 
-def test_send_sms_raises_if_firetext_rejects_with_unexpected_data(mocker, mock_firetext_client):
+def test_try_send_sms_raises_if_firetext_rejects_with_unexpected_data(mocker, mock_firetext_client):
     to = content = reference = 'foo'
     response_dict = {"something": "gone bad"}
 
     with pytest.raises(SmsClientResponseException) as exc, requests_mock.Mocker() as request_mock:
         request_mock.post('https://example.com/firetext', json=response_dict, status_code=400)
-        mock_firetext_client.send_sms(to, content, reference, False)
+        mock_firetext_client.try_send_sms(to, content, reference, False)
 
     assert exc.value.status_code == 400
     assert exc.value.text == '{"something": "gone bad"}'
     assert type(exc.value.exception) == HTTPError
 
 
-def test_send_sms_override_configured_shortcode_with_sender(mocker, mock_firetext_client):
+def test_try_send_sms_override_configured_shortcode_with_sender(mocker, mock_firetext_client):
     to = '+447234567890'
     content = 'my message'
     reference = 'my reference'
@@ -145,29 +145,29 @@ def test_send_sms_override_configured_shortcode_with_sender(mocker, mock_firetex
 
     with requests_mock.Mocker() as request_mock:
         request_mock.post('https://example.com/firetext', json=response_dict, status_code=200)
-        mock_firetext_client.send_sms(to, content, reference, False, sender=sender)
+        mock_firetext_client.try_send_sms(to, content, reference, False, sender=sender)
 
     request_args = parse_qs(request_mock.request_history[0].text)
     assert request_args['from'][0] == 'fromservice'
 
 
-def test_send_sms_raises_if_firetext_rejects_with_connect_timeout(rmock, mock_firetext_client):
+def test_try_send_sms_raises_if_firetext_rejects_with_connect_timeout(rmock, mock_firetext_client):
     to = content = reference = 'foo'
 
     with pytest.raises(FiretextClientResponseException) as exc:
         rmock.register_uri('POST', 'https://example.com/firetext', exc=ConnectTimeout)
-        mock_firetext_client.send_sms(to, content, reference, False)
+        mock_firetext_client.try_send_sms(to, content, reference, False)
 
     assert exc.value.status_code == 504
     assert exc.value.text == 'Gateway Time-out'
 
 
-def test_send_sms_raises_if_firetext_rejects_with_read_timeout(rmock, mock_firetext_client):
+def test_try_send_sms_raises_if_firetext_rejects_with_read_timeout(rmock, mock_firetext_client):
     to = content = reference = 'foo'
 
     with pytest.raises(FiretextClientResponseException) as exc:
         rmock.register_uri('POST', 'https://example.com/firetext', exc=ReadTimeout)
-        mock_firetext_client.send_sms(to, content, reference, False)
+        mock_firetext_client.try_send_sms(to, content, reference, False)
 
     assert exc.value.status_code == 504
     assert exc.value.text == 'Gateway Time-out'

tests/app/clients/test_mmg.py

@@ -38,20 +38,20 @@ def test_get_mmg_responses_raises_KeyError_if_unrecognised_status_code():
     assert '99' in str(e.value)
 
 
-def test_send_sms_successful_returns_mmg_response(notify_api, mocker):
+def test_try_send_sms_successful_returns_mmg_response(notify_api, mocker):
     to = content = reference = 'foo'
     response_dict = {'Reference': 12345678}
 
     with requests_mock.Mocker() as request_mock:
         request_mock.post('https://example.com/mmg', json=response_dict, status_code=200)
-        response = mmg_client.send_sms(to, content, reference, False)
+        response = mmg_client.try_send_sms(to, content, reference, False)
 
     response_json = response.json()
     assert response.status_code == 200
     assert response_json['Reference'] == 12345678
 
 
-def test_send_sms_calls_mmg_correctly(notify_api, mocker):
+def test_try_send_sms_calls_mmg_correctly(notify_api, mocker):
     to = '+447234567890'
     content = 'my message'
     reference = 'my reference'
@@ -59,7 +59,7 @@ def test_send_sms_calls_mmg_correctly(notify_api, mocker):
 
     with requests_mock.Mocker() as request_mock:
         request_mock.post('https://example.com/mmg', json=response_dict, status_code=200)
-        mmg_client.send_sms(to, content, reference, False)
+        mmg_client.try_send_sms(to, content, reference, False)
 
     assert request_mock.call_count == 1
     assert request_mock.request_history[0].url == 'https://example.com/mmg'
@@ -74,7 +74,7 @@ def test_send_sms_calls_mmg_correctly(notify_api, mocker):
     assert request_args['multi'] is True
 
 
-def test_send_sms_raises_if_mmg_rejects(notify_api, mocker):
+def test_try_send_sms_raises_if_mmg_rejects(notify_api, mocker):
     to = content = reference = 'foo'
     response_dict = {
         'Error': 206,
@@ -83,7 +83,7 @@ def test_send_sms_raises_if_mmg_rejects(notify_api, mocker):
 
     with pytest.raises(SmsClientResponseException) as exc, requests_mock.Mocker() as request_mock:
         request_mock.post('https://example.com/mmg', json=response_dict, status_code=400)
-        mmg_client.send_sms(to, content, reference, False)
+        mmg_client.try_send_sms(to, content, reference, False)
 
     assert exc.value.status_code == 400
     assert '"Error": 206' in exc.value.text
@@ -91,7 +91,7 @@ def test_send_sms_raises_if_mmg_rejects(notify_api, mocker):
     assert type(exc.value.exception) == HTTPError
 
 
-def test_send_sms_override_configured_shortcode_with_sender(notify_api, mocker):
+def test_try_send_sms_override_configured_shortcode_with_sender(notify_api, mocker):
     to = '+447234567890'
     content = 'my message'
     reference = 'my reference'
@@ -100,42 +100,42 @@ def test_send_sms_override_configured_shortcode_with_sender(notify_api, mocker):
 
     with requests_mock.Mocker() as request_mock:
         request_mock.post('https://example.com/mmg', json=response_dict, status_code=200)
-        mmg_client.send_sms(to, content, reference, False, sender=sender)
+        mmg_client.try_send_sms(to, content, reference, False, sender=sender)
 
     request_args = request_mock.request_history[0].json()
     assert request_args['sender'] == 'fromservice'
 
 
-def test_send_sms_raises_if_mmg_fails_to_return_json(notify_api, mocker):
+def test_try_send_sms_raises_if_mmg_fails_to_return_json(notify_api, mocker):
     to = content = reference = 'foo'
     response_dict = 'NOT AT ALL VALID JSON {"key" : "value"}}'
 
     with pytest.raises(SmsClientResponseException) as exc, requests_mock.Mocker() as request_mock:
         request_mock.post('https://example.com/mmg', text=response_dict, status_code=200)
-        mmg_client.send_sms(to, content, reference, False)
+        mmg_client.try_send_sms(to, content, reference, False)
 
     assert 'Code 200 text NOT AT ALL VALID JSON {"key" : "value"}} exception Expecting value: line 1 column 1 (char 0)' in str(exc.value)  # noqa
     assert exc.value.status_code == 200
     assert exc.value.text == 'NOT AT ALL VALID JSON {"key" : "value"}}'
 
 
-def test_send_sms_raises_if_mmg_rejects_with_connect_timeout(rmock):
+def test_try_send_sms_raises_if_mmg_rejects_with_connect_timeout(rmock):
     to = content = reference = 'foo'
 
     with pytest.raises(MMGClientResponseException) as exc:
         rmock.register_uri('POST', 'https://example.com/mmg', exc=ConnectTimeout)
-        mmg_client.send_sms(to, content, reference, False)
+        mmg_client.try_send_sms(to, content, reference, False)
 
     assert exc.value.status_code == 504
     assert exc.value.text == 'Gateway Time-out'
 
 
-def test_send_sms_raises_if_mmg_rejects_with_read_timeout(rmock):
+def test_try_send_sms_raises_if_mmg_rejects_with_read_timeout(rmock):
     to = content = reference = 'foo'
 
     with pytest.raises(MMGClientResponseException) as exc:
         rmock.register_uri('POST', 'https://example.com/mmg', exc=ReadTimeout)
-        mmg_client.send_sms(to, content, reference, False)
+        mmg_client.try_send_sms(to, content, reference, False)
 
     assert exc.value.status_code == 504
     assert exc.value.text == 'Gateway Time-out'

tests/app/clients/test_sms.py

@@ -0,0 +1,45 @@
+import pytest
+
+from app import statsd_client
+from app.clients.sms import SmsClient, SmsClientResponseException
+
+
+@pytest.fixture
+def fake_client(notify_api):
+    class FakeSmsClient(SmsClient):
+        @property
+        def name(self):
+            return 'fake'
+
+    fake_client = FakeSmsClient()
+    fake_client.init_app(notify_api, statsd_client)
+    return fake_client
+
+
+def test_send_sms(fake_client, mocker):
+    mock_send = mocker.patch.object(fake_client, 'try_send_sms')
+
+    fake_client.send_sms(
+        to='to',
+        content='content',
+        reference='reference',
+        international=False,
+    )
+
+    mock_send.assert_called_with(
+        'to', 'content', 'reference', False, None
+    )
+
+
+def test_send_sms_error(fake_client, mocker):
+    mocker.patch.object(
+        fake_client, 'try_send_sms', side_effect=SmsClientResponseException('error')
+    )
+
+    with pytest.raises(SmsClientResponseException):
+        fake_client.send_sms(
+            to='to',
+            content='content',
+            reference='reference',
+            international=False,
+        )