feat: Improve logging for debugging and monitoring

agents/goal_preprocessor/conversational.py

@@ -34,6 +34,9 @@ def __init__(self, *, llm, memory: MutableMapping | None = None):  # type: ignor
 
     @observe()
     def process(self, goal: str, history: Sequence[Dict[str, Any]]) -> Tuple[str, str | None]:
+        logger.debug("goal_preprocessor_entry",
+                     goal=goal,
+                     history_length=len(history))
         current_time, time_zone = self._current_time_and_timezone()
         history_str = "\n".join(f"Goal: {item['goal']}\nResult: {item['result']}" for item in history)
         prompt = _PROMPTS["clarify_goal"].format(

agents/llm/base_llm.py

@@ -127,7 +127,16 @@ def prompt(self, content: str, **kwargs) -> str:
         Returns:
             The assistant's response text.
         """
+        logger.debug("llm_prompt",
+                     model=self.model,
+                     prompt_preview=content[:100] + "..." if len(content) > 100 else content,
+                     kwargs=kwargs)
         resp = self.completion([{"role": "user", "content": content}], **kwargs)
+        logger.debug("llm_response",
+                     model=self.model,
+                     response_length=len(resp.text),
+                     prompt_tokens=resp.prompt_tokens,
+                     completion_tokens=resp.completion_tokens)
         return resp.text
 
     def prompt_to_json(self, content: str, **kwargs) -> Dict[str, Any]:
@@ -148,9 +157,12 @@ def prompt_to_json(self, content: str, **kwargs) -> Dict[str, Any]:
         Raises:
             json.JSONDecodeError: If JSON parsing fails
         """
+        logger.debug("llm_json_request", model=self.model)
         # Use JSON mode if supported by the LLM
         kwargs_with_json = kwargs.copy()
         kwargs_with_json.setdefault("response_format", {"type": "json_object"})
         raw_response = self.prompt(content, **kwargs_with_json)
         cleaned_response = self._fence_pattern.sub(lambda m: m.group(1).strip(), raw_response)
-        return json.loads(cleaned_response)
+        result = json.loads(cleaned_response)
+        logger.debug("llm_json_response", model=self.model, keys=list(result.keys()) if result else [])
+        return result

agents/llm/litellm.py

@@ -49,6 +49,12 @@ def completion(self, messages: List[Dict[str, str]], **kwargs) -> BaseLLM.LLMRes
 
         prompt_tokens, completion_tokens, total_tokens = self._extract_token_usage(resp)
 
+        logger.debug("llm_completion_success",
+                     model=self.model,
+                     prompt_tokens=prompt_tokens,
+                     completion_tokens=completion_tokens,
+                     total_tokens=total_tokens)
+
         return BaseLLM.LLMResponse(
             text=text,
             prompt_tokens=prompt_tokens if isinstance(prompt_tokens, int) else None,
@@ -138,5 +144,6 @@ def _get_token(obj: Any, *keys: str) -> int | None:
                 total_tokens = prompt_tokens + completion_tokens
 
             return prompt_tokens, completion_tokens, total_tokens
-        except Exception:
+        except Exception as e:
+            logger.debug("token_usage_extraction_failed", model=self.model, error=str(e))
             return None, None, None

agents/reasoner/react.py

@@ -32,6 +32,10 @@ def __init__(
         self.max_turns = max_turns
         self.top_k = top_k
 
+        logger.info("react_reasoner_initialized",
+                    max_turns=self.max_turns,
+                    top_k=self.top_k)
+
     @observe
     def run(self, goal: str) -> ReasoningResult:
         logger.info("ReACT reasoner started", goal=goal, max_turns=self.max_turns)

agents/reasoner/rewoo.py

@@ -75,6 +75,11 @@ def __init__(
         self.max_retries = max_retries
         self.top_k = top_k
 
+        logger.info("rewoo_reasoner_initialized",
+                    max_iterations=self.max_iterations,
+                    max_retries=self.max_retries,
+                    top_k=self.top_k)
+
     @observe
     def run(self, goal: str) -> ReasoningResult:
         state = ReasonerState(goal=goal)

agents/standard_agent.py

@@ -80,6 +80,13 @@ def __init__(
 
         self._state: AgentState = AgentState.READY
 
+        logger.info("agent_initialized",
+                    reasoner=self.reasoner.__class__.__name__,
+                    llm_model=getattr(self.llm, 'model', None),
+                    has_goal_preprocessor=self.goal_preprocessor is not None,
+                    conversation_history_window=self.conversation_history_window,
+                    timezone=self.memory["context"]["timezone"])
+
     @property
     def state(self) -> AgentState:
         return self._state
@@ -90,9 +97,15 @@ def solve(self, goal: str) -> ReasoningResult:
         run_id = uuid4().hex
         start_time = time.perf_counter()
 
+        logger.info("agent_solve_start",
+                    run_id=run_id,
+                    goal_preview=goal[:100] + "..." if len(goal) > 100 else goal)
+
         if self.goal_preprocessor:
+            logger.debug("goal_preprocessing", original_goal=goal)
             revised_goal, intervention_message = self.goal_preprocessor.process(goal, self.memory.get("conversation_history"))
             if intervention_message:
+                logger.info("goal_preprocessing_intervention", intervention=intervention_message)
                 self._record_interaction({"goal": goal, "result": f"user intervention message: {intervention_message}"})
                 return ReasoningResult(success=False, final_answer=intervention_message)
             goal = revised_goal

agents/tools/jentic.py

@@ -123,7 +123,13 @@ def search(self, query: str, *, top_k: int = 10) -> List[ToolBase]:
         logger.info("tool_search", query=query, top_k=top_k, filter_by_credentials=self._filter_by_credentials)
 
         response = asyncio.run(self._jentic.search(SearchRequest(query=query, limit=top_k, filter_by_credentials=self._filter_by_credentials,)))
-        return [JenticTool(result.model_dump(exclude_none=False)) for result in response.results] if response.results else []
+        results = [JenticTool(result.model_dump(exclude_none=False)) for result in response.results] if response.results else []
+
+        logger.info("tool_search_complete",
+                    query=query,
+                    result_count=len(results),
+                    found_tools=len(results) > 0)
+        return results
 
     @observe
     def load(self, tool: ToolBase) -> ToolBase:
@@ -166,6 +172,10 @@ def execute(self, tool: ToolBase, parameters: Dict[str, Any]) -> Any:
                     raise ToolCredentialsMissingError(result.error, tool)
 
                 raise ToolExecutionError(result.error, tool)
+
+            logger.info("tool_execution_success",
+                        tool_id=tool.id,
+                        output_length=len(str(result.output)) if result.output else 0)
             return result.output
 
         except ToolError: