Perf: Instrument RAG pipeline for performance diagnostics

src/enhanced_groq_medical_rag.py

@@ -98,14 +98,26 @@ class EnhancedGroqMedicalRAG:
         self.reranker = CrossEncoder('cross-encoder/ms-marco-MiniLM-L-6-v2')
         self.logger.info("✅ Cross-Encoder Re-ranker loaded")
         
-        self.logger.info("🎯 Enhanced Medical RAG System ready - Medical-grade safety protocols active")
-        self._test_groq_connection()
+        # Add timers for performance diagnostics
+        self.timers = {}
 
     def setup_logging(self):
         """Setup logging for the enhanced medical RAG system"""
         logging.basicConfig(level=logging.INFO, format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')
         self.logger = logging.getLogger(__name__)
 
+    def _start_timer(self, name: str):
+        """Starts a timer for a specific operation."""
+        self.timers[name] = time.time()
+
+    def _stop_timer(self, name: str):
+        """Stops a timer and logs the duration."""
+        if name in self.timers:
+            duration = time.time() - self.timers[name]
+            self.logger.info(f"⏱️ Timing: {name} took {duration:.2f}s")
+            return duration
+        return 0.0
+
     @retry(
         stop=stop_after_attempt(3),
         wait=wait_fixed(2),
@@ -341,12 +353,15 @@ class EnhancedGroqMedicalRAG:
 
     def query(self, query: str, history: Optional[List[Dict[str, str]]] = None, use_llm: bool = True) -> EnhancedMedicalResponse:
         """ENHANCED multi-stage medical query processing with comprehensive retrieval and timing."""
-        start_time = time.time()
+        self._start_timer("Total Query Time")
+        total_processing_time = 0
         try:
             self.logger.info(f"🔍 Processing enhanced medical query: {query[:50]}...")
             
             # Step 1: Analyze query for comprehensive understanding
+            self._start_timer("Query Analysis")
             query_analysis = self.analyze_medical_query(query)
+            self._stop_timer("Query Analysis")
             
             # Step 2: Multi-stage comprehensive retrieval
             all_documents = []
@@ -376,7 +391,7 @@ class EnhancedGroqMedicalRAG:
                         seen_content.add(doc.content)
             
             if not all_documents:
-                return self._create_no_results_response(query, start_time)
+                return self._create_no_results_response(query, self._stop_timer("Total Query Time"))
             
             # Step 3: Advanced multi-criteria re-ranking
             reranked_docs = self._advanced_medical_reranking(query_analysis, all_documents)
@@ -426,7 +441,7 @@ class EnhancedGroqMedicalRAG:
                 safety_status = "CONTEXT_ONLY"
             
             context_adherence_score = verification_result.verification_score if verification_result else 1.0
-            query_time = time.time() - start_time
+            query_time = self._stop_timer("Total Query Time") - total_processing_time
             
             enhanced_response = EnhancedMedicalResponse(
                 answer=final_response,
@@ -442,11 +457,10 @@ class EnhancedGroqMedicalRAG:
             
             self.logger.info(f"🎯 Enhanced medical query completed in {query_time:.2f}s - Safety: {safety_status}")
         finally:
-            end_time = time.time()
-            processing_time = end_time - start_time
+            total_processing_time = self._stop_timer("Total Query Time")
             
             if 'enhanced_response' in locals() and isinstance(enhanced_response, EnhancedMedicalResponse):
-                enhanced_response.query_time = processing_time
+                enhanced_response.query_time = total_processing_time
                 # Ensure other fields are not None
                 if not hasattr(enhanced_response, 'answer') or enhanced_response.answer is None:
                     enhanced_response.answer = "An error occurred during processing."
@@ -461,7 +475,7 @@ class EnhancedGroqMedicalRAG:
                     answer="A critical error occurred. Unable to generate a full response.",
                     confidence=0.0,
                     sources=[],
-                    query_time=processing_time,
+                    query_time=total_processing_time,
                     verification_result=None,
                     safety_status="ERROR",
                     medical_entities_count=0,