From f1abce22ae016cf369c8efa467afc04bc0a7101c Mon Sep 17 00:00:00 2001
From: Richard Chapman <richard.chapman@digital.cabinet-office.gov.uk>
Date: Tue, 3 Apr 2018 12:31:52 +0100
Subject: [PATCH] Logging refactor to make debugging easier. Before the
 filename needed to be known. Added the notification id to the logging message
 so that the notification can be traced through the logging system by knowing
 the notification id, making it easier to debug. Also changed to raise an
 exception so that alerts are generated. This way we should get an email to
 say that there has been an error.

---
 app/celery/letters_pdf_tasks.py            | 11 ++++++++---
 app/errors.py                              |  6 ++++++
 tests/app/celery/test_letters_pdf_tasks.py |  9 +++++++--
 3 files changed, 21 insertions(+), 5 deletions(-)

diff --git a/app/celery/letters_pdf_tasks.py b/app/celery/letters_pdf_tasks.py
index 9c05ab223..0d4f77fef 100644
--- a/app/celery/letters_pdf_tasks.py
+++ b/app/celery/letters_pdf_tasks.py
@@ -21,6 +21,7 @@ from app.dao.notifications_dao import (
     dao_get_notifications_by_references,
     dao_update_notifications_by_reference,
 )
+from app.errors import VirusScanError
 from app.letters.utils import (
     get_reference_from_filename,
     move_scanned_pdf_to_test_or_live_pdf_bucket,
@@ -162,9 +163,9 @@ def letter_in_created_state(filename):
 
 @notify_celery.task(name='process-virus-scan-passed')
 def process_virus_scan_passed(filename):
-    current_app.logger.info('Virus scan passed: {}'.format(filename))
     reference = get_reference_from_filename(filename)
     notification = dao_get_notification_by_reference(reference)
+    current_app.logger.info('notification id {} Virus scan passed: {}'.format(notification.id, filename))
 
     is_test_key = notification.key_type == KEY_TYPE_TEST
     move_scanned_pdf_to_test_or_live_pdf_bucket(
@@ -179,9 +180,9 @@ def process_virus_scan_passed(filename):
 
 @notify_celery.task(name='process-virus-scan-failed')
 def process_virus_scan_failed(filename):
-    current_app.logger.exception('Virus scan failed: {}'.format(filename))
     move_failed_pdf(filename, ScanErrorType.FAILURE)
     reference = get_reference_from_filename(filename)
+    notification = dao_get_notification_by_reference(reference)
     updated_count = update_letter_pdf_status(reference, NOTIFICATION_VIRUS_SCAN_FAILED)
 
     if updated_count != 1:
@@ -191,12 +192,14 @@ def process_virus_scan_failed(filename):
             )
         )
 
+    raise VirusScanError('notification id {} Virus scan failed: {}'.format(notification.id, filename))
+
 
 @notify_celery.task(name='process-virus-scan-error')
 def process_virus_scan_error(filename):
-    current_app.logger.exception('Virus scan error: {}'.format(filename))
     move_failed_pdf(filename, ScanErrorType.ERROR)
     reference = get_reference_from_filename(filename)
+    notification = dao_get_notification_by_reference(reference)
     updated_count = update_letter_pdf_status(reference, NOTIFICATION_TECHNICAL_FAILURE)
 
     if updated_count != 1:
@@ -206,6 +209,8 @@ def process_virus_scan_error(filename):
             )
         )
 
+    raise VirusScanError('notification id {} Virus scan error: {}'.format(notification.id, filename))
+
 
 def update_letter_pdf_status(reference, status):
     return dao_update_notifications_by_reference(
diff --git a/app/errors.py b/app/errors.py
index c2461f3cd..c5df8892f 100644
--- a/app/errors.py
+++ b/app/errors.py
@@ -10,6 +10,12 @@ from jsonschema import ValidationError as JsonSchemaValidationError
 from app.authentication.auth import AuthError
 
 
+class VirusScanError(Exception):
+    def __init__(self, message):
+
+        super().__init__(message)
+
+
 class InvalidRequest(Exception):
     code = None
     fields = []
diff --git a/tests/app/celery/test_letters_pdf_tasks.py b/tests/app/celery/test_letters_pdf_tasks.py
index 9d07e7239..055b711d9 100644
--- a/tests/app/celery/test_letters_pdf_tasks.py
+++ b/tests/app/celery/test_letters_pdf_tasks.py
@@ -10,6 +10,7 @@ from celery.exceptions import MaxRetriesExceededError
 from requests import RequestException
 from sqlalchemy.orm.exc import NoResultFound
 
+from app.errors import VirusScanError
 from app.variables import Retention
 from app.celery.letters_pdf_tasks import (
     create_letters_pdf,
@@ -343,8 +344,10 @@ def test_process_letter_task_check_virus_scan_failed(sample_letter_notification,
     sample_letter_notification.status = 'pending-virus-check'
     mock_move_failed_pdf = mocker.patch('app.celery.letters_pdf_tasks.move_failed_pdf')
 
-    process_virus_scan_failed(filename)
+    with pytest.raises(VirusScanError) as e:
+        process_virus_scan_failed(filename)
 
+    assert "Virus scan failed:" in str(e)
     mock_move_failed_pdf.assert_called_once_with(filename, ScanErrorType.FAILURE)
     assert sample_letter_notification.status == NOTIFICATION_VIRUS_SCAN_FAILED
 
@@ -354,7 +357,9 @@ def test_process_letter_task_check_virus_scan_error(sample_letter_notification,
     sample_letter_notification.status = 'pending-virus-check'
     mock_move_failed_pdf = mocker.patch('app.celery.letters_pdf_tasks.move_failed_pdf')
 
-    process_virus_scan_error(filename)
+    with pytest.raises(VirusScanError) as e:
+        process_virus_scan_error(filename)
 
+    assert "Virus scan error:" in str(e)
     mock_move_failed_pdf.assert_called_once_with(filename, ScanErrorType.ERROR)
     assert sample_letter_notification.status == NOTIFICATION_TECHNICAL_FAILURE