From 224d9bf35aab5fc4c7cdec7f96405ae45ebcd9e8 Mon Sep 17 00:00:00 2001 From: David McDonald Date: Fri, 13 Nov 2020 16:41:48 +0000 Subject: [PATCH] Log when we don't retry a callback We don't retry any callbacks when it receives a 4xx status. We should probably be aware of this happening and at the moment there is nothing in our logs to easily identify whether the request failed and is being retried or if it failed and is not being retried. This will enable us to search our logs easily and figure out how much it's happening. It's quite likely that we should in the future allow callbacks to retry if they get a 429 http response (rate limiting) but we should do this in a smart way (exponential backoff) and so this is a first step to being aware of how big a problem it is in case we want to do something about it. --- app/celery/service_callback_tasks.py | 11 ++++++++++- app/celery/tasks.py | 22 +++++++++++----------- 2 files changed, 21 insertions(+), 12 deletions(-) diff --git a/app/celery/service_callback_tasks.py b/app/celery/service_callback_tasks.py index 10694635a..0bec3a48b 100644 --- a/app/celery/service_callback_tasks.py +++ b/app/celery/service_callback_tasks.py @@ -85,7 +85,7 @@ def _send_data_to_service_callback_api(self, data, service_callback_url, token, response.raise_for_status() except RequestException as e: current_app.logger.warning( - "{} request failed for notification_id: {} and url: {}. exc: {}".format( + "{} request failed for notification_id: {} and url: {}. exception: {}".format( function_name, notification_id, service_callback_url, @@ -103,6 +103,15 @@ def _send_data_to_service_callback_api(self, data, service_callback_url, token, notification_id ) ) + else: + current_app.logger.warning( + "{} callback is not being retried for notification_id: {} and url: {}. exception: {}".format( + function_name, + notification_id, + service_callback_url, + e + ) + ) def create_delivery_status_callback_data(notification, service_callback_api): diff --git a/app/celery/tasks.py b/app/celery/tasks.py index a97364fa1..22262aabd 100644 --- a/app/celery/tasks.py +++ b/app/celery/tasks.py @@ -589,20 +589,15 @@ def send_inbound_sms_to_service(self, inbound_sms_id, service_id): }, timeout=60 ) - current_app.logger.debug('send_inbound_sms_to_service sending {} to {}, response {}'.format( - inbound_sms_id, - inbound_api.url, - response.status_code - )) + current_app.logger.debug( + f"send_inbound_sms_to_service sending {inbound_sms_id} to {inbound_api.url}, " + + f"response {response.status_code}" + ) response.raise_for_status() except RequestException as e: current_app.logger.warning( - "send_inbound_sms_to_service failed for service_id: {} for inbound_sms_id: {} and url: {}. exc: {}".format( - service_id, - inbound_sms_id, - inbound_api.url, - e - ) + f"send_inbound_sms_to_service failed for service_id: {service_id} for inbound_sms_id: {inbound_sms_id} " + + f"and url: {inbound_api.url}. exception: {e}" ) if not isinstance(e, HTTPError) or e.response.status_code >= 500: try: @@ -612,6 +607,11 @@ def send_inbound_sms_to_service(self, inbound_sms_id, service_id): f"Retry: send_inbound_sms_to_service has retried the max number of" + f"times for service: {service_id} and inbound_sms {inbound_sms_id}" ) + else: + current_app.logger.warning( + f"send_inbound_sms_to_service is not being retried for service_id: {service_id} for " + + f"inbound_sms id: {inbound_sms_id} and url: {inbound_api.url}. exception: {e}" + ) @notify_celery.task(name='process-incomplete-jobs')