feat: Refactored timing logic to its own class

search/api.py

@@ -1,15 +1,13 @@
 """ search business logic implementations """
 
 from datetime import datetime
-import time
-
 from django.conf import settings
 
 from eventtracking import tracker as track
 from .filter_generator import SearchFilterGenerator
 from .search_engine_base import SearchEngine
 from .result_processor import SearchResultProcessor
-from .utils import DateRange
+from .utils import DateRange, Timer
 
 # Default filters that we support, override using COURSE_DISCOVERY_FILTERS setting if desired
 DEFAULT_FILTER_FIELDS = ["org", "modes", "language"]
@@ -54,14 +52,13 @@ def perform_search(
     """
     # field_, filter_ and exclude_dictionary(s) can be overridden by calling application
     # field_dictionary includes course if course_id provided
-    filter_generation_time = {
-        "start": time.time()
-    }
+    filter_generation_timer = Timer()
+    filter_generation_timer.start()
     (field_dictionary, filter_dictionary, exclude_dictionary) = SearchFilterGenerator.generate_field_filters(
         user=user,
         course_id=course_id
     )
-    filter_generation_time['end'] = time.time()
+    filter_generation_timer.stop()
 
     searcher = SearchEngine.get_search_engine(
         getattr(settings, "COURSEWARE_CONTENT_INDEX_NAME", "courseware_content")
@@ -70,9 +67,8 @@ def perform_search(
         raise NoSearchEngineError("No search engine specified in settings.SEARCH_ENGINE")
     log_search_params = getattr(settings, "SEARCH_COURSEWARE_CONTENT_LOG_PARAMS", False)
 
-    search_time = {
-        "start": time.time()
-    }
+    search_timer = Timer()
+    search_timer.start()
 
     results = searcher.search(
         query_string=search_term,
@@ -84,9 +80,8 @@ def perform_search(
         log_search_params=log_search_params,
     )
 
-    processing_time = {
-        "start": time.time()
-    }
+    processing_timer = Timer()
+    processing_timer.start()
 
     # post-process the result
     for result in results["results"]:
@@ -95,18 +90,26 @@ def perform_search(
     results["access_denied_count"] = len([r for r in results["results"] if r["data"] is None])
     results["results"] = [r for r in results["results"] if r["data"] is not None]
 
-    processing_time['end'] = time.time()
-    search_time['end'] = time.time()
-
-    processing_time_in_seconds = processing_time['end'] - processing_time['start']
-    search_time_in_seconds = search_time['end'] - search_time['start']
-    filter_generation_time_in_seconds = filter_generation_time['end'] - filter_generation_time['start']
+    processing_timer.stop()
+    search_timer.stop()
 
     track.emit("edx.course.search.executed", {
         "search_term": search_term,
-        "processing_time_in_seconds": processing_time_in_seconds,
-        "search_time_in_seconds": search_time_in_seconds,
-        "filter_generation_time_in_seconds": filter_generation_time_in_seconds,
+        "processing_time": {
+            "start": processing_timer.start_time,
+            "end": processing_timer.end_time,
+            "elapsed": processing_timer.elapsed_time,
+        }
+        "search_time": {
+            "start": search_timer.start_time,
+            "end": search_timer.end_time,
+            "elapsed":  search_timer.elapsed_time,
+        }
+        "filter_generation_time": {
+            "start": filter_generation_timer.start_time,
+            "end": filter_generation_timer.end_time,
+            "elapsed": filter_generation_timer.elapsed_time,
+        }
     })
     return results
 

search/utils.py

@@ -1,6 +1,7 @@
 """ Utility classes to support others """
 
 import importlib
+import time
 from collections.abc import Iterable
 
 
@@ -65,3 +66,32 @@ def upper_string(self):
     def lower_string(self):
         """ use isoformat for _lower date's string format """
         return self._lower.isoformat()
+
+class Timer:
+    """ Simple timer class to measure elapsed time """
+    def __init__(self):
+        self._start_time = None
+        self._end_time = None
+
+    def start(self):
+        """ Start the timer """
+        self._start_time = time.time()
+
+    def stop(self):
+        """ Stop the timer """
+        self._end_time = time.time()
+
+    @property
+    def start_time(self):
+        """ Return the start time """
+        return self._start_time
+
+    @property
+    def end_time(self):
+        """ Return the end time """
+        return self._end_time
+
+    @property
+    def elapsed_time(self):
+        """ Return the elapsed time """
+        return self._end_time - self._start_time