diff --git a/app/celery/scheduled_tasks.py b/app/celery/scheduled_tasks.py index ed8e068e8..1c8d561c7 100644 --- a/app/celery/scheduled_tasks.py +++ b/app/celery/scheduled_tasks.py @@ -37,7 +37,7 @@ from app.dao.notifications_dao import ( ) from app.dao.provider_details_dao import ( get_current_provider, - dao_toggle_sms_provider + # dao_toggle_sms_provider ) from app.dao.service_callback_api_dao import get_service_delivery_status_callback_api_for_service from app.dao.services_dao import ( @@ -256,28 +256,25 @@ def switch_current_sms_provider_on_slow_delivery(): Switch providers if there are at least two slow delivery notifications (more than four minutes) in the last ten minutes. Search from the time we last switched to the current provider. """ - functional_test_provider_service_id = current_app.config.get('FUNCTIONAL_TEST_PROVIDER_SERVICE_ID') - functional_test_provider_template_id = current_app.config.get('FUNCTIONAL_TEST_PROVIDER_SMS_TEMPLATE_ID') + current_provider = get_current_provider('sms') + if current_provider.updated_at > datetime.utcnow() - timedelta(minutes=10): + current_app.logger.info("Slow delivery provider switched less than 10 minutes ago.") + return + slow_delivery_notifications = is_delivery_slow_for_provider( + provider=current_provider.identifier, + threshold=0.1, + created_at=datetime.utcnow() - timedelta(minutes=10), + delivery_time=timedelta(minutes=4), + ) - if functional_test_provider_service_id and functional_test_provider_template_id: - current_provider = get_current_provider('sms') - slow_delivery_notifications = is_delivery_slow_for_provider( - provider=current_provider.identifier, - threshold=2, - sent_at=max(datetime.utcnow() - timedelta(minutes=10), current_provider.updated_at), - delivery_time=timedelta(minutes=4), - service_id=functional_test_provider_service_id, - template_id=functional_test_provider_template_id + if slow_delivery_notifications: + current_app.logger.warning( + 'Slow delivery notifications detected for provider {}'.format( + current_provider.identifier + ) ) - if slow_delivery_notifications: - current_app.logger.warning( - 'Slow delivery notifications detected for provider {}'.format( - current_provider.identifier - ) - ) - - dao_toggle_sms_provider(current_provider.identifier) + # dao_toggle_sms_provider(current_provider.identifier) @notify_celery.task(name="delete-inbound-sms") diff --git a/app/config.py b/app/config.py index d93d7c497..138d18b65 100644 --- a/app/config.py +++ b/app/config.py @@ -290,9 +290,6 @@ class Config(object): SIMULATED_SMS_NUMBERS = ('+447700900000', '+447700900111', '+447700900222') - FUNCTIONAL_TEST_PROVIDER_SERVICE_ID = None - FUNCTIONAL_TEST_PROVIDER_SMS_TEMPLATE_ID = None - DVLA_BUCKETS = { 'job': '{}-dvla-file-per-job'.format(os.getenv('NOTIFY_ENVIRONMENT')), 'notification': '{}-dvla-letter-api-files'.format(os.getenv('NOTIFY_ENVIRONMENT')) @@ -438,8 +435,6 @@ class Live(Config): INVALID_PDF_BUCKET_NAME = 'production-letters-invalid-pdf' STATSD_ENABLED = True FROM_NUMBER = 'GOVUK' - FUNCTIONAL_TEST_PROVIDER_SERVICE_ID = '6c1d81bb-dae2-4ee9-80b0-89a4aae9f649' - FUNCTIONAL_TEST_PROVIDER_SMS_TEMPLATE_ID = 'ba9e1789-a804-40b8-871f-cc60d4c1286f' PERFORMANCE_PLATFORM_ENABLED = True API_RATE_LIMIT_ENABLED = True CHECK_PROXY_HEADER = True diff --git a/app/dao/notifications_dao.py b/app/dao/notifications_dao.py index 0ff1ffa67..f5b733033 100644 --- a/app/dao/notifications_dao.py +++ b/app/dao/notifications_dao.py @@ -443,22 +443,34 @@ def get_total_sent_notifications_in_date_range(start_date, end_date, notificatio def is_delivery_slow_for_provider( - sent_at, + created_at, provider, threshold, delivery_time, - service_id, - template_id ): - count = db.session.query(Notification).filter( - Notification.service_id == service_id, - Notification.template_id == template_id, - Notification.sent_at >= sent_at, - Notification.status == NOTIFICATION_DELIVERED, + count = db.session.query( + case( + [( + Notification.status == NOTIFICATION_DELIVERED, + (Notification.updated_at - Notification.sent_at) >= delivery_time + )], + else_=(datetime.utcnow() - Notification.sent_at) >= delivery_time + ).label("slow"), func.count() + + ).filter( + Notification.created_at >= created_at, + Notification.sent_at.isnot(None), + Notification.status.in_([NOTIFICATION_DELIVERED, NOTIFICATION_SENDING]), Notification.sent_by == provider, - (Notification.updated_at - Notification.sent_at) >= delivery_time, - ).count() - return count >= threshold + Notification.key_type != KEY_TYPE_TEST + ).group_by("slow").all() + + counts = {c[0]: c[1] for c in count} + total_notifications = sum(counts.values()) + if total_notifications: + return counts.get(True, 0) / total_notifications >= threshold + else: + return False @statsd(namespace="dao") diff --git a/tests/app/celery/test_scheduled_tasks.py b/tests/app/celery/test_scheduled_tasks.py index f62a98a60..a0c621529 100644 --- a/tests/app/celery/test_scheduled_tasks.py +++ b/tests/app/celery/test_scheduled_tasks.py @@ -47,7 +47,6 @@ from app.dao.provider_details_dao import ( from app.exceptions import NotificationTechnicalFailureException from app.models import ( NotificationHistory, - Service, StatsTemplateUsageByMonth, JOB_STATUS_IN_PROGRESS, JOB_STATUS_ERROR, @@ -71,33 +70,20 @@ from tests.app.conftest import ( sample_job as create_sample_job, sample_notification_history as create_notification_history, sample_template as create_sample_template, - create_custom_template, datetime_in_past ) -from tests.conftest import set_config_values -def _create_slow_delivery_notification(provider='mmg'): +def _create_slow_delivery_notification(template, provider='mmg'): now = datetime.utcnow() five_minutes_from_now = now + timedelta(minutes=5) - service = Service.query.get(current_app.config['FUNCTIONAL_TEST_PROVIDER_SERVICE_ID']) - if not service: - service = create_service( - service_id=current_app.config.get('FUNCTIONAL_TEST_PROVIDER_SERVICE_ID') - ) - - template = create_custom_template( - service=service, - user=service.users[0], - template_config_name='FUNCTIONAL_TEST_PROVIDER_SMS_TEMPLATE_ID', - template_type='sms' - ) create_notification( template=template, status='delivered', sent_by=provider, - updated_at=five_minutes_from_now + updated_at=five_minutes_from_now, + sent_at=now, ) @@ -129,8 +115,9 @@ def test_should_have_decorated_tasks_functions(): @pytest.fixture(scope='function') def prepare_current_provider(restore_provider_details): initial_provider = get_current_provider('sms') - initial_provider.updated_at = datetime.utcnow() - timedelta(minutes=30) dao_update_provider_details(initial_provider) + initial_provider.updated_at = datetime.utcnow() - timedelta(minutes=30) + db.session.commit() def test_should_call_delete_sms_notifications_more_than_week_in_task(notify_api, mocker): @@ -413,134 +400,32 @@ def test_send_total_sent_notifications_to_performance_platform_calls_with_correc ]) -def test_switch_current_sms_provider_on_slow_delivery_does_not_run_if_config_unset( - notify_api, - mocker -): - get_notifications_mock = mocker.patch( - 'app.celery.scheduled_tasks.is_delivery_slow_for_provider' - ) - toggle_sms_mock = mocker.patch('app.celery.scheduled_tasks.dao_toggle_sms_provider') - - with set_config_values(notify_api, { - 'FUNCTIONAL_TEST_PROVIDER_SERVICE_ID': None, - 'FUNCTIONAL_TEST_PROVIDER_SMS_TEMPLATE_ID': None - }): - switch_current_sms_provider_on_slow_delivery() - - assert get_notifications_mock.called is False - assert toggle_sms_mock.called is False - - -def test_switch_providers_on_slow_delivery_runs_if_config_set( - notify_api, - mocker, - prepare_current_provider -): - get_notifications_mock = mocker.patch( - 'app.celery.scheduled_tasks.is_delivery_slow_for_provider', - return_value=[] - ) - - with set_config_values(notify_api, { - 'FUNCTIONAL_TEST_PROVIDER_SERVICE_ID': '7954469d-8c6d-43dc-b8f7-86be2d69f5f3', - 'FUNCTIONAL_TEST_PROVIDER_SMS_TEMPLATE_ID': '331a63e6-f1aa-4588-ad3f-96c268788ae7' - }): - switch_current_sms_provider_on_slow_delivery() - - assert get_notifications_mock.called is True - - -def test_switch_providers_triggers_on_slow_notification_delivery( - notify_api, - mocker, - prepare_current_provider, - sample_user -): - mocker.patch('app.provider_details.switch_providers.get_user_by_id', return_value=sample_user) - starting_provider = get_current_provider('sms') - - with set_config_values(notify_api, { - 'FUNCTIONAL_TEST_PROVIDER_SERVICE_ID': '7954469d-8c6d-43dc-b8f7-86be2d69f5f3', - 'FUNCTIONAL_TEST_PROVIDER_SMS_TEMPLATE_ID': '331a63e6-f1aa-4588-ad3f-96c268788ae7' - }): - _create_slow_delivery_notification(starting_provider.identifier) - _create_slow_delivery_notification(starting_provider.identifier) - switch_current_sms_provider_on_slow_delivery() - - new_provider = get_current_provider('sms') - assert new_provider.identifier != starting_provider.identifier - assert new_provider.priority < starting_provider.priority - - -def test_switch_providers_on_slow_delivery_does_not_switch_if_already_switched( - notify_api, - mocker, - prepare_current_provider, - sample_user -): - mocker.patch('app.provider_details.switch_providers.get_user_by_id', return_value=sample_user) - starting_provider = get_current_provider('sms') - - with set_config_values(notify_api, { - 'FUNCTIONAL_TEST_PROVIDER_SERVICE_ID': '7954469d-8c6d-43dc-b8f7-86be2d69f5f3', - 'FUNCTIONAL_TEST_PROVIDER_SMS_TEMPLATE_ID': '331a63e6-f1aa-4588-ad3f-96c268788ae7' - }): - _create_slow_delivery_notification() - _create_slow_delivery_notification() - - switch_current_sms_provider_on_slow_delivery() - switch_current_sms_provider_on_slow_delivery() - - new_provider = get_current_provider('sms') - assert new_provider.identifier != starting_provider.identifier - assert new_provider.priority < starting_provider.priority - - -def test_switch_providers_on_slow_delivery_does_not_switch_based_on_older_notifications( +@pytest.mark.skip(reason="Not switching it on yet") +def test_switch_providers_on_slow_delivery_switches_once_then_does_not_switch_if_already_switched( notify_api, mocker, prepare_current_provider, sample_user, - + sample_template ): - """ - Assume we have three slow delivery notifications for the current provider x. This triggers - a switch to provider y. If we experience some slow delivery notifications on this provider, - we switch back to provider x. - - Provider x had three slow deliveries initially, but we do not want to trigger another switch - based on these as they are old. We only want to look for slow notifications after the point at - which we switched back to provider x. - """ mocker.patch('app.provider_details.switch_providers.get_user_by_id', return_value=sample_user) starting_provider = get_current_provider('sms') - with set_config_values(notify_api, { - 'FUNCTIONAL_TEST_PROVIDER_SERVICE_ID': '7954469d-8c6d-43dc-b8f7-86be2d69f5f3', - 'FUNCTIONAL_TEST_PROVIDER_SMS_TEMPLATE_ID': '331a63e6-f1aa-4588-ad3f-96c268788ae7' - }): - # Provider x -> y - _create_slow_delivery_notification(starting_provider.identifier) - _create_slow_delivery_notification(starting_provider.identifier) - _create_slow_delivery_notification(starting_provider.identifier) - switch_current_sms_provider_on_slow_delivery() + _create_slow_delivery_notification(sample_template) + _create_slow_delivery_notification(sample_template) - current_provider = get_current_provider('sms') - assert current_provider.identifier != starting_provider.identifier + switch_current_sms_provider_on_slow_delivery() - # Provider y -> x - _create_slow_delivery_notification(current_provider.identifier) - _create_slow_delivery_notification(current_provider.identifier) - switch_current_sms_provider_on_slow_delivery() + new_provider = get_current_provider('sms') + _create_slow_delivery_notification(sample_template, new_provider.identifier) + _create_slow_delivery_notification(sample_template, new_provider.identifier) + switch_current_sms_provider_on_slow_delivery() - new_provider = get_current_provider('sms') - assert new_provider.identifier != current_provider.identifier + final_provider = get_current_provider('sms') - # Expect to stay on provider x - switch_current_sms_provider_on_slow_delivery() - current_provider = get_current_provider('sms') - assert starting_provider.identifier == current_provider.identifier + assert new_provider.identifier != starting_provider.identifier + assert new_provider.priority < starting_provider.priority + assert final_provider.identifier == new_provider.identifier @freeze_time("2017-05-01 14:00:00") diff --git a/tests/app/dao/notification_dao/test_notification_dao.py b/tests/app/dao/notification_dao/test_notification_dao.py index c40b315d3..0cbc1067c 100644 --- a/tests/app/dao/notification_dao/test_notification_dao.py +++ b/tests/app/dao/notification_dao/test_notification_dao.py @@ -45,6 +45,8 @@ from app.models import ( ScheduledNotification, NOTIFICATION_STATUS_TYPES, NOTIFICATION_STATUS_TYPES_FAILED, + NOTIFICATION_TEMPORARY_FAILURE, + NOTIFICATION_SENDING, NOTIFICATION_SENT, NOTIFICATION_DELIVERED, KEY_TYPE_NORMAL, @@ -1206,131 +1208,85 @@ def test_get_total_sent_notifications_for_email_excludes_sms_counts( assert total_count == 2 -@freeze_time("2016-01-10 12:00:00.000000") -def test_slow_provider_delivery_returns_for_sent_notifications( - sample_template +@pytest.mark.parametrize( + "normal_sending,slow_sending,normal_delivered,slow_delivered,threshold,expected_result", + [ + (0, 0, 0, 0, 0.1, False), + (1, 0, 0, 0, 0.1, False), + (1, 1, 0, 0, 0.1, True), + (0, 0, 1, 1, 0.1, True), + (1, 1, 1, 1, 0.5, True), + (1, 1, 1, 1, 0.6, False), + (45, 5, 45, 5, 0.1, True), + ] +) +@freeze_time("2018-12-04 12:00:00.000000") +def test_is_delivery_slow_for_provider( + notify_db_session, + sample_template, + normal_sending, + slow_sending, + normal_delivered, + slow_delivered, + threshold, + expected_result ): - now = datetime.utcnow() - one_minute_from_now = now + timedelta(minutes=1) - five_minutes_from_now = now + timedelta(minutes=5) - - notification_five_minutes_to_deliver = partial( + normal_notification = partial( create_notification, template=sample_template, - status='delivered', sent_by='mmg', - updated_at=five_minutes_from_now + sent_at=datetime.now(), + updated_at=datetime.now() ) - notification_five_minutes_to_deliver(sent_at=now) - notification_five_minutes_to_deliver(sent_at=one_minute_from_now) - notification_five_minutes_to_deliver(sent_at=one_minute_from_now) - - slow_delivery = is_delivery_slow_for_provider( - sent_at=one_minute_from_now, - provider='mmg', - threshold=2, - delivery_time=timedelta(minutes=3), - service_id=sample_template.service.id, - template_id=sample_template.id - ) - - assert slow_delivery - - -@freeze_time("2016-01-10 12:00:00.000000") -def test_slow_provider_delivery_observes_threshold( - sample_template -): - now = datetime.utcnow() - five_minutes_from_now = now + timedelta(minutes=5) - - notification_five_minutes_to_deliver = partial( + slow_notification = partial( create_notification, template=sample_template, - status='delivered', - sent_at=now, sent_by='mmg', - updated_at=five_minutes_from_now + sent_at=datetime.now() - timedelta(minutes=5), + updated_at=datetime.now() ) - notification_five_minutes_to_deliver() - notification_five_minutes_to_deliver() + for _ in range(normal_sending): + normal_notification(status='sending') + for _ in range(slow_sending): + slow_notification(status='sending') + for _ in range(normal_delivered): + normal_notification(status='delivered') + for _ in range(slow_delivered): + slow_notification(status='delivered') - slow_delivery = is_delivery_slow_for_provider( - sent_at=now, - provider='mmg', - threshold=3, - delivery_time=timedelta(minutes=5), - service_id=sample_template.service.id, - template_id=sample_template.id - ) - - assert not slow_delivery + assert is_delivery_slow_for_provider(datetime.utcnow(), "mmg", threshold, timedelta(minutes=4)) is expected_result -@freeze_time("2016-01-10 12:00:00.000000") -def test_slow_provider_delivery_returns_for_delivered_notifications_only( - sample_template +@pytest.mark.parametrize("options,expected_result", [ + ({"status": NOTIFICATION_TEMPORARY_FAILURE, "sent_by": "mmg"}, False), + ({"status": NOTIFICATION_DELIVERED, "sent_by": "firetext"}, False), + ({"status": NOTIFICATION_DELIVERED, "sent_by": "mmg"}, True), + ({"status": NOTIFICATION_DELIVERED, "sent_by": "mmg", "sent_at": None}, False), + ({"status": NOTIFICATION_DELIVERED, "sent_by": "mmg", "key_type": KEY_TYPE_TEST}, False), + ({"status": NOTIFICATION_SENDING, "sent_by": "firetext"}, False), + ({"status": NOTIFICATION_SENDING, "sent_by": "mmg"}, True), + ({"status": NOTIFICATION_SENDING, "sent_by": "mmg", "sent_at": None}, False), + ({"status": NOTIFICATION_SENDING, "sent_by": "mmg", "key_type": KEY_TYPE_TEST}, False), +]) +@freeze_time("2018-12-04 12:00:00.000000") +def test_delivery_is_delivery_slow_for_provider_filters_out_notifications_it_should_not_count( + notify_db_session, + sample_template, + options, + expected_result ): - now = datetime.utcnow() - five_minutes_from_now = now + timedelta(minutes=5) - - notification_five_minutes_to_deliver = partial( - create_notification, - template=sample_template, - sent_at=now, - sent_by='firetext', - created_at=now, - updated_at=five_minutes_from_now + create_notification_with = { + "template": sample_template, + "sent_at": datetime.now() - timedelta(minutes=5), + "updated_at": datetime.now(), + } + create_notification_with.update(options) + create_notification( + **create_notification_with ) - - notification_five_minutes_to_deliver(status='sending') - notification_five_minutes_to_deliver(status='delivered') - notification_five_minutes_to_deliver(status='delivered') - - slow_delivery = is_delivery_slow_for_provider( - sent_at=now, - provider='firetext', - threshold=2, - delivery_time=timedelta(minutes=5), - service_id=sample_template.service.id, - template_id=sample_template.id - ) - - assert slow_delivery - - -@freeze_time("2016-01-10 12:00:00.000000") -def test_slow_provider_delivery_does_not_return_for_standard_delivery_time( - sample_template -): - now = datetime.utcnow() - five_minutes_from_now = now + timedelta(minutes=5) - - notification = partial( - create_notification, - template=sample_template, - created_at=now, - sent_at=now, - sent_by='mmg', - status='delivered' - ) - - notification(updated_at=five_minutes_from_now - timedelta(seconds=1)) - notification(updated_at=five_minutes_from_now - timedelta(seconds=1)) - notification(updated_at=five_minutes_from_now) - - slow_delivery = is_delivery_slow_for_provider( - sent_at=now, - provider='mmg', - threshold=2, - delivery_time=timedelta(minutes=5), - service_id=sample_template.service.id, - template_id=sample_template.id - ) - - assert not slow_delivery + assert is_delivery_slow_for_provider(datetime.utcnow(), "mmg", 0.1, timedelta(minutes=4)) is expected_result def test_dao_get_notifications_by_to_field(sample_template):