Improve twilio callback logging (#1998)

# What this PR does

## Which issue(s) this PR fixes

## Checklist

- [ ] Unit, integration, and e2e (if applicable) tests updated
- [ ] Documentation added (or `pr:no public docs` PR label added if not
required)
- [ ] `CHANGELOG.md` updated (or `pr:no changelog` PR label added if not
required)

engine/apps/twilioapp/gather.py

@@ -1,3 +1,5 @@
+import logging
+
 from django.apps import apps
 from django.urls import reverse
 from twilio.twiml.voice_response import Gather, VoiceResponse
@@ -6,6 +8,8 @@
 from apps.twilioapp.models import TwilioPhoneCall
 from common.api_helpers.utils import create_engine_url
 
+logger = logging.getLogger(__name__)
+
 
 def process_gather_data(call_sid: str, digit: str) -> VoiceResponse:
     """
@@ -50,10 +54,12 @@ def process_digit(call_sid, digit):
 
     """
     if call_sid and digit:
+        logger.info(f"twilioapp.process_digit: processing sid={call_sid} digit={digit}")
         twilio_phone_call = TwilioPhoneCall.objects.filter(sid=call_sid).first()
         # Check twilio phone call and then oncall phone call for backward compatibility after PhoneCall migration.
         # Will be removed soon.
         if twilio_phone_call:
+            logger.info(f"twilioapp.process_digit: found legacy twilio_phone_call sid={call_sid} digit={digit}")
             phone_call_record = twilio_phone_call.phone_call_record
         else:
             PhoneCallRecord = apps.get_model("phone_notifications", "PhoneCallRecord")
@@ -63,6 +69,11 @@ def process_digit(call_sid, digit):
             alert_group = phone_call_record.represents_alert_group
             user = phone_call_record.receiver
 
+            logger.info(
+                f"twilioapp.process_digit: processing using phone_call_record id={phone_call_record.id} "
+                f"twilio_phone_call sid={call_sid} digit={digit} alert_group_id={alert_group.id}"
+            )
+
             if digit == "1":
                 alert_group.acknowledge_by_user(user, action_source=ActionSource.PHONE)
             elif digit == "2":

engine/apps/twilioapp/status_callback.py

@@ -1,10 +1,14 @@
+import logging
+
 from django.apps import apps
 from django.urls import reverse
 
 from apps.alerts.signals import user_notification_action_triggered_signal
 from apps.twilioapp.models import TwilioCallStatuses, TwilioPhoneCall, TwilioSMS, TwilioSMSstatuses
 from common.api_helpers.utils import create_engine_url
 
+logger = logging.getLogger(__name__)
+
 
 def update_twilio_call_status(call_sid, call_status):
     """The function checks existence of TwilioPhoneCall instance
@@ -20,13 +24,18 @@ def update_twilio_call_status(call_sid, call_status):
     UserNotificationPolicyLogRecord = apps.get_model("base", "UserNotificationPolicyLogRecord")
 
     if call_sid and call_status:
+        logger.info(f"twilioapp.update_twilio_call_status: processing sid={call_sid} status={call_status}")
         status = TwilioCallStatuses.DETERMINANT.get(call_status)
 
         twilio_phone_call = TwilioPhoneCall.objects.filter(sid=call_sid).first()
 
         # Check twilio phone call and then oncall phone call for backward compatibility after PhoneCall migration.
         # Will be removed soon.
         if twilio_phone_call:
+            logger.info(
+                f"twilioapp.update_twilio_call_status: found legacy twilio_phone_call sid={call_sid}"
+                f" status={call_status}"
+            )
             status = TwilioCallStatuses.DETERMINANT.get(call_status)
             twilio_phone_call.status = status
             twilio_phone_call.save(update_fields=["status"])
@@ -36,6 +45,10 @@ def update_twilio_call_status(call_sid, call_status):
             phone_call_record = PhoneCallRecord.objects.filter(sid=call_sid).first()
 
         if phone_call_record and status:
+            logger.info(
+                f"twilioapp.update_twilio_call_status: processing using phone_call_record id={phone_call_record.id} "
+                f"sid={call_sid} status={call_status}"
+            )
             log_record_type = None
             log_record_error_code = None
 
@@ -87,13 +100,18 @@ def update_twilio_sms_status(message_sid, message_status):
     UserNotificationPolicyLogRecord = apps.get_model("base", "UserNotificationPolicyLogRecord")
 
     if message_sid and message_status:
+        logger.info(f"twilioapp.update_twilio_message_status: processing sid={message_sid} status={message_status}")
         status = TwilioSMSstatuses.DETERMINANT.get(message_status)
 
         twilio_sms = TwilioSMS.objects.filter(sid=message_sid).first()
 
         # Check twilio phone call and then oncall phone call for backward compatibility after PhoneCall migration.
         # Will be removed soon.
         if twilio_sms:
+            logger.info(
+                f"twilioapp.update_twilio_sms_status: found legacy twilio_phone_call sid={message_sid}"
+                f" status={message_sid}"
+            )
             twilio_sms.status = status
             twilio_sms.save(update_fields=["status"])
             sms_record = twilio_sms.sms_record
@@ -102,6 +120,10 @@ def update_twilio_sms_status(message_sid, message_status):
             sms_record = PhoneCallRecord.objects.filter(sid=message_sid).first()
 
         if sms_record and status:
+            logger.info(
+                f"twilioapp.update_twilio_sms_status: processing using sms_record id={sms_record.id} "
+                f"sid={message_sid} status={message_status}"
+            )
             log_record_type = None
             log_record_error_code = None
             if status == TwilioSMSstatuses.DELIVERED:

engine/apps/twilioapp/views.py

@@ -68,8 +68,5 @@ def post(self, request):
         call_sid = request.POST.get("CallSid")
         call_status = request.POST.get("CallStatus")
 
-        logging.info(f"CallStatusCallback: SID: {call_sid}, Status: {call_status}")
-
         update_twilio_call_status(call_sid=call_sid, call_status=call_status)
-
         return Response(data="", status=status.HTTP_204_NO_CONTENT)