merge from main

app/celery/tasks.py

@@ -26,7 +26,7 @@ from app.notifications.process_notifications import persist_notification
 from app.notifications.validators import check_service_over_total_message_limit
 from app.serialised_models import SerialisedService, SerialisedTemplate
 from app.service.utils import service_allowed_to_send_to
-from app.utils import DATETIME_FORMAT, hilite, scrub, utc_now
+from app.utils import DATETIME_FORMAT, hilite, utc_now
 from notifications_utils.recipients import RecipientCSV
 
 
@@ -193,7 +193,7 @@ def save_sms(self, service_id, notification_id, encrypted_notification, sender_i
     if not service_allowed_to_send_to(notification["to"], service, KeyType.NORMAL):
         current_app.logger.info(
             hilite(
-                scrub(f"service not allowed to send to {notification['to']}, aborting")
+                f"service not allowed to send for job_id {notification.get('job', None)}, aborting"
             )
         )
         current_app.logger.debug(
@@ -226,8 +226,11 @@ def save_sms(self, service_id, notification_id, encrypted_notification, sender_i
         )
 
         # Kick off sns process in provider_tasks.py
+        sn = saved_notification
         current_app.logger.info(
-            hilite(scrub(f"Going to deliver sms for recipient: {notification['to']}"))
+            hilite(
+                f"Deliver sms for job_id: {sn.job_id} row_number: {sn.job_row_number}"
+            )
         )
         provider_tasks.deliver_sms.apply_async(
             [str(saved_notification.id)], queue=QueueNames.SEND_SMS

app/clients/cloudwatch/aws_cloudwatch.py

@@ -9,7 +9,7 @@ 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
-from app.utils import hilite, scrub, utc_now
+from app.utils import hilite, utc_now
 
 
 class AwsCloudwatchClient(Client):
@@ -124,7 +124,14 @@ class AwsCloudwatchClient(Client):
             self.warn_if_dev_is_opted_out(
                 message["delivery"]["providerResponse"], notification_id
             )
-            current_app.logger.info(hilite(scrub(f"DELIVERED: {message}")))
+            # Here we map the answer from aws to the message_id.
+            # Previously, in send_to_providers, we mapped the job_id and row number
+            # to the message id.  And on the admin side we mapped the csv filename
+            # to the job_id.  So by tracing through all the logs we can go:
+            # filename->job_id->message_id->what really happened
+            current_app.logger.info(
+                hilite(f"DELIVERED: {message} for message_id {message_id}")
+            )
             return (
                 "success",
                 message["delivery"]["providerResponse"],
@@ -142,7 +149,9 @@ class AwsCloudwatchClient(Client):
                 message["delivery"]["providerResponse"], notification_id
             )
 
-            current_app.logger.info(hilite(scrub(f"FAILED: {message}")))
+            current_app.logger.info(
+                hilite(f"FAILED: {message} for message_id {message_id}")
+            )
             return (
                 "failure",
                 message["delivery"]["providerResponse"],

app/delivery/send_to_providers.py

@@ -13,7 +13,7 @@ from app.dao.provider_details_dao import get_provider_details_by_notification_ty
 from app.enums import BrandType, KeyType, NotificationStatus, NotificationType
 from app.exceptions import NotificationTechnicalFailureException
 from app.serialised_models import SerialisedService, SerialisedTemplate
-from app.utils import hilite, scrub, utc_now
+from app.utils import hilite, utc_now
 from notifications_utils.template import (
     HTMLEmailTemplate,
     PlainTextEmailTemplate,
@@ -89,7 +89,7 @@ def send_sms_to_provider(notification):
                 except Exception:
                     # It is our 2facode, maybe
                     key = f"2facode-{notification.id}".replace(" ", "")
-                    recipient = redis_store.raw_get(key)
+                    recipient = redis_store.get(key)
 
                     if recipient:
                         recipient = recipient.decode("utf-8")
@@ -113,15 +113,18 @@ def send_sms_to_provider(notification):
                 message_id = provider.send_sms(**send_sms_kwargs)
                 current_app.logger.info(f"got message_id {message_id}")
             except Exception as e:
-                msg = f"FAILED sending message for this recipient: {recipient} to sms"
-                current_app.logger.error(hilite(scrub(f"{msg} {e}")))
+                n = notification
+                msg = f"FAILED send to sms, job_id: {n.job_id} row_number {n.job_row_number} message_id {message_id}"
+                current_app.logger.error(hilite(f"{msg} {e}"))
 
                 notification.billable_units = template.fragment_count
                 dao_update_notification(notification)
                 raise e
             else:
-                msg = f"Sending message for this recipient: {recipient} to sms"
-                current_app.logger.info(hilite(scrub(msg)))
+                # Here we map the job_id and row number to the aws message_id
+                n = notification
+                msg = f"Send to aws for job_id {n.job_id} row_number {n.job_row_number} message_id {message_id}"
+                current_app.logger.info(hilite(msg))
                 notification.billable_units = template.fragment_count
                 update_notification_to_sending(notification, provider)
     return message_id

app/notifications/process_notifications.py

@@ -12,7 +12,7 @@ from app.dao.notifications_dao import (
 from app.enums import KeyType, NotificationStatus, NotificationType
 from app.errors import BadRequestError
 from app.models import Notification
-from app.utils import hilite, scrub, utc_now
+from app.utils import hilite, utc_now
 from notifications_utils.recipients import (
     format_email_address,
     get_international_phone_info,
@@ -112,7 +112,7 @@ def persist_notification(
         )
         current_app.logger.info(
             hilite(
-                scrub(f"Persisting notification with recipient {formatted_recipient}")
+                f"Persisting notification with job_id: {job_id} row_number: {job_row_number}"
             )
         )
         recipient_info = get_international_phone_info(formatted_recipient)

app/user/rest.py

@@ -361,7 +361,7 @@ def create_2fa_code(
     saved_notification.personalisation = personalisation
     key = f"2facode-{saved_notification.id}".replace(" ", "")
     recipient = str(recipient)
-    redis_store.raw_set(key, recipient, ex=60 * 60)
+    redis_store.set(key, recipient, ex=60 * 60)
 
     # Assume that we never want to observe the Notify service's research mode
     # setting for this notification - we still need to be able to log into the

app/utils.py

@@ -1,4 +1,3 @@
-import re
 from datetime import datetime, timedelta, timezone
 
 from flask import url_for
@@ -145,15 +144,3 @@ def naive_utcnow():
 
 def utc_now():
     return naive_utcnow()
-
-
-def scrub(msg):
-    # Eventually we want to scrub all messages in all logs for phone numbers
-    # and email addresses, masking them.  Ultimately this will probably get
-    # refactored into a 'SafeLogger' subclass or something, but let's start here
-    # with phones.
-    phones = re.findall("(?:\\+ *)?\\d[\\d\\- ]{7,}\\d", msg)
-    phones = [phone.replace("-", "").replace(" ", "") for phone in phones]
-    for phone in phones:
-        msg = msg.replace(phone, f"1XXXXX{phone[-5:]}")
-    return msg