feat: add timing for results filtering

search/api.py

@@ -1,9 +1,11 @@
 """ 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
@@ -52,10 +54,14 @@ 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()
+    }
     (field_dictionary, filter_dictionary, exclude_dictionary) = SearchFilterGenerator.generate_field_filters(
         user=user,
         course_id=course_id
     )
+    filter_generation_time['end'] = time.time()
 
     searcher = SearchEngine.get_search_engine(
         getattr(settings, "COURSEWARE_CONTENT_INDEX_NAME", "courseware_content")
@@ -64,6 +70,10 @@ 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()
+    }
+
     results = searcher.search(
         query_string=search_term,
         field_dictionary=field_dictionary,
@@ -74,13 +84,30 @@ def perform_search(
         log_search_params=log_search_params,
     )
 
+    processing_time = {
+        "start": time.time()
+    }
+
     # post-process the result
     for result in results["results"]:
         result["data"] = SearchResultProcessor.process_result(result["data"], search_term, user)
 
     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']
+
+    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,
+    })
     return results