Fix logging line to include response context

We have been getting log lines of the following:

`API POST request on
https://api.notifications.service.gov.uk/notifications/sms/mmg failed
with None`

It's not clear what error caused the request to fail because the value
of `api_error.response` is always `None`.

There appears to be something wrong with this logging.
`raise_for_status` will raise an `HTTPError`, so then there should be no
reason to then pass that error into another `HTTPError` (which is
causing the response to be lost).

We can instead simply catch the `HTTPError` and log it's status
code.

This might not be perfect, but it's definitely an improvement and should
give us some more context about why these requests occasionally fail.
This commit is contained in:
David McDonald
2020-12-21 14:30:39 +00:00
parent 2749a707f2
commit fae7e917b5
2 changed files with 25 additions and 7 deletions

View File

@@ -3,7 +3,7 @@ from datetime import datetime, timedelta
import json
from flask import current_app
from requests import request, RequestException, HTTPError
from requests import request, HTTPError
from notifications_utils.s3 import s3upload
@@ -66,16 +66,14 @@ def make_request(notification_type, provider, data, headers):
timeout=60
)
response.raise_for_status()
except RequestException as e:
api_error = HTTPError(e)
except HTTPError as e:
current_app.logger.error(
"API {} request on {} failed with {}".format(
"POST",
"API POST request on {} failed with status {}".format(
api_call,
api_error.response
e.response.status_code
)
)
raise api_error
raise e
finally:
current_app.logger.info("Mocked provider callback request finished")
return response.json()

View File

@@ -14,6 +14,7 @@ from app.celery.research_mode_tasks import (
firetext_callback,
ses_notification_callback,
create_fake_letter_response_file,
HTTPError
)
from tests.conftest import set_config_values, Matcher
@@ -38,6 +39,25 @@ def test_make_mmg_callback(notify_api, rmock):
assert json.loads(rmock.request_history[0].text)['MSISDN'] == '07700900001'
def test_callback_logs_on_api_call_failure(notify_api, rmock, mocker):
endpoint = "http://localhost:6011/notifications/sms/mmg"
rmock.request(
"POST",
endpoint,
json={"error": "something went wrong"},
status_code=500)
mock_logger = mocker.patch('app.celery.tasks.current_app.logger.error')
with pytest.raises(HTTPError):
send_sms_response("mmg", "1234", "07700900001")
assert rmock.called
assert rmock.request_history[0].url == endpoint
mock_logger.assert_called_once_with(
'API POST request on http://localhost:6011/notifications/sms/mmg failed with status 500'
)
@pytest.mark.parametrize("phone_number",
["07700900001", "07700900002", "07700900003",
"07700900236"])