diff --git a/app/__init__.py b/app/__init__.py index 2b1a168b7..be9f8aa95 100644 --- a/app/__init__.py +++ b/app/__init__.py @@ -48,8 +48,8 @@ def create_app(app_name=None): init_app(application) db.init_app(application) ma.init_app(application) - logging.init_app(application) statsd_client.init_app(application) + logging.init_app(application, statsd_client) firetext_client.init_app(application, statsd_client=statsd_client) loadtest_client.init_app(application, statsd_client=statsd_client) mmg_client.init_app(application, statsd_client=statsd_client) @@ -107,8 +107,9 @@ def init_app(app): return error @app.before_request - def record_start_time(): + def record_request_details(): g.start = monotonic() + g.endpoint = request.endpoint @app.after_request def after_request(response): diff --git a/app/celery/provider_tasks.py b/app/celery/provider_tasks.py index 8b7af54fd..0f23ce321 100644 --- a/app/celery/provider_tasks.py +++ b/app/celery/provider_tasks.py @@ -24,6 +24,7 @@ from notifications_utils.template import Template, get_sms_fragment_count from notifications_utils.renderers import HTMLEmail, PlainTextEmail, SMSMessage from app.models import SMS_TYPE, EMAIL_TYPE, KEY_TYPE_TEST +from app.statsd_decorators import statsd def retry_iteration_to_delay(retry=0): @@ -50,9 +51,8 @@ def retry_iteration_to_delay(retry=0): @notify_celery.task(bind=True, name="send-sms-to-provider", max_retries=5, default_retry_delay=5) +@statsd(namespace="tasks") def send_sms_to_provider(self, service_id, notification_id): - task_start = monotonic() - service = dao_fetch_service_by_id(service_id) provider = provider_to_use(SMS_TYPE, notification_id) notification = get_notification_by_id(notification_id) @@ -102,10 +102,8 @@ def send_sms_to_provider(self, service_id, notification_id): current_app.logger.info( "SMS {} sent to provider at {}".format(notification_id, notification.sent_at) ) - statsd_client.incr("notifications.tasks.send-sms-to-provider") - statsd_client.timing("notifications.tasks.send-sms-to-provider.task-time", monotonic() - task_start) delta_milliseconds = (datetime.utcnow() - notification.created_at).total_seconds() * 1000 - statsd_client.timing("notifications.sms.total-time", delta_milliseconds) + statsd_client.timing("sms.total-time", delta_milliseconds) def provider_to_use(notification_type, notification_id): @@ -123,8 +121,8 @@ def provider_to_use(notification_type, notification_id): @notify_celery.task(bind=True, name="send-email-to-provider", max_retries=5, default_retry_delay=5) +@statsd(namespace="tasks") def send_email_to_provider(self, service_id, notification_id): - task_start = monotonic() service = dao_fetch_service_by_id(service_id) provider = provider_to_use(EMAIL_TYPE, notification_id) notification = get_notification_by_id(notification_id) @@ -185,7 +183,5 @@ def send_email_to_provider(self, service_id, notification_id): current_app.logger.info( "Email {} sent to provider at {}".format(notification_id, notification.sent_at) ) - statsd_client.incr("notifications.tasks.send-email-to-provider") - statsd_client.timing("notifications.tasks.send-email-to-provider.task-time", monotonic() - task_start) delta_milliseconds = (datetime.utcnow() - notification.created_at).total_seconds() * 1000 - statsd_client.timing("notifications.email.total-time", delta_milliseconds) + statsd_client.timing("email.total-time", delta_milliseconds) diff --git a/app/celery/scheduled_tasks.py b/app/celery/scheduled_tasks.py index a1145a0f3..5606ecb2d 100644 --- a/app/celery/scheduled_tasks.py +++ b/app/celery/scheduled_tasks.py @@ -9,9 +9,11 @@ from app.dao.invited_user_dao import delete_invitations_created_more_than_two_da from app.dao.notifications_dao import delete_notifications_created_more_than_a_week_ago, get_notifications, \ update_notification_status_by_id from app.dao.users_dao import delete_codes_older_created_more_than_a_day_ago +from app.statsd_decorators import statsd @notify_celery.task(name="delete-verify-codes") +@statsd(namespace="tasks") def delete_verify_codes(): try: start = datetime.utcnow() @@ -25,6 +27,7 @@ def delete_verify_codes(): @notify_celery.task(name="delete-successful-notifications") +@statsd(namespace="tasks") def delete_successful_notifications(): try: start = datetime.utcnow() @@ -42,6 +45,7 @@ def delete_successful_notifications(): @notify_celery.task(name="delete-failed-notifications") +@statsd(namespace="tasks") def delete_failed_notifications(): try: start = datetime.utcnow() @@ -62,6 +66,7 @@ def delete_failed_notifications(): @notify_celery.task(name="delete-invitations") +@statsd(namespace="tasks") def delete_invitations(): try: start = datetime.utcnow() @@ -75,6 +80,7 @@ def delete_invitations(): @notify_celery.task(name='timeout-sending-notifications') +@statsd(namespace="tasks") def timeout_notifications(): # TODO: optimize the query by adding the date where clause to this query. notifications = get_notifications(filter_dict={'status': 'sending'}) diff --git a/app/celery/tasks.py b/app/celery/tasks.py index 6c9706ec8..bdcb37327 100644 --- a/app/celery/tasks.py +++ b/app/celery/tasks.py @@ -10,7 +10,6 @@ from notifications_utils.recipients import ( from notifications_utils.template import Template from sqlalchemy.exc import SQLAlchemyError -from app import statsd_client from app import ( create_uuid, DATETIME_FORMAT, @@ -36,11 +35,12 @@ from app.models import ( SMS_TYPE, KEY_TYPE_NORMAL ) +from app.statsd_decorators import statsd @notify_celery.task(name="process-job") +@statsd(namespace="tasks") def process_job(job_id): - task_start = monotonic() start = datetime.utcnow() job = dao_get_job_by_id(job_id) @@ -116,11 +116,10 @@ def process_job(job_id): current_app.logger.info( "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") +@statsd(namespace="tasks") def remove_job(job_id): job = dao_get_job_by_id(job_id) s3.remove_job_from_s3(job.service.id, str(job_id)) @@ -128,6 +127,7 @@ def remove_job(job_id): @notify_celery.task(bind=True, name="send-sms", max_retries=5, default_retry_delay=5) +@statsd(namespace="tasks") def send_sms(self, service_id, notification_id, @@ -135,7 +135,6 @@ def send_sms(self, created_at, api_key_id=None, key_type=KEY_TYPE_NORMAL): - task_start = monotonic() notification = encryption.decrypt(encrypted_notification) service = dao_fetch_service_by_id(service_id) @@ -154,21 +153,19 @@ def send_sms(self, "SMS {} created at {}".format(notification_id, created_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) raise self.retry(queue="retry", exc=e) @notify_celery.task(bind=True, name="send-email", max_retries=5, default_retry_delay=5) +@statsd(namespace="tasks") def send_email(self, service_id, notification_id, encrypted_notification, created_at, api_key_id=None, key_type=KEY_TYPE_NORMAL): - task_start = monotonic() notification = encryption.decrypt(encrypted_notification) service = dao_fetch_service_by_id(service_id) @@ -182,8 +179,6 @@ def send_email(self, service_id, send_email_to_provider.apply_async((service_id, notification_id), queue='email') current_app.logger.info("Email {} created at {}".format(notification_id, created_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) raise self.retry(queue="retry", exc=e) diff --git a/app/clients/email/aws_ses.py b/app/clients/email/aws_ses.py index 6fe62e82a..63536ae43 100644 --- a/app/clients/email/aws_ses.py +++ b/app/clients/email/aws_ses.py @@ -93,9 +93,10 @@ class AwsSesClient(EmailClient): ReplyToAddresses=reply_to_addresses) elapsed_time = monotonic() - start_time current_app.logger.info("AWS SES request finished in {}".format(elapsed_time)) - self.statsd_client.timing("notifications.clients.ses.request-time", elapsed_time) + self.statsd_client.timing("clients.ses.request-time", elapsed_time) + self.statsd_client.incr("clients.ses.success") return response['MessageId'] except Exception as e: # TODO logging exceptions - self.statsd_client.incr("notifications.clients.ses.error") + self.statsd_client.incr("clients.ses.error") raise AwsSesClientException(str(e)) diff --git a/app/clients/sms/firetext.py b/app/clients/sms/firetext.py index 938a86689..e9760a4e6 100644 --- a/app/clients/sms/firetext.py +++ b/app/clients/sms/firetext.py @@ -106,10 +106,11 @@ class FiretextClient(SmsClient): api_error.message ) ) - self.statsd_client.incr("notifications.clients.firetext.error") + self.statsd_client.incr("clients.firetext.error") raise api_error finally: elapsed_time = monotonic() - start_time self.current_app.logger.info("Firetext request finished in {}".format(elapsed_time)) - self.statsd_client.timing("notifications.clients.firetext.request-time", elapsed_time) + self.statsd_client.incr("clients.firetext.success") + self.statsd_client.timing("clients.firetext.request-time", elapsed_time) return response diff --git a/app/clients/sms/mmg.py b/app/clients/sms/mmg.py index bec425966..9636be86b 100644 --- a/app/clients/sms/mmg.py +++ b/app/clients/sms/mmg.py @@ -106,10 +106,11 @@ class MMGClient(SmsClient): api_error.message ) ) - self.statsd_client.incr("notifications.clients.mmg.error") + self.statsd_client.incr("clients.mmg.error") raise api_error finally: elapsed_time = monotonic() - start_time - self.statsd_client.timing("notifications.clients.mmg.request-time", elapsed_time) + self.statsd_client.timing("clients.mmg.request-time", elapsed_time) + self.statsd_client.incr("clients.mmg.success") self.current_app.logger.info("MMG request finished in {}".format(elapsed_time)) return response diff --git a/app/clients/statsd/statsd_client.py b/app/clients/statsd/statsd_client.py index 986aa2628..6b127da93 100644 --- a/app/clients/statsd/statsd_client.py +++ b/app/clients/statsd/statsd_client.py @@ -10,16 +10,15 @@ class StatsdClient(StatsClient): prefix=app.config.get('STATSD_PREFIX') ) self.active = app.config.get('STATSD_ENABLED') + self.namespace = app.config.get('NOTIFY_ENVIRONMENT') + ".notifications.api." + + def format_stat_name(self, stat): + return self.namespace + stat def incr(self, stat, count=1, rate=1): if self.active: - super(StatsClient, self).incr(stat, count, rate) + super(StatsClient, self).incr(self.format_stat_name(stat), count, rate) def timing(self, stat, delta, rate=1): if self.active: - super(StatsClient, self).timing(stat, delta, rate) - - def timing_with_dates(self, stat, start, end, rate=1): - if self.active: - delta = (start - end).total_seconds() * 1000 - super(StatsClient, self).timing(stat, delta, rate) + super(StatsClient, self).timing(self.format_stat_name(stat), delta, rate) diff --git a/app/dao/notifications_dao.py b/app/dao/notifications_dao.py index 1e7f2d75e..d25adac3a 100644 --- a/app/dao/notifications_dao.py +++ b/app/dao/notifications_dao.py @@ -31,8 +31,10 @@ from app.clients import ( STATISTICS_REQUESTED ) from app.dao.dao_utils import transactional +from app.statsd_decorators import statsd +@statsd(namespace="dao") def dao_get_notification_statistics_for_service(service_id, limit_days=None): query_filter = [NotificationStatistics.service_id == service_id] if limit_days is not None: @@ -44,6 +46,7 @@ def dao_get_notification_statistics_for_service(service_id, limit_days=None): ).all() +@statsd(namespace="dao") def dao_get_notification_statistics_for_service_and_day(service_id, day): return NotificationStatistics.query.filter_by( service_id=service_id, @@ -51,10 +54,12 @@ def dao_get_notification_statistics_for_service_and_day(service_id, day): ).order_by(desc(NotificationStatistics.day)).first() +@statsd(namespace="dao") def dao_get_notification_statistics_for_day(day): return NotificationStatistics.query.filter_by(day=day).all() +@statsd(namespace="dao") def dao_get_potential_notification_statistics_for_day(day): all_services = db.session.query( Service.id, @@ -102,6 +107,7 @@ def create_notification_statistics_dict(service_id, day): } +@statsd(namespace="dao") def dao_get_7_day_agg_notification_statistics_for_service(service_id, date_from, week_count=52): @@ -129,6 +135,7 @@ def dao_get_7_day_agg_notification_statistics_for_service(service_id, ) +@statsd(namespace="dao") def dao_get_template_statistics_for_service(service_id, limit_days=None): query_filter = [TemplateStatistics.service_id == service_id] if limit_days is not None: @@ -137,6 +144,7 @@ def dao_get_template_statistics_for_service(service_id, limit_days=None): desc(TemplateStatistics.updated_at)).all() +@statsd(namespace="dao") def dao_get_template_statistics_for_template(template_id): return TemplateStatistics.query.filter( TemplateStatistics.template_id == template_id @@ -145,6 +153,7 @@ def dao_get_template_statistics_for_template(template_id): ).all() +@statsd(namespace="dao") @transactional def dao_create_notification(notification, notification_type): if notification.job_id: @@ -252,6 +261,7 @@ def _update_notification_status(notification, status, notification_statistics_st return True +@statsd(namespace="dao") @transactional def update_notification_status_by_id(notification_id, status, notification_statistics_status=None): notification = Notification.query.with_lockmode("update").filter( @@ -270,6 +280,7 @@ def update_notification_status_by_id(notification_id, status, notification_stati ) +@statsd(namespace="dao") @transactional def update_notification_status_by_reference(reference, status, notification_statistics_status): notification = Notification.query.filter(Notification.reference == reference, @@ -286,6 +297,7 @@ def update_notification_status_by_reference(reference, status, notification_stat ) +@statsd(namespace="dao") def dao_update_notification(notification): notification.updated_at = datetime.utcnow() notification_history = NotificationHistory.query.get(notification.id) @@ -294,6 +306,7 @@ def dao_update_notification(notification): db.session.commit() +@statsd(namespace="dao") @transactional def update_provider_stats( id_, @@ -320,10 +333,12 @@ def update_provider_stats( db.session.add(provider_stats) +@statsd(namespace="dao") def get_notification_for_job(service_id, job_id, notification_id): return Notification.query.filter_by(service_id=service_id, job_id=job_id, id=notification_id).one() +@statsd(namespace="dao") def get_notifications_for_job(service_id, job_id, filter_dict=None, page=1, page_size=None): if page_size is None: page_size = current_app.config['PAGE_SIZE'] @@ -335,6 +350,7 @@ def get_notifications_for_job(service_id, job_id, filter_dict=None, page=1, page ) +@statsd(namespace="dao") def get_notification(service_id, notification_id, key_type=None): filter_dict = {'service_id': service_id, 'id': notification_id} if key_type: @@ -343,6 +359,7 @@ def get_notification(service_id, notification_id, key_type=None): return Notification.query.filter_by(**filter_dict).one() +@statsd(namespace="dao") def get_notification_by_id(notification_id): return Notification.query.filter_by(id=notification_id).first() @@ -351,6 +368,7 @@ def get_notifications(filter_dict=None): return _filter_query(Notification.query, filter_dict=filter_dict) +@statsd(namespace="dao") def get_notifications_for_service(service_id, filter_dict=None, page=1, @@ -390,6 +408,7 @@ def _filter_query(query, filter_dict=None): return query +@statsd(namespace="dao") def delete_notifications_created_more_than_a_week_ago(status): seven_days_ago = date.today() - timedelta(days=7) deleted = db.session.query(Notification).filter( diff --git a/app/dao/services_dao.py b/app/dao/services_dao.py index a16aff007..5bd2e975a 100644 --- a/app/dao/services_dao.py +++ b/app/dao/services_dao.py @@ -24,6 +24,7 @@ from app.models import ( InvitedUser, Service ) +from app.statsd_decorators import statsd def dao_fetch_all_services(): @@ -136,10 +137,12 @@ def delete_service_and_all_associated_db_objects(service): db.session.commit() +@statsd(namespace="dao") def dao_fetch_stats_for_service(service_id): return _stats_for_service_query(service_id).all() +@statsd(namespace="dao") def dao_fetch_todays_stats_for_service(service_id): return _stats_for_service_query(service_id).filter( func.date(Notification.created_at) == date.today() @@ -159,6 +162,7 @@ def _stats_for_service_query(service_id): ) +@statsd(namespace="dao") def dao_fetch_weekly_historical_stats_for_service(service_id): monday_of_notification_week = func.date_trunc('week', NotificationHistory.created_at).label('week_start') return db.session.query( diff --git a/app/notifications/process_client_response.py b/app/notifications/process_client_response.py index aafc88659..737ad21c0 100644 --- a/app/notifications/process_client_response.py +++ b/app/notifications/process_client_response.py @@ -39,8 +39,6 @@ def process_sms_client_response(status, reference, client_name): except KeyError: return success, 'unknown sms client: {}'.format(client_name) - statsd_client.incr('notifications.callback.{}.status.{}'.format(client_name.lower(), status)) - # validate status try: response_dict = response_parser(status) @@ -71,6 +69,6 @@ def process_sms_client_response(status, reference, client_name): reference, notification_status_message)) - statsd_client.incr('notifications.callback.{}.{}'.format(client_name.lower(), notification_statistics_status)) + statsd_client.incr('callback.{}.{}'.format(client_name.lower(), notification_statistics_status)) success = "{} callback succeeded. reference {} updated".format(client_name, reference) return success, errors diff --git a/app/notifications/rest.py b/app/notifications/rest.py index 897dbc456..5461c198e 100644 --- a/app/notifications/rest.py +++ b/app/notifications/rest.py @@ -102,7 +102,7 @@ def process_ses_response(): ) ) - statsd_client.incr('notifications.callback.ses.{}'.format(notification_statistics_status)) + statsd_client.incr('callback.ses.{}'.format(notification_statistics_status)) return jsonify( result="success", message="SES callback succeeded" ), 200 @@ -158,7 +158,6 @@ def process_firetext_response(): response_code = request.form.get('code') status = request.form.get('status') - statsd_client.incr('notifications.callback.firetext.code.{}'.format(response_code)) current_app.logger.info('Firetext status: {}, extended error code: {}'.format(status, response_code)) success, errors = process_sms_client_response(status=status, @@ -306,7 +305,6 @@ def send_notification(notification_type): queue='email' ) - statsd_client.incr('notifications.api.{}'.format(notification_type)) return jsonify( data=get_notification_return_data( notification_id, diff --git a/app/statsd_decorators.py b/app/statsd_decorators.py new file mode 100644 index 000000000..2f83f13b6 --- /dev/null +++ b/app/statsd_decorators.py @@ -0,0 +1,30 @@ +import functools + +from app import statsd_client +from flask import current_app +from monotonic import monotonic + + +def statsd(namespace): + def time_function(func): + @functools.wraps(func) + def wrapper(*args, **kwargs): + start_time = monotonic() + res = func(*args, **kwargs) + elapsed_time = monotonic() - start_time + current_app.logger.info( + "{namespace} call {func} took {time}".format( + namespace=namespace, func=func.__name__, time="{0:.4f}".format(elapsed_time) + ) + ) + statsd_client.incr('{namespace}.{func}'.format( + namespace=namespace, func=func.__name__) + ) + statsd_client.timing('{namespace}.{func}'.format( + namespace=namespace, func=func.__name__), elapsed_time + ) + return res + wrapper.__wrapped__.__name__ = func.__name__ + return wrapper + + return time_function diff --git a/config.py b/config.py index c15993e97..3ae8441c7 100644 --- a/config.py +++ b/config.py @@ -102,32 +102,44 @@ class Config(object): FROM_NUMBER = os.getenv('FROM_NUMBER') STATSD_ENABLED = False - STATSD_HOST = "localhost" - STATSD_PORT = None + STATSD_HOST = "statsd.hostedgraphite.com" + STATSD_PORT = 8125 STATSD_PREFIX = None SENDING_NOTIFICATIONS_TIMEOUT_PERIOD = 259200 class Development(Config): + NOTIFY_ENVIRONMENT = 'development' + CSV_UPLOAD_BUCKET_NAME = 'developement-martyn-notifications-csv-upload' DEBUG = True class Preview(Config): + NOTIFY_ENVIRONMENT = 'preview' CSV_UPLOAD_BUCKET_NAME = 'preview-notifications-csv-upload' + STATSD_PREFIX = "preview" class Test(Development): + NOTIFY_ENVIRONMENT = 'test' CSV_UPLOAD_BUCKET_NAME = 'test-notifications-csv-upload' + STATSD_PREFIX = "test" class Staging(Config): + NOTIFY_ENVIRONMENT = 'staging' CSV_UPLOAD_BUCKET_NAME = 'staging-notify-csv-upload' + STATSD_PREFIX = os.getenv('STATSD_PREFIX') + STATSD_ENABLED = True class Live(Config): + NOTIFY_ENVIRONMENT = 'live' CSV_UPLOAD_BUCKET_NAME = 'live-notifications-csv-upload' STATSD_ENABLED = True + STATSD_PREFIX = os.getenv('STATSD_PREFIX') + STATSD_ENABLED = True configs = { diff --git a/notifications-api.zip b/notifications-api.zip new file mode 100644 index 000000000..83298c812 Binary files /dev/null and b/notifications-api.zip differ diff --git a/requirements.txt b/requirements.txt index 751797f28..1617a241e 100644 --- a/requirements.txt +++ b/requirements.txt @@ -23,4 +23,4 @@ statsd==3.2.1 git+https://github.com/alphagov/notifications-python-client.git@1.0.0#egg=notifications-python-client==1.0.0 -git+https://github.com/alphagov/notifications-utils.git@8.7.2#egg=notifications-utils==8.7.2 +git+https://github.com/alphagov/notifications-utils.git@8.7.3#egg=notifications-utils==8.7.3 diff --git a/tests/app/celery/test_provider_tasks.py b/tests/app/celery/test_provider_tasks.py index eb788129a..648c4a33d 100644 --- a/tests/app/celery/test_provider_tasks.py +++ b/tests/app/celery/test_provider_tasks.py @@ -20,6 +20,11 @@ from app.models import Notification, NotificationStatistics, Job, KEY_TYPE_NORMA from tests.app.conftest import sample_notification +def test_should_have_decorated_tasks_functions(): + assert send_sms_to_provider.__wrapped__.__name__ == 'send_sms_to_provider' + assert send_email_to_provider.__wrapped__.__name__ == 'send_email_to_provider' + + def test_should_by_10_second_delay_as_default(): assert provider_tasks.retry_iteration_to_delay() == 10 @@ -91,9 +96,6 @@ def test_should_send_personalised_template_to_correct_sms_provider_and_persist( mocker.patch('app.mmg_client.send_sms') 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') send_sms_to_provider( db_notification.service_id, @@ -130,9 +132,6 @@ def test_should_send_personalised_template_to_correct_email_provider_and_persist mocker.patch('app.aws_ses_client.send_email', return_value='reference') mocker.patch('app.aws_ses_client.get_name', return_value="ses") - mocker.patch('app.statsd_client.incr') - mocker.patch('app.statsd_client.timing_with_dates') - mocker.patch('app.statsd_client.timing') send_email_to_provider( db_notification.service_id, @@ -296,29 +295,6 @@ def test_should_not_send_to_provider_when_status_is_not_created(notify_db, notif app.celery.research_mode_tasks.send_sms_response.apply_async.assert_not_called() -def test_send_sms_statsd_updates(notify_db, notify_db_session, sample_service, sample_notification, mocker): - mocker.patch('app.statsd_client.incr') - mocker.patch('app.statsd_client.timing') - mocker.patch('app.mmg_client.send_sms') - mocker.patch('app.mmg_client.get_name', return_value="mmg") - - send_sms_to_provider( - sample_notification.service_id, - sample_notification.id - ) - - statsd_client.incr.assert_called_once_with("notifications.tasks.send-sms-to-provider") - - statsd_client.timing.assert_has_calls([ - call("notifications.tasks.send-sms-to-provider.task-time", ANY), - call("notifications.sms.total-time", ANY) - ]) - - # assert that the ANYs above are at least floats - for call_arg in statsd_client.timing.call_args_list: - assert isinstance(call_arg[0][1], float) - - def test_should_go_into_technical_error_if_exceeds_retries( notify_db, notify_db_session, @@ -328,8 +304,6 @@ def test_should_go_into_technical_error_if_exceeds_retries( notification = sample_notification(notify_db=notify_db, notify_db_session=notify_db_session, service=sample_service, status='created') - mocker.patch('app.statsd_client.incr') - mocker.patch('app.statsd_client.timing') mocker.patch('app.mmg_client.send_sms', side_effect=SmsClientException("EXPECTED")) mocker.patch('app.celery.provider_tasks.send_sms_to_provider.retry', side_effect=MaxRetriesExceededError()) @@ -339,8 +313,6 @@ def test_should_go_into_technical_error_if_exceeds_retries( ) provider_tasks.send_sms_to_provider.retry.assert_called_with(queue='retry', countdown=10) - assert statsd_client.incr.assert_not_called - assert statsd_client.timing.assert_not_called db_notification = Notification.query.filter_by(id=notification.id).one() assert db_notification.status == 'technical-failure' @@ -368,9 +340,6 @@ def test_should_send_sms_sender_from_service_if_present( mocker.patch('app.mmg_client.send_sms') 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') send_sms_to_provider( db_notification.service_id, @@ -449,8 +418,6 @@ def test_send_email_to_provider_should_go_into_technical_error_if_exceeds_retrie notification = sample_notification(notify_db=notify_db, notify_db_session=notify_db_session, service=sample_service, status='created', template=sample_email_template) - mocker.patch('app.statsd_client.incr') - mocker.patch('app.statsd_client.timing') mocker.patch('app.aws_ses_client.send_email', side_effect=EmailClientException("EXPECTED")) mocker.patch('app.celery.provider_tasks.send_email_to_provider.retry', side_effect=MaxRetriesExceededError()) @@ -460,8 +427,6 @@ def test_send_email_to_provider_should_go_into_technical_error_if_exceeds_retrie ) provider_tasks.send_email_to_provider.retry.assert_called_with(queue='retry', countdown=10) - assert statsd_client.incr.assert_not_called - assert statsd_client.timing.assert_not_called db_notification = Notification.query.filter_by(id=notification.id).one() assert db_notification.status == 'technical-failure' @@ -473,31 +438,6 @@ def test_send_email_to_provider_should_go_into_technical_error_if_exceeds_retrie assert job.notifications_failed == 1 -def test_send_email_to_provider_statsd_updates(notify_db, notify_db_session, sample_service, - sample_email_template, mocker): - mocker.patch('app.statsd_client.incr') - mocker.patch('app.statsd_client.timing') - mocker.patch('app.aws_ses_client.send_email', return_value='reference') - mocker.patch('app.aws_ses_client.get_name', return_value="ses") - notification = sample_notification(notify_db=notify_db, notify_db_session=notify_db_session, - template=sample_email_template) - send_email_to_provider( - notification.service_id, - notification.id - ) - - statsd_client.incr.assert_called_once_with("notifications.tasks.send-email-to-provider") - - statsd_client.timing.assert_has_calls([ - call("notifications.tasks.send-email-to-provider.task-time", ANY), - call("notifications.email.total-time", ANY) - ]) - - # assert that the ANYs above are at least floats - for call_arg in statsd_client.timing.call_args_list: - assert isinstance(call_arg[0][1], float) - - def test_send_email_to_provider_should_not_send_to_provider_when_status_is_not_created(notify_db, notify_db_session, sample_service, sample_email_template, @@ -524,8 +464,6 @@ def test_send_email_should_use_service_reply_to_email( sample_service, sample_email_template, mocker): - mocker.patch('app.statsd_client.incr') - mocker.patch('app.statsd_client.timing') mocker.patch('app.aws_ses_client.send_email', return_value='reference') mocker.patch('app.aws_ses_client.get_name', return_value="ses") diff --git a/tests/app/celery/test_scheduled_tasks.py b/tests/app/celery/test_scheduled_tasks.py index 9c477918d..0564b1712 100644 --- a/tests/app/celery/test_scheduled_tasks.py +++ b/tests/app/celery/test_scheduled_tasks.py @@ -11,6 +11,14 @@ from app.celery.scheduled_tasks import (delete_verify_codes, from tests.app.conftest import sample_notification +def test_should_have_decorated_tasks_functions(): + assert delete_verify_codes.__wrapped__.__name__ == 'delete_verify_codes' + assert delete_successful_notifications.__wrapped__.__name__ == 'delete_successful_notifications' + assert delete_failed_notifications.__wrapped__.__name__ == 'delete_failed_notifications' + assert timeout_notifications.__wrapped__.__name__ == 'timeout_notifications' + assert delete_invitations.__wrapped__.__name__ == 'delete_invitations' + + def test_should_call_delete_notifications_more_than_week_in_task(notify_api, mocker): mocked = mocker.patch('app.celery.scheduled_tasksgit .delete_notifications_created_more_than_a_week_ago') delete_successful_notifications() diff --git a/tests/app/celery/test_tasks.py b/tests/app/celery/test_tasks.py index ab6a6cafb..547ee769e 100644 --- a/tests/app/celery/test_tasks.py +++ b/tests/app/celery/test_tasks.py @@ -7,10 +7,10 @@ from mock import ANY from sqlalchemy.exc import SQLAlchemyError from sqlalchemy.orm.exc import NoResultFound -from app import (encryption, DATETIME_FORMAT, statsd_client) +from app import (encryption, DATETIME_FORMAT) from app.celery import provider_tasks from app.celery import tasks -from app.celery.tasks import s3 +from app.celery.tasks import s3, remove_job from app.celery.tasks import ( send_sms, process_job, @@ -53,10 +53,15 @@ def _notification_json(template, to, personalisation=None, job_id=None, row_numb return notification +def test_should_have_decorated_tasks_functions(): + assert process_job.__wrapped__.__name__ == 'process_job' + assert remove_job.__wrapped__.__name__ == 'remove_job' + assert send_sms.__wrapped__.__name__ == 'send_sms' + assert send_email.__wrapped__.__name__ == 'send_email' + + @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") @@ -81,8 +86,6 @@ 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") @@ -278,9 +281,6 @@ def test_should_send_template_to_correct_sms_task_and_persist(sample_template_wi notification = _notification_json(sample_template_with_placeholders, to="+447234123123", personalisation={"name": "Jo"}) - mocker.patch('app.statsd_client.incr') - mocker.patch('app.statsd_client.timing_with_dates') - mocker.patch('app.statsd_client.timing') mocker.patch('app.celery.provider_tasks.send_sms_to_provider.apply_async') notification_id = uuid.uuid4() @@ -292,15 +292,12 @@ def test_should_send_template_to_correct_sms_task_and_persist(sample_template_wi datetime.utcnow().strftime(DATETIME_FORMAT) ) - statsd_client.timing.assert_called_once_with("notifications.tasks.send-sms.task-time", ANY) - provider_tasks.send_sms_to_provider.apply_async.assert_called_once_with( (sample_template_with_placeholders.service_id, notification_id), queue="sms" ) - statsd_client.incr.assert_called_once_with("notifications.tasks.send-sms") persisted_notification = Notification.query.filter_by(id=notification_id).one() assert persisted_notification.id == notification_id assert persisted_notification.to == '+447234123123' @@ -436,9 +433,6 @@ def test_should_use_email_template_and_persist(sample_email_template_with_placeh "my_email@my_email.com", {"name": "Jo"}, row_number=1) - mocker.patch('app.statsd_client.incr') - mocker.patch('app.statsd_client.timing_with_dates') - mocker.patch('app.statsd_client.timing') mocker.patch('app.celery.provider_tasks.send_email_to_provider.apply_async') notification_id = uuid.uuid4() @@ -456,8 +450,6 @@ def test_should_use_email_template_and_persist(sample_email_template_with_placeh key_type=KEY_TYPE_TEAM ) - statsd_client.incr.assert_called_once_with("notifications.tasks.send-email") - statsd_client.timing.assert_called_once_with("notifications.tasks.send-email.task-time", ANY) persisted_notification = Notification.query.filter_by(id=notification_id).one() provider_tasks.send_email_to_provider.apply_async.assert_called_once_with( (sample_email_template_with_placeholders.service_id, notification_id), queue='email') diff --git a/tests/app/conftest.py b/tests/app/conftest.py index 38a5ca956..495b8ec48 100644 --- a/tests/app/conftest.py +++ b/tests/app/conftest.py @@ -370,6 +370,16 @@ def sample_notification(notify_db, return notification +@pytest.fixture(scope='function') +def mock_statsd_inc(mocker): + return mocker.patch('app.statsd_client.incr') + + +@pytest.fixture(scope='function') +def mock_statsd_timing(mocker): + return mocker.patch('app.statsd_client.timing') + + @pytest.fixture(scope='function') def sample_notification_history(notify_db, notify_db_session, diff --git a/tests/app/dao/test_notification_dao.py b/tests/app/dao/test_notification_dao.py index 972f65944..40c5228a2 100644 --- a/tests/app/dao/test_notification_dao.py +++ b/tests/app/dao/test_notification_dao.py @@ -5,6 +5,7 @@ from functools import partial import pytest from freezegun import freeze_time +from mock import ANY from sqlalchemy.exc import SQLAlchemyError, IntegrityError from app import db @@ -32,14 +33,36 @@ from app.dao.notifications_dao import ( update_provider_stats, update_notification_status_by_reference, dao_get_template_statistics_for_service, - get_notifications_for_service -) + get_notifications_for_service, dao_get_7_day_agg_notification_statistics_for_service, + dao_get_potential_notification_statistics_for_day, dao_get_notification_statistics_for_day, + dao_get_template_statistics_for_template, get_notification_by_id) from notifications_utils.template import get_sms_fragment_count from tests.app.conftest import (sample_notification) +def test_should_have_decorated_notifications_dao_functions(): + assert dao_get_notification_statistics_for_service.__wrapped__.__name__ == 'dao_get_notification_statistics_for_service' # noqa + assert dao_get_notification_statistics_for_service_and_day.__wrapped__.__name__ == 'dao_get_notification_statistics_for_service_and_day' # noqa + assert dao_get_notification_statistics_for_day.__wrapped__.__name__ == 'dao_get_notification_statistics_for_day' # noqa + assert dao_get_potential_notification_statistics_for_day.__wrapped__.__name__ == 'dao_get_potential_notification_statistics_for_day' # noqa + assert dao_get_7_day_agg_notification_statistics_for_service.__wrapped__.__name__ == 'dao_get_7_day_agg_notification_statistics_for_service' # noqa + assert dao_get_template_statistics_for_service.__wrapped__.__name__ == 'dao_get_template_statistics_for_service' # noqa + assert dao_get_template_statistics_for_template.__wrapped__.__name__ == 'dao_get_template_statistics_for_template' # noqa + assert dao_create_notification.__wrapped__.__name__ == 'dao_create_notification' # noqa + assert update_notification_status_by_id.__wrapped__.__name__ == 'update_notification_status_by_id' # noqa + assert dao_update_notification.__wrapped__.__name__ == 'dao_update_notification' # noqa + assert update_provider_stats.__wrapped__.__name__ == 'update_provider_stats' # noqa + assert update_notification_status_by_reference.__wrapped__.__name__ == 'update_notification_status_by_reference' # noqa + assert get_notification_for_job.__wrapped__.__name__ == 'get_notification_for_job' # noqa + assert get_notifications_for_job.__wrapped__.__name__ == 'get_notifications_for_job' # noqa + assert get_notification.__wrapped__.__name__ == 'get_notification' # noqa + assert get_notifications_for_service.__wrapped__.__name__ == 'get_notifications_for_service' # noqa + assert get_notification_by_id.__wrapped__.__name__ == 'get_notification_by_id' # noqa + assert delete_notifications_created_more_than_a_week_ago.__wrapped__.__name__ == 'delete_notifications_created_more_than_a_week_ago' # noqa + + def test_should_by_able_to_update_status_by_reference(sample_email_template, ses_provider): data = _notification_json(sample_email_template, status='sending') @@ -163,7 +186,7 @@ def test_should_not_update_status_one_notification_status_is_delivered(notify_db _assert_job_stats(notification.job_id, sent=1, count=1, delivered=1, failed=0) -def test_should_be_able_to_record_statistics_failure_for_sms(notify_db, notify_db_session,): +def test_should_be_able_to_record_statistics_failure_for_sms(notify_db, notify_db_session, ): notification = sample_notification(notify_db=notify_db, notify_db_session=notify_db_session, status='sending') assert Notification.query.get(notification.id).status == 'sending' @@ -313,7 +336,6 @@ def test_should_be_able_to_get_all_statistics_for_a_service_for_several_days_pre def test_create_notification_creates_notification_with_personalisation(notify_db, notify_db_session, sample_template_with_placeholders, sample_job, mmg_provider): - assert Notification.query.count() == 0 assert NotificationStatistics.query.count() == 0 assert TemplateStatistics.query.count() == 0 @@ -664,7 +686,6 @@ def test_get_all_notifications_for_job(notify_db, notify_db_session, sample_job) def test_get_all_notifications_for_job_by_status(notify_db, notify_db_session, sample_job): - notifications = partial(get_notifications_for_job, sample_job.service.id, sample_job.id) for status in NOTIFICATION_STATUS_TYPES: diff --git a/tests/app/dao/test_services_dao.py b/tests/app/dao/test_services_dao.py index 4369c1c4f..943343b61 100644 --- a/tests/app/dao/test_services_dao.py +++ b/tests/app/dao/test_services_dao.py @@ -44,6 +44,12 @@ from tests.app.conftest import ( ) +def test_should_have_decorated_services_dao_functions(): + assert dao_fetch_weekly_historical_stats_for_service.__wrapped__.__name__ == 'dao_fetch_weekly_historical_stats_for_service' # noqa + assert dao_fetch_todays_stats_for_service.__wrapped__.__name__ == 'dao_fetch_todays_stats_for_service' # noqa + assert dao_fetch_stats_for_service.__wrapped__.__name__ == 'dao_fetch_stats_for_service' # noqa + + def test_create_service(sample_user): assert Service.query.count() == 0 service = Service(name="service_name", diff --git a/tests/app/notifications/rest/test_callbacks.py b/tests/app/notifications/rest/test_callbacks.py index b173fc90d..738e8ae95 100644 --- a/tests/app/notifications/rest/test_callbacks.py +++ b/tests/app/notifications/rest/test_callbacks.py @@ -542,34 +542,6 @@ def test_ses_callback_should_update_multiple_notification_status_sent( assert stats.emails_failed == 0 -def test_ses_callback_should_update_record_statsd( - notify_api, - notify_db, - notify_db_session, - sample_email_template, - mocker): - with notify_api.test_request_context(): - with notify_api.test_client() as client: - mocker.patch('app.statsd_client.incr') - - notification = create_sample_notification( - notify_db, - notify_db_session, - template=sample_email_template, - reference='ref', - status='sending' - ) - - assert get_notification_by_id(notification.id).status == 'sending' - - client.post( - path='/notifications/email/ses', - data=ses_notification_callback(), - headers=[('Content-Type', 'text/plain; charset=UTF-8')] - ) - app.statsd_client.incr.assert_called_once_with("notifications.callback.ses.delivered") - - def test_ses_callback_should_set_status_to_temporary_failure(notify_api, notify_db, notify_db_session, @@ -707,9 +679,7 @@ def test_process_mmg_response_records_statsd(notify_api, sample_notification, mo client.post(path='notifications/sms/mmg', data=data, headers=[('Content-Type', 'application/json')]) - assert app.statsd_client.incr.call_count == 2 - app.statsd_client.incr.assert_any_call("notifications.callback.mmg.delivered") - app.statsd_client.incr.assert_any_call("notifications.callback.mmg.status.3") + app.statsd_client.incr.assert_any_call("callback.mmg.delivered") def test_firetext_callback_should_record_statsd(notify_api, notify_db, notify_db_session, mocker): @@ -725,10 +695,7 @@ def test_firetext_callback_should_record_statsd(notify_api, notify_db, notify_db ), headers=[('Content-Type', 'application/x-www-form-urlencoded')]) - assert app.statsd_client.incr.call_count == 3 - app.statsd_client.incr.assert_any_call("notifications.callback.firetext.code.101") - app.statsd_client.incr.assert_any_call("notifications.callback.firetext.status.0") - app.statsd_client.incr.assert_any_call("notifications.callback.firetext.delivered") + app.statsd_client.incr.assert_any_call("callback.firetext.delivered") def ses_validation_code_callback(): diff --git a/tests/app/notifications/rest/test_send_notification.py b/tests/app/notifications/rest/test_send_notification.py index 301c67ecf..c201a11d0 100644 --- a/tests/app/notifications/rest/test_send_notification.py +++ b/tests/app/notifications/rest/test_send_notification.py @@ -10,7 +10,7 @@ from notifications_python_client.authentication import create_jwt_token import app from app import encryption -from app.models import ApiKey, KEY_TYPE_TEAM, KEY_TYPE_TEST +from app.models import ApiKey, KEY_TYPE_TEAM from app.dao.templates_dao import dao_get_all_templates_for_service, dao_update_template from app.dao.services_dao import dao_update_service from app.dao.api_key_dao import save_model_api_key @@ -37,7 +37,6 @@ def test_create_sms_should_reject_if_missing_required_fields(notify_api, sample_ headers=[('Content-Type', 'application/json'), auth_header]) json_resp = json.loads(response.get_data(as_text=True)) - app.celery.tasks.send_sms.apply_async.assert_not_called() assert json_resp['result'] == 'error' assert 'Missing data for required field.' in json_resp['message']['to'][0] assert 'Missing data for required field.' in json_resp['message']['template'][0] @@ -313,13 +312,13 @@ def test_should_not_allow_template_from_another_service(notify_api, service_fact ] ) def test_should_not_allow_template_content_too_large( - notify_api, - notify_db, - notify_db_session, - sample_user, - template_type, - mocker, - should_error + notify_api, + notify_db, + notify_db_session, + sample_user, + template_type, + mocker, + should_error ): with notify_api.test_request_context(): with notify_api.test_client() as client: @@ -655,50 +654,6 @@ def test_should_allow_api_call_if_under_day_limit_regardless_of_type(notify_db, assert response.status_code == 201 -def test_should_record_email_request_in_statsd(notify_api, sample_email_template, mocker): - with notify_api.test_request_context(): - with notify_api.test_client() as client: - mocker.patch('app.statsd_client.incr') - mocker.patch('app.celery.tasks.send_email.apply_async') - mocker.patch('app.encryption.encrypt', return_value="something_encrypted") - - data = { - 'to': 'ok@ok.com', - 'template': str(sample_email_template.id) - } - - auth_header = create_authorization_header(service_id=sample_email_template.service_id) - - response = client.post( - path='/notifications/email', - data=json.dumps(data), - headers=[('Content-Type', 'application/json'), auth_header]) - assert response.status_code == 201 - app.statsd_client.incr.assert_called_once_with("notifications.api.email") - - -def test_should_record_sms_request_in_statsd(notify_api, sample_template, mocker): - with notify_api.test_request_context(): - with notify_api.test_client() as client: - mocker.patch('app.statsd_client.incr') - mocker.patch('app.celery.tasks.send_sms.apply_async') - mocker.patch('app.encryption.encrypt', return_value="something_encrypted") - - data = { - 'to': '07123123123', - 'template': str(sample_template.id) - } - - auth_header = create_authorization_header(service_id=sample_template.service_id) - - response = client.post( - path='/notifications/sms', - data=json.dumps(data), - headers=[('Content-Type', 'application/json'), auth_header]) - assert response.status_code == 201 - app.statsd_client.incr.assert_called_once_with("notifications.api.sms") - - def test_should_not_return_html_in_body(notify_api, notify_db, notify_db_session, mocker): with notify_api.test_request_context(): with notify_api.test_client() as client: diff --git a/tests/app/test_statsd_decorators.py b/tests/app/test_statsd_decorators.py new file mode 100644 index 000000000..3470f9038 --- /dev/null +++ b/tests/app/test_statsd_decorators.py @@ -0,0 +1,24 @@ +from mock import ANY + +from app.statsd_decorators import statsd +import app + + +class AnyStringWith(str): + def __eq__(self, other): + return self in other + + +def test_should_call_statsd(notify_api, mocker): + mocker.patch('app.statsd_client.incr') + mocker.patch('app.statsd_client.timing') + mock_logger = mocker.patch.object(notify_api.logger, 'info') + + @statsd(namespace="test") + def test_function(): + return True + + assert test_function() + app.statsd_client.incr.assert_called_once_with("test.test_function") + app.statsd_client.timing.assert_called_once_with("test.test_function", ANY) + mock_logger.assert_called_once_with(AnyStringWith("test call test_function took "))