Merge pull request #78 from uktrade/LTD-1088-Export-queue-status-to-S…

…entry

LTD-1088: Expose Mail queue status to Sentry periodically

mail/libraries/helpers.py

@@ -1,6 +1,7 @@
 import base64
 import json
 import logging
+import sentry_sdk
 
 from dateutil.parser import parse
 from django.conf import settings
@@ -11,6 +12,7 @@
 from mail.enums import SourceEnum, ExtractTypeEnum, UnitMapping, ReceptionStatusEnum
 from mail.libraries.email_message_dto import EmailMessageDto, HmrcEmailMessageDto
 from mail.models import LicenceData, UsageData, Mail, GoodIdMapping, LicenceIdMapping
+from mail import serializers
 
 ALLOWED_FILE_MIMETYPES = ["application/octet-stream", "text/plain"]
 
@@ -335,3 +337,77 @@ def get_country_id(country):
 
 def sort_dtos_by_date(input_dtos):
     return sorted(input_dtos, key=lambda d: d[0].date)
+
+
+def log_to_sentry(message, extra=None, level="info"):
+    extra = extra or {}
+    with sentry_sdk.push_scope() as scope:
+        for key, value in extra.items():
+            scope.set_extra(key, value)
+        sentry_sdk.capture_message(message, level=level)
+
+
+def get_licence_data_status():
+    mail = (
+        Mail.objects.filter(extract_type__in=[ExtractTypeEnum.LICENCE_DATA, ExtractTypeEnum.LICENCE_REPLY])
+        .order_by("created_at")
+        .last()
+    )
+    licence_data_qs = LicenceData.objects.filter(mail=mail)
+    if not licence_data_qs:
+        return {}
+
+    licence_data = licence_data_qs.first()
+    status = serializers.LicenceDataStatusSerializer(licence_data).data
+
+    # usually we should receive reply in 20-30 min
+    processing_time_min = status.get("processing_time")
+    if mail.status == ReceptionStatusEnum.REPLY_PENDING:
+        status["waiting_time"] = f"Reply waiting time {processing_time_min} min"
+    elif mail.status == ReceptionStatusEnum.REPLY_SENT:
+        status["round_trip_time"] = f"Total round trip time {processing_time_min} min"
+
+    return status
+
+
+def get_usage_data_status():
+    mail = Mail.objects.filter(extract_type=ExtractTypeEnum.USAGE_DATA).order_by("created_at").last()
+    usage_data_qs = UsageData.objects.filter(mail=mail)
+    if not usage_data_qs:
+        return {}
+
+    usage_data = usage_data_qs.first()
+    return serializers.UsageDataStatusSerializer(usage_data).data
+
+
+def publish_queue_status():
+    """
+    Uses the last Licence data mail and Usage data to get the status of the queue.
+
+    Since we shouldn't sent next licence data mail without receiving reply for the previous one
+    checking the last mail is sufficient to detect any anamolies.
+    """
+    queue_status = {}
+    queue_status["licence_data"] = get_licence_data_status()
+    queue_status["usage_data"] = get_usage_data_status()
+
+    ## In the increasing order of severity
+    queue_state = "HEALTHY"
+    extra_state = {}
+
+    licence_data_status = queue_status.get("licence_data")
+    if licence_data_status:
+        processing_time = licence_data_status.get("processing_time")
+        if "waiting_time" in licence_data_status and processing_time > 30:
+            queue_state = "RESPONSE TIMEOUT"
+
+        # we should only be waiting for reply for one licence data mail
+        if licence_data_status["reply_pending_count"] > 1:
+            queue_state = "REQUIRES ATTENTION"
+
+        extra_state = {**queue_status["licence_data"]}
+
+    if "usage_data" in queue_status:
+        extra_state = {**extra_state, **queue_status["usage_data"]}
+
+    log_to_sentry(f"Mail queue status: {queue_state} (see additional data below)", extra=extra_state)

mail/libraries/routing_controller.py

@@ -16,7 +16,12 @@
     lock_db_for_sending_transaction,
 )
 from mail.libraries.email_message_dto import EmailMessageDto
-from mail.libraries.helpers import select_email_for_sending, sort_dtos_by_date, check_for_pending_messages
+from mail.libraries.helpers import (
+    select_email_for_sending,
+    sort_dtos_by_date,
+    check_for_pending_messages,
+    publish_queue_status,
+)
 from mail.libraries.mailbox_service import send_email, get_message_iterator
 from mail.models import Mail
 from mail.servers import MailServer
@@ -101,6 +106,9 @@ def check_and_route_emails():
             _collect_and_send(pending_message)
 
         logger.info(f"No new emails found from {hmrc_to_dit_server.user} or {spire_to_dit_server.user}")
+
+        publish_queue_status()
+
         return
 
     for email, mark_status in email_message_dtos:
@@ -121,6 +129,8 @@ def check_and_route_emails():
         )
         _collect_and_send(mail)
 
+    publish_queue_status()
+
 
 def update_mail(mail: Mail, mail_dto: EmailMessageDto):
     previous_status = mail.status

mail/serializers.py

@@ -1,9 +1,10 @@
 import json
 import logging
 
+from datetime import datetime
 from rest_framework import serializers
 
-from mail.enums import LicenceActionEnum
+from mail import enums
 from mail.models import Mail, LicenceData, UsageData, LicenceIdMapping
 
 
@@ -181,14 +182,58 @@ class LiteLicenceDataSerializer(serializers.Serializer):
     old_id = serializers.CharField(required=False)
 
     def validate(self, attrs):
-        if self.initial_data.get("action") == LicenceActionEnum.UPDATE and not attrs.get("old_id"):
+        if self.initial_data.get("action") == enums.LicenceActionEnum.UPDATE and not attrs.get("old_id"):
             raise serializers.ValidationError("old_id is a required field for action - update")
         return attrs
 
     def validate_old_id(self, value):
         if (
-            self.initial_data.get("action") == LicenceActionEnum.UPDATE
+            self.initial_data.get("action") == enums.LicenceActionEnum.UPDATE
             and not LicenceIdMapping.objects.filter(lite_id=value).exists()
         ):
             raise serializers.ValidationError("This licence does not exist in HMRC integration records")
         return value
+
+
+class LicenceDataStatusSerializer(serializers.ModelSerializer):
+    licence_data_status = serializers.SerializerMethodField()
+    reply_pending_count = serializers.SerializerMethodField()
+    processing_time = serializers.SerializerMethodField()
+
+    class Meta:
+        model = LicenceData
+        fields = ("licence_data_status", "reply_pending_count", "processing_time")
+
+    def get_licence_data_status(self, instance):
+        if instance.mail.status == enums.ReceptionStatusEnum.PENDING:
+            return f"The mail with run number {instance.hmrc_run_number} is not yet sent to HMRC (which is {instance.source_run_number} for {instance.source})"
+        elif instance.mail.status == enums.ReceptionStatusEnum.REPLY_PENDING:
+            return f"Reply pending, waiting for reply for HMRC run number {instance.hmrc_run_number} (which is {instance.source_run_number} for {instance.source})"  # noqa
+        elif instance.mail.status == enums.ReceptionStatusEnum.REPLY_SENT:
+            return f"Reply sent for run number {instance.hmrc_run_number} (which is {instance.source_run_number} for {instance.source}). Waiting for next mail from SPIRE/LITE"  # noqa
+
+    def get_reply_pending_count(self, instance):
+        return Mail.objects.filter(
+            extract_type=enums.ExtractTypeEnum.LICENCE_DATA, status=enums.ReceptionStatusEnum.REPLY_PENDING
+        ).count()
+
+    def get_processing_time(self, instance):
+        if instance.mail.status == enums.ReceptionStatusEnum.REPLY_PENDING:
+            if instance.mail.sent_at:
+                return int(datetime.now().timestamp() - instance.mail.sent_at.timestamp()) // 60
+        elif instance.mail.status == enums.ReceptionStatusEnum.REPLY_SENT:
+            if instance.mail.sent_at and instance.mail.response_date:
+                return int((instance.mail.response_date - instance.mail.sent_at).total_seconds()) // 60
+
+        return 0
+
+
+class UsageDataStatusSerializer(serializers.ModelSerializer):
+    usage_data_status = serializers.SerializerMethodField()
+
+    class Meta:
+        model = UsageData
+        fields = ("usage_data_status", "has_lite_data")
+
+    def get_usage_data_status(self, instance):
+        return f"Run number of last usage data processed is {instance.hmrc_run_number}"

mail/tests/test_select_email_for_sending.py

@@ -1,3 +1,4 @@
+from datetime import datetime, timezone
 from django.test import tag
 from unittest import mock
 
@@ -145,6 +146,7 @@ def test_case1_sending_of_pending_licencedata_mails(self, email_dtos, send_mail)
             edi_filename=filename,
             edi_data=mail_body,
             status=ReceptionStatusEnum.PENDING,
+            sent_at=datetime.now(timezone.utc),
         )
         LicenceData.objects.create(
             mail=pending_mail,