diff --git a/.talismanrc b/.talismanrc index c0f9368bde..d8bf3b3542 100644 --- a/.talismanrc +++ b/.talismanrc @@ -54,7 +54,7 @@ fileignoreconfig: - filename: lambda_functions/va_profile/va_profile_opt_in_out_lambda.py checksum: a05165537ffbfac90000c5d04d8628251d771f6d1334c91c3aed28bf6c32368c - filename: poetry.lock - checksum: 375493d3f6a4c5d0530b40cc06c15f68cd87f1e929f3b73ec456f414a1fc2d57 + checksum: 0d77076ee13746c0b551ea8bd40cf15a6f92277102b6d2020bf87a39394af49c - filename: scripts/trigger_task.py checksum: 0e9d244dbe285de23fc84bb643407963dacf7d25a3358373f01f6272fb217778 - filename: tests/README.md diff --git a/app/authentication/auth.py b/app/authentication/auth.py index e804713266..2822edf5ab 100644 --- a/app/authentication/auth.py +++ b/app/authentication/auth.py @@ -1,5 +1,6 @@ import functools from typing import Callable +from uuid import uuid4 from flask import request, current_app, g from flask_jwt_extended import verify_jwt_in_request, current_user @@ -165,6 +166,8 @@ def wrapper( def validate_service_api_key_auth(): # noqa: C901 + # Set the id here for tracking purposes - becomes notification id + g.request_id = str(uuid4()) request_helper.check_proxy_header_before_request() auth_token = get_auth_token(request) diff --git a/app/celery/celery.py b/app/celery/celery.py index 88e72af7c8..a5e950b493 100644 --- a/app/celery/celery.py +++ b/app/celery/celery.py @@ -1,7 +1,8 @@ +import logging import time -from celery import Celery, Task -from celery.signals import worker_process_shutdown, worker_shutting_down, worker_process_init +from celery import Celery, signals, Task +from celery.signals import task_prerun, task_postrun, worker_process_shutdown, worker_shutting_down, worker_process_init from flask import current_app @@ -90,3 +91,84 @@ def init_app( ) self.conf.update(app.config['CELERY_SETTINGS']) + + +class CeleryRequestIdFilter(logging.Filter): + def __init__(self, request_id: str, name=''): + self.request_id = request_id + super().__init__(name) + + def filter(self, record) -> bool: + """Determine if the specified record is to be logged. + + Args: + record (LogRecord): The log record representing this log + + Returns: + bool: If the record should be logged + """ + record.requestId = self.request_id + return True + + +def _get_request_id(task_id: str, *args, **kwargs) -> str: + """Get the notification id if it is available, otherwise use the task id. + + Args: + task_id (str): Celery task id + + Returns: + str: The request_id to use for all logging related to this task + """ + request_id = '' + try: + # Depending on the call it may be an arg + if len(args) > 1: + # Example: tasks = [deliver_email.si(notification_id=str(notification.id))]; chain(*tasks).apply_async() + request_id = args[1].get('kwargs', {}).get('notification_id', '') + + # or kwarg - separated for readability + if not request_id: + # Example: deliver_email.apply_async(args=(),kwargs={'notification_id':str(notification.id)}) + request_id = kwargs.get('kwargs', {}).get('notification_id', task_id) + except AttributeError: + logger = logging.getLogger() + logger.exception('celery prerun args: %s | kwargs: %s | task_id: %s', args, kwargs, task_id) + request_id = task_id + return request_id + + +@task_prerun.connect +def add_id_to_logger(task_id, task, *args, **kwargs): + """Create filter for all logs related to this task. + + Args: + task_id (str): The celery task id + task (Task): The celery Task object + """ + request_id = _get_request_id(task_id, args, kwargs) + current_app.logger.addFilter(CeleryRequestIdFilter(request_id, f'celery-{request_id}')) + + +@task_postrun.connect +def id_cleanup_logger(task_id, task, *args, **kwargs): + """Removes previously created filters when they are no longer necessary. + + Args: + task_id (str): The celery task id + task (Task): The celery Task object + """ + request_id = _get_request_id(task_id, args, kwargs) + for filter in current_app.logger.filters: + if filter.name == f'celery-{request_id}': + current_app.logger.removeFilter(filter) + + +@signals.setup_logging.connect +def remove_log_handler(*args, **kwargs) -> None: + """Remove Celery log handler. + + Just by using .connect this will disable the logger hijacking. + https://docs.celeryq.dev/en/stable/userguide/signals.html#setup-logging + """ + pass diff --git a/app/celery/contact_information_tasks.py b/app/celery/contact_information_tasks.py index f8e35a8909..433db7b186 100644 --- a/app/celery/contact_information_tasks.py +++ b/app/celery/contact_information_tasks.py @@ -140,7 +140,7 @@ def handle_lookup_contact_info_exception( f"Can't proceed after querying VA Profile for contact information for {notification.id}. " 'Stopping execution of following tasks. Notification has been updated to permanent-failure.' ) - current_app.logger.warning('%s - %s: %s', e.__class__.__name__, str(e), message) + current_app.logger.info('%s - %s: %s', e.__class__.__name__, str(e), message) update_notification_status_by_id( notification.id, NOTIFICATION_PERMANENT_FAILURE, status_reason=e.failure_reason @@ -149,11 +149,11 @@ def handle_lookup_contact_info_exception( # Expected chain termination lookup_task.request.chain = None elif isinstance(e, (VAProfileIDNotFoundException, VAProfileNonRetryableException)): - current_app.logger.exception(e) message = ( f'The task lookup_contact_info failed for notification {notification.id}. ' 'Notification has been updated to permanent-failure' ) + current_app.logger.info(message) update_notification_status_by_id( notification.id, NOTIFICATION_PERMANENT_FAILURE, status_reason=e.failure_reason ) diff --git a/app/celery/process_ses_receipts_tasks.py b/app/celery/process_ses_receipts_tasks.py index f8e02788ca..6479349ea3 100644 --- a/app/celery/process_ses_receipts_tasks.py +++ b/app/celery/process_ses_receipts_tasks.py @@ -1,4 +1,5 @@ from datetime import datetime, timedelta +from uuid import uuid4 import iso8601 from app.celery.common import log_notification_total_time @@ -330,6 +331,7 @@ def process_ses_smtp_results( created_at=headers['date'], status=notification_status, reference=ses_message['mail']['messageId'], + notification_id=uuid4(), ) if notification_type == 'Complaint': diff --git a/app/celery/service_callback_tasks.py b/app/celery/service_callback_tasks.py index 02bac6a1c0..63add27b50 100644 --- a/app/celery/service_callback_tasks.py +++ b/app/celery/service_callback_tasks.py @@ -344,7 +344,13 @@ def check_and_queue_service_callback_task(notification: Notification, payload=No # build dictionary for notification notification_data = create_delivery_status_callback_data(notification, service_callback_api, payload) send_delivery_status_to_service.apply_async( - [service_callback_api.id, str(notification.id), notification_data], queue=QueueNames.CALLBACKS + args=(), + kwargs={ + 'service_callback_id': service_callback_api.id, + 'notification_id': str(notification.id), + 'encrypted_status_update': notification_data, + }, + queue=QueueNames.CALLBACKS, ) else: current_app.logger.debug( @@ -367,6 +373,7 @@ def send_delivery_status_from_notification( callback_signature: str, callback_url: str, notification_data: dict[str, str], + notification_id: str, ) -> None: """ Send a delivery status notification to the given callback URL. @@ -393,7 +400,7 @@ def send_delivery_status_from_notification( response.raise_for_status() except Timeout as e: current_app.logger.warning( - 'Timeout error sending callback for notification %s, url %s', notification_data['id'], callback_url + 'Timeout error sending callback for notification %s, url %s', notification_id, callback_url ) raise AutoRetryException(f'Found {type(e).__name__}, autoretrying...', e) except RequestException as e: @@ -403,7 +410,7 @@ def send_delivery_status_from_notification( if e.response is not None and e.response.status_code == 429 or e.response.status_code >= 500: current_app.logger.warning( 'Retryable error sending callback for notification %s, url %s | status code: %s, exception: %s', - notification_data.get('id'), + notification_id, callback_url, e.response.status_code if e.response is not None else 'unknown', str(e), @@ -412,7 +419,7 @@ def send_delivery_status_from_notification( else: current_app.logger.warning( 'Non-retryable error sending callback for notification %s, url %s | status code: %s, exception: %s', - notification_data.get('id'), + notification_id, callback_url, e.response.status_code if e.response is not None else 'unknown', str(e), @@ -421,7 +428,7 @@ def send_delivery_status_from_notification( current_app.logger.debug( 'Callback successfully sent for notification %s, url: %s | status code: %d', - notification_data.get('id'), + notification_id, callback_url, response.status_code, ) @@ -440,7 +447,13 @@ def check_and_queue_notification_callback_task(notification: Notification) -> No callback_signature = generate_callback_signature(notification.api_key_id, notification_data) send_delivery_status_from_notification.apply_async( - [callback_signature, notification.callback_url, notification_data], + args=(), + kwargs={ + 'callback_signature': callback_signature, + 'callback_url': notification.callback_url, + 'notification_data': notification_data, + 'notification_id': str(notification.id), + }, queue=QueueNames.CALLBACKS, ) diff --git a/app/celery/tasks.py b/app/celery/tasks.py index 0564ce2d83..504b3f301c 100644 --- a/app/celery/tasks.py +++ b/app/celery/tasks.py @@ -228,12 +228,14 @@ def save_sms( if is_feature_enabled(FeatureFlag.SMS_SENDER_RATE_LIMIT_ENABLED) and sms_sender and sms_sender.rate_limit: provider_tasks.deliver_sms_with_rate_limiting.apply_async( - [str(saved_notification.id)], + args=(), + kwargs={'notification_id': str(saved_notification.id)}, queue=QueueNames.SEND_SMS if not service.research_mode else QueueNames.NOTIFY, ) else: provider_tasks.deliver_sms.apply_async( - [str(saved_notification.id)], + args=(), + kwargs={'notification_id': str(saved_notification.id)}, queue=QueueNames.SEND_SMS if not service.research_mode else QueueNames.NOTIFY, ) @@ -289,7 +291,8 @@ def save_email( ) provider_tasks.deliver_email.apply_async( - [str(saved_notification.id)], + args=(), + kwargs={'notification_id': str(saved_notification.id)}, queue=QueueNames.SEND_EMAIL if not service.research_mode else QueueNames.NOTIFY, ) diff --git a/app/integrations/comp_and_pen/scheduled_message_helpers.py b/app/integrations/comp_and_pen/scheduled_message_helpers.py index 584257c91a..c86f3350b7 100644 --- a/app/integrations/comp_and_pen/scheduled_message_helpers.py +++ b/app/integrations/comp_and_pen/scheduled_message_helpers.py @@ -1,3 +1,5 @@ +from uuid import uuid4 + import boto3 from boto3.dynamodb.conditions import Attr from flask import current_app @@ -179,6 +181,7 @@ def send_comp_and_pen_sms( sms_sender_id=sms_sender_id, recipient=recipient, recipient_item=recipient_item, + notification_id=uuid4(), ) except Exception as e: current_app.logger.critical( diff --git a/app/notifications/process_notifications.py b/app/notifications/process_notifications.py index c04ca09c58..33327b0127 100644 --- a/app/notifications/process_notifications.py +++ b/app/notifications/process_notifications.py @@ -1,7 +1,7 @@ import uuid from datetime import datetime -from flask import current_app +from flask import current_app, g from celery import chain from notifications_utils.clients import redis @@ -92,7 +92,9 @@ def persist_notification( notification_created_at = created_at or datetime.utcnow() if notification_id is None: - notification_id = uuid.uuid4() + # utils sets this so we can unify logging + # Any internal code that calls this method in a loop cannot use g (Example: send_notification_to_service_users) + notification_id = g.request_id if getattr(g, 'request_id', '') else uuid.uuid4() notification = Notification( id=notification_id, @@ -170,12 +172,14 @@ def send_notification_to_queue( if communication_item_id is not None: if recipient_id_type != IdentifierType.VA_PROFILE_ID.value: - tasks.append(lookup_va_profile_id.si(notification.id).set(queue=QueueNames.LOOKUP_VA_PROFILE_ID)) + tasks.append( + lookup_va_profile_id.si(notification_id=notification.id).set(queue=QueueNames.LOOKUP_VA_PROFILE_ID) + ) # Including sms_sender_id is necessary so the correct sender can be chosen. # https://docs.celeryq.dev/en/v4.4.7/userguide/canvas.html#immutability deliver_task, queue = _get_delivery_task(notification, research_mode, queue, sms_sender_id) - tasks.append(deliver_task.si(str(notification.id), sms_sender_id).set(queue=queue)) + tasks.append(deliver_task.si(notification_id=str(notification.id), sms_sender_id=sms_sender_id).set(queue=queue)) try: # This executes the task list. Each task calls a function that makes a request to @@ -261,15 +265,15 @@ def send_to_queue_for_recipient_info_based_on_recipient_identifier( else: tasks = [ - lookup_va_profile_id.si(notification.id).set(queue=QueueNames.LOOKUP_VA_PROFILE_ID), + lookup_va_profile_id.si(notification_id=notification.id).set(queue=QueueNames.LOOKUP_VA_PROFILE_ID), send_va_onsite_notification_task.s(str(notification.template.id), onsite_enabled).set( queue=QueueNames.NOTIFY ), ] - tasks.append(lookup_contact_info.si(notification.id).set(queue=QueueNames.LOOKUP_CONTACT_INFO)) + tasks.append(lookup_contact_info.si(notification_id=notification.id).set(queue=QueueNames.LOOKUP_CONTACT_INFO)) deliver_task, deliver_queue = _get_delivery_task(notification) - tasks.append(deliver_task.si(notification.id).set(queue=deliver_queue)) + tasks.append(deliver_task.si(notification_id=notification.id).set(queue=deliver_queue)) try: # This executes the task list. Each task calls a function that makes a request to diff --git a/app/notifications/send_notifications.py b/app/notifications/send_notifications.py index 05ac4b6a0b..d5e01beeb2 100644 --- a/app/notifications/send_notifications.py +++ b/app/notifications/send_notifications.py @@ -60,6 +60,7 @@ def send_notification_bypass_route( sms_sender_id: str = None, recipient_item: dict = None, api_key_type: str = KEY_TYPE_NORMAL, + notification_id: UUID | None = None, ): """ This will create a notification and add it to the proper celery queue using the given parameters. @@ -118,6 +119,7 @@ def send_notification_bypass_route( recipient_identifier=recipient_item, sms_sender_id=sms_sender_id, reply_to_text=reply_to_text, + notification_id=notification_id, ) if recipient_item is not None: diff --git a/app/service/sender.py b/app/service/sender.py index 429740d98c..bf49c5d3e7 100644 --- a/app/service/sender.py +++ b/app/service/sender.py @@ -1,3 +1,5 @@ +from uuid import uuid4 + from flask import current_app from app.config import QueueNames @@ -32,6 +34,7 @@ def send_notification_to_service_users( api_key_id=None, key_type=KEY_TYPE_NORMAL, reply_to_text=notify_service.get_default_reply_to_email_address(), + notification_id=uuid4(), ) send_notification_to_queue(notification, False, queue=QueueNames.NOTIFY) diff --git a/app/va/va_profile/va_profile_client.py b/app/va/va_profile/va_profile_client.py index 532cc522b8..178096e7fa 100644 --- a/app/va/va_profile/va_profile_client.py +++ b/app/va/va_profile/va_profile_client.py @@ -138,7 +138,7 @@ def get_mobile_telephone_from_contact_info(self, contact_info: ContactInformatio self.statsd_client.incr('clients.va-profile.get-telephone.failure') self.statsd_client.incr(f'clients.va-profile.get-{self.PHONE_BIO_TYPE}.no-{self.PHONE_BIO_TYPE}') raise NoContactInfoException( - f'No {self.PHONE_BIO_TYPE} in response for VA Profile ID {contact_info.get("vaProfileId")}' + f'No {self.PHONE_BIO_TYPE} in response for VA Profile ID {contact_info.get("vaProfileId")} ' f'with AuditId {contact_info.get(self.TX_AUDIT_ID)}' ) diff --git a/poetry.lock b/poetry.lock index c37bf29d20..79585b25ab 100644 --- a/poetry.lock +++ b/poetry.lock @@ -2254,7 +2254,7 @@ statsd = ">=3.3.0" type = "git" url = "https://github.com/department-of-veterans-affairs/notification-utils.git" reference = "HEAD" -resolved_reference = "5ab78d95ba2350be1834fd7b4bee7aca5d9c94ae" +resolved_reference = "ab7d6c4b0e04032de415a864c3d2fcef552881bc" [[package]] name = "notifications-python-client" diff --git a/tests/app/celery/test_nightly_tasks.py b/tests/app/celery/test_nightly_tasks.py index e5e0154f17..abc34c8bc2 100644 --- a/tests/app/celery/test_nightly_tasks.py +++ b/tests/app/celery/test_nightly_tasks.py @@ -290,7 +290,15 @@ def test_timeout_notifications_sends_status_update_to_service( notify_db_session.session.refresh(notification) encrypted_data = create_delivery_status_callback_data(notification, callback_api) - mocked.assert_called_with([callback_id, str(notification.id), encrypted_data], queue=QueueNames.CALLBACKS) + mocked.assert_called_with( + args=(), + kwargs={ + 'service_callback_id': callback_id, + 'notification_id': str(notification.id), + 'encrypted_status_update': encrypted_data, + }, + queue=QueueNames.CALLBACKS, + ) def test_send_daily_performance_stats_calls_does_not_send_if_inactive(client, mocker): diff --git a/tests/app/celery/test_process_ses_receipts_tasks.py b/tests/app/celery/test_process_ses_receipts_tasks.py index aa5152555e..63d6db3db9 100644 --- a/tests/app/celery/test_process_ses_receipts_tasks.py +++ b/tests/app/celery/test_process_ses_receipts_tasks.py @@ -122,7 +122,13 @@ def test_ses_callback_should_call_send_delivery_status_to_service( encrypted_data = create_delivery_status_callback_data(updated_notification, service_callback) send_mock.assert_called_once_with( - [service_callback.id, str(notification.id), encrypted_data], queue='service-callbacks' + args=(), + kwargs={ + 'service_callback_id': service_callback.id, + 'notification_id': str(notification.id), + 'encrypted_status_update': encrypted_data, + }, + queue='service-callbacks', ) diff --git a/tests/app/celery/test_scheduled_tasks.py b/tests/app/celery/test_scheduled_tasks.py index d376c1bd9e..3fcd240704 100644 --- a/tests/app/celery/test_scheduled_tasks.py +++ b/tests/app/celery/test_scheduled_tasks.py @@ -132,7 +132,7 @@ def test_should_send_all_scheduled_notifications_to_deliver_queue(mocker, sample args, _ = mocked_chain.call_args for called_task, expected_task in zip(args, ['send-sms-tasks']): assert called_task.options['queue'] == expected_task - assert called_task.args[0] == str(message_to_deliver.id) + assert called_task.kwargs.get('notification_id') == str(message_to_deliver.id) scheduled_notifications = dao_get_scheduled_notifications() assert not scheduled_notifications @@ -321,11 +321,11 @@ def test_replay_created_notifications( ) replay_created_notifications() - (result_notification_id, _), result_queue = mocked.call_args.args - assert result_notification_id == str(old_notification.id) - assert mocked.call_args.kwargs['queue'] == f'send-{notification_type}-tasks' mocked.assert_called_once() + args, kwargs = mocked.call_args + assert args[1] == {'notification_id': str(old_notification.id), 'sms_sender_id': None} + assert kwargs['queue'] == f'send-{notification_type}-tasks' @pytest.mark.serial diff --git a/tests/app/celery/test_service_callback_tasks.py b/tests/app/celery/test_service_callback_tasks.py index aa9ea6e238..509c1157ad 100644 --- a/tests/app/celery/test_service_callback_tasks.py +++ b/tests/app/celery/test_service_callback_tasks.py @@ -334,7 +334,13 @@ def test_check_and_queue_callback_task_queues_task_if_service_callback_api_exist mock_create_callback_data.assert_called_once_with(mock_notification, mock_service_callback_api, {}) mock_send_delivery_status.assert_called_once_with( - [mock_service_callback_api.id, str(mock_notification.id), mock_notification_data], queue=QueueNames.CALLBACKS + args=(), + kwargs={ + 'service_callback_id': mock_service_callback_api.id, + 'notification_id': str(mock_notification.id), + 'encrypted_status_update': mock_notification_data, + }, + queue=QueueNames.CALLBACKS, ) @@ -602,7 +608,13 @@ def test_check_and_queue_notification_callback_task_queues_task_with_proper_data check_and_queue_notification_callback_task(notification) mock_delivery_status_from_notification.assert_called_once_with( - [callback_signature_value, test_url, notification_data], + args=(), + kwargs={ + 'callback_signature': callback_signature_value, + 'callback_url': test_url, + 'notification_data': notification_data, + 'notification_id': str(notification.id), + }, queue=QueueNames.CALLBACKS, ) @@ -610,10 +622,11 @@ def test_check_and_queue_notification_callback_task_queues_task_with_proper_data def test_send_delivery_status_from_notification_posts_https_request_to_service(rmock): callback_signature = '6842b32e800372de4079e20d6e7e753bad182e44f7f3e19a46fd8509889a0014' callback_url = 'https://test_url.com/' + notification_id = str(uuid.uuid4()) notification_data = {'callback_url': callback_url} rmock.post(callback_url, json=notification_data, status_code=200) - send_delivery_status_from_notification(callback_signature, callback_url, notification_data) + send_delivery_status_from_notification(callback_signature, callback_url, notification_data, notification_id) assert rmock.call_count == 1 assert rmock.request_history[0].url == callback_url @@ -626,19 +639,21 @@ def test_send_delivery_status_from_notification_posts_https_request_to_service(r def test_send_delivery_status_from_notification_raises_auto_retry_exception(rmock, status_code): callback_signature = '6842b32e800372de4079e20d6e7e753bad182e44f7f3e19a46fd8509889a0014' callback_url = 'https://test_url.com/' + notification_id = str(uuid.uuid4()) notification_data = {'callback_url': callback_url} rmock.post(callback_url, json=notification_data, status_code=status_code) with pytest.raises(AutoRetryException): - send_delivery_status_from_notification(callback_signature, callback_url, notification_data) + send_delivery_status_from_notification(callback_signature, callback_url, notification_data, notification_id) @pytest.mark.parametrize('status_code', [400, 403, 404]) def test_send_delivery_status_from_notification_raises_non_retryable_exception(rmock, status_code): callback_signature = '6842b32e800372de4079e20d6e7e753bad182e44f7f3e19a46fd8509889a0014' callback_url = 'https://test_url.com/' + notification_id = str(uuid.uuid4()) notification_data = {'callback_url': callback_url} rmock.post(callback_url, json=notification_data, status_code=status_code) with pytest.raises(NonRetryableException): - send_delivery_status_from_notification(callback_signature, callback_url, notification_data) + send_delivery_status_from_notification(callback_signature, callback_url, notification_data, notification_id) diff --git a/tests/app/celery/test_tasks.py b/tests/app/celery/test_tasks.py index 95cb0dedeb..894f9a91f7 100644 --- a/tests/app/celery/test_tasks.py +++ b/tests/app/celery/test_tasks.py @@ -495,7 +495,11 @@ def test_should_send_template_to_correct_sms_task_and_persist( assert persisted_notification.personalisation == {'name': 'Jo'} assert persisted_notification._personalisation == encryption.encrypt({'name': 'Jo'}) assert persisted_notification.notification_type == SMS_TYPE - mocked_deliver_sms.assert_called_once_with([str(persisted_notification.id)], queue='send-sms-tasks') + mocked_deliver_sms.assert_called_once_with( + args=(), + kwargs={'notification_id': str(persisted_notification.id)}, + queue='send-sms-tasks', + ) def test_should_put_save_sms_task_in_research_mode_queue_if_research_mode_service( @@ -520,7 +524,9 @@ def test_should_put_save_sms_task_in_research_mode_queue_if_research_mode_servic persisted_notification = notify_db_session.session.get(Notification, notification_id) provider_tasks.deliver_sms.apply_async.assert_called_once_with( - [str(persisted_notification.id)], queue='notify-internal-tasks' + args=(), + kwargs={'notification_id': str(persisted_notification.id)}, + queue='notify-internal-tasks', ) assert mocked_deliver_sms.called @@ -565,7 +571,9 @@ def test_should_save_sms_if_restricted_service_and_valid_number( assert not persisted_notification.personalisation assert persisted_notification.notification_type == SMS_TYPE provider_tasks.deliver_sms.apply_async.assert_called_once_with( - [str(persisted_notification.id)], queue='send-sms-tasks' + args=(), + kwargs={'notification_id': str(persisted_notification.id)}, + queue='send-sms-tasks', ) @@ -600,7 +608,11 @@ def test_save_sms_should_call_deliver_sms_with_rate_limiting_if_sender_id_provid notification2 = notify_db_session.session.get(Notification, notification_id) assert notification2 is not None - deliver_sms.assert_called_once_with([str(notification_id)], queue='send-sms-tasks') + deliver_sms.assert_called_once_with( + args=(), + kwargs={'notification_id': str(notification_id)}, + queue='send-sms-tasks', + ) def test_save_email_should_save_default_email_reply_to_text_on_notification( @@ -739,7 +751,11 @@ def test_should_put_save_email_task_in_research_mode_queue_if_research_mode_serv persisted_notification = notify_db_session.session.get(Notification, notification_id) provider_tasks.deliver_email.apply_async.assert_called_once_with( - [str(persisted_notification.id)], queue='notify-internal-tasks' + args=(), + kwargs={ + 'notification_id': str(persisted_notification.id), + }, + queue='notify-internal-tasks', ) @@ -778,9 +794,10 @@ def test_should_save_sms_template_to_and_persist_with_job_id( assert persisted_notification.api_key_id is None assert persisted_notification.key_type == KEY_TYPE_NORMAL assert persisted_notification.notification_type == SMS_TYPE - provider_tasks.deliver_sms.apply_async.assert_called_once_with( - [str(persisted_notification.id)], queue='send-sms-tasks' + args=(), + kwargs={'notification_id': str(persisted_notification.id)}, + queue='send-sms-tasks', ) @@ -857,10 +874,11 @@ def test_should_use_email_template_and_persist( assert persisted_notification.notification_type == EMAIL_TYPE provider_tasks.deliver_email.apply_async.assert_called_once_with( - [str(persisted_notification.id)], queue='send-email-tasks' + args=(), kwargs={'notification_id': str(persisted_notification.id)}, queue='send-email-tasks' ) +@pytest.mark.serial def test_save_email_should_use_template_version_from_job_not_latest( notify_db_session, sample_template, @@ -884,6 +902,7 @@ def test_save_email_should_use_template_version_from_job_not_latest( notification_id = uuid4() + # Intermittently makes the status 'technical-failure' save_email( template.service_id, notification_id, @@ -901,7 +920,9 @@ def test_save_email_should_use_template_version_from_job_not_latest( assert not persisted_notification.sent_by assert persisted_notification.notification_type == EMAIL_TYPE provider_tasks.deliver_email.apply_async.assert_called_once_with( - [str(persisted_notification.id)], queue='send-email-tasks' + args=(), + kwargs={'notification_id': str(persisted_notification.id)}, + queue='send-email-tasks', ) @@ -939,7 +960,11 @@ def test_should_use_email_template_subject_placeholders( assert persisted_notification.personalisation == {'name': 'Jo'} assert not persisted_notification.reference assert persisted_notification.notification_type == EMAIL_TYPE - provider_tasks.deliver_email.apply_async.assert_called_once_with([str(notification_id)], queue='send-email-tasks') + provider_tasks.deliver_email.apply_async.assert_called_once_with( + args=(), + kwargs={'notification_id': str(notification_id)}, + queue='send-email-tasks', + ) def test_save_email_uses_the_reply_to_text_when_provided( @@ -1033,7 +1058,9 @@ def test_should_use_email_template_and_persist_without_personalisation( assert not persisted_notification.reference assert persisted_notification.notification_type == EMAIL_TYPE provider_tasks.deliver_email.apply_async.assert_called_once_with( - [str(persisted_notification.id)], queue='send-email-tasks' + args=(), + kwargs={'notification_id': str(persisted_notification.id)}, + queue='send-email-tasks', ) diff --git a/tests/app/integrations/comp_and_pen/test_scheduled_message_helpers.py b/tests/app/integrations/comp_and_pen/test_scheduled_message_helpers.py index 44b4533337..38784356f8 100644 --- a/tests/app/integrations/comp_and_pen/test_scheduled_message_helpers.py +++ b/tests/app/integrations/comp_and_pen/test_scheduled_message_helpers.py @@ -1,4 +1,5 @@ from decimal import Decimal +from uuid import uuid4 import pytest @@ -141,6 +142,8 @@ def test_ut_send_scheduled_comp_and_pen_sms_calls_send_notification_with_recipie recipient_item = {'id_type': IdentifierType.VA_PROFILE_ID.value, 'id_value': '123'} mocker.patch('app.celery.scheduled_tasks.is_feature_enabled', return_value=True) + notification_id = uuid4() + mocker.patch('app.integrations.comp_and_pen.scheduled_message_helpers.uuid4', return_value=notification_id) service: Service = sample_service() template = sample_template() @@ -169,6 +172,7 @@ def test_ut_send_scheduled_comp_and_pen_sms_calls_send_notification_with_recipie sms_sender_id=sms_sender_id, recipient=None, recipient_item=recipient_item, + notification_id=notification_id, ) @@ -198,6 +202,8 @@ def test_ut_send_scheduled_comp_and_pen_sms_formatted_amount_correctly( ] recipient_item = {'id_type': IdentifierType.VA_PROFILE_ID.value, 'id_value': '123'} + notification_id = uuid4() + mocker.patch('app.integrations.comp_and_pen.scheduled_message_helpers.uuid4', return_value=notification_id) mocker.patch('app.celery.scheduled_tasks.is_feature_enabled', return_value=True) @@ -226,6 +232,7 @@ def test_ut_send_scheduled_comp_and_pen_sms_formatted_amount_correctly( sms_sender_id=sms_sender_id, recipient=None, recipient_item=recipient_item, + notification_id=notification_id, ) @@ -248,6 +255,8 @@ def test_ut_send_scheduled_comp_and_pen_sms_payment_amount_key_does_not_exist( recipient_item = {'id_type': IdentifierType.VA_PROFILE_ID.value, 'id_value': '123'} mocker.patch('app.celery.scheduled_tasks.is_feature_enabled', return_value=True) + notification_id = uuid4() + mocker.patch('app.integrations.comp_and_pen.scheduled_message_helpers.uuid4', return_value=notification_id) service = sample_service() template = sample_template() @@ -274,4 +283,5 @@ def test_ut_send_scheduled_comp_and_pen_sms_payment_amount_key_does_not_exist( sms_sender_id=sms_sender_id, recipient=None, recipient_item=recipient_item, + notification_id=notification_id, ) diff --git a/tests/app/notifications/rest/test_send_notification.py b/tests/app/notifications/rest/test_send_notification.py index 7778b8d4b5..329478642d 100644 --- a/tests/app/notifications/rest/test_send_notification.py +++ b/tests/app/notifications/rest/test_send_notification.py @@ -405,8 +405,6 @@ def test_should_send_email_to_anyone_with_test_key( limit, ): mocked = mocker.patch('app.celery.provider_tasks.deliver_email.apply_async') - mocked_uuid = str(uuid4()) - mocker.patch('app.notifications.process_notifications.uuid.uuid4', return_value=mocked_uuid) template = sample_template(template_type=EMAIL_TYPE) api_key = sample_api_key(service=template.service, key_type=KEY_TYPE_TEST) @@ -427,8 +425,7 @@ def test_should_send_email_to_anyone_with_test_key( mocked.assert_called_once() result_notification_id, result_queue = mocked.call_args - result_id, *rest = result_notification_id[0] - assert result_id == mocked_uuid + assert result_notification_id[1].get('notification_id') is not None assert result_queue['queue'] == 'notify-internal-tasks' # Teardown diff --git a/tests/app/notifications/test_process_client_response.py b/tests/app/notifications/test_process_client_response.py index b74ad46eb1..0d3a1bb17b 100644 --- a/tests/app/notifications/test_process_client_response.py +++ b/tests/app/notifications/test_process_client_response.py @@ -65,7 +65,15 @@ def test_outcome_statistics_called_for_successful_callback( assert success == 'MMG callback succeeded. reference {} updated'.format(str(reference)) assert error is None encrypted_data = create_delivery_status_callback_data(notification, callback_api) - send_mock.assert_called_once_with([callback_id, str(notification.id), encrypted_data], queue='service-callbacks') + send_mock.assert_called_once_with( + args=(), + kwargs={ + 'service_callback_id': callback_id, + 'notification_id': str(notification.id), + 'encrypted_status_update': encrypted_data, + }, + queue='service-callbacks', + ) def test_sms_resonse_does_not_call_send_callback_if_no_db_entry( diff --git a/tests/app/notifications/test_process_notifications.py b/tests/app/notifications/test_process_notifications.py index 4b9780796d..e494f1acef 100644 --- a/tests/app/notifications/test_process_notifications.py +++ b/tests/app/notifications/test_process_notifications.py @@ -380,8 +380,7 @@ def test_send_notification_to_queue_with_no_recipient_identifiers( args, _ = mocked_chain.call_args for called_task, expected_task in zip(args, expected_tasks): assert called_task.name == expected_task.name - called_task_notification_arg = args[0].args[0] - assert called_task_notification_arg == str(notification.id) + assert args[0].kwargs.get('notification_id') == str(notification.id) @pytest.mark.parametrize( @@ -588,7 +587,7 @@ def test_send_notification_to_queue_throws_exception_deletes_notification( args, _ = mocked_chain.call_args for called_task, expected_task in zip(args, ['send-sms-tasks']): - assert called_task.args[0] == str(notification.id) + assert called_task.kwargs.get('notification_id') == str(notification.id) assert called_task.options['queue'] == expected_task diff --git a/tests/app/notifications/test_send_notifications.py b/tests/app/notifications/test_send_notifications.py index c20a52a41c..47ec0a7d7d 100644 --- a/tests/app/notifications/test_send_notifications.py +++ b/tests/app/notifications/test_send_notifications.py @@ -129,6 +129,7 @@ def test_send_notification_bypass_route_sms_with_recipient_and_default_sms_sende recipient_identifier=None, sms_sender_id=default_sms_sender, reply_to_text=sender_number, + notification_id=None, ) # Assert that the notification was queued correctly @@ -182,6 +183,7 @@ def test_send_notification_bypass_route_sms_with_recipient_item( recipient_identifier=recipient_item, sms_sender_id='test_sms_sender', reply_to_text=sender_number, + notification_id=None, ) # Assert that the notification was queued correctly, with expected params @@ -233,6 +235,7 @@ def test_send_notification_bypass_route_email_with_recipient( recipient_identifier=None, sms_sender_id=None, reply_to_text=send_number, + notification_id=None, ) # Assert the notification was queued correctly, with expected params @@ -284,6 +287,7 @@ def test_send_notification_bypass_route_email_with_recipient_item( recipient_identifier=recipient_item, sms_sender_id=None, reply_to_text=reply_to, + notification_id=None, ) # Assert that the notification was queued correctly, with the expected params diff --git a/tests/app/service/test_sender.py b/tests/app/service/test_sender.py index 02b86a4c9e..8ac6bb58cd 100644 --- a/tests/app/service/test_sender.py +++ b/tests/app/service/test_sender.py @@ -102,13 +102,20 @@ def test_send_notification_to_service_users_sends_to_active_users_only( mocker.patch('app.service.sender.send_notification_to_queue') # User and service setup - first_active_user = sample_user() - second_active_user = sample_user() + total_users = 12 + first_active_user: User = sample_user() + second_active_user: User = sample_user() pending_user = sample_user(state='pending') service = sample_service(user=first_active_user) dao_add_user_to_service(service, second_active_user) + # add more users + extra_user_emails = [] + for _ in range(total_users - 2): + extra_user: User = sample_user() + extra_user_emails.append(extra_user.email_address) + dao_add_user_to_service(service, extra_user) dao_add_user_to_service(service, pending_user) - email_addresses = [first_active_user.email_address, second_active_user.email_address] + email_addresses = [first_active_user.email_address, second_active_user.email_address, *extra_user_emails] # Sending the notifications template = sample_template(service=service, template_type=EMAIL_TYPE) @@ -125,7 +132,7 @@ def test_send_notification_to_service_users_sends_to_active_users_only( notifications = notify_db_session.session.scalars(stmt).all() notifications_recipients = [notification.to for notification in notifications] - assert len(notifications) == 2 + assert len(notifications) == total_users assert pending_user.email_address not in notifications_recipients - assert first_active_user.email_address in notifications_recipients - assert second_active_user.email_address in notifications_recipients + for user_email in email_addresses: + assert user_email in notifications_recipients diff --git a/tests/app/v2/notifications/test_post_notifications.py b/tests/app/v2/notifications/test_post_notifications.py index 24eef4e16f..09df6e14b1 100644 --- a/tests/app/v2/notifications/test_post_notifications.py +++ b/tests/app/v2/notifications/test_post_notifications.py @@ -146,8 +146,8 @@ def test_post_sms_notification_uses_inbound_number_as_sender( select(Notification).where(Notification.service_id == template.service_id) ).all() assert len(notifications) == 1 - notification_id = notifications[0].id - assert resp_json['id'] == str(notification_id) + notification_id = str(notifications[0].id) + assert resp_json['id'] == notification_id # These two should be the same assert resp_json['content']['from_number'] == sms_sender.sms_sender # Our number assert notifications[0].reply_to_text == sms_sender.sms_sender # Our number @@ -156,7 +156,7 @@ def test_post_sms_notification_uses_inbound_number_as_sender( args, _ = mocked_chain.call_args for called_task, expected_task in zip(args, ['send-sms-tasks']): assert called_task.options['queue'] == expected_task - assert called_task.args[0] == str(notification_id) + assert args[0].kwargs.get('notification_id') == notification_id def test_post_sms_notification_uses_inbound_number_reply_to_as_sender( @@ -180,8 +180,8 @@ def test_post_sms_notification_uses_inbound_number_reply_to_as_sender( assert validate(resp_json, post_sms_response) == resp_json stmt = select(Notification).where(Notification.service_id == template.service_id) notification = notify_db_session.session.scalars(stmt).one() - notification_id = notification.id - assert resp_json['id'] == str(notification_id) + notification_id = str(notification.id) + assert resp_json['id'] == notification_id assert resp_json['content']['from_number'] == service_number assert notification.reply_to_text == service_number @@ -189,7 +189,7 @@ def test_post_sms_notification_uses_inbound_number_reply_to_as_sender( args, _ = mocked_chain.call_args for called_task, expected_task in zip(args, ['send-sms-tasks']): assert called_task.options['queue'] == expected_task - assert called_task.args[0] == str(notification_id) + assert called_task.kwargs.get('notification_id') == notification_id @pytest.mark.parametrize('sms_sender_id', [None, 'user provided']) @@ -253,7 +253,7 @@ def test_post_sms_notification_returns_201_with_sms_sender_id( args, _ = mocked_chain.call_args for called_task, expected_task in zip(args, ['send-sms-tasks']): assert called_task.options['queue'] == expected_task - assert called_task.args[0] == resp_json['id'] + assert called_task.kwargs.get('notification_id') == resp_json['id'] def test_post_sms_notification_uses_sms_sender_id_reply_to( @@ -289,7 +289,7 @@ def test_post_sms_notification_uses_sms_sender_id_reply_to( args, _ = mocked_chain.call_args for called_task, expected_task in zip(args, ['send-sms-tasks']): assert called_task.options['queue'] == expected_task - assert called_task.args[0] == resp_json['id'] + assert called_task.kwargs.get('notification_id') == resp_json['id'] def test_notification_reply_to_text_is_original_value_if_sender_is_changed_after_post_notification( @@ -634,7 +634,7 @@ def test_send_notification_uses_email_or_sms_queue_when_template_is_marked_as_pr response = post_send_notification(client, sample_api_key(service=template.service), notification_type, data) - notification_id = json.loads(response.data)['id'] + notification_id = str(json.loads(response.data)['id']) assert response.status_code == 201 @@ -643,7 +643,7 @@ def test_send_notification_uses_email_or_sms_queue_when_template_is_marked_as_pr args, _ = mocked_chain.call_args for called_task, expected_task in zip(args, [f'send-{notification_type}-tasks']): assert called_task.options['queue'] == expected_task - assert called_task.args[0] == str(notification_id) + assert called_task.kwargs.get('notification_id') == notification_id @pytest.mark.parametrize(