notify-api-521 fix sms temporary failure message

app/celery/provider_tasks.py

@@ -1,6 +1,5 @@
 import os
 from datetime import datetime, timedelta
-from time import time
 
 from flask import current_app
 from sqlalchemy.orm.exc import NoResultFound
@@ -21,6 +20,7 @@ from app.models import (
     NOTIFICATION_DELIVERED,
     NOTIFICATION_FAILED,
     NOTIFICATION_TECHNICAL_FAILURE,
+    NOTIFICATION_TEMPORARY_FAILURE,
 )
 
 # This is the amount of time to wait after sending an sms message before we check the aws logs and look for delivery
@@ -49,9 +49,20 @@ def check_sms_delivery_receipt(self, message_id, notification_id, sent_at):
         status = "success"
         provider_response = "this is a fake successful localstack sms message"
     else:
-        status, provider_response = aws_cloudwatch_client.check_sms(
-            message_id, notification_id, sent_at
-        )
+        try:
+            status, provider_response = aws_cloudwatch_client.check_sms(
+                message_id, notification_id, sent_at
+            )
+        except NotificationTechnicalFailureException as ntfe:
+            provider_response = "Unable to find carrier response -- still looking"
+            status = "pending"
+            current_app.logger.info(
+                "UPDATING WITH TEMPORARY FAILURE AND GOING TO RETRY"
+            )
+            update_notification_status_by_id(
+                notification_id, status, provider_response=provider_response
+            )
+            raise self.retry(exc=ntfe)
 
     if status == "success":
         status = NOTIFICATION_DELIVERED
@@ -80,8 +91,6 @@ def check_sms_delivery_receipt(self, message_id, notification_id, sent_at):
 )
 def deliver_sms(self, notification_id):
     try:
-        # Get the time we are doing the sending, to minimize the time period we need to check over for receipt
-        now = round(time() * 1000)
         current_app.logger.info(
             "Start sending SMS for notification id: {}".format(notification_id)
         )
@@ -106,9 +115,15 @@ def deliver_sms(self, notification_id):
             seconds=DELIVERY_RECEIPT_DELAY_IN_SECONDS
         )
         check_sms_delivery_receipt.apply_async(
-            [message_id, notification_id, now], eta=my_eta, queue=QueueNames.CHECK_SMS
+            [message_id, notification_id, notification.created_at],
+            eta=my_eta,
+            queue=QueueNames.CHECK_SMS,
         )
     except Exception as e:
+        current_app.logger.info("TEMPORARY FAILURE!")
+        update_notification_status_by_id(
+            notification_id, NOTIFICATION_TEMPORARY_FAILURE
+        )
         if isinstance(e, SmsClientResponseException):
             current_app.logger.warning(
                 "SMS notification delivery for id: {} failed".format(notification_id),
@@ -125,6 +140,7 @@ def deliver_sms(self, notification_id):
             else:
                 self.retry(queue=QueueNames.RETRY)
         except self.MaxRetriesExceededError:
+            current_app.logger.info("PERMANENT FAILURE!")
             message = (
                 "RETRY FAILED: Max retries reached. The task send_sms_to_provider failed for notification {}. "
                 "Notification has been updated to technical-failure".format(

app/clients/cloudwatch/aws_cloudwatch.py

@@ -2,12 +2,15 @@ import json
 import os
 import re
 import time
+from datetime import datetime
 
+from _datetime import timedelta
 from boto3 import client
 from flask import current_app
 
 from app.clients import AWS_CLIENT_CONFIG, Client
 from app.cloudfoundry_config import cloud_config
+from app.exceptions import NotificationTechnicalFailureException
 
 
 class AwsCloudwatchClient(Client):
@@ -89,6 +92,7 @@ class AwsCloudwatchClient(Client):
         # TODO this clumsy approach to getting the account number will be fixed as part of notify-api #258
         account_number = self._extract_account_number(cloud_config.ses_domain_arn)
 
+        time_now = datetime.utcnow()
         log_group_name = f"sns/{region}/{account_number[4]}/DirectPublishToPhoneNumber"
         current_app.logger.info(
             f"Log group name: {log_group_name} message id: {message_id}"
@@ -105,7 +109,7 @@ class AwsCloudwatchClient(Client):
         log_group_name = (
             f"sns/{region}/{account_number[4]}/DirectPublishToPhoneNumber/Failure"
         )
-        # current_app.logger.info(f"Failure log group name: {log_group_name}")
+        current_app.logger.info(f"Failure log group name: {log_group_name}")
         all_failed_events = self._get_log(filter_pattern, log_group_name, created_at)
         if all_failed_events and len(all_failed_events) > 0:
             current_app.logger.info("SHOULD RETURN FAILED BECAUSE WE FOUND A FAILURE")
@@ -114,6 +118,10 @@ class AwsCloudwatchClient(Client):
             current_app.logger.info(f"MESSAGE {message}")
             return "failure", message["delivery"]["providerResponse"]
 
-        raise Exception(
+        if time_now > (created_at + timedelta(hours=3)):
+            # see app/models.py Notification. This message corresponds to "permanent-failure",
+            # but we are copy/pasting here to avoid circular imports.
+            return "failure", "Unable to find carrier response."
+        raise NotificationTechnicalFailureException(
             f"No event found for message_id {message_id} notification_id {notification_id}"
         )

app/models.py

@@ -1727,8 +1727,8 @@ class Notification(db.Model):
             "sms": {
                 "failed": "Failed",
                 "technical-failure": "Technical failure",
-                "temporary-failure": "Phone not accepting messages right now",
-                "permanent-failure": "Phone number doesn’t exist",
+                "temporary-failure": "Unable to find carrier response -- still looking",
+                "permanent-failure": "Unable to find carrier response.",
                 "delivered": "Delivered",
                 "sending": "Sending",
                 "created": "Sending",

tests/app/celery/test_provider_tasks.py

@@ -105,7 +105,7 @@ def test_should_go_into_technical_error_if_exceeds_retries_on_deliver_sms_task(
         queue="retry-tasks", countdown=0
     )
 
-    assert sample_notification.status == "technical-failure"
+    assert sample_notification.status == "temporary-failure"
     assert mock_logger_exception.called
 
 

tests/app/test_model.py

@@ -139,8 +139,12 @@ def test_notification_for_csv_returns_correct_job_row_number(sample_job):
         ("email", "technical-failure", "Technical failure"),
         ("email", "temporary-failure", "Inbox not accepting messages right now"),
         ("email", "permanent-failure", "Email address doesn’t exist"),
-        ("sms", "temporary-failure", "Phone not accepting messages right now"),
-        ("sms", "permanent-failure", "Phone number doesn’t exist"),
+        (
+            "sms",
+            "temporary-failure",
+            "Unable to find carrier response -- still looking",
+        ),
+        ("sms", "permanent-failure", "Unable to find carrier response."),
         ("sms", "sent", "Sent internationally"),
     ],
 )