diff --git a/app/celery/tasks.py b/app/celery/tasks.py index 767c7d4d9..887ca6468 100644 --- a/app/celery/tasks.py +++ b/app/celery/tasks.py @@ -2,6 +2,7 @@ import itertools from datetime import datetime from flask import current_app +from monotonic import monotonic from sqlalchemy.exc import SQLAlchemyError from app import clients, statsd_client from app.clients.email import EmailClientException @@ -112,6 +113,7 @@ def delete_invitations(): @notify_celery.task(name="process-job") def process_job(job_id): + task_start = monotonic() start = datetime.utcnow() job = dao_get_job_by_id(job_id) @@ -191,6 +193,7 @@ def process_job(job_id): "Job {} created at {} started at {} finished at {}".format(job_id, job.created_at, start, finished) ) statsd_client.incr("notifications.tasks.process-job") + statsd_client.timing("notifications.tasks.process-job.task-time", monotonic() - task_start) @notify_celery.task(name="remove-job") @@ -202,6 +205,7 @@ def remove_job(job_id): @notify_celery.task(name="send-sms") def send_sms(service_id, notification_id, encrypted_notification, created_at): + task_start = monotonic() notification = encryption.decrypt(encrypted_notification) service = dao_fetch_service_by_id(service_id) @@ -265,12 +269,14 @@ def send_sms(service_id, notification_id, encrypted_notification, created_at): "SMS {} created at {} sent at {}".format(notification_id, created_at, sent_at) ) statsd_client.incr("notifications.tasks.send-sms") + statsd_client.timing("notifications.tasks.send-sms.task-time", monotonic() - task_start) except SQLAlchemyError as e: current_app.logger.exception(e) @notify_celery.task(name="send-email") def send_email(service_id, notification_id, from_address, encrypted_notification, created_at): + task_start = monotonic() notification = encryption.decrypt(encrypted_notification) service = dao_fetch_service_by_id(service_id) @@ -332,6 +338,7 @@ def send_email(service_id, notification_id, from_address, encrypted_notification "Email {} created at {} sent at {}".format(notification_id, created_at, sent_at) ) statsd_client.incr("notifications.tasks.send-email") + statsd_client.timing("notifications.tasks.send-email.task-time", monotonic() - task_start) except SQLAlchemyError as e: current_app.logger.exception(e) diff --git a/tests/app/celery/test_tasks.py b/tests/app/celery/test_tasks.py index f2818861d..d4b982ee2 100644 --- a/tests/app/celery/test_tasks.py +++ b/tests/app/celery/test_tasks.py @@ -1,6 +1,7 @@ import uuid import pytest from flask import current_app +from mock import ANY from notifications_utils.recipients import validate_phone_number, format_phone_number from app.celery.tasks import ( @@ -104,6 +105,7 @@ def test_should_call_delete_invotations_on_delete_invitations_task(notify_api, m @freeze_time("2016-01-01 11:09:00.061258") def test_should_process_sms_job(sample_job, mocker, mock_celery_remove_job): mocker.patch('app.statsd_client.incr') + mocker.patch('app.statsd_client.timing') mocker.patch('app.celery.tasks.s3.get_job_from_s3', return_value=load_example_csv('sms')) mocker.patch('app.celery.tasks.send_sms.apply_async') mocker.patch('app.encryption.encrypt', return_value="something_encrypted") @@ -126,6 +128,7 @@ def test_should_process_sms_job(sample_job, mocker, mock_celery_remove_job): job = jobs_dao.dao_get_job_by_id(sample_job.id) assert job.status == 'finished' statsd_client.incr.assert_called_once_with("notifications.tasks.process-job") + statsd_client.timing.assert_called_once_with("notifications.tasks.process-job.task-time", ANY) @freeze_time("2016-01-01 11:09:00.061258") @@ -333,6 +336,7 @@ def test_should_send_template_to_correct_sms_provider_and_persist(sample_templat mocker.patch('app.mmg_client.get_name', return_value="mmg") mocker.patch('app.statsd_client.incr') mocker.patch('app.statsd_client.timing_with_dates') + mocker.patch('app.statsd_client.timing') notification_id = uuid.uuid4() @@ -357,6 +361,7 @@ def test_should_send_template_to_correct_sms_provider_and_persist(sample_templat datetime(2016, 1, 1, 11, 10, 0, 00000), datetime(2016, 1, 1, 11, 9, 0, 00000) ) + statsd_client.timing.assert_called_once_with("notifications.tasks.send-sms.task-time", ANY) mmg_client.send_sms.assert_called_once_with( to=format_phone_number(validate_phone_number("+447234123123")), @@ -561,6 +566,7 @@ def test_should_use_email_template_and_persist(sample_email_template_with_placeh mocker.patch('app.encryption.decrypt', return_value=notification) mocker.patch('app.statsd_client.incr') mocker.patch('app.statsd_client.timing_with_dates') + mocker.patch('app.statsd_client.timing') mocker.patch('app.aws_ses_client.get_name', return_value='ses') mocker.patch('app.aws_ses_client.send_email', return_value='ses') @@ -597,7 +603,7 @@ def test_should_use_email_template_and_persist(sample_email_template_with_placeh datetime(2016, 1, 1, 11, 10, 0, 00000), datetime(2016, 1, 1, 11, 9, 0, 00000) ) - + statsd_client.timing.assert_called_once_with("notifications.tasks.send-email.task-time", ANY) persisted_notification = notifications_dao.get_notification( sample_email_template_with_placeholders.service_id, notification_id )