From c42420c32907f326b34a294c61e83c6917e493b0 Mon Sep 17 00:00:00 2001 From: Rebecca Law Date: Wed, 13 Nov 2019 16:39:59 +0000 Subject: [PATCH 1/4] Add an alert when a letter is created but doesn't have a file in S3 for sending. We can tell this is the case because there is no updated_at and billable units are still 0. At this point we are just creating a zendesk ticket - perhaps we can just call the create_letter_pdf task. --- app/celery/scheduled_tasks.py | 20 +++++++++ app/dao/notifications_dao.py | 24 +++++++++-- tests/app/celery/test_scheduled_tasks.py | 54 ++++++++++++++++++------ 3 files changed, 82 insertions(+), 16 deletions(-) diff --git a/app/celery/scheduled_tasks.py b/app/celery/scheduled_tasks.py index 383f80462..bc1391710 100644 --- a/app/celery/scheduled_tasks.py +++ b/app/celery/scheduled_tasks.py @@ -30,6 +30,7 @@ from app.dao.notifications_dao import ( notifications_not_yet_sent, dao_precompiled_letters_still_pending_virus_check, dao_old_letters_with_created_status, + letters_missing_from_sending_bucket ) from app.dao.provider_details_dao import ( get_current_provider, @@ -189,6 +190,25 @@ def replay_created_notifications(): for n in notifications_to_resend: send_notification_to_queue(notification=n, research_mode=n.service.research_mode) + # if the letter has not be send after 4 hours + 15 minutes, then create a zendesk ticket + letters = letters_missing_from_sending_bucket(resend_created_notifications_older_than) + + if len(letters) > 0: + msg = "{} letters were created four hours and 15 minutes ago, " \ + "but do not have an updated_at timestamp or billable units. " \ + "It is likely you need to run the " \ + "app.celery.letters_pdf_tasks.create_letters_pdf task again with " \ + "the notification id.\n {}".format(len(letters), + [x.id for x in letters]) + current_app.logger.info(msg) + if current_app.config['NOTIFY_ENVIRONMENT'] in ['live', 'production', 'test']: + zendesk_client.create_ticket( + subject="[{}] Letters still in created status might be missing from S3".format( + current_app.config['NOTIFY_ENVIRONMENT']), + message=msg, + ticket_type=zendesk_client.TYPE_INCIDENT + ) + @notify_celery.task(name='check-precompiled-letter-state') @statsd(namespace="tasks") diff --git a/app/dao/notifications_dao.py b/app/dao/notifications_dao.py index 8b8c20cb8..1a179481a 100644 --- a/app/dao/notifications_dao.py +++ b/app/dao/notifications_dao.py @@ -32,6 +32,7 @@ from app.models import ( Notification, NotificationHistory, ScheduledNotification, + KEY_TYPE_NORMAL, KEY_TYPE_TEST, LETTER_TYPE, NOTIFICATION_CREATED, @@ -46,7 +47,7 @@ from app.models import ( SMS_TYPE, EMAIL_TYPE, ServiceDataRetention, - Service + Service, ) from app.utils import get_london_midnight_in_utc from app.utils import midnight_n_days_ago, escape_special_characters @@ -698,15 +699,32 @@ def dao_old_letters_with_created_status(): last_processing_deadline = yesterday_bst.replace(hour=17, minute=30, second=0, microsecond=0) notifications = Notification.query.filter( - Notification.updated_at < convert_bst_to_utc(last_processing_deadline), + Notification.created_at < convert_bst_to_utc(last_processing_deadline), Notification.notification_type == LETTER_TYPE, Notification.status == NOTIFICATION_CREATED ).order_by( - Notification.updated_at + Notification.created_at ).all() return notifications +def letters_missing_from_sending_bucket(seconds_to_subtract): + older_than_date = datetime.utcnow() - timedelta(seconds=seconds_to_subtract) + + notifications = Notification.query.filter( + Notification.updated_at == None, # noqa + Notification.status == NOTIFICATION_CREATED, + Notification.billable_units == 0, + Notification.created_at <= older_than_date, + Notification.notification_type == LETTER_TYPE, + Notification.key_type == KEY_TYPE_NORMAL + ).order_by( + Notification.created_at + ).all() + + return notifications + + def dao_precompiled_letters_still_pending_virus_check(): ninety_minutes_ago = datetime.utcnow() - timedelta(seconds=5400) diff --git a/tests/app/celery/test_scheduled_tasks.py b/tests/app/celery/test_scheduled_tasks.py index f8d0f0a1d..29388eb6a 100644 --- a/tests/app/celery/test_scheduled_tasks.py +++ b/tests/app/celery/test_scheduled_tasks.py @@ -309,6 +309,34 @@ def test_replay_created_notifications(notify_db_session, sample_service, mocker) queue="send-sms-tasks") +def test_replay_created_notifications_create_zendesk_ticket_for_letters_not_ready_to_send( + sample_letter_template, mocker +): + mock_create_ticket = mocker.patch('app.celery.scheduled_tasks.zendesk_client.create_ticket') + create_notification(template=sample_letter_template, billable_units=0, + created_at=datetime.utcnow() - timedelta(hours=4)) + + notification_1 = create_notification(template=sample_letter_template, billable_units=0, + created_at=datetime.utcnow() - timedelta(hours=4, minutes=20)) + notification_2 = create_notification(template=sample_letter_template, billable_units=0, + created_at=datetime.utcnow() - timedelta(hours=5)) + + replay_created_notifications() + + message = "{} letters were created four hours and 15 minutes ago, " \ + "but do not have an updated_at timestamp or billable units. " \ + "It is likely you need to run the " \ + "app.celery.letters_pdf_tasks.create_letters_pdf task again with " \ + "the notification id.\n {}".format(2, + [notification_2.id, notification_1.id]) + + mock_create_ticket.assert_called_with( + message=message, + subject='[test] Letters still in created status might be missing from S3', + ticket_type='incident' + ) + + def test_check_job_status_task_does_not_raise_error(sample_template): create_job( template=sample_template, @@ -363,12 +391,12 @@ def test_check_templated_letter_state_during_bst(mocker, sample_letter_template) mock_logger = mocker.patch('app.celery.tasks.current_app.logger.exception') mock_create_ticket = mocker.patch('app.celery.nightly_tasks.zendesk_client.create_ticket') - noti_1 = create_notification(template=sample_letter_template, updated_at=datetime(2019, 5, 1, 12, 0)) - noti_2 = create_notification(template=sample_letter_template, updated_at=datetime(2019, 5, 29, 16, 29)) - create_notification(template=sample_letter_template, updated_at=datetime(2019, 5, 29, 16, 30)) - create_notification(template=sample_letter_template, updated_at=datetime(2019, 5, 29, 17, 29)) - create_notification(template=sample_letter_template, status='delivered', updated_at=datetime(2019, 5, 28, 10, 0)) - create_notification(template=sample_letter_template, updated_at=datetime(2019, 5, 30, 10, 0)) + noti_1 = create_notification(template=sample_letter_template, created_at=datetime(2019, 5, 1, 12, 0)) + noti_2 = create_notification(template=sample_letter_template, created_at=datetime(2019, 5, 29, 16, 29)) + create_notification(template=sample_letter_template, created_at=datetime(2019, 5, 29, 16, 30)) + create_notification(template=sample_letter_template, created_at=datetime(2019, 5, 29, 17, 29)) + create_notification(template=sample_letter_template, status='delivered', created_at=datetime(2019, 5, 28, 10, 0)) + create_notification(template=sample_letter_template, created_at=datetime(2019, 5, 30, 10, 0)) check_templated_letter_state() @@ -386,14 +414,14 @@ def test_check_templated_letter_state_during_bst(mocker, sample_letter_template) @freeze_time("2019-01-30 14:00:00") def test_check_templated_letter_state_during_utc(mocker, sample_letter_template): mock_logger = mocker.patch('app.celery.tasks.current_app.logger.exception') - mock_create_ticket = mocker.patch('app.celery.nightly_tasks.zendesk_client.create_ticket') + mock_create_ticket = mocker.patch('app.celery.scheduled_tasks.zendesk_client.create_ticket') - noti_1 = create_notification(template=sample_letter_template, updated_at=datetime(2018, 12, 1, 12, 0)) - noti_2 = create_notification(template=sample_letter_template, updated_at=datetime(2019, 1, 29, 17, 29)) - create_notification(template=sample_letter_template, updated_at=datetime(2019, 1, 29, 17, 30)) - create_notification(template=sample_letter_template, updated_at=datetime(2019, 1, 29, 18, 29)) - create_notification(template=sample_letter_template, status='delivered', updated_at=datetime(2019, 1, 29, 10, 0)) - create_notification(template=sample_letter_template, updated_at=datetime(2019, 1, 30, 10, 0)) + noti_1 = create_notification(template=sample_letter_template, created_at=datetime(2018, 12, 1, 12, 0)) + noti_2 = create_notification(template=sample_letter_template, created_at=datetime(2019, 1, 29, 17, 29)) + create_notification(template=sample_letter_template, created_at=datetime(2019, 1, 29, 17, 30)) + create_notification(template=sample_letter_template, created_at=datetime(2019, 1, 29, 18, 29)) + create_notification(template=sample_letter_template, status='delivered', created_at=datetime(2019, 1, 29, 10, 0)) + create_notification(template=sample_letter_template, created_at=datetime(2019, 1, 30, 10, 0)) check_templated_letter_state() From ac4f0e8027f23be960fd730fdfa1c43439f9b82e Mon Sep 17 00:00:00 2001 From: Rebecca Law Date: Tue, 19 Nov 2019 16:04:21 +0000 Subject: [PATCH 2/4] After a comment from @idavidmcdonald, I asked myself why are not creating the task to upload the pdf and update the notification. The assumption was that S3 would throw an exception if the object was uploaded twice. That's not the case the default behaviour is that if a file already exists it will be overwritten. So it is completely safe to run the task from the alert. It can also mean that we don't need to wait 4hours 15 minutes. Shall I decease the amount of time before restarting the task? --- app/celery/scheduled_tasks.py | 18 +++++++----------- app/dao/notifications_dao.py | 4 ++-- tests/app/celery/test_scheduled_tasks.py | 20 ++++++-------------- 3 files changed, 15 insertions(+), 27 deletions(-) diff --git a/app/celery/scheduled_tasks.py b/app/celery/scheduled_tasks.py index bc1391710..0d5618768 100644 --- a/app/celery/scheduled_tasks.py +++ b/app/celery/scheduled_tasks.py @@ -14,6 +14,7 @@ from app.celery.tasks import ( get_recipient_csv_and_template, process_row ) +from app.celery.letters_pdf_tasks import create_letters_pdf from app.config import QueueNames, TaskNames from app.dao.invited_org_user_dao import delete_org_invitations_created_more_than_two_days_ago from app.dao.invited_user_dao import delete_invitations_created_more_than_two_days_ago @@ -196,18 +197,13 @@ def replay_created_notifications(): if len(letters) > 0: msg = "{} letters were created four hours and 15 minutes ago, " \ "but do not have an updated_at timestamp or billable units. " \ - "It is likely you need to run the " \ - "app.celery.letters_pdf_tasks.create_letters_pdf task again with " \ - "the notification id.\n {}".format(len(letters), - [x.id for x in letters]) + "\n Creating app.celery.letters_pdf_tasks.create_letters tasks to upload letter to S3 " \ + "and update notifications for the following notification ids: " \ + "\n {}".format(len(letters), [x.id for x in letters]) + current_app.logger.info(msg) - if current_app.config['NOTIFY_ENVIRONMENT'] in ['live', 'production', 'test']: - zendesk_client.create_ticket( - subject="[{}] Letters still in created status might be missing from S3".format( - current_app.config['NOTIFY_ENVIRONMENT']), - message=msg, - ticket_type=zendesk_client.TYPE_INCIDENT - ) + for letter in letters: + create_letters_pdf.apply_async([letter.id], queue=QueueNames.LETTERS) @notify_celery.task(name='check-precompiled-letter-state') diff --git a/app/dao/notifications_dao.py b/app/dao/notifications_dao.py index 1a179481a..025b355e5 100644 --- a/app/dao/notifications_dao.py +++ b/app/dao/notifications_dao.py @@ -710,11 +710,11 @@ def dao_old_letters_with_created_status(): def letters_missing_from_sending_bucket(seconds_to_subtract): older_than_date = datetime.utcnow() - timedelta(seconds=seconds_to_subtract) - + # We expect letters to have a `created` status, updated_at timestamp and billable units greater than zero. notifications = Notification.query.filter( + Notification.billable_units == 0, Notification.updated_at == None, # noqa Notification.status == NOTIFICATION_CREATED, - Notification.billable_units == 0, Notification.created_at <= older_than_date, Notification.notification_type == LETTER_TYPE, Notification.key_type == KEY_TYPE_NORMAL diff --git a/tests/app/celery/test_scheduled_tasks.py b/tests/app/celery/test_scheduled_tasks.py index 29388eb6a..847b09ffe 100644 --- a/tests/app/celery/test_scheduled_tasks.py +++ b/tests/app/celery/test_scheduled_tasks.py @@ -309,10 +309,10 @@ def test_replay_created_notifications(notify_db_session, sample_service, mocker) queue="send-sms-tasks") -def test_replay_created_notifications_create_zendesk_ticket_for_letters_not_ready_to_send( +def test_replay_created_notifications_create_letters_pdf_tasks_for_letters_not_ready_to_send( sample_letter_template, mocker ): - mock_create_ticket = mocker.patch('app.celery.scheduled_tasks.zendesk_client.create_ticket') + mock_task = mocker.patch('app.celery.scheduled_tasks.create_letters_pdf.apply_async') create_notification(template=sample_letter_template, billable_units=0, created_at=datetime.utcnow() - timedelta(hours=4)) @@ -323,18 +323,10 @@ def test_replay_created_notifications_create_zendesk_ticket_for_letters_not_read replay_created_notifications() - message = "{} letters were created four hours and 15 minutes ago, " \ - "but do not have an updated_at timestamp or billable units. " \ - "It is likely you need to run the " \ - "app.celery.letters_pdf_tasks.create_letters_pdf task again with " \ - "the notification id.\n {}".format(2, - [notification_2.id, notification_1.id]) - - mock_create_ticket.assert_called_with( - message=message, - subject='[test] Letters still in created status might be missing from S3', - ticket_type='incident' - ) + calls = [call([notification_1.id], queue=QueueNames.LETTERS), + call([notification_2.id], queue=QueueNames.LETTERS), + ] + mock_task.assert_has_calls(calls, any_order=True) def test_check_job_status_task_does_not_raise_error(sample_template): From e0b4b258aa3d8f1f63285dbfe2c9fff7f29b6db6 Mon Sep 17 00:00:00 2001 From: Rebecca Law Date: Thu, 21 Nov 2019 15:51:27 +0000 Subject: [PATCH 3/4] Shortened the length of time to check for messages with the wrong state. There is a chance that the there is an outstanding retry task that has yet to run but the task that are replayed here protect against the task running twice. So this just means it might get sent sooner than later. --- app/celery/scheduled_tasks.py | 6 +++--- tests/app/celery/test_scheduled_tasks.py | 6 ++++-- 2 files changed, 7 insertions(+), 5 deletions(-) diff --git a/app/celery/scheduled_tasks.py b/app/celery/scheduled_tasks.py index 0d5618768..6530ea596 100644 --- a/app/celery/scheduled_tasks.py +++ b/app/celery/scheduled_tasks.py @@ -175,8 +175,8 @@ def check_job_status(): @notify_celery.task(name='replay-created-notifications') @statsd(namespace="tasks") def replay_created_notifications(): - # if the notification has not be send after 4 hours + 15 minutes, then try to resend. - resend_created_notifications_older_than = (60 * 60 * 4) + (60 * 15) + # if the notification has not be send after 1 hour, then try to resend. + resend_created_notifications_older_than = (60 * 60) for notification_type in (EMAIL_TYPE, SMS_TYPE): notifications_to_resend = notifications_not_yet_sent( resend_created_notifications_older_than, @@ -195,7 +195,7 @@ def replay_created_notifications(): letters = letters_missing_from_sending_bucket(resend_created_notifications_older_than) if len(letters) > 0: - msg = "{} letters were created four hours and 15 minutes ago, " \ + msg = "{} letters were created over an hour ago, " \ "but do not have an updated_at timestamp or billable units. " \ "\n Creating app.celery.letters_pdf_tasks.create_letters tasks to upload letter to S3 " \ "and update notifications for the following notification ids: " \ diff --git a/tests/app/celery/test_scheduled_tasks.py b/tests/app/celery/test_scheduled_tasks.py index 847b09ffe..6601ef4ce 100644 --- a/tests/app/celery/test_scheduled_tasks.py +++ b/tests/app/celery/test_scheduled_tasks.py @@ -285,7 +285,7 @@ def test_replay_created_notifications(notify_db_session, sample_service, mocker) sms_template = create_template(service=sample_service, template_type='sms') email_template = create_template(service=sample_service, template_type='email') - older_than = (60 * 60 * 4) + (60 * 15) # 4 hours 15 minutes + older_than = (60 * 60) + (60 * 15) # 1 hour 15 minutes # notifications expected to be resent old_sms = create_notification(template=sms_template, created_at=datetime.utcnow() - timedelta(seconds=older_than), status='created') @@ -316,8 +316,10 @@ def test_replay_created_notifications_create_letters_pdf_tasks_for_letters_not_r create_notification(template=sample_letter_template, billable_units=0, created_at=datetime.utcnow() - timedelta(hours=4)) + create_notification(template=sample_letter_template, billable_units=0, + created_at=datetime.utcnow() - timedelta(minutes=20)) notification_1 = create_notification(template=sample_letter_template, billable_units=0, - created_at=datetime.utcnow() - timedelta(hours=4, minutes=20)) + created_at=datetime.utcnow() - timedelta(hours=1, minutes=20)) notification_2 = create_notification(template=sample_letter_template, billable_units=0, created_at=datetime.utcnow() - timedelta(hours=5)) From 853df6fbfbe40a845cdb609247adf91c47986d5b Mon Sep 17 00:00:00 2001 From: Rebecca Law Date: Wed, 27 Nov 2019 13:26:53 +0000 Subject: [PATCH 4/4] Fix reference to old time frame for task. --- app/celery/scheduled_tasks.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/app/celery/scheduled_tasks.py b/app/celery/scheduled_tasks.py index 6530ea596..ee7693c79 100644 --- a/app/celery/scheduled_tasks.py +++ b/app/celery/scheduled_tasks.py @@ -191,7 +191,7 @@ def replay_created_notifications(): for n in notifications_to_resend: send_notification_to_queue(notification=n, research_mode=n.service.research_mode) - # if the letter has not be send after 4 hours + 15 minutes, then create a zendesk ticket + # if the letter has not be send after an hour, then create a zendesk ticket letters = letters_missing_from_sending_bucket(resend_created_notifications_older_than) if len(letters) > 0: