From afe50b5c1e6d103a57c2423fe7d6a1a37ba90e8b Mon Sep 17 00:00:00 2001
From: michaelroytman <mroytman@edx.org>
Date: Tue, 26 Oct 2021 11:57:16 -0400
Subject: [PATCH] fix: Add Additional IDV Signal and Celery Task Logs

To gain further information about why VerifiedName records are not reliably transitioning from "pending" to "submitted", add additional logs to test that the IDV related signals are being received successfully and successfully triggering the Celery task.

[MST-1130](https://openedx.atlassian.net/browse/MST-1130)
---
 CHANGELOG.rst                    |  4 ++++
 edx_name_affirmation/__init__.py |  2 +-
 edx_name_affirmation/handlers.py | 16 ++++++++++++++++
 edx_name_affirmation/tasks.py    |  8 ++++++++
 4 files changed, 29 insertions(+), 1 deletion(-)

diff --git a/CHANGELOG.rst b/CHANGELOG.rst
index 7897178..340f17a 100644
--- a/CHANGELOG.rst
+++ b/CHANGELOG.rst
@@ -13,7 +13,11 @@ Change Log
 
 Unreleased
 ~~~~~~~~~~
+
+[1.0.3] - 2021-10-26
+~~~~~~~~~~~~~~~~~~~~~
 * Add system check to CI.
+* Add additional logs to IDV signal handler and Celery task logic.
 
 [1.0.2] - 2021-09-29
 ~~~~~~~~~~~~~~~~~~~~~
diff --git a/edx_name_affirmation/__init__.py b/edx_name_affirmation/__init__.py
index cb65737..dd27420 100644
--- a/edx_name_affirmation/__init__.py
+++ b/edx_name_affirmation/__init__.py
@@ -2,6 +2,6 @@
 Django app housing name affirmation logic.
 """
 
-__version__ = '1.0.2'
+__version__ = '1.0.3'
 
 default_app_config = 'edx_name_affirmation.apps.EdxNameAffirmationConfig'  # pylint: disable=invalid-name
diff --git a/edx_name_affirmation/handlers.py b/edx_name_affirmation/handlers.py
index 3d57faa..f00f212 100644
--- a/edx_name_affirmation/handlers.py
+++ b/edx_name_affirmation/handlers.py
@@ -43,7 +43,23 @@ def idv_attempt_handler(attempt_id, user_id, status, photo_id_name, full_name, *
         photo_id_name(str): name to be used as verified name
         full_name(str): user's pending name change or current profile name
     """
+    log.info('VerifiedName: idv_attempt_handler started for user %(user_id)s '
+             'with photo_id_name %(photo_id_name)s and status %(status)s',
+             {
+                 'user_id': user_id,
+                 'photo_id_name': photo_id_name,
+                 'status': status
+             }
+             )
     if is_verified_name_enabled():
+        log.info('VerifiedName: idv_attempt_handler triggering Celery task for user %(user_id)s '
+                 'with photo_id_name %(photo_id_name)s and status %(status)s',
+                 {
+                     'user_id': user_id,
+                     'photo_id_name': photo_id_name,
+                     'status': status
+                 }
+                 )
         idv_update_verified_name.delay(attempt_id, user_id, status, photo_id_name, full_name)
 
 
diff --git a/edx_name_affirmation/tasks.py b/edx_name_affirmation/tasks.py
index 3be6848..1de4405 100644
--- a/edx_name_affirmation/tasks.py
+++ b/edx_name_affirmation/tasks.py
@@ -29,6 +29,14 @@ def idv_update_verified_name(self, attempt_id, user_id, status, photo_id_name, f
     """
     Celery task for updating a verified name based on an IDV attempt
     """
+    log.info('VerifiedName: idv_update_verified_name triggering Celery task started for user %(user_id)s '
+             'with attempt_id %(attempt_id)s and status %(status)s',
+             {
+                'user_id': user_id,
+                'attempt_id': attempt_id,
+                'status': status
+             }
+             )
     trigger_status = VerifiedNameStatus.trigger_state_change_from_idv(status)
     verified_names = VerifiedName.objects.filter(user__id=user_id, verified_name=photo_id_name).order_by('-created')
     if verified_names: