added extra logs

Author: Dhruvkumar-Microsoft

src/backend/common/database/database_base.py

@@ -153,6 +153,7 @@ async def get_steps_for_plan(self, plan_id: str) -> List[Step]:
     @abstractmethod
     async def get_current_team(self, user_id: str) -> Optional[UserCurrentTeam]:
         """Retrieve the current team for a user."""
+        pass
 
     @abstractmethod
     async def delete_current_team(self, user_id: str) -> Optional[UserCurrentTeam]:

src/backend/v3/api/router.py

@@ -396,6 +396,9 @@ async def plan_approval(
                 orchestration_config
                 and human_feedback.m_plan_id in orchestration_config.approvals
             ):
+                # orchestration_config.approvals[human_feedback.m_plan_id] = (
+                #     human_feedback.approved
+                # )
                 orchestration_config.set_approval_result(
                     human_feedback.m_plan_id, human_feedback.approved
                 )
@@ -528,6 +531,9 @@ async def user_clarification(
             orchestration_config
             and human_feedback.request_id in orchestration_config.clarifications
         ):
+            # orchestration_config.clarifications[human_feedback.request_id] = (
+            #     human_feedback.answer
+            # )
             # Use the new event-driven method to set clarification result
             orchestration_config.set_clarification_result(
                 human_feedback.request_id, human_feedback.answer
@@ -749,10 +755,12 @@ async def upload_team_config(
         )
 
         # Validate search indexes
+        logger.info(f"🔍 Validating search indexes for user: {user_id}")
         search_valid, search_errors = await team_service.validate_team_search_indexes(
             json_data
         )
         if not search_valid:
+            logger.warning(f"❌ Search validation failed for user {user_id}: {search_errors}")
             error_message = (
                 f"Search index validation failed:\n\n{chr(10).join([f'• {error}' for error in search_errors])}\n\n"
                 f"Please ensure all referenced search indexes exist in your Azure AI Search service."
@@ -768,6 +776,7 @@ async def upload_team_config(
             )
             raise HTTPException(status_code=400, detail=error_message)
 
+        logger.info(f"✅ Search validation passed for user: {user_id}")
         track_event_if_configured(
             "Team configuration search validation passed",
             {"status": "passed", "user_id": user_id, "filename": file.filename},

src/backend/v3/callbacks/response_handlers.py

@@ -17,6 +17,8 @@
     WebsocketMessageType,
 )
 
+logger = logging.getLogger(__name__)
+
 
 def clean_citations(text: str) -> str:
     """Remove citation markers from agent responses while preserving formatting."""
@@ -42,19 +44,26 @@ def agent_response_callback(message: ChatMessageContent, user_id: str = None) ->
 
     # Get agent name to determine handling
     agent_name = message.name or "Unknown Agent"
+    
+    logger.info(f"🤖 Agent Response from '{agent_name}' for user: {user_id}")
 
     role = getattr(message, "role", "unknown")
 
     # Send to WebSocket
     if user_id:
         try:
             if message.items and message.items[0].content_type == "function_call":
+                logger.info(f"🔧 Tool calls detected from agent: {agent_name}")
                 final_message = AgentToolMessage(agent_name=agent_name)
                 for item in message.items:
                     if item.content_type == "function_call":
+                        tool_name = item.name or "unknown_tool"
+                        tool_args = item.arguments or {}
+                        logger.info(f"🛠️ Tool call: {tool_name} with args: {str(tool_args)[:200]}...")
+                        
                         tool_call = AgentToolCall(
-                            tool_name=item.name or "unknown_tool",
-                            arguments=item.arguments or {},
+                            tool_name=tool_name,
+                            arguments=tool_args,
                         )
                         final_message.tool_calls.append(tool_call)
 
@@ -65,11 +74,18 @@ def agent_response_callback(message: ChatMessageContent, user_id: str = None) ->
                         message_type=WebsocketMessageType.AGENT_TOOL_MESSAGE,
                     )
                 )
-                logging.info(f"Function call: {final_message}")
+                logging.info(f"📤 Tool message sent via WebSocket for user: {user_id}")
             elif message.items and message.items[0].content_type == "function_result":
+                # Log function results for debugging
+                logger.info(f"📥 Function result received from agent: {agent_name}")
+                for item in message.items:
+                    if item.content_type == "function_result":
+                        result_content = str(item.result)[:300] if hasattr(item, 'result') else "No result"
+                        logger.info(f"🔍 Function result: {result_content}...")
                 # skip returning these results for now - agent will return in a later message
                 pass
             else:
+                logger.info(f"💬 Text message from agent: {agent_name}")
                 final_message = AgentMessage(
                     agent_name=agent_name,
                     timestamp=time.time() or "",

src/backend/v3/config/settings.py

@@ -61,14 +61,17 @@ def __init__(self):
         self.url = config.MCP_SERVER_ENDPOINT
         self.name = config.MCP_SERVER_NAME
         self.description = config.MCP_SERVER_DESCRIPTION
+        logger.info(f"🔧 MCP Config initialized - URL: {self.url}, Name: {self.name}")
 
     def get_headers(self, token: str):
         """Get MCP headers with authentication token."""
-        return (
+        headers = (
             {"Authorization": f"Bearer {token}", "Content-Type": "application/json"}
             if token
             else {}
         )
+        logger.debug(f"📋 MCP Headers created: {headers}")
+        return headers
 
 
 class OrchestrationConfig:
@@ -127,6 +130,7 @@ async def wait_for_approval(self, plan_id: str, timeout: Optional[float] = None)
             asyncio.TimeoutError: If timeout is exceeded
             KeyError: If plan_id is not found in approvals
         """
+        logger.info(f"Waiting for approval: {plan_id}")
         if timeout is None:
             timeout = self.default_timeout
 
@@ -142,9 +146,11 @@ async def wait_for_approval(self, plan_id: str, timeout: Optional[float] = None)
 
         try:
             await asyncio.wait_for(self._approval_events[plan_id].wait(), timeout=timeout)
+            logger.info(f"Approval received: {plan_id}")
             return self.approvals[plan_id]
         except asyncio.TimeoutError:
             # Clean up on timeout
+            logger.warning(f"Approval timeout: {plan_id}")
             self.cleanup_approval(plan_id)
             raise
         except asyncio.CancelledError:

src/backend/v3/magentic_agents/common/lifecycle.py

@@ -1,5 +1,6 @@
 from contextlib import AsyncExitStack
 from typing import Any
+import logging
 
 from azure.ai.projects.aio import AIProjectClient
 from azure.identity.aio import DefaultAzureCredential
@@ -8,6 +9,8 @@
 from v3.magentic_agents.models.agent_models import MCPConfig
 from v3.config.agent_registry import agent_registry
 
+logger = logging.getLogger(__name__)
+
 
 class MCPEnabledBase:
     """
@@ -74,6 +77,7 @@ async def _after_open(self) -> None:
 
     async def _enter_mcp_if_configured(self) -> None:
         if not self.mcp_cfg:
+            logger.debug("No MCP configuration provided")
             return
         # headers = self._build_mcp_headers()
         plugin = MCPStreamableHttpPlugin(
@@ -85,7 +89,13 @@ async def _enter_mcp_if_configured(self) -> None:
         # Enter MCP async context via the stack to ensure correct LIFO cleanup
         if self._stack is None:
             self._stack = AsyncExitStack()
-        self.mcp_plugin = await self._stack.enter_async_context(plugin)
+        
+        try:
+            self.mcp_plugin = await self._stack.enter_async_context(plugin)
+            logger.info(f"✅ MCP plugin '{self.mcp_cfg.name}' successfully initialized")
+        except Exception as e:
+            logger.error(f"❌ Failed to initialize MCP plugin '{self.mcp_cfg.name}': {e}")
+            raise
 
 
 class AzureAgentBase(MCPEnabledBase):

src/backend/v3/magentic_agents/foundry_agent.py

@@ -171,15 +171,23 @@ async def _after_open(self) -> None:
 
         # Add MCP plugins if available
         plugins = [self.mcp_plugin] if self.mcp_plugin else []
+        
+        if self.mcp_plugin:
+            self.logger.info(f"🔧 Adding MCP plugin to agent: {self.agent_name}")
+            self.logger.debug(f"MCP plugin name: {getattr(self.mcp_plugin, 'name', 'Unknown')}")
+        else:
+            self.logger.debug(f"No MCP plugin for agent: {self.agent_name}")
 
         try:
+            self.logger.info(f"🤖 Creating AzureAI agent: {self.agent_name}")
             self._agent = AzureAIAgent(
                 client=self.client,
                 definition=definition,
                 plugins=plugins,
             )
+            self.logger.info(f"✅ AzureAI agent created successfully: {self.agent_name}")
         except Exception as ex:
-            self.logger.error("Failed to create AzureAIAgent: %s", ex)
+            self.logger.error("❌ Failed to create AzureAIAgent '%s': %s", self.agent_name, ex)
             raise
 
         # Register agent with global registry for tracking and cleanup

src/backend/v3/magentic_agents/proxy_agent.py

@@ -282,7 +282,7 @@ async def _wait_for_user_clarification(
         Raises:
             asyncio.TimeoutError: If timeout is exceeded (300 seconds default)
         """
-        # logger.info(f"Waiting for user clarification for request: {request_id}")
+        logger.info(f"Waiting for clarification: {request_id}")
 
         # Initialize clarification as pending using the new event-driven method
         orchestration_config.set_clarification_pending(request_id)
@@ -291,14 +291,14 @@ async def _wait_for_user_clarification(
             # Wait for clarification with timeout using the new event-driven method
             answer = await orchestration_config.wait_for_clarification(request_id)
 
-            # logger.info(f"Clarification received for request {request_id}: {answer}")
+            logger.info(f"Clarification received for: {request_id}")
             return UserClarificationResponse(
                 request_id=request_id,
                 answer=answer,
             )
         except asyncio.TimeoutError:
             # Enhanced timeout handling - notify user via WebSocket and cleanup
-            logger.debug(f"Clarification timeout for request {request_id} - notifying user and terminating process")
+            logger.warning(f"Clarification timeout for request: {request_id}")
 
             # Create timeout notification message
             from v3.models.messages import TimeoutNotification, WebsocketMessageType

src/backend/v3/orchestration/human_approval_manager.py

@@ -53,23 +53,31 @@ def __init__(self, user_id: str, *args, **kwargs):
         # Remove any custom kwargs before passing to parent
 
         plan_append = """
-IMPORTANT: Never ask the user for information or clarification until all agents on the team have been asked first.
+ 
+CRITICAL DOMAIN CHECK: Examine team agents first - if request doesn't match team domain, reject immediately:
+- CustomerDataAgent/OrderDataAgent = RETAIL team (reject HR/employee requests)
+- HRHelperAgent = HR team (reject non-HR requests)  
+- ProductAgent/MarketingAgent = MARKETING team (reject non-marketing requests)
+
+- **ProxyAgent** to politely inform the user that this request does not match this team’s domain and should be redirected to the appropriate team. No clarifications or follow-up questions should be asked.
 
+ 
+IMPORTANT: Never ask the user for information or clarification until all agents on the team have been asked first.
+ 
 EXAMPLE: If the user request involves product information, first ask all agents on the team to provide the information.
 Do not ask the user unless all agents have been consulted and the information is still missing.
-
+ 
 Plan steps should always include a bullet point, followed by an agent name, followed by a description of the action
 to be taken. If a step involves multiple actions, separate them into distinct steps with an agent included in each step.
 If the step is taken by an agent that is not part of the team, such as the MagenticManager, please always list the MagenticManager as the agent for that step. At any time, if more information is needed from the user, use the ProxyAgent to request this information.
-
+ 
 Here is an example of a well-structured plan:
 - **EnhancedResearchAgent** to gather authoritative data on the latest industry trends and best practices in employee onboarding
 - **EnhancedResearchAgent** to gather authoritative data on Innovative onboarding techniques that enhance new hire engagement and retention.
 - **DocumentCreationAgent** to draft a comprehensive onboarding plan that includes a detailed schedule of onboarding activities and milestones.
 - **DocumentCreationAgent** to draft a comprehensive onboarding plan that includes a checklist of resources and materials needed for effective onboarding.
 - **ProxyAgent** to review the drafted onboarding plan for clarity and completeness.
 - **MagenticManager** to finalize the onboarding plan and prepare it for presentation to stakeholders.
-
 """
 
         final_append = """

src/backend/v3/orchestration/orchestration_manager.py

@@ -39,6 +39,7 @@ async def init_orchestration(
         cls, agents: List, user_id: str = None
     ) -> MagenticOrchestration:
         """Main function to run the agents."""
+        cls.logger.info(f"Initializing orchestration for user: {user_id}")
 
         # Custom execution settings that should work with Azure OpenAI
         execution_settings = OpenAIChatPromptExecutionSettings(
@@ -97,6 +98,7 @@ async def get_current_or_new_orchestration(
         cls, user_id: str, team_config: TeamConfiguration, team_switched: bool
     ) -> MagenticOrchestration:  # add team_switched: bool parameter
         """get existing orchestration instance."""
+        cls.logger.info(f"Getting orchestration for user: {user_id}, team_switched: {team_switched}")
         current_orchestration = orchestration_config.get_current_orchestration(user_id)
         if (
             current_orchestration is None or team_switched
@@ -117,6 +119,7 @@ async def get_current_or_new_orchestration(
 
     async def run_orchestration(self, user_id, input_task) -> None:
         """Run the orchestration with user input loop."""
+        self.logger.info(f"Starting orchestration run for user: {user_id}")
 
         job_id = str(uuid.uuid4())
 
@@ -139,13 +142,15 @@ async def run_orchestration(self, user_id, input_task) -> None:
 
         runtime = InProcessRuntime()
         runtime.start()
+        self.logger.info(f"🎯 Starting task execution: {input_task.description[:100]}...")
 
         try:
 
             orchestration_result = await magentic_orchestration.invoke(
                 task=input_task.description,
                 runtime=runtime,
             )
+            self.logger.info("📊 Task invocation completed, retrieving results")
 
             try:
                 self.logger.info("\nAgent responses:")