From c5a83d24f31e4193300ea256a5263fa616c5ea3f Mon Sep 17 00:00:00 2001
From: OmarEdraak <47500477+OmarEdraak@users.noreply.github.com>
Date: Sun, 8 Aug 2021 21:50:55 +0300
Subject: [PATCH 01/10] (don't merge) extensive time logs for
 EdraakCourseListView

---
 common/djangoapps/enrollment/__init__.py    | 23 ++++++++++++++
 common/djangoapps/enrollment/data.py        | 11 ++++++-
 common/djangoapps/enrollment/serializers.py | 33 +++++++++++++++++++--
 common/djangoapps/enrollment/views.py       |  9 ++++--
 4 files changed, 70 insertions(+), 6 deletions(-)

diff --git a/common/djangoapps/enrollment/__init__.py b/common/djangoapps/enrollment/__init__.py
index 963bb1d78f9..f07679d4598 100644
--- a/common/djangoapps/enrollment/__init__.py
+++ b/common/djangoapps/enrollment/__init__.py
@@ -1,3 +1,26 @@
 """
 Enrollment API helpers and settings
 """
+
+
+class Timer(object):
+    last_time = None
+    last_time_name = None
+
+    @classmethod
+    def log_time(cls, name, level):
+        import timeit
+        time = timeit.default_timer()
+        execution_time = stop - start
+
+        if cls.last_time and cls.last_time_name:
+            extra = '{time_diff} since {name}'.format(
+                time_diff=time - cls.last_time,
+                name=cls.last_time_name,
+            )
+        else:
+            extra = 'no last time'
+
+        cls.last_time = time
+        cls.last_time_name = name
+        log.info('%s edraak_timer: %s [%s]', level * ' >', name, extra)
diff --git a/common/djangoapps/enrollment/data.py b/common/djangoapps/enrollment/data.py
index cf5546c8d3d..de553e9f4dc 100644
--- a/common/djangoapps/enrollment/data.py
+++ b/common/djangoapps/enrollment/data.py
@@ -45,11 +45,16 @@ def get_course_enrollments(user_id):
         A serializable list of dictionaries of all aggregated enrollment data for a user.
 
     """
+    from . import Timer
+
+    Timer.log_time('start CourseEnrollment_query', 2)
     qset = CourseEnrollment.objects.filter(
-        user__username=user_id,
+        user__username=user_id,  # TODO: Omar user_id is not username
         is_active=True
     ).order_by('created')
 
+    Timer.log_time('end CourseEnrollment_query', 2)
+
     # Edraak: use EdraakCourseEnrollmentSerializer instead of CourseEnrollmentSerializer
     enrollments = EdraakCourseEnrollmentSerializer(
         qset,
@@ -57,6 +62,8 @@ def get_course_enrollments(user_id):
         context={'request': get_request_or_stub()}
     ).data
 
+    Timer.log_time('end EdraakCourseEnrollmentSerializer', 2)
+
     # Find deleted courses and filter them out of the results
     deleted = []
     valid = []
@@ -74,6 +81,8 @@ def get_course_enrollments(user_id):
             ), user_id,
         )
 
+    Timer.log_time('end get_course_enrollments', 2)
+
     return valid
 
 
diff --git a/common/djangoapps/enrollment/serializers.py b/common/djangoapps/enrollment/serializers.py
index ad08a14778d..475ba57fed7 100644
--- a/common/djangoapps/enrollment/serializers.py
+++ b/common/djangoapps/enrollment/serializers.py
@@ -114,17 +114,28 @@ class EdraakCourseEnrollmentSerializer(CourseEnrollmentSerializer):
     is_completed = serializers.SerializerMethodField()
     is_certificate_available = serializers.SerializerMethodField()
 
+    def to_representation(self, *args, **kwargs):
+        Timer.log_time('start to_representation', 3)
+        result = super(self).to_representation(*args, **kwargs)
+        Timer.log_time('end to_representation', 3)
+        return result
+
     def get_edraak_course_details(self, obj):
+        from . import Timer
+        Timer.log_time('start get_edraak_course_details', 4)
+
         context = self.context.copy()
         CourseDetailMarketingSerializer.update_marketing_context(
             context=context,
             course_key=obj.course_id
         )
 
-        return CourseDetailMarketingSerializer(
+        data = CourseDetailMarketingSerializer(
             obj.course_overview,
             context=context
         ).data
+        Timer.log_time('end get_edraak_course_details', 4)
+        return data
 
     def _get_user(self):
         request = self.context.get('request')
@@ -133,6 +144,8 @@ def _get_user(self):
         return None
 
     def get_is_certificate_allowed(self, obj):
+        from . import Timer
+        Timer.log_time('start get_is_certificate_allowed', 4)
         # Keep this import local to hide LMS related stuff from pytest when testing CMS
         from edraak_certificates.utils import is_certificate_allowed
 
@@ -144,24 +157,34 @@ def get_is_certificate_allowed(self, obj):
                 'EDRAAK: Certificate is not allowed because EdraakCourseEnrollmentSerializer cannot find user!'
             )
             allowed = False
-
+        Timer.log_time('end get_is_certificate_allowed', 4)
         return allowed
 
     def get_specialization_slug(self, obj):
+        from . import Timer
+        Timer.log_time('start get_specialization_slug', 4)
         try:
             specialization_info = CourseSpecializationInfo.objects.get(course_id=obj.course_id)
         except CourseSpecializationInfo.DoesNotExist:
             return None
+
+        Timer.log_time('end get_specialization_slug', 4)
         return specialization_info.specialization_slug
 
     def get_subscribed_to_emails(self, obj):
+        from . import Timer
+        Timer.log_time('start get_subscribed_to_emails', 4)
         user = self._get_user()
         if not user or not user.is_authenticated:
             return False
 
-        return not Optout.objects.filter(user=user, course_id=obj.course_id).exists()
+        result = not Optout.objects.filter(user=user, course_id=obj.course_id).exists()
+        Timer.log_time('end get_subscribed_to_emails', 4)
+        return result
 
     def get_is_completed(self, obj):
+        from . import Timer
+        Timer.log_time('start get_is_completed', 4)
         # Keep this import local to hide LMS related stuff from pytest when testing CMS
         from lms.djangoapps.grades.models import PersistentCourseGrade
 
@@ -178,9 +201,12 @@ def get_is_completed(self, obj):
             else:
                 if grade.percent_grade >= obj.course_overview.lowest_passing_grade:
                     completed = True
+        Timer.log_time('end get_is_completed', 4)
         return completed
 
     def get_is_certificate_available(self, obj):
+        from . import Timer
+        Timer.log_time('start get_is_certificate_available', 4)
         # Keep this import local to hide LMS related stuff from pytest when testing CMS
         from lms.djangoapps.certificates.models import CertificateStatuses, GeneratedCertificate
 
@@ -197,6 +223,7 @@ def get_is_certificate_available(self, obj):
                 pass
             else:
                 available = True
+        Timer.log_time('end get_is_certificate_available', 4)
         return available
 
     class Meta(object):
diff --git a/common/djangoapps/enrollment/views.py b/common/djangoapps/enrollment/views.py
index c0b1edfa2b9..d2fb0219e8b 100644
--- a/common/djangoapps/enrollment/views.py
+++ b/common/djangoapps/enrollment/views.py
@@ -788,6 +788,8 @@ def post(self, request):
                 )
 
 
+
+
 @can_disable_rate_limit
 class EdraakCourseListView(APIView, ApiKeyPermissionMixIn):
     """
@@ -815,6 +817,8 @@ def get(self, request):
         Example: api/enrollment/v1/edraak_course_list?is_completed=true
             get all enrollments for current user, where courses are completed, regardless of certificate status
         """
+        from . import Timer
+        Timer.log_time('start get_course_enrollments', 1)
         try:
             enrollment_data = get_course_enrollments(
                 request.user.username
@@ -828,7 +832,7 @@ def get(self, request):
                     ).format(username=request.user.username)
                 }
             )
-
+        Timer.log_time('end get_course_enrollments', 1)
         filters = {}
         try:
             for parameter_name in ('is_certificate_allowed', 'is_certificate_available', 'is_completed',):
@@ -838,8 +842,9 @@ def get(self, request):
                 status=status.HTTP_400_BAD_REQUEST,
                 data={"message": six.text_type(error)}
             )
-
+        Timer.log_time('end api_filtering', 1)
         final_data = [enrollment for enrollment in enrollment_data if self._is_enrollment_match(filters, enrollment)]
+        Timer.log_time('end final_data', 1)
 
         return Response(final_data)
 

From aab9b99f0c3a1240e8405c536224789a44b99008 Mon Sep 17 00:00:00 2001
From: OmarEdraak <47500477+OmarEdraak@users.noreply.github.com>
Date: Sun, 8 Aug 2021 22:07:33 +0300
Subject: [PATCH 02/10] fixup

---
 common/djangoapps/enrollment/__init__.py | 1 -
 1 file changed, 1 deletion(-)

diff --git a/common/djangoapps/enrollment/__init__.py b/common/djangoapps/enrollment/__init__.py
index f07679d4598..b722703fcbd 100644
--- a/common/djangoapps/enrollment/__init__.py
+++ b/common/djangoapps/enrollment/__init__.py
@@ -11,7 +11,6 @@ class Timer(object):
     def log_time(cls, name, level):
         import timeit
         time = timeit.default_timer()
-        execution_time = stop - start
 
         if cls.last_time and cls.last_time_name:
             extra = '{time_diff} since {name}'.format(

From dd4598b07aba2be5fd61e988ad2c527e16197f40 Mon Sep 17 00:00:00 2001
From: OmarEdraak <47500477+OmarEdraak@users.noreply.github.com>
Date: Wed, 11 Aug 2021 06:15:06 +0300
Subject: [PATCH 03/10] fixup

---
 common/djangoapps/enrollment/__init__.py | 5 ++++-
 1 file changed, 4 insertions(+), 1 deletion(-)

diff --git a/common/djangoapps/enrollment/__init__.py b/common/djangoapps/enrollment/__init__.py
index b722703fcbd..88be7eba9ec 100644
--- a/common/djangoapps/enrollment/__init__.py
+++ b/common/djangoapps/enrollment/__init__.py
@@ -1,6 +1,10 @@
 """
 Enrollment API helpers and settings
 """
+import timeit
+import logging
+
+log = logging.getLogger(__name__)
 
 
 class Timer(object):
@@ -9,7 +13,6 @@ class Timer(object):
 
     @classmethod
     def log_time(cls, name, level):
-        import timeit
         time = timeit.default_timer()
 
         if cls.last_time and cls.last_time_name:

From 4db06bdb9c7ade6187de2466d7085f4f2240be94 Mon Sep 17 00:00:00 2001
From: OmarEdraak <47500477+OmarEdraak@users.noreply.github.com>
Date: Wed, 11 Aug 2021 06:18:39 +0300
Subject: [PATCH 04/10] fixup

---
 common/djangoapps/enrollment/serializers.py | 1 +
 1 file changed, 1 insertion(+)

diff --git a/common/djangoapps/enrollment/serializers.py b/common/djangoapps/enrollment/serializers.py
index 475ba57fed7..acf1dd5d770 100644
--- a/common/djangoapps/enrollment/serializers.py
+++ b/common/djangoapps/enrollment/serializers.py
@@ -115,6 +115,7 @@ class EdraakCourseEnrollmentSerializer(CourseEnrollmentSerializer):
     is_certificate_available = serializers.SerializerMethodField()
 
     def to_representation(self, *args, **kwargs):
+        from . import Timer
         Timer.log_time('start to_representation', 3)
         result = super(self).to_representation(*args, **kwargs)
         Timer.log_time('end to_representation', 3)

From c415e9ab374e66ca868be00055be46088cc80b2f Mon Sep 17 00:00:00 2001
From: OmarEdraak <47500477+OmarEdraak@users.noreply.github.com>
Date: Wed, 11 Aug 2021 06:20:00 +0300
Subject: [PATCH 05/10] fix 500: type error

---
 common/djangoapps/enrollment/serializers.py | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/common/djangoapps/enrollment/serializers.py b/common/djangoapps/enrollment/serializers.py
index acf1dd5d770..8b1b495a8af 100644
--- a/common/djangoapps/enrollment/serializers.py
+++ b/common/djangoapps/enrollment/serializers.py
@@ -117,7 +117,7 @@ class EdraakCourseEnrollmentSerializer(CourseEnrollmentSerializer):
     def to_representation(self, *args, **kwargs):
         from . import Timer
         Timer.log_time('start to_representation', 3)
-        result = super(self).to_representation(*args, **kwargs)
+        result = super(EdraakCourseEnrollmentSerializer, self).to_representation(*args, **kwargs)
         Timer.log_time('end to_representation', 3)
         return result
 

From 94a39986360ae125ee2d94da29e903189df61185 Mon Sep 17 00:00:00 2001
From: OmarEdraak <47500477+OmarEdraak@users.noreply.github.com>
Date: Wed, 11 Aug 2021 06:43:19 +0300
Subject: [PATCH 06/10] use context manager

---
 common/djangoapps/enrollment/__init__.py    |  29 ++--
 common/djangoapps/enrollment/data.py        |  68 ++++----
 common/djangoapps/enrollment/serializers.py | 164 ++++++++++----------
 common/djangoapps/enrollment/views.py       |  36 ++---
 4 files changed, 138 insertions(+), 159 deletions(-)

diff --git a/common/djangoapps/enrollment/__init__.py b/common/djangoapps/enrollment/__init__.py
index 88be7eba9ec..dd39cd9c263 100644
--- a/common/djangoapps/enrollment/__init__.py
+++ b/common/djangoapps/enrollment/__init__.py
@@ -3,26 +3,17 @@
 """
 import timeit
 import logging
+from contextlib import contextmanager
 
 log = logging.getLogger(__name__)
 
 
-class Timer(object):
-    last_time = None
-    last_time_name = None
-
-    @classmethod
-    def log_time(cls, name, level):
-        time = timeit.default_timer()
-
-        if cls.last_time and cls.last_time_name:
-            extra = '{time_diff} since {name}'.format(
-                time_diff=time - cls.last_time,
-                name=cls.last_time_name,
-            )
-        else:
-            extra = 'no last time'
-
-        cls.last_time = time
-        cls.last_time_name = name
-        log.info('%s edraak_timer: %s [%s]', level * ' >', name, extra)
+@contextmanager
+def time_block(name, level):
+    start_time = timeit.default_timer()
+    log.info('%s edraak_time_block: %s [start]', level * ' >>', name)
+    try:
+        yield
+    finally:
+        diff = timeit.default_timer() - start_time
+        log.info('%s edraak_time_block: %s [end: %s ms]', level * ' >>', name, diff * 1000)
diff --git a/common/djangoapps/enrollment/data.py b/common/djangoapps/enrollment/data.py
index de553e9f4dc..e4323c0a384 100644
--- a/common/djangoapps/enrollment/data.py
+++ b/common/djangoapps/enrollment/data.py
@@ -45,43 +45,39 @@ def get_course_enrollments(user_id):
         A serializable list of dictionaries of all aggregated enrollment data for a user.
 
     """
-    from . import Timer
-
-    Timer.log_time('start CourseEnrollment_query', 2)
-    qset = CourseEnrollment.objects.filter(
-        user__username=user_id,  # TODO: Omar user_id is not username
-        is_active=True
-    ).order_by('created')
-
-    Timer.log_time('end CourseEnrollment_query', 2)
-
-    # Edraak: use EdraakCourseEnrollmentSerializer instead of CourseEnrollmentSerializer
-    enrollments = EdraakCourseEnrollmentSerializer(
-        qset,
-        many=True,
-        context={'request': get_request_or_stub()}
-    ).data
-
-    Timer.log_time('end EdraakCourseEnrollmentSerializer', 2)
-
-    # Find deleted courses and filter them out of the results
-    deleted = []
-    valid = []
-    for enrollment in enrollments:
-        if enrollment.get("course_details") is not None:
-            valid.append(enrollment)
-        else:
-            deleted.append(enrollment)
-
-    if deleted:
-        log.warning(
-            (
-                u"Course enrollments for user %s reference "
-                u"courses that do not exist (this can occur if a course is deleted)."
-            ), user_id,
-        )
+    from . import time_block
+
+    with time_block('CourseEnrollment_query', 2):
+        qset = CourseEnrollment.objects.filter(
+            user__username=user_id,  # TODO: Omar user_id is not username
+            is_active=True
+        ).order_by('created')
+
+    with time_block('EdraakCourseEnrollmentSerializer', 2):
+        # Edraak: use EdraakCourseEnrollmentSerializer instead of CourseEnrollmentSerializer
+        enrollments = EdraakCourseEnrollmentSerializer(
+            qset,
+            many=True,
+            context={'request': get_request_or_stub()}
+        ).data
 
-    Timer.log_time('end get_course_enrollments', 2)
+    with time_block('append_enrollments', 2):
+        # Find deleted courses and filter them out of the results
+        deleted = []
+        valid = []
+        for enrollment in enrollments:
+            if enrollment.get("course_details") is not None:
+                valid.append(enrollment)
+            else:
+                deleted.append(enrollment)
+
+        if deleted:
+            log.warning(
+                (
+                    u"Course enrollments for user %s reference "
+                    u"courses that do not exist (this can occur if a course is deleted)."
+                ), user_id,
+            )
 
     return valid
 
diff --git a/common/djangoapps/enrollment/serializers.py b/common/djangoapps/enrollment/serializers.py
index 8b1b495a8af..e99db73dfe1 100644
--- a/common/djangoapps/enrollment/serializers.py
+++ b/common/djangoapps/enrollment/serializers.py
@@ -115,27 +115,24 @@ class EdraakCourseEnrollmentSerializer(CourseEnrollmentSerializer):
     is_certificate_available = serializers.SerializerMethodField()
 
     def to_representation(self, *args, **kwargs):
-        from . import Timer
-        Timer.log_time('start to_representation', 3)
-        result = super(EdraakCourseEnrollmentSerializer, self).to_representation(*args, **kwargs)
-        Timer.log_time('end to_representation', 3)
+        from . import time_block
+        with time_block('to_representation', 3):
+            result = super(EdraakCourseEnrollmentSerializer, self).to_representation(*args, **kwargs)
         return result
 
     def get_edraak_course_details(self, obj):
-        from . import Timer
-        Timer.log_time('start get_edraak_course_details', 4)
-
-        context = self.context.copy()
-        CourseDetailMarketingSerializer.update_marketing_context(
-            context=context,
-            course_key=obj.course_id
-        )
+        from . import time_block
+        with time_block('get_edraak_course_details', 4):
+            context = self.context.copy()
+            CourseDetailMarketingSerializer.update_marketing_context(
+                context=context,
+                course_key=obj.course_id
+            )
 
-        data = CourseDetailMarketingSerializer(
-            obj.course_overview,
-            context=context
-        ).data
-        Timer.log_time('end get_edraak_course_details', 4)
+            data = CourseDetailMarketingSerializer(
+                obj.course_overview,
+                context=context
+            ).data
         return data
 
     def _get_user(self):
@@ -145,86 +142,83 @@ def _get_user(self):
         return None
 
     def get_is_certificate_allowed(self, obj):
-        from . import Timer
-        Timer.log_time('start get_is_certificate_allowed', 4)
-        # Keep this import local to hide LMS related stuff from pytest when testing CMS
-        from edraak_certificates.utils import is_certificate_allowed
-
-        user = self._get_user()
-        if user:
-            allowed = obj.course_overview and is_certificate_allowed(user, obj.course_overview)
-        else:
-            log.warning(
-                'EDRAAK: Certificate is not allowed because EdraakCourseEnrollmentSerializer cannot find user!'
-            )
-            allowed = False
-        Timer.log_time('end get_is_certificate_allowed', 4)
+        from . import time_block
+        with time_block('get_is_certificate_allowed', 4):
+            # Keep this import local to hide LMS related stuff from pytest when testing CMS
+            from edraak_certificates.utils import is_certificate_allowed
+
+            user = self._get_user()
+            if user:
+                allowed = obj.course_overview and is_certificate_allowed(user, obj.course_overview)
+            else:
+                log.warning(
+                    'EDRAAK: Certificate is not allowed because EdraakCourseEnrollmentSerializer cannot find user!'
+                )
+                allowed = False
         return allowed
 
     def get_specialization_slug(self, obj):
-        from . import Timer
-        Timer.log_time('start get_specialization_slug', 4)
-        try:
-            specialization_info = CourseSpecializationInfo.objects.get(course_id=obj.course_id)
-        except CourseSpecializationInfo.DoesNotExist:
-            return None
+        from . import time_block
+        with time_block('get_specialization_slug', 4):
+            try:
+                specialization_info = CourseSpecializationInfo.objects.get(course_id=obj.course_id)
+            except CourseSpecializationInfo.DoesNotExist:
+                specialization_info = None
 
-        Timer.log_time('end get_specialization_slug', 4)
-        return specialization_info.specialization_slug
+        if specialization_info:
+            return specialization_info.specialization_slug
+        return None
 
     def get_subscribed_to_emails(self, obj):
-        from . import Timer
-        Timer.log_time('start get_subscribed_to_emails', 4)
-        user = self._get_user()
-        if not user or not user.is_authenticated:
-            return False
-
-        result = not Optout.objects.filter(user=user, course_id=obj.course_id).exists()
-        Timer.log_time('end get_subscribed_to_emails', 4)
+        from . import time_block
+        with time_block('get_subscribed_to_emails', 4):
+            user = self._get_user()
+            if not user or not user.is_authenticated:
+                return False
+
+            result = not Optout.objects.filter(user=user, course_id=obj.course_id).exists()
         return result
 
     def get_is_completed(self, obj):
-        from . import Timer
-        Timer.log_time('start get_is_completed', 4)
-        # Keep this import local to hide LMS related stuff from pytest when testing CMS
-        from lms.djangoapps.grades.models import PersistentCourseGrade
-
-        user = self._get_user()
-        completed = False
-        if user:
-            try:
-                grade = PersistentCourseGrade.objects.get(
-                    user_id=user.id,
-                    course_id=obj.course_id,
-                )
-            except PersistentCourseGrade.DoesNotExist:
-                pass
-            else:
-                if grade.percent_grade >= obj.course_overview.lowest_passing_grade:
-                    completed = True
-        Timer.log_time('end get_is_completed', 4)
+        from . import time_block
+        with time_block('get_is_completed', 4):
+            # Keep this import local to hide LMS related stuff from pytest when testing CMS
+            from lms.djangoapps.grades.models import PersistentCourseGrade
+
+            user = self._get_user()
+            completed = False
+            if user:
+                try:
+                    grade = PersistentCourseGrade.objects.get(
+                        user_id=user.id,
+                        course_id=obj.course_id,
+                    )
+                except PersistentCourseGrade.DoesNotExist:
+                    pass
+                else:
+                    if grade.percent_grade >= obj.course_overview.lowest_passing_grade:
+                        completed = True
         return completed
 
     def get_is_certificate_available(self, obj):
-        from . import Timer
-        Timer.log_time('start get_is_certificate_available', 4)
-        # Keep this import local to hide LMS related stuff from pytest when testing CMS
-        from lms.djangoapps.certificates.models import CertificateStatuses, GeneratedCertificate
-
-        user = self._get_user()
-        available = False
-        if user:
-            try:
-                _ = GeneratedCertificate.objects.get(
-                    user_id=user.id,
-                    course_id=obj.course_id,
-                    status__in=[CertificateStatuses.downloadable, CertificateStatuses.error],
-                )
-            except GeneratedCertificate.DoesNotExist:
-                pass
-            else:
-                available = True
-        Timer.log_time('end get_is_certificate_available', 4)
+        from . import time_block
+        with time_block('get_is_certificate_available', 4):
+            # Keep this import local to hide LMS related stuff from pytest when testing CMS
+            from lms.djangoapps.certificates.models import CertificateStatuses, GeneratedCertificate
+
+            user = self._get_user()
+            available = False
+            if user:
+                try:
+                    _ = GeneratedCertificate.objects.get(
+                        user_id=user.id,
+                        course_id=obj.course_id,
+                        status__in=[CertificateStatuses.downloadable, CertificateStatuses.error],
+                    )
+                except GeneratedCertificate.DoesNotExist:
+                    pass
+                else:
+                    available = True
         return available
 
     class Meta(object):
diff --git a/common/djangoapps/enrollment/views.py b/common/djangoapps/enrollment/views.py
index d2fb0219e8b..2507a0e5e45 100644
--- a/common/djangoapps/enrollment/views.py
+++ b/common/djangoapps/enrollment/views.py
@@ -817,22 +817,21 @@ def get(self, request):
         Example: api/enrollment/v1/edraak_course_list?is_completed=true
             get all enrollments for current user, where courses are completed, regardless of certificate status
         """
-        from . import Timer
-        Timer.log_time('start get_course_enrollments', 1)
-        try:
-            enrollment_data = get_course_enrollments(
-                request.user.username
-            )
-        except CourseEnrollmentError:
-            return Response(
-                status=status.HTTP_400_BAD_REQUEST,
-                data={
-                    "message": (
-                        u"An error occurred while retrieving enrollments for user '{username}'"
-                    ).format(username=request.user.username)
-                }
-            )
-        Timer.log_time('end get_course_enrollments', 1)
+        from . import time_block
+        with time_block('get_course_enrollments', 1):
+            try:
+                enrollment_data = get_course_enrollments(
+                    request.user.username
+                )
+            except CourseEnrollmentError:
+                return Response(
+                    status=status.HTTP_400_BAD_REQUEST,
+                    data={
+                        "message": (
+                            u"An error occurred while retrieving enrollments for user '{username}'"
+                        ).format(username=request.user.username)
+                    }
+                )
         filters = {}
         try:
             for parameter_name in ('is_certificate_allowed', 'is_certificate_available', 'is_completed',):
@@ -842,9 +841,8 @@ def get(self, request):
                 status=status.HTTP_400_BAD_REQUEST,
                 data={"message": six.text_type(error)}
             )
-        Timer.log_time('end api_filtering', 1)
-        final_data = [enrollment for enrollment in enrollment_data if self._is_enrollment_match(filters, enrollment)]
-        Timer.log_time('end final_data', 1)
+        with time_block('api_filtering', 1):
+            final_data = [enrollment for enrollment in enrollment_data if self._is_enrollment_match(filters, enrollment)]
 
         return Response(final_data)
 

From b20420c8d8cdb96e3b1edee290d801faa17dfeca Mon Sep 17 00:00:00 2001
From: OmarEdraak <47500477+OmarEdraak@users.noreply.github.com>
Date: Wed, 11 Aug 2021 06:50:30 +0300
Subject: [PATCH 07/10] fixup

---
 common/djangoapps/enrollment/serializers.py |  6 +--
 common/djangoapps/enrollment/views.py       | 47 +++++++++++----------
 2 files changed, 26 insertions(+), 27 deletions(-)

diff --git a/common/djangoapps/enrollment/serializers.py b/common/djangoapps/enrollment/serializers.py
index e99db73dfe1..27fa2acf782 100644
--- a/common/djangoapps/enrollment/serializers.py
+++ b/common/djangoapps/enrollment/serializers.py
@@ -163,11 +163,9 @@ def get_specialization_slug(self, obj):
             try:
                 specialization_info = CourseSpecializationInfo.objects.get(course_id=obj.course_id)
             except CourseSpecializationInfo.DoesNotExist:
-                specialization_info = None
+                return None
 
-        if specialization_info:
-            return specialization_info.specialization_slug
-        return None
+        return specialization_info.specialization_slug
 
     def get_subscribed_to_emails(self, obj):
         from . import time_block
diff --git a/common/djangoapps/enrollment/views.py b/common/djangoapps/enrollment/views.py
index 2507a0e5e45..0e5c418af88 100644
--- a/common/djangoapps/enrollment/views.py
+++ b/common/djangoapps/enrollment/views.py
@@ -818,33 +818,34 @@ def get(self, request):
             get all enrollments for current user, where courses are completed, regardless of certificate status
         """
         from . import time_block
-        with time_block('get_course_enrollments', 1):
+        with time_block('GET_EdraakCourseListView', 0):
+            with time_block('get_course_enrollments', 1):
+                try:
+                    enrollment_data = get_course_enrollments(
+                        request.user.username
+                    )
+                except CourseEnrollmentError:
+                    return Response(
+                        status=status.HTTP_400_BAD_REQUEST,
+                        data={
+                            "message": (
+                                u"An error occurred while retrieving enrollments for user '{username}'"
+                            ).format(username=request.user.username)
+                        }
+                    )
+            filters = {}
             try:
-                enrollment_data = get_course_enrollments(
-                    request.user.username
-                )
-            except CourseEnrollmentError:
+                for parameter_name in ('is_certificate_allowed', 'is_certificate_available', 'is_completed',):
+                    self._add_filter(filters=filters, request=request, parameter_name=parameter_name)
+            except ValueError as error:
                 return Response(
                     status=status.HTTP_400_BAD_REQUEST,
-                    data={
-                        "message": (
-                            u"An error occurred while retrieving enrollments for user '{username}'"
-                        ).format(username=request.user.username)
-                    }
+                    data={"message": six.text_type(error)}
                 )
-        filters = {}
-        try:
-            for parameter_name in ('is_certificate_allowed', 'is_certificate_available', 'is_completed',):
-                self._add_filter(filters=filters, request=request, parameter_name=parameter_name)
-        except ValueError as error:
-            return Response(
-                status=status.HTTP_400_BAD_REQUEST,
-                data={"message": six.text_type(error)}
-            )
-        with time_block('api_filtering', 1):
-            final_data = [enrollment for enrollment in enrollment_data if self._is_enrollment_match(filters, enrollment)]
-
-        return Response(final_data)
+            with time_block('api_filtering', 1):
+                final_data = [enrollment for enrollment in enrollment_data if self._is_enrollment_match(filters, enrollment)]
+            response = Response(final_data)
+        return response
 
     def _add_filter(self, filters, request, parameter_name):
         parameter_value = self._get_boolean(request=request, param=parameter_name)

From e97d187f1733249a0020d74be9ca12e0c33d3182 Mon Sep 17 00:00:00 2001
From: OmarEdraak <47500477+OmarEdraak@users.noreply.github.com>
Date: Wed, 11 Aug 2021 07:01:22 +0300
Subject: [PATCH 08/10] level 5 logging

---
 lms/djangoapps/course_api/helpers.py     | 33 ++++++------
 lms/djangoapps/course_api/serializers.py | 64 +++++++++++++-----------
 2 files changed, 53 insertions(+), 44 deletions(-)

diff --git a/lms/djangoapps/course_api/helpers.py b/lms/djangoapps/course_api/helpers.py
index ddea24d1c60..9d44f73ed93 100644
--- a/lms/djangoapps/course_api/helpers.py
+++ b/lms/djangoapps/course_api/helpers.py
@@ -51,19 +51,22 @@ def get_marketing_data(course_key, language):
     :returns a course details from the marketing API or None if
     no marketing details found.
     """
+    from enrollment import time_block
     CACHE_KEY = "MKTG_API_" + str(course_key) + str(language)
-    if cache.get(CACHE_KEY):
-        return cache.get(CACHE_KEY)
-    marketing_root_format = marketing_link('COURSE_DETAILS_API_FORMAT')
-    url = marketing_root_format.format(course_id=course_key)
-
-    response = requests.get(url=url, headers={
-        'Accept-Language': language,
-    })
-
-    if response.status_code != 200:
-        log.warning('Could not fetch the marketing details from the API. course_key=[%s], status_code=[%s], url=[%s].',
-                    course_key, response.status_code, url)
-        return {}
-    cache.set(CACHE_KEY, response.json(), 30 * 60)
-    return response.json()
+    with time_block(CACHE_KEY, 5):
+        if cache.get(CACHE_KEY):
+            return cache.get(CACHE_KEY)
+        marketing_root_format = marketing_link('COURSE_DETAILS_API_FORMAT')
+        url = marketing_root_format.format(course_id=course_key)
+    
+        response = requests.get(url=url, headers={
+            'Accept-Language': language,
+        })
+    
+        if response.status_code != 200:
+            log.warning('Could not fetch the marketing details from the API. course_key=[%s], status_code=[%s], url=[%s].',
+                        course_key, response.status_code, url)
+            return {}
+        cache.set(CACHE_KEY, response.json(), 30 * 60)
+        response_json = response.json() 
+    return response_json
diff --git a/lms/djangoapps/course_api/serializers.py b/lms/djangoapps/course_api/serializers.py
index b8edfc933f1..69f615e249d 100644
--- a/lms/djangoapps/course_api/serializers.py
+++ b/lms/djangoapps/course_api/serializers.py
@@ -135,45 +135,51 @@ class CourseDetailMarketingSerializer(CourseSerializer):
     """
     @staticmethod
     def update_marketing_context(context, course_key):
-        if is_marketing_api_enabled():
-            lang = 'en'
-            if context.get('request') and hasattr(context['request'], 'LANGUAGE_CODE'):
-                lang = context['request'].LANGUAGE_CODE
-            context['marketing_data'] = get_marketing_data(
-                course_key=course_key,
-                language=lang,
-            )
+        from enrollment import time_block
+        with time_block('CourseDetailMarketingSerializer.update_marketing_context', 5):
+            if is_marketing_api_enabled():
+                lang = 'en'
+                if context.get('request') and hasattr(context['request'], 'LANGUAGE_CODE'):
+                    lang = context['request'].LANGUAGE_CODE
+                context['marketing_data'] = get_marketing_data(
+                    course_key=course_key,
+                    language=lang,
+                )
 
     def get_data_with_marketing_overrides(self, original_serialized_data):
-        marketing_data = self.context.get('marketing_data')
-        if not marketing_data:
-            return original_serialized_data
+        from enrollment import time_block
+        with time_block('CourseDetailMarketingSerializer.get_data_with_marketing_overrides', 5):
+            marketing_data = self.context.get('marketing_data')
+            if not marketing_data:
+                return original_serialized_data
 
-        overridden = {}
-        overridden.update(original_serialized_data)
+            overridden = {}
+            overridden.update(original_serialized_data)
 
-        overridden['effort'] = marketing_data['effort']
-        overridden['name'] = marketing_data['name']
-        if get_language() == 'en':
-            overridden['short_description'] = marketing_data['short_description_en']
-        else:
-            overridden['short_description'] = marketing_data['short_description_ar']
-        overridden['overview'] = marketing_data['overview'] or ''
-        overridden['name_en'] = marketing_data['name_en']
-        overridden['name_ar'] = marketing_data['name_ar']
+            overridden['effort'] = marketing_data['effort']
+            overridden['name'] = marketing_data['name']
+            if get_language() == 'en':
+                overridden['short_description'] = marketing_data['short_description_en']
+            else:
+                overridden['short_description'] = marketing_data['short_description_ar']
+            overridden['overview'] = marketing_data['overview'] or ''
+            overridden['name_en'] = marketing_data['name_en']
+            overridden['name_ar'] = marketing_data['name_ar']
 
-        if marketing_data.get('course_image'):
-            overridden['media']['course_image']['uri'] = marketing_data['course_image']
+            if marketing_data.get('course_image'):
+                overridden['media']['course_image']['uri'] = marketing_data['course_image']
 
-        if marketing_data.get('course_video'):
-            overridden['media']['course_video']['uri'] = marketing_data['course_video']
+            if marketing_data.get('course_video'):
+                overridden['media']['course_video']['uri'] = marketing_data['course_video']
 
-        return overridden
+            return overridden
 
     @property
     def data(self):
-        serialized_data = super(CourseDetailMarketingSerializer, self).data
-        return self.get_data_with_marketing_overrides(serialized_data)
+        from enrollment import time_block
+        with time_block('CourseDetailMarketingSerializer.data', 5):
+            serialized_data = super(CourseDetailMarketingSerializer, self).data
+            return self.get_data_with_marketing_overrides(serialized_data)
 
 
 class CourseDetailSerializer(CourseSerializer):  # pylint: disable=abstract-method

From e6d20f56695821a3c85e625d3725877054c67fe0 Mon Sep 17 00:00:00 2001
From: OmarEdraak <47500477+OmarEdraak@users.noreply.github.com>
Date: Wed, 11 Aug 2021 07:18:56 +0300
Subject: [PATCH 09/10] more logs

---
 common/djangoapps/enrollment/data.py     |  2 +-
 lms/djangoapps/course_api/serializers.py | 15 +++++++++++----
 2 files changed, 12 insertions(+), 5 deletions(-)

diff --git a/common/djangoapps/enrollment/data.py b/common/djangoapps/enrollment/data.py
index e4323c0a384..0eee0e8af53 100644
--- a/common/djangoapps/enrollment/data.py
+++ b/common/djangoapps/enrollment/data.py
@@ -75,7 +75,7 @@ def get_course_enrollments(user_id):
             log.warning(
                 (
                     u"Course enrollments for user %s reference "
-                    u"courses that do not exist (this can occur if a course is deleted)."
+                    u"courses that do not exist (this can occur if a course is deleted). %s"
                 ), user_id,
             )
 
diff --git a/lms/djangoapps/course_api/serializers.py b/lms/djangoapps/course_api/serializers.py
index 69f615e249d..db3ce4f898a 100644
--- a/lms/djangoapps/course_api/serializers.py
+++ b/lms/djangoapps/course_api/serializers.py
@@ -120,11 +120,18 @@ def get_duration(self, obj):
             return 0
 
     def get_completed(self, obj):
-        from edraak_certificates.utils import is_student_pass
+        from enrollment import time_block
+        with time_block('CourseSerializer.get_completed', 5):
+            from edraak_certificates.utils import is_student_pass
+
+            request = self.context['request']
+            course_id_str = str(obj.id)
+            return bool(is_student_pass(request.user, course_id_str))
 
-        request = self.context['request']
-        course_id_str = str(obj.id)
-        return bool(is_student_pass(request.user, course_id_str))
+    def to_representation(self, obj):
+        from enrollment import time_block
+        with time_block('CourseSerializer.to_representation', 5):
+            return super(CourseSerializer, self).to_representation(obj)
 
 
 class CourseDetailMarketingSerializer(CourseSerializer):

From d2efefe6b205c1404e779f5a363f67f8de1a0e52 Mon Sep 17 00:00:00 2001
From: OmarEdraak <47500477+OmarEdraak@users.noreply.github.com>
Date: Wed, 11 Aug 2021 07:22:49 +0300
Subject: [PATCH 10/10] fixup

---
 common/djangoapps/enrollment/data.py | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/common/djangoapps/enrollment/data.py b/common/djangoapps/enrollment/data.py
index 0eee0e8af53..e4323c0a384 100644
--- a/common/djangoapps/enrollment/data.py
+++ b/common/djangoapps/enrollment/data.py
@@ -75,7 +75,7 @@ def get_course_enrollments(user_id):
             log.warning(
                 (
                     u"Course enrollments for user %s reference "
-                    u"courses that do not exist (this can occur if a course is deleted). %s"
+                    u"courses that do not exist (this can occur if a course is deleted)."
                 ), user_id,
             )