From 666ac1ab4f1303425939e355da6e2ba3ec4072af Mon Sep 17 00:00:00 2001 From: Ben Thorner Date: Tue, 16 Nov 2021 17:33:36 +0000 Subject: [PATCH] Log activity on all periodic Celery tasks As stated in the comment, this would have been helpful during an incident to give further reassurance that a task had at least started running - at the time the only evidence for this was the Cronitor dashboard itself, which we don't often look at. I've removed other, equivalent "starting" logs, but kept those that provide additional information in the log message. --- app/celery/letters_pdf_tasks.py | 1 - app/celery/reporting_tasks.py | 2 -- app/cronitor.py | 5 ++++- tests/app/test_cronitor.py | 4 ++++ 4 files changed, 8 insertions(+), 4 deletions(-) diff --git a/app/celery/letters_pdf_tasks.py b/app/celery/letters_pdf_tasks.py index 4efb22f64..19e627c8a 100644 --- a/app/celery/letters_pdf_tasks.py +++ b/app/celery/letters_pdf_tasks.py @@ -126,7 +126,6 @@ def collate_letter_pdfs_to_be_sent(): that have not yet been sent. If run after midnight, it will collect up letters created before 5:30pm the day before. """ - current_app.logger.info("starting collate-letter-pdfs-to-be-sent") print_run_date = convert_utc_to_bst(datetime.utcnow()) if print_run_date.time() < LETTER_PROCESSING_DEADLINE: print_run_date = print_run_date - timedelta(days=1) diff --git a/app/celery/reporting_tasks.py b/app/celery/reporting_tasks.py index 1645f8b25..dc8940291 100644 --- a/app/celery/reporting_tasks.py +++ b/app/celery/reporting_tasks.py @@ -20,7 +20,6 @@ from app.models import EMAIL_TYPE, LETTER_TYPE, SMS_TYPE @notify_celery.task(name="create-nightly-billing") @cronitor("create-nightly-billing") def create_nightly_billing(day_start=None): - current_app.logger.info("create-nightly-billing task: started") # day_start is a datetime.date() object. e.g. # up to 4 days of data counting back from day_start is consolidated if day_start is None: @@ -67,7 +66,6 @@ def create_nightly_billing_for_day(process_day): @notify_celery.task(name="create-nightly-notification-status") @cronitor("create-nightly-notification-status") def create_nightly_notification_status(): - current_app.logger.info("create-nightly-notification-status task: started") yesterday = convert_utc_to_bst(datetime.utcnow()).date() - timedelta(days=1) # email and sms diff --git a/app/cronitor.py b/app/cronitor.py index e0580fec4..e50cad122 100644 --- a/app/cronitor.py +++ b/app/cronitor.py @@ -5,12 +5,15 @@ from flask import current_app def cronitor(task_name): - # check if task_name is in config def decorator(func): def ping_cronitor(command): if not current_app.config['CRONITOR_ENABLED']: return + # it's useful to have a log that a periodic task has started in case it + # get stuck without generating any other logs - we know it got this far + current_app.logger.info(f'Pinging Cronitor for Celery task {task_name}') + task_slug = current_app.config['CRONITOR_KEYS'].get(task_name) if not task_slug: current_app.logger.error( diff --git a/tests/app/test_cronitor.py b/tests/app/test_cronitor.py index dcf494e7a..1ffba7ba1 100644 --- a/tests/app/test_cronitor.py +++ b/tests/app/test_cronitor.py @@ -1,3 +1,4 @@ +import logging from urllib import parse import pytest @@ -75,6 +76,9 @@ def test_cronitor_does_nothing_if_cronitor_not_enabled(notify_api, rmock): def test_cronitor_does_nothing_if_name_not_recognised(notify_api, rmock, caplog): + # ignore "INFO" log about task starting + caplog.set_level(logging.ERROR) + with set_config_values(notify_api, { 'CRONITOR_ENABLED': True, 'CRONITOR_KEYS': {'not-hello': 'other'}