Coverage for core / tool_logging.py: 21.8%

1"""Canonical tool-execution logging decorator (#509 unification). 

2 

3Originally defined inline at `create_recipe.py:329` and applied as 

4`@log_tool_execution` on ~40 tool functions across 

5`core/agent_tools.py` and `integrations/channels/agent_tools.py`. Moved 

6here so the *autogen registration chokepoint* 

7(`core.labeled_autogen_function.register_labeled_function`) can reuse it 

8without dragging the heavy `create_recipe` module in as a dependency. 

9 

10Behavior preserved verbatim from the original: 

11 - Sync vs async branching via inspect.iscoroutinefunction(func). 

12 - Logs entry with args+kwargs. 

13 - Coerces non-string returns to str (autogen contract). 

14 - Sync wrapper: if the underlying func accidentally returns a 

15 coroutine, drives it to completion via get_event_loop(). 

16 - On exception: logs error + traceback, returns a structured JSON 

17 error envelope as a string ("Tool execution failed: {...}") so the 

18 LLM sees the failure as a normal tool message. 

19 

20#509 extension: emits a per-tool UI status 

21(`publish_chat_stage('tool_call', text=<TOOL_LABELS[name] or fallback>)`) 

22BEFORE invoking the function, so the chat spinner shows tool-specific 

23verb text (e.g. "Searching CRM…") instead of staying on generic 

24"Thinking…". The emit is best-effort: failures are LOGGED at warning 

25level (no silent gulp per user directive 2026-05-11), never block the 

26tool. 

27 

28Per CLAUDE.md Gate 4 (no parallel paths) this is THE single canonical 

29home for tool-execution logging + per-tool UI emit. `create_recipe.py` 

30re-exports `log_tool_execution` for backward compatibility with the 

31existing 40+ decorator sites. LangChain's `_with_tool_logging` in 

32`hart_intelligence_entry.py` is functionally similar but operates on 

33LangChain `Tool.func` objects and has a different error-format 

34contract (LangChain agent_executor wants a plain string, not the 

35JSON envelope) — left in place pending a future merge. 

36""" 

37from __future__ import annotations 

38 

39import asyncio 

40import inspect 

41import json 

42import logging 

43from functools import wraps 

44 

45# Module-level tool_logger named "agent_logger" — matches the legacy 

46# logger create_recipe.py:284 configured with a RotatingFileHandler. 

47# When that file is imported (which always happens at HARTOS boot) 

48# the handler is attached; this module just looks up the same logger. 

49tool_logger = logging.getLogger("agent_logger") 

50 

51# Local fallback logger for the UI-emit warning channel (kept distinct 

52# from agent_logger so emit-failure warnings don't drown the per-tool 

53# success/error stream). 

54_emit_logger = logging.getLogger(__name__) 

55 

56 

57def _emit_tool_call_stage(tool_name: str) -> None: 

58 """Emit the canonical per-tool UI status event. 

59 

60 Best-effort: catches and LOGS any failure (publish_chat_stage import 

61 error, transport error, missing thread-local context) so the tool 

62 invocation is never blocked by an emit issue. Per user directive 

63 2026-05-11: exceptions are logged at warning level, never silently 

64 swallowed. 

65 """ 

66 try: 

67 from core.constants import TOOL_LABELS 

68 from core.peer_link.crossbar_publish import publish_chat_stage 

69 from threadlocal import thread_local_data 

70 

71 user_id = thread_local_data.get_user_id() or '' 

72 request_id = thread_local_data.get_request_id() or '' 

73 if user_id: 

74 publish_chat_stage( 

75 'tool_call', 

76 user_id=str(user_id), 

77 request_id=str(request_id), 

78 text=TOOL_LABELS.get(tool_name, f'Running {tool_name}…'), 

79 ) 

80 else: 

81 _emit_logger.debug( 

82 "[tool_logging] %s invoked with no chat context; " 

83 "UI emit skipped", 

84 tool_name, 

85 ) 

86 except Exception: 

87 _emit_logger.warning( 

88 "[tool_logging] UI emit for %s failed", 

89 tool_name, exc_info=True, 

90 ) 

91 

92 

93def _error_envelope(func_name: str, exc: BaseException) -> str: 

94 """Structured JSON error returned to the LLM on tool failure. 

95 

96 Preserves the legacy contract from create_recipe.py:344-359 so the 

97 40+ existing tools using `@log_tool_execution` see identical output. 

98 """ 

99 payload = { 

100 "status": "error", 

101 "tool_function": func_name, 

102 "error_type": type(exc).__name__, 

103 "error_message": str(exc), 

104 "suggestion": "Check logs for detailed traceback information", 

105 } 

106 return f"Tool execution failed: {json.dumps(payload)}" 

107 

108 

109def log_tool_execution(func): 

110 """Decorator wrapping a tool function with logging + UI emit. 

111 

112 Handles both sync and async callables. Apply with `@log_tool_execution` 

113 or programmatically as `wrapped = log_tool_execution(func)`. 

114 

115 See module docstring for the full behavior contract. 

116 """ 

117 if inspect.iscoroutinefunction(func): 

118 

119 @wraps(func) 

120 async def async_wrapper(*args, **kwargs): 

121 tool_logger.info(f"TOOL EXECUTION START: {func.__name__}") 

122 tool_logger.info( 

123 f"Arguments: {args}, Keyword Arguments: {kwargs}") 

124 _emit_tool_call_stage(func.__name__) 

125 try: 

126 result = await func(*args, **kwargs) 

127 if not isinstance(result, str): 

128 tool_logger.warning( 

129 f"Tool function {func.__name__} returned " 

130 f"non-string type: {type(result)}") 

131 result = str(result) 

132 tool_logger.info( 

133 f"TOOL EXECUTION SUCCESS: {func.__name__}") 

134 tool_logger.info( 

135 f"Result: {result[:100]}..." 

136 if len(result) > 100 else f"Result: {result}" 

137 ) 

138 return result 

139 except Exception as e: 

140 tool_logger.error( 

141 f"TOOL EXECUTION ERROR: {func.__name__} - {e}") 

142 tool_logger.exception("Exception details:") 

143 envelope = _error_envelope(func.__name__, e) 

144 tool_logger.info(f"Returning error response: {envelope}") 

145 return envelope 

146 

147 return async_wrapper 

148 

149 @wraps(func) 

150 def sync_wrapper(*args, **kwargs): 

151 tool_logger.info(f"TOOL EXECUTION START: {func.__name__}") 

152 tool_logger.info( 

153 f"Arguments: {args}, Keyword Arguments: {kwargs}") 

154 _emit_tool_call_stage(func.__name__) 

155 try: 

156 result = func(*args, **kwargs) 

157 # If the sync function accidentally returned a coroutine, 

158 # drive it to completion. Behavior preserved from the 

159 # original create_recipe.py:365-367. 

160 if asyncio.iscoroutine(result): 

161 tool_logger.info( 

162 f"Detected coroutine return from {func.__name__}, " 

163 f"running it to completion") 

164 result = asyncio.get_event_loop().run_until_complete( 

165 result) 

166 if not isinstance(result, str): 

167 tool_logger.warning( 

168 f"Tool function {func.__name__} returned " 

169 f"non-string type: {type(result)}") 

170 result = str(result) 

171 tool_logger.info(f"TOOL EXECUTION SUCCESS: {func.__name__}") 

172 tool_logger.info( 

173 f"Result: {result[:100]}..." 

174 if len(result) > 100 else f"Result: {result}" 

175 ) 

176 return result 

177 except Exception as e: 

178 tool_logger.error( 

179 f"TOOL EXECUTION ERROR: {func.__name__} - {e}") 

180 tool_logger.exception("Exception details:") 

181 envelope = _error_envelope(func.__name__, e) 

182 tool_logger.info(f"Returning error response: {envelope}") 

183 return envelope 

184 

185 return sync_wrapper 

186 

187 

188__all__ = ['log_tool_execution', 'tool_logger']