feat: adding more performance tweaks and logging (#623)

enterprise_catalog/apps/api/tasks.py

@@ -2,6 +2,7 @@
 import functools
 import json
 import logging
+import time
 from collections import defaultdict
 from datetime import timedelta
 
@@ -772,6 +773,7 @@ def update_catalog_metadata_task(self, catalog_query_id, force=False):  # pylint
         list of str: Returns the content keys for ContentMetadata objects that were associated with the query.
             This result can be passed to the `update_full_content_metadata_task`.
     """
+    start_time = time.perf_counter()
     try:
         catalog_query = CatalogQuery.objects.get(id=catalog_query_id)
     except CatalogQuery.DoesNotExist:
@@ -781,13 +783,16 @@ def update_catalog_metadata_task(self, catalog_query_id, force=False):  # pylint
         associated_content_keys = update_contentmetadata_from_discovery(catalog_query)
     except Exception as e:
         logger.exception(
-            f'Something went wrong while updating content metadata from discovery using catalog: {catalog_query_id}. ',
+            f'Something went wrong while updating content metadata from discovery using catalog: {catalog_query_id} '
+            f'after update_catalog_metadata_task_seconds={time.perf_counter()-start_time} seconds',
             exc_info=e,
         )
         raise e
-    logger.info('Finished update_catalog_metadata_task with {} associated content keys for catalog {}'.format(
-        len(associated_content_keys), catalog_query_id
-    ))
+    logger.info(
+        f'Finished update_catalog_metadata_task with {len(associated_content_keys)} '
+        f'associated content keys for catalog {catalog_query_id} '
+        f'after update_catalog_metadata_task_seconds={time.perf_counter()-start_time} seconds'
+    )
 
 
 @shared_task(base=LoggedTaskWithRetry, bind=True)

enterprise_catalog/apps/api_client/base_oauth_with_retry.py

@@ -7,12 +7,21 @@
 class BaseOAuthClientWithRetry(BaseOAuthClient):
     """
     Base class for OAuth API clients wrapped in Retry.
+    The value of exponential backoff (with jitter) is discussed here:
+    https://aws.amazon.com/blogs/architecture/exponential-backoff-and-jitter/
     """
-    def __init__(self, backoff_factor=2, max_retries=3, **kwargs):
+    def __init__(
+            self,
+            backoff_factor=2,
+            max_retries=3,
+            backoff_jitter=1,
+            **kwargs
+    ):
         super().__init__(**kwargs)
         retry = Retry(
             total=max_retries,
             backoff_factor=backoff_factor,
+            backoff_jitter=backoff_jitter,
         )
         adapter = HTTPAdapter(max_retries=retry)
         self.client.mount('http://', adapter)

enterprise_catalog/apps/api_client/discovery.py

@@ -23,6 +23,8 @@ class DiscoveryApiClient(BaseOAuthClientWithRetry):
     Object builds an API client to make calls to the Discovery Service.
     """
 
+    HTTP_TIMEOUT = getattr(settings, "ENTERPRISE_DISCOVERY_CLIENT_TIMEOUT", 15)
+
     def __init__(self):
         backoff_factor = getattr(settings, "ENTERPRISE_DISCOVERY_CLIENT_BACKOFF_FACTOR", 2)
         max_retries = getattr(settings, "ENTERPRISE_DISCOVERY_CLIENT_MAX_RETRIES", 4)
@@ -38,9 +40,12 @@ def _retrieve_metadata_for_content_filter(self, content_filter, page, request_pa
             DISCOVERY_SEARCH_ALL_ENDPOINT,
             json=content_filter,
             params=request_params,
+            timeout=self.HTTP_TIMEOUT,
         )
-        elabsed_seconds = response.elapsed.total_seconds()
-        LOGGER.info(f'Retrieved results from course-discovery for page {page} in {elabsed_seconds} seconds.')
+        elapsed_seconds = response.elapsed.total_seconds()
+        LOGGER.info(
+            f'Retrieved results from course-discovery for page {page} in '
+            f'retrieve_metadata_for_content_filter_seconds={elapsed_seconds} seconds.')
         return response.json()
 
     def get_metadata_by_query(self, catalog_query):
@@ -95,6 +100,7 @@ def _retrieve_courses(self, offset, request_params):
         response = self.client.get(
             DISCOVERY_COURSES_ENDPOINT,
             params=request_params,
+            timeout=self.HTTP_TIMEOUT,
         ).json()
         return response
 
@@ -151,6 +157,7 @@ def _retrieve_programs(self, offset, request_params):
         response = self.client.get(
             DISCOVERY_PROGRAMS_ENDPOINT,
             params=request_params,
+            timeout=self.HTTP_TIMEOUT,
         ).json()
         return response