fix get_job_from_s3

app/__init__.py

@@ -389,7 +389,6 @@ def setup_sqlalchemy_events(app):
 
         @event.listens_for(db.engine, "connect")
         def connect(dbapi_connection, connection_record):
-            current_app.logger.debug(f"Using {dbapi_connection} {connection_record}")
             pass
 
         @event.listens_for(db.engine, "close")
@@ -398,7 +397,6 @@ def setup_sqlalchemy_events(app):
 
         @event.listens_for(db.engine, "checkout")
         def checkout(dbapi_connection, connection_record, connection_proxy):
-            current_app.logger.debug(f"Using {dbapi_connection} {connection_proxy}")
 
             try:
                 # this will overwrite any previous checkout_at timestamp

app/aws/s3.py

@@ -412,6 +412,10 @@ def get_job_from_s3(service_id, job_id):
     that indicates things are permanently broken, we want to give up right away
     to save time.
     """
+
+    job = get_job_cache(job_id)
+    if job:
+        return job
     # We have to make sure the retries don't take up to much time, because
     # we might be retrieving dozens of jobs.  So max time is:
     # 0.2 + 0.4 + 0.8 + 1.6 = 3.0 seconds
@@ -479,7 +483,9 @@ def extract_phones(job, service_id, job_id):
     try:
         first_row = next(csv_reader)
     except StopIteration:
-        current_app.logger.warning(f"Empty CSV file for job {job_id} in service {service_id}")
+        current_app.logger.warning(
+            f"Empty CSV file for job {job_id} in service {service_id}"
+        )
         return {}
 
     phone_index = 0
@@ -511,7 +517,9 @@ def extract_phones(job, service_id, job_id):
 
 def extract_personalisation(job):
     if job is None:
-        current_app.logger.warning("No job data provided for personalisation extraction")
+        current_app.logger.warning(
+            "No job data provided for personalisation extraction"
+        )
         return {}
     if isinstance(job, dict):
         job = job[0]
@@ -520,7 +528,9 @@ def extract_personalisation(job):
         return {}
     job = job.split("\r\n")
     if not job or not job[0]:
-        current_app.logger.warning("Empty job data after split for personalisation extraction")
+        current_app.logger.warning(
+            "Empty job data after split for personalisation extraction"
+        )
         return {}
     first_row = job[0]
     job.pop(0)
@@ -554,10 +564,8 @@ def get_phone_number_from_s3(service_id, job_id, job_row_number):
 
     phones = get_job_cache(f"{job_id}_phones")
     if phones is None:
-        current_app.logger.debug("HAVE TO REEXTRACT PHONES!")
         phones = extract_phones(job, service_id, job_id)
         set_job_cache(f"{job_id}_phones", phones)
-        current_app.logger.debug(f"SETTING PHONES TO {phones}")
     else:
         phones = phones[
             0
@@ -606,9 +614,7 @@ def get_personalisation_from_s3(service_id, job_id, job_row_number):
 
 
 def get_job_metadata_from_s3(service_id, job_id):
-    current_app.logger.debug(
-        f"#notify-debug-s3-partitioning CALLING GET_JOB_METADATA with {service_id}, {job_id}"
-    )
+
     obj = get_s3_object(*get_job_location(service_id, job_id))
     return obj.get()["Metadata"]
 

app/celery/provider_tasks.py

@@ -23,9 +23,6 @@ from notifications_utils.clients.redis import total_limit_cache_key
 def deliver_sms(self, notification_id):
     """Branch off to the final step in delivering the notification to sns and get delivery receipts."""
     try:
-        current_app.logger.info(
-            "Start sending SMS for notification id: {}".format(notification_id)
-        )
         notification = notifications_dao.get_notification_by_id(notification_id)
         ansi_green = "\033[32m"
         ansi_reset = "\033[0m"

app/clients/sms/aws_sns.py

@@ -5,10 +5,12 @@ from time import monotonic
 import botocore
 import phonenumbers
 from boto3 import client
+from flask import current_app
 
 from app.clients import AWS_CLIENT_CONFIG
 from app.clients.sms import SmsClient
 from app.cloudfoundry_config import cloud_config
+from app.utils import hilite
 
 
 class AwsSnsClient(SmsClient):
@@ -66,32 +68,13 @@ class AwsSnsClient(SmsClient):
                 }
             }
 
-            default_num = " ".join(self.current_app.config["AWS_US_TOLL_FREE_NUMBER"])
-            if isinstance(sender, str):
-                non_scrubbable = " ".join(sender)
-
-                self.current_app.logger.info(
-                    f"notify-debug-api-1385 sender {non_scrubbable} is a {type(sender)} \
-                        default is a {type(default_num)}"
-                )
-            else:
-                self.current_app.logger.warning(
-                    f"notify-debug-api-1385 sender is type {type(sender)}!! {sender}"
-                )
             if self._valid_sender_number(sender):
-                self.current_app.logger.info(
-                    f"notify-debug-api-1385 use valid sender {non_scrubbable} instead of default {default_num}"
-                )
 
                 attributes["AWS.MM.SMS.OriginationNumber"] = {
                     "DataType": "String",
                     "StringValue": sender,
                 }
             else:
-                self.current_app.logger.info(
-                    f"notify-debug-api-1385 use default {default_num} instead of invalid sender"
-                )
-
                 attributes["AWS.MM.SMS.OriginationNumber"] = {
                     "DataType": "String",
                     "StringValue": self.current_app.config["AWS_US_TOLL_FREE_NUMBER"],
@@ -102,6 +85,7 @@ class AwsSnsClient(SmsClient):
                 response = self._client.publish(
                     PhoneNumber=to, Message=content, MessageAttributes=attributes
                 )
+                current_app.logger.info(hilite(f"send response = {response}"))
             except botocore.exceptions.ClientError as e:
                 self.current_app.logger.exception("An error occurred sending sms")
                 raise str(e)

app/delivery/send_to_providers.py

@@ -7,7 +7,6 @@ from cachetools import TTLCache, cached
 from flask import current_app
 
 from app import (
-    aws_pinpoint_client,
     create_uuid,
     db,
     notification_provider_clients,
@@ -101,10 +100,6 @@ def send_sms_to_provider(notification):
                         notification.job_row_number,
                     )
 
-                # TODO This is temporary to test the capability of validating phone numbers
-                # The future home of the validation is TBD
-                _experimentally_validate_phone_numbers(recipient)
-
                 # TODO current we allow US phone numbers to be uploaded without the country code (1)
                 # This will break certain international phone numbers (Norway, Denmark, East Timor)
                 # When we officially announce support for international numbers, US numbers must contain
@@ -134,9 +129,6 @@ def send_sms_to_provider(notification):
                 # interleave spaces to bypass PII scrubbing since sender number is not PII
                 arr = list(real_sender_number)
                 real_sender_number = " ".join(arr)
-                current_app.logger.info(
-                    f"#notify-debug-api-1701 real sender number going to AWS is {real_sender_number}"
-                )
                 message_id = provider.send_sms(**send_sms_kwargs)
 
                 update_notification_message_id(notification.id, message_id)
@@ -162,18 +154,6 @@ def send_sms_to_provider(notification):
     return message_id
 
 
-def _experimentally_validate_phone_numbers(recipient):
-    if "+" not in recipient:
-        recipient_lookup = f"+{recipient}"
-    else:
-        recipient_lookup = recipient
-    if recipient_lookup in current_app.config["SIMULATED_SMS_NUMBERS"] and os.getenv(
-        "NOTIFY_ENVIRONMENT"
-    ) in ["development", "test"]:
-        current_app.logger.info(hilite("#notify-debug-validate-phone-number fired"))
-        aws_pinpoint_client.validate_phone_number("01", recipient)
-
-
 def _get_verify_code(notification):
     key = f"2facode-{notification.id}".replace(" ", "")
     recipient = redis_store.get(key)

app/job/rest.py

@@ -66,7 +66,9 @@ def get_job_by_service_and_job_id(service_id, job_id):
 @job_blueprint.route("/<job_id>/status", methods=["GET"])
 def get_job_status(service_id, job_id):
     """Lightweight endpoint for polling job status with aggressive caching."""
-    current_app.logger.info(f"Getting job status for service_id={service_id}, job_id={job_id}")
+    current_app.logger.info(
+        f"Getting job status for service_id={service_id}, job_id={job_id}"
+    )
     check_suspicious_id(service_id, job_id)
 
     # Check cache first (10 second TTL)
@@ -86,21 +88,29 @@ def get_job_status(service_id, job_id):
     pending_count = 0
 
     status_mapping = {
-        'sent': ['sent'],
-        'delivered': ['sent'],
-        'failed': ['failed', 'permanent-failure', 'temporary-failure', 'technical-failure', 'virus-scan-failed'],
-        'pending': ['created', 'sending', 'pending', 'pending-virus-check']
+        "sent": ["sent"],
+        "delivered": ["sent"],
+        "failed": [
+            "failed",
+            "permanent-failure",
+            "temporary-failure",
+            "technical-failure",
+            "virus-scan-failed",
+        ],
+        "pending": ["created", "sending", "pending", "pending-virus-check"],
     }
 
     for stat in statistics:
         count = stat[0] if isinstance(stat, tuple) else stat.count
         status = stat[1] if isinstance(stat, tuple) else stat.status
 
-        if status in status_mapping.get('delivered', []) or status in status_mapping.get('sent', []):
+        if status in status_mapping.get(
+            "delivered", []
+        ) or status in status_mapping.get("sent", []):
             sent_count += count
-        elif status in status_mapping.get('failed', []):
+        elif status in status_mapping.get("failed", []):
             failed_count += count
-        elif status in status_mapping.get('pending', []):
+        elif status in status_mapping.get("pending", []):
             pending_count += count
         else:
             if job.processing_finished:
@@ -114,7 +124,7 @@ def get_job_status(service_id, job_id):
         "pending_count": pending_count,
         "total_count": job.notification_count,
         "job_status": job.job_status,
-        "processing_finished": job.processing_finished is not None
+        "processing_finished": job.processing_finished is not None,
     }
 
     if job.processing_finished:
@@ -331,9 +341,6 @@ def create_job(service_id):
     original_file_name = data.get("original_file_name")
     data.update({"service": service_id})
     try:
-        current_app.logger.info(
-            f"#notify-debug-s3-partitioning DATA IN CREATE_JOB: {data}"
-        )
         data.update(**get_job_metadata_from_s3(service_id, data["id"]))
     except KeyError:
         raise InvalidRequest(

app/utils.py

@@ -149,7 +149,6 @@ def debug_not_production(msg):
 def emit_job_update_summary(job):
     from app import socketio
 
-    current_app.logger.info(f"Emitting summary for job {job.id}")
     socketio.emit(
         "job_updated",
         {