Bug fix: callback URL timing out and preventing notification processi…

…ng slowdown (#2153)

* Bringing callback changes from upstream

- Reduce callback http request timeout from 60 to 5 seconds.
- Retry callbacks into a dedicated queue to not affect other retryable tasks.

* Fixing test with the declaration for new retry callback queue

.vscode/launch.json

@@ -43,7 +43,7 @@
                 "-l",
                 "DEBUG",
                 "-Q",
-                "database-tasks,-priority-database-tasks.fifo,-normal-database-tasks,-bulk-database-tasks,job-tasks,notify-internal-tasks,periodic-tasks,priority-tasks,normal-tasks,bulk-tasks,reporting-tasks,research-mode-tasks,retry-tasks,send-sms-tasks,send-sms-high,send-sms-medium,send-sms-low,send-throttled-sms-tasks,send-email-high,send-email-medium,send-email-low,send-email-tasks,service-callbacks,delivery-receipts",
+                "database-tasks,-priority-database-tasks.fifo,-normal-database-tasks,-bulk-database-tasks,job-tasks,notify-internal-tasks,periodic-tasks,priority-tasks,normal-tasks,bulk-tasks,reporting-tasks,research-mode-tasks,retry-tasks,service-callbacks-retry,send-sms-tasks,send-sms-high,send-sms-medium,send-sms-low,send-throttled-sms-tasks,send-email-high,send-email-medium,send-email-low,send-email-tasks,service-callbacks,delivery-receipts",
             ]
         },
         {

app/celery/service_callback_tasks.py

@@ -67,7 +67,7 @@ def _send_data_to_service_callback_api(self, data, service_callback_url, token,
                 "Content-Type": "application/json",
                 "Authorization": "Bearer {}".format(token),
             },
-            timeout=60,
+            timeout=5,
         )
         current_app.logger.info(
             "{} sending {} to {}, response {}".format(
@@ -86,7 +86,7 @@ def _send_data_to_service_callback_api(self, data, service_callback_url, token,
         )
         if not isinstance(e, HTTPError) or e.response.status_code >= 500:
             try:
-                self.retry(queue=QueueNames.RETRY)
+                self.retry(queue=QueueNames.CALLBACKS_RETRY)
             except self.MaxRetriesExceededError:
                 current_app.logger.warning(
                     "Retry: {} has retried the max num of times for callback url {} and notification_id: {}".format(

app/config.py

@@ -107,6 +107,7 @@ class QueueNames(object):
     PROCESS_FTP = "process-ftp-tasks"
     CREATE_LETTERS_PDF = "create-letters-pdf-tasks"
     CALLBACKS = "service-callbacks"
+    CALLBACKS_RETRY = "service-callbacks-retry"
 
     # Queue for letters, unused by CDS at this time as we don't use these.
     LETTERS = "letter-tasks"
@@ -156,6 +157,7 @@ def all_queues():
             QueueNames.REPORTING,
             QueueNames.JOBS,
             QueueNames.RETRY,
+            QueueNames.CALLBACKS_RETRY,
             QueueNames.NOTIFY,
             # QueueNames.CREATE_LETTERS_PDF,
             QueueNames.CALLBACKS,

scripts/run_celery.ps1

@@ -1,3 +1,3 @@
 $ENV:FORKED_BY_MULTIPROCESSING=1
 
-celery --app run_celery worker --pidfile="$env:TEMP\celery.pid" --pool=solo --loglevel=DEBUG --concurrency=1 -Q "database-tasks,-priority-database-tasks.fifo,-normal-database-tasks,-bulk-database-tasks,job-tasks,notify-internal-tasks,periodic-tasks,priority-tasks,normal-tasks,bulk-tasks,reporting-tasks,research-mode-tasks,retry-tasks,send-sms-high,send-sms-medium,send-sms-low,service-callbacks,delivery-receipts"
+celery --app run_celery worker --pidfile="$env:TEMP\celery.pid" --pool=solo --loglevel=DEBUG --concurrency=1 -Q "database-tasks,-priority-database-tasks.fifo,-normal-database-tasks,-bulk-database-tasks,job-tasks,notify-internal-tasks,periodic-tasks,priority-tasks,normal-tasks,bulk-tasks,reporting-tasks,research-mode-tasks,retry-tasks,send-sms-high,send-sms-medium,send-sms-low,service-callbacks,service-callbacks-retry,delivery-receipts"

scripts/run_celery.sh

@@ -6,4 +6,4 @@ set -e
 
 echo "Start celery, concurrency: ${CELERY_CONCURRENCY-4}"
 
-celery -A run_celery.notify_celery worker --pidfile="/tmp/celery.pid" --loglevel=INFO --concurrency="${CELERY_CONCURRENCY-4}" -Q database-tasks,-priority-database-tasks.fifo,-normal-database-tasks,-bulk-database-tasks,job-tasks,notify-internal-tasks,periodic-tasks,priority-tasks,normal-tasks,bulk-tasks,reporting-tasks,research-mode-tasks,retry-tasks,send-sms-high,send-sms-medium,send-sms-low,service-callbacks,delivery-receipts
+celery -A run_celery.notify_celery worker --pidfile="/tmp/celery.pid" --loglevel=INFO --concurrency="${CELERY_CONCURRENCY-4}" -Q database-tasks,-priority-database-tasks.fifo,-normal-database-tasks,-bulk-database-tasks,job-tasks,notify-internal-tasks,periodic-tasks,priority-tasks,normal-tasks,bulk-tasks,reporting-tasks,research-mode-tasks,retry-tasks,send-sms-high,send-sms-medium,send-sms-low,service-callbacks,service-callbacks-retry,delivery-receipts

scripts/run_celery_core_tasks.sh

@@ -7,4 +7,4 @@ set -e
 
 echo "Start celery, concurrency: ${CELERY_CONCURRENCY-4}"
 
-celery -A run_celery.notify_celery worker --pidfile="/tmp/celery.pid" --loglevel=INFO --concurrency="${CELERY_CONCURRENCY-4}" -Q database-tasks,-priority-database-tasks.fifo,-normal-database-tasks,-bulk-database-tasks,job-tasks,notify-internal-tasks,periodic-tasks,priority-tasks,normal-tasks,bulk-tasks,reporting-tasks,research-mode-tasks,retry-tasks,service-callbacks,delivery-receipts
+celery -A run_celery.notify_celery worker --pidfile="/tmp/celery.pid" --loglevel=INFO --concurrency="${CELERY_CONCURRENCY-4}" -Q database-tasks,-priority-database-tasks.fifo,-normal-database-tasks,-bulk-database-tasks,job-tasks,notify-internal-tasks,periodic-tasks,priority-tasks,normal-tasks,bulk-tasks,reporting-tasks,research-mode-tasks,retry-tasks,service-callbacks,service-callbacks-retry,delivery-receipts

scripts/run_celery_local.sh

@@ -7,4 +7,4 @@ set -e
 
 echo "Start celery, concurrency: ${CELERY_CONCURRENCY-4}"
 
-celery -A run_celery.notify_celery worker --beat --pidfile="/tmp/celery.pid" --loglevel=INFO --concurrency="${CELERY_CONCURRENCY-4}" -Q database-tasks,-priority-database-tasks.fifo,-normal-database-tasks,-bulk-database-tasks,job-tasks,notify-internal-tasks,periodic-tasks,priority-tasks,normal-tasks,bulk-tasks,reporting-tasks,research-mode-tasks,retry-tasks,send-sms-high,send-sms-medium,send-sms-low,send-throttled-sms-tasks,send-email-high,send-email-medium,send-email-low,service-callbacks,delivery-receipts
+celery -A run_celery.notify_celery worker --beat --pidfile="/tmp/celery.pid" --loglevel=INFO --concurrency="${CELERY_CONCURRENCY-4}" -Q database-tasks,-priority-database-tasks.fifo,-normal-database-tasks,-bulk-database-tasks,job-tasks,notify-internal-tasks,periodic-tasks,priority-tasks,normal-tasks,bulk-tasks,reporting-tasks,research-mode-tasks,retry-tasks,send-sms-high,send-sms-medium,send-sms-low,send-throttled-sms-tasks,send-email-high,send-email-medium,send-email-low,service-callbacks,service-callbacks-retry,delivery-receipts

scripts/run_celery_no_sms_sending.sh

@@ -28,4 +28,4 @@ fi
 
 echo "Start celery, concurrency: ${CELERY_CONCURRENCY-4}"
 
-celery -A run_celery.notify_celery worker --pidfile="/tmp/celery.pid" --loglevel=INFO --concurrency="${CELERY_CONCURRENCY-4}" -Q database-tasks,-priority-database-tasks.fifo,-normal-database-tasks,-bulk-database-tasks,job-tasks,notify-internal-tasks,periodic-tasks,priority-tasks,normal-tasks,bulk-tasks,reporting-tasks,research-mode-tasks,retry-tasks,send-email-high,send-email-medium,send-email-low,service-callbacks,delivery-receipts
+celery -A run_celery.notify_celery worker --pidfile="/tmp/celery.pid" --loglevel=INFO --concurrency="${CELERY_CONCURRENCY-4}" -Q database-tasks,-priority-database-tasks.fifo,-normal-database-tasks,-bulk-database-tasks,job-tasks,notify-internal-tasks,periodic-tasks,priority-tasks,normal-tasks,bulk-tasks,reporting-tasks,research-mode-tasks,retry-tasks,send-email-high,send-email-medium,send-email-low,service-callbacks,service-callbacks-retry,delivery-receipts

tests/app/celery/test_service_callback_tasks.py

@@ -111,7 +111,7 @@ def test__send_data_to_service_callback_api_retries_if_request_returns_500_with_
         send_delivery_status_to_service(notification.id, signed_status_update=signed_data)
 
     assert mocked.call_count == 1
-    assert mocked.call_args[1]["queue"] == "retry-tasks"
+    assert mocked.call_args[1]["queue"] == "service-callbacks-retry"
 
 
 @pytest.mark.parametrize("notification_type", ["email", "letter", "sms"])

tests/app/test_config.py

@@ -27,7 +27,7 @@ def reload_config():
 def test_queue_names_all_queues_correct():
     # Need to ensure that all_queues() only returns queue names used in API
     queues = QueueNames.all_queues()
-    assert len(queues) == 21
+    assert len(queues) == 22
     assert set(
         [
             QueueNames.PRIORITY,
@@ -48,6 +48,7 @@ def test_queue_names_all_queues_correct():
             QueueNames.REPORTING,
             QueueNames.JOBS,
             QueueNames.RETRY,
+            QueueNames.CALLBACKS_RETRY,
             QueueNames.NOTIFY,
             # QueueNames.CREATE_LETTERS_PDF,
             QueueNames.CALLBACKS,