44from copy import deepcopy
55
66import rigging as rg
7+ from loguru import logger
78from pydantic import ConfigDict , Field , PrivateAttr , SkipValidation , field_validator
89from rigging .message import inject_system_content
910from ulid import ULID # can't access via rg
@@ -237,6 +238,8 @@ async def _generate(
237238 try :
238239 messages = rg .caching .apply_cache_mode_to_messages (self .caching , [messages ])[0 ]
239240
241+ logger .trace (f"Generating with model '{ generator .model } '. Messages: { messages !r} " )
242+
240243 generated = (await generator .generate_messages ([messages ], [params ]))[0 ]
241244 if isinstance (generated , BaseException ):
242245 raise generated # noqa: TRY301
@@ -252,6 +255,7 @@ async def _generate(
252255 )
253256
254257 except Exception as error : # noqa: BLE001
258+ logger .error (f"Error during generation: { error } " , exc_info = True )
255259 chat = rg .Chat (
256260 messages ,
257261 [],
@@ -278,6 +282,13 @@ async def _stream( # noqa: PLR0912, PLR0915
278282 stop_conditions = self .stop_conditions
279283 session_id = ULID ()
280284
285+ logger .info (
286+ f"Starting Agent '{ self .name } ' ({ session_id } ): "
287+ f"model='{ self .model } ', "
288+ f"max_steps={ self .max_steps } , "
289+ f"tools={ [tool .name for tool in self .all_tools ]} "
290+ )
291+
281292 # Event dispatcher
282293
283294 async def _dispatch (event : AgentEvent ) -> t .AsyncIterator [AgentEvent ]:
@@ -292,6 +303,11 @@ async def _dispatch(event: AgentEvent) -> t.AsyncIterator[AgentEvent]:
292303 if not applicable_hooks :
293304 return
294305
306+ logger .debug (
307+ f"Agent '{ self .name } ' ({ session_id } ) dispatching '{ type (event ).__name__ } ': "
308+ f"applicable_hooks={ [get_callable_name (h , short = True ) for h in applicable_hooks ]} "
309+ )
310+
295311 # Run all applicable hooks and collect their reactions
296312 hook_reactions : dict [str , Reaction | None ] = {}
297313 for hook in applicable_hooks :
@@ -310,6 +326,10 @@ async def _dispatch(event: AgentEvent) -> t.AsyncIterator[AgentEvent]:
310326 if reaction is None :
311327 continue
312328
329+ logger .debug (
330+ f"Agent '{ self .name } ' ({ session_id } ) hook '{ hook_name } ' returned reaction: { reaction !r} "
331+ )
332+
313333 if not isinstance (reaction , Reaction ):
314334 warn_at_user_stacklevel (
315335 f"Hook '{ hook_name } ' returned { reaction } , but expected a Reaction." ,
@@ -386,6 +406,9 @@ async def _dispatch(event: AgentEvent) -> t.AsyncIterator[AgentEvent]:
386406 return
387407
388408 if isinstance (winning_reaction , RetryWithFeedback ):
409+ logger .debug (
410+ f"Agent '{ self .name } ' ({ session_id } ) injecting feedback for retry: '{ winning_reaction .feedback } '"
411+ )
389412 messages .append (rg .Message ("user" , winning_reaction .feedback ))
390413 raise Retry (messages = messages ) from winning_reaction
391414
@@ -408,6 +431,10 @@ async def _process_tool_call(
408431 ):
409432 yield event
410433
434+ logger .debug (
435+ f"Executing tool '{ tool_call .name } ' with args: { tool_call .function .arguments } "
436+ )
437+
411438 message : rg .Message
412439 stop = False
413440 tool = next ((t for t in self .all_tools if t .name == tool_call .name ), None )
@@ -431,6 +458,7 @@ async def _process_tool_call(
431458 yield event
432459 raise
433460 else :
461+ logger .warning (f"Tool '{ tool_call .name } ' not found." )
434462 message = rg .Message .from_model (
435463 rg .model .SystemErrorModel (content = f"Tool '{ tool_call .name } ' not found." )
436464 )
@@ -516,6 +544,7 @@ async def _process_tool_call(
516544 # Check for stop conditions
517545
518546 if any (cond (events ) for cond in stop_conditions ):
547+ logger .info ("A stop condition was met. Ending run." )
519548 break
520549
521550 # Check if stalled
@@ -524,6 +553,10 @@ async def _process_tool_call(
524553 if not stop_conditions :
525554 break
526555
556+ logger .warning (
557+ f"Agent '{ self .name } ' ({ session_id } ) stalled: No tool calls and no stop conditions met."
558+ )
559+
527560 async for event in _dispatch (
528561 AgentStalled (
529562 session_id = session_id ,
@@ -589,6 +622,23 @@ async def _process_tool_call(
589622 thread .messages = messages
590623 thread .events .extend (events )
591624
625+ total_usage = _total_usage_from_events (events )
626+ log_message = (
627+ f"Agent '{ self .name } ' finished: "
628+ f"reason='{ stop_reason } ', "
629+ f"steps={ step - 1 } , "
630+ f"total_tokens={ total_usage .total_tokens } , "
631+ f"in_tokens={ total_usage .input_tokens } , "
632+ f"out_tokens={ total_usage .output_tokens } "
633+ )
634+
635+ if stop_reason == "finished" :
636+ logger .success (log_message )
637+ elif stop_reason == "error" :
638+ logger .error (f"{ log_message } , error='{ error !r} '" )
639+ else :
640+ logger .warning (log_message )
641+
592642 yield AgentEnd (
593643 session_id = session_id ,
594644 agent = self ,
0 commit comments