workflow errors debugging V3

LOGGING_GUIDE.md

@@ -0,0 +1,234 @@
+# 📋 Logging Guide
+
+## Overview
+
+The application now includes comprehensive logging throughout all components for debugging and monitoring in container environments.
+
+## Log Levels
+
+- **INFO**: General application flow and important events
+- **WARNING**: Non-critical issues (e.g., missing tokens, fallback modes)
+- **ERROR**: Errors that are caught and handled
+- **DEBUG**: Detailed debugging information
+
+## Log Output Locations
+
+1. **Console/Stdout** - Real-time logs visible in container output
+2. **File** - `app.log` in the working directory
+
+## What Gets Logged
+
+### App Initialization (`app.py`)
+
+```python
+# Component import attempts
+logger.info("Attempting to import orchestration components...")
+logger.info("✓ Successfully imported orchestration components")
+
+# System initialization
+logger.info("INITIALIZING ORCHESTRATION SYSTEM")
+logger.info("Step 1/6: Initializing LLM Router...")
+logger.info("✓ LLM Router initialized")
+logger.info("Step 2/6: Initializing Agents...")
+logger.info("Step 3/6: Initializing Context Manager...")
+logger.info("Step 4/6: Initializing Orchestrator...")
+logger.info("ORCHESTRATION SYSTEM READY")
+```
+
+### Request Processing (`app.py`)
+
+```python
+logger.info(f"Processing message: {message[:100]}")
+logger.info(f"Session ID: {session_id}")
+logger.info("Attempting full orchestration...")
+logger.info("Orchestrator returned response: {response[:100]}")
+logger.info("Message processing complete")
+```
+
+### Orchestrator (`orchestrator_engine.py`)
+
+```python
+logger.info(f"Processing request for session {session_id}")
+logger.info(f"User input: {user_input[:100]}")
+logger.info(f"Generated interaction ID: {interaction_id}")
+logger.info("Step 2: Managing context...")
+logger.info(f"Context retrieved: {len(context.get('interactions', []))} interactions")
+logger.info("Step 3: Recognizing intent...")
+logger.info(f"Intent detected: {intent_result.get('primary_intent', 'unknown')}")
+logger.info("Step 4: Creating execution plan...")
+logger.info("Step 5: Executing agents...")
+logger.info(f"Agent execution complete: {len(agent_results)} results")
+logger.info("Step 6: Synthesizing response...")
+logger.info("Step 7: Safety check...")
+logger.info(f"Request processing complete. Response length: ...")
+```
+
+### Context Manager (`context_manager.py`)
+
+```python
+logger.info(f"Initializing ContextManager with DB path: {db_path}")
+logger.info("Initializing database...")
+logger.info("✓ Sessions table ready")
+logger.info("✓ Interactions table ready")
+logger.info("Database initialization complete")
+```
+
+### LLM Router (`llm_router.py`)
+
+```python
+logger.info("LLMRouter initialized")
+logger.info("HF token available")
+logger.info(f"Routing inference for task: {task_type}")
+logger.info(f"Selected model: {model_config['model_id']}")
+logger.info(f"Calling HF API for model: {model_id}")
+logger.info(f"HF API returned response (length: ...)")
+logger.info(f"Inference complete for {task_type}")
+```
+
+## Viewing Logs
+
+### In Development
+
+```bash
+# View real-time logs
+python app.py
+
+# View log file
+tail -f app.log
+
+# Search logs
+grep "ERROR" app.log
+grep "Processing request" app.log
+```
+
+### In Container/Docker
+
+```bash
+# View container logs
+docker logs <container_id>
+
+# Follow logs in real-time
+docker logs -f <container_id>
+
+# View recent logs
+docker logs --tail 100 <container_id>
+```
+
+### In Kubernetes
+
+```bash
+# View pod logs
+kubectl logs <pod-name>
+
+# Follow logs
+kubectl logs -f <pod-name>
+
+# View logs from specific container
+kubectl logs <pod-name> -c <container-name>
+```
+
+## Debugging with Logs
+
+### Example Log Flow for a Request
+
+```
+2024-01-15 10:30:00 - app - INFO - Processing message: Hello, I need help with...
+2024-01-15 10:30:00 - app - INFO - Session ID: abc12345
+2024-01-15 10:30:00 - app - INFO - Attempting full orchestration...
+2024-01-15 10:30:00 - orchestrator_engine - INFO - Processing request for session abc12345
+2024-01-15 10:30:00 - orchestrator_engine - INFO - User input: Hello, I need help with...
+2024-01-15 10:30:00 - orchestrator_engine - INFO - Generated interaction ID: ...
+2024-01-15 10:30:01 - orchestrator_engine - INFO - Step 2: Managing context...
+2024-01-15 10:30:01 - context_manager - INFO - Retrieving context for session abc12345
+2024-01-15 10:30:01 - orchestrator_engine - INFO - Context retrieved: 5 interactions
+2024-01-15 10:30:01 - orchestrator_engine - INFO - Step 3: Recognizing intent...
+2024-01-15 10:30:02 - intent_agent - INFO - INTENT_REC_001 processing user input: Hello...
+2024-01-15 10:30:02 - orchestrator_engine - INFO - Intent detected: information_request
+...
+```
+
+## Common Error Patterns
+
+### Missing Dependencies
+```
+ERROR - Could not import orchestration components: No module named 'src.agents'
+```
+**Solution**: Check imports and PYTHONPATH
+
+### Database Issues
+```
+ERROR - Database initialization error: unable to open database file
+```
+**Solution**: Check file permissions and disk space
+
+### API Errors
+```
+ERROR - HF API error: 429 - Rate limit exceeded
+```
+**Solution**: Check rate limits and API token
+
+### Orchestrator Errors
+```
+ERROR - Orchestrator error: 'NoneType' object has no attribute 'execute'
+```
+**Solution**: Check agent initialization
+
+## Log Management
+
+### Log Rotation
+
+For production, consider adding log rotation:
+
+```python
+from logging.handlers import RotatingFileHandler
+
+handler = RotatingFileHandler(
+    'app.log', 
+    maxBytes=10*1024*1024,  # 10MB
+    backupCount=5
+)
+```
+
+### Structured Logging
+
+For JSON logging (useful in containers):
+
+```python
+import structlog
+
+logger = structlog.get_logger()
+logger.info("event", session_id=session_id, status="success")
+```
+
+## Performance Considerations
+
+- Logging to file has minimal overhead
+- Console logging is fast in containers
+- DEBUG level can be verbose - use only when needed
+- Consider async logging for high-throughput scenarios
+
+## Best Practices
+
+1. ✅ Log entry and exit of critical functions
+2. ✅ Include context (session_id, request_id, etc.)
+3. ✅ Log errors with full stack traces (`exc_info=True`)
+4. ✅ Use appropriate log levels
+5. ❌ Don't log sensitive data (tokens, passwords)
+6. ❌ Don't over-log in hot paths
+
+## Quick Commands
+
+```bash
+# Find all errors
+grep "ERROR" app.log
+
+# Count messages processed
+grep "Message processing complete" app.log | wc -l
+
+# Find slow requests
+grep -E "processing|complete" app.log | grep -E "[0-9]{4,}"
+
+# Watch real-time
+tail -f app.log | grep -E "INFO|ERROR|WARNING"
+```
+

app.py

@@ -1,14 +1,55 @@
 # app.py - Mobile-First Implementation
 import gradio as gr
 import uuid
+import logging
+import traceback
+from typing import Optional, Tuple, List, Dict, Any
+import os
+
+# Configure comprehensive logging
+logging.basicConfig(
+    level=logging.INFO,
+    format='%(asctime)s - %(name)s - %(levelname)s - %(message)s',
+    handlers=[
+        logging.StreamHandler(),
+        logging.FileHandler('app.log')
+    ]
+)
+logger = logging.getLogger(__name__)
+
+# Try to import orchestration components
+orchestrator = None
+orchestrator_available = False
+
+try:
+    logger.info("Attempting to import orchestration components...")
+    import sys
+    sys.path.insert(0, '.')
+    sys.path.insert(0, 'src')
+    
+    from src.agents.intent_agent import create_intent_agent
+    from src.agents.synthesis_agent import create_synthesis_agent
+    from src.agents.safety_agent import create_safety_agent
+    from llm_router import LLMRouter
+    from orchestrator_engine import MVPOrchestrator
+    from context_manager import EfficientContextManager
+    from config import settings
+    
+    logger.info("✓ Successfully imported orchestration components")
+    orchestrator_available = True
+except ImportError as e:
+    logger.warning(f"Could not import orchestration components: {e}")
+    logger.info("Will use placeholder mode")
 
 try:
     from spaces import GPU
     SPACES_GPU_AVAILABLE = True
+    logger.info("HF Spaces GPU available")
 except ImportError:
     # Not running on HF Spaces or spaces module not available
     SPACES_GPU_AVAILABLE = False
     GPU = None
+    logger.info("Running without HF Spaces GPU")
 
 def create_mobile_optimized_interface():
     """Create the mobile-optimized Gradio interface and return demo with components"""
@@ -264,50 +305,86 @@ def setup_event_handlers(demo, event_handlers):
     
     return demo
 
-def process_message(message, history):
+async def process_message_async(message: str, history: Optional[List], session_id: str) -> Tuple[List, str]:
     """
-    Process message with messages format - returns immediately
-    
-    NOTE: This is currently using a placeholder. For full orchestration:
-    - Make this function async if you need to call async orchestrator methods
-    - Or use threading/background tasks for long-running operations
-    - Or use Gradio's streaming capabilities for progressive responses
+    Process message with full orchestration system
+    Returns (updated_history, empty_string)
     """
+    global orchestrator
+    
     try:
-        # Handle empty messages
+        logger.info(f"Processing message: {message[:100]}")
+        logger.info(f"Session ID: {session_id}")
+        
         if not message or not message.strip():
+            logger.debug("Empty message received")
             return history if history else [], ""
         
-        # Initialize history if None
         if history is None:
             history = []
         
-        # Create a copy to avoid mutating the input
         new_history = list(history) if isinstance(history, list) else []
         
         # Add user message
         new_history.append({"role": "user", "content": message.strip()})
         
-        # Generate immediate response (placeholder)
-        response = f"I received your message: {message}\n\nThis is a placeholder response. The full agent system is ready to integrate!"
+        # Try to use orchestrator if available
+        if orchestrator is not None:
+            try:
+                logger.info("Attempting full orchestration...")
+                # Use orchestrator to process
+                result = await orchestrator.process_request(
+                    session_id=session_id,
+                    user_input=message.strip()
+                )
+                
+                # Extract response from result
+                response = result.get('response', result.get('final_response', str(result)))
+                logger.info(f"Orchestrator returned response: {response[:100]}")
+                
+            except Exception as orch_error:
+                logger.error(f"Orchestrator error: {orch_error}", exc_info=True)
+                response = f"[Orchestrator Error] {str(orch_error)}"
+        else:
+            # Fallback placeholder
+            logger.info("Using placeholder response")
+            response = f"I received your message: {message}\n\nThis is a placeholder response. The orchestrator system is {'' if orchestrator_available else 'not'} available."
         
-        # Add assistant response  
+        # Add assistant response
         new_history.append({"role": "assistant", "content": response})
+        logger.info("Message processing complete")
         
-        # Return updated history and clear input
         return new_history, ""
         
     except Exception as e:
-        # Error handling - return error message to user
-        import traceback
-        print(f"ERROR in process_message: {e}")
-        traceback.print_exc()
-        
+        logger.error(f"Error in process_message_async: {e}", exc_info=True)
         error_history = list(history) if history else []
         error_history.append({"role": "user", "content": message})
         error_history.append({"role": "assistant", "content": f"I encountered an error: {str(e)}"})
         return error_history, ""
 
+def process_message(message: str, history: Optional[List]) -> Tuple[List, str]:
+    """
+    Synchronous wrapper for async processing
+    """
+    import asyncio
+    
+    # Generate a session ID
+    session_id = str(uuid.uuid4())[:8]
+    
+    try:
+        # Run async processing
+        loop = asyncio.new_event_loop()
+        asyncio.set_event_loop(loop)
+        result = loop.run_until_complete(process_message_async(message, history, session_id))
+        return result
+    except Exception as e:
+        logger.error(f"Error in process_message: {e}", exc_info=True)
+        error_history = list(history) if history else []
+        error_history.append({"role": "user", "content": message})
+        error_history.append({"role": "assistant", "content": f"Error: {str(e)}"})
+        return error_history, ""
+
 # Decorate the chat handler with GPU if available
 if SPACES_GPU_AVAILABLE and GPU is not None:
     @GPU  # This decorator is detected by HF Spaces for ZeroGPU allocation
@@ -318,10 +395,74 @@ if SPACES_GPU_AVAILABLE and GPU is not None:
 else:
     chat_handler_fn = process_message
 
+# Initialize orchestrator on module load
+def initialize_orchestrator():
+    """Initialize the orchestration system with logging"""
+    global orchestrator
+    
+    if not orchestrator_available:
+        logger.info("Orchestrator components not available, skipping initialization")
+        return
+    
+    try:
+        logger.info("=" * 60)
+        logger.info("INITIALIZING ORCHESTRATION SYSTEM")
+        logger.info("=" * 60)
+        
+        # Get HF token
+        hf_token = os.getenv('HF_TOKEN', '')
+        if not hf_token:
+            logger.warning("HF_TOKEN not found in environment")
+        
+        # Initialize LLM Router
+        logger.info("Step 1/6: Initializing LLM Router...")
+        llm_router = LLMRouter(hf_token)
+        logger.info("✓ LLM Router initialized")
+        
+        # Initialize Agents
+        logger.info("Step 2/6: Initializing Agents...")
+        agents = {
+            'intent_recognition': create_intent_agent(llm_router),
+            'response_synthesis': create_synthesis_agent(llm_router),
+            'safety_check': create_safety_agent(llm_router)
+        }
+        logger.info(f"✓ Initialized {len(agents)} agents")
+        
+        # Initialize Context Manager
+        logger.info("Step 3/6: Initializing Context Manager...")
+        context_manager = EfficientContextManager()
+        logger.info("✓ Context Manager initialized")
+        
+        # Initialize Orchestrator
+        logger.info("Step 4/6: Initializing Orchestrator...")
+        orchestrator = MVPOrchestrator(llm_router, context_manager, agents)
+        logger.info("✓ Orchestrator initialized")
+        
+        logger.info("=" * 60)
+        logger.info("ORCHESTRATION SYSTEM READY")
+        logger.info("=" * 60)
+        
+    except Exception as e:
+        logger.error(f"Failed to initialize orchestrator: {e}", exc_info=True)
+        orchestrator = None
+
+# Try to initialize orchestrator
+initialize_orchestrator()
+
 if __name__ == "__main__":
+    logger.info("=" * 60)
+    logger.info("STARTING APP")
+    logger.info("=" * 60)
+    
     demo, components = create_mobile_optimized_interface()
     
+    logger.info("✓ Interface created")
+    logger.info(f"Orchestrator available: {orchestrator is not None}")
+    
     # Launch the app
+    logger.info("=" * 60)
+    logger.info("LAUNCHING GRADIO APP")
+    logger.info("=" * 60)
     demo.launch(
         server_name="0.0.0.0",
         server_port=7860,

context_manager.py

@@ -1,8 +1,11 @@
 # context_manager.py
 import sqlite3
 import json
+import logging
 from datetime import datetime, timedelta
 
+logger = logging.getLogger(__name__)
+
 class EfficientContextManager:
     def __init__(self):
         self.session_cache = {}  # In-memory for active sessions
@@ -13,11 +16,13 @@ class EfficientContextManager:
             "eviction_policy": "LRU"
         }
         self.db_path = "sessions.db"
+        logger.info(f"Initializing ContextManager with DB path: {self.db_path}")
         self._init_database()
     
     def _init_database(self):
         """Initialize database and create tables"""
         try:
+            logger.info("Initializing database...")
             conn = sqlite3.connect(self.db_path)
             cursor = conn.cursor()
             
@@ -31,6 +36,7 @@ class EfficientContextManager:
                     user_metadata TEXT
                 )
             """)
+            logger.info("✓ Sessions table ready")
             
             # Create interactions table
             cursor.execute("""
@@ -43,12 +49,14 @@ class EfficientContextManager:
                     FOREIGN KEY(session_id) REFERENCES sessions(session_id)
                 )
             """)
+            logger.info("✓ Interactions table ready")
             
             conn.commit()
             conn.close()
+            logger.info("Database initialization complete")
             
         except Exception as e:
-            print(f"Database initialization warning: {e}")
+            logger.error(f"Database initialization error: {e}", exc_info=True)
     
     async def manage_context(self, session_id: str, user_input: str) -> dict:
         """

llm_router.py

@@ -1,22 +1,36 @@
 # llm_router.py
+import logging
 from models_config import LLM_CONFIG
 
+logger = logging.getLogger(__name__)
+
 class LLMRouter:
     def __init__(self, hf_token):
         self.hf_token = hf_token
         self.health_status = {}
+        logger.info("LLMRouter initialized")
+        if hf_token:
+            logger.info("HF token available")
+        else:
+            logger.warning("No HF token provided")
         
     async def route_inference(self, task_type: str, prompt: str, **kwargs):
         """
         Smart routing based on task specialization
         """
+        logger.info(f"Routing inference for task: {task_type}")
         model_config = self._select_model(task_type)
+        logger.info(f"Selected model: {model_config['model_id']}")
         
         # Health check and fallback logic
         if not await self._is_model_healthy(model_config["model_id"]):
+            logger.warning(f"Model unhealthy, using fallback")
             model_config = self._get_fallback_model(task_type)
+            logger.info(f"Fallback model: {model_config['model_id']}")
             
-        return await self._call_hf_endpoint(model_config, prompt, **kwargs)
+        result = await self._call_hf_endpoint(model_config, prompt, **kwargs)
+        logger.info(f"Inference complete for {task_type}")
+        return result
     
     def _select_model(self, task_type: str) -> dict:
         model_map = {
@@ -64,6 +78,9 @@ class LLMRouter:
             model_id = model_config["model_id"]
             api_url = f"https://api-inference.huggingface.co/models/{model_id}"
             
+            logger.info(f"Calling HF API for model: {model_id}")
+            logger.debug(f"Prompt length: {len(prompt)}")
+            
             headers = {
                 "Authorization": f"Bearer {self.hf_token}",
                 "Content-Type": "application/json"
@@ -90,15 +107,16 @@ class LLMRouter:
                     generated_text = result[0].get("generated_text", "")
                 else:
                     generated_text = str(result)
+                logger.info(f"HF API returned response (length: {len(generated_text)})")
                 return generated_text
             else:
-                print(f"HF API error: {response.status_code} - {response.text}")
+                logger.error(f"HF API error: {response.status_code} - {response.text}")
                 return None
                 
         except ImportError:
-            print("requests library not available, using mock response")
+            logger.warning("requests library not available, using mock response")
             return f"[Mock] Response to: {prompt[:100]}..."
         except Exception as e:
-            print(f"Error calling HF endpoint: {e}")
+            logger.error(f"Error calling HF endpoint: {e}", exc_info=True)
             return None
 

orchestrator_engine.py

@@ -1,50 +1,78 @@
 # orchestrator_engine.py
 import uuid
+import logging
 from datetime import datetime
 
+logger = logging.getLogger(__name__)
+
 class MVPOrchestrator:
     def __init__(self, llm_router, context_manager, agents):
         self.llm_router = llm_router
         self.context_manager = context_manager
         self.agents = agents
         self.execution_trace = []
+        logger.info("MVPOrchestrator initialized")
         
     async def process_request(self, session_id: str, user_input: str) -> dict:
         """
         Main orchestration flow with academic differentiation
         """
-        # Step 1: Generate unique interaction ID
-        interaction_id = self._generate_interaction_id(session_id)
-        
-        # Step 2: Context management
-        context = await self.context_manager.manage_context(session_id, user_input)
-        
-        # Step 3: Intent recognition with CoT
-        intent_result = await self.agents['intent_recognition'].execute(
-            user_input=user_input,
-            context=context
-        )
-        
-        # Step 4: Agent execution planning
-        execution_plan = await self._create_execution_plan(intent_result, context)
+        logger.info(f"Processing request for session {session_id}")
+        logger.info(f"User input: {user_input[:100]}")
         
-        # Step 5: Parallel agent execution
-        agent_results = await self._execute_agents(execution_plan, user_input, context)
-        
-        # Step 6: Response synthesis
-        final_response = await self.agents['response_synthesis'].execute(
-            agent_outputs=agent_results,
-            user_input=user_input,
-            context=context
-        )
-        
-        # Step 7: Safety and bias check
-        safety_checked = await self.agents['safety_check'].execute(
-            response=final_response,
-            context=context
-        )
-        
-        return self._format_final_output(safety_checked, interaction_id)
+        try:
+            # Step 1: Generate unique interaction ID
+            interaction_id = self._generate_interaction_id(session_id)
+            logger.info(f"Generated interaction ID: {interaction_id}")
+            
+            # Step 2: Context management
+            logger.info("Step 2: Managing context...")
+            context = await self.context_manager.manage_context(session_id, user_input)
+            logger.info(f"Context retrieved: {len(context.get('interactions', []))} interactions")
+            
+            # Step 3: Intent recognition with CoT
+            logger.info("Step 3: Recognizing intent...")
+            intent_result = await self.agents['intent_recognition'].execute(
+                user_input=user_input,
+                context=context
+            )
+            logger.info(f"Intent detected: {intent_result.get('primary_intent', 'unknown')}")
+            
+            # Step 4: Agent execution planning
+            logger.info("Step 4: Creating execution plan...")
+            execution_plan = await self._create_execution_plan(intent_result, context)
+            
+            # Step 5: Parallel agent execution
+            logger.info("Step 5: Executing agents...")
+            agent_results = await self._execute_agents(execution_plan, user_input, context)
+            logger.info(f"Agent execution complete: {len(agent_results)} results")
+            
+            # Step 6: Response synthesis
+            logger.info("Step 6: Synthesizing response...")
+            final_response = await self.agents['response_synthesis'].execute(
+                agent_outputs=agent_results,
+                user_input=user_input,
+                context=context
+            )
+            
+            # Step 7: Safety and bias check
+            logger.info("Step 7: Safety check...")
+            safety_checked = await self.agents['safety_check'].execute(
+                response=final_response,
+                context=context
+            )
+            
+            result = self._format_final_output(safety_checked, interaction_id)
+            logger.info(f"Request processing complete. Response length: {len(str(result.get('response', '')))}")
+            return result
+            
+        except Exception as e:
+            logger.error(f"Error in process_request: {e}", exc_info=True)
+            return {
+                "response": f"Error processing request: {str(e)}",
+                "error": str(e),
+                "interaction_id": str(uuid.uuid4())[:8]
+            }
     
     def _generate_interaction_id(self, session_id: str) -> str:
         """