From 05e01065925c6860da05f15984afad81d9481748 Mon Sep 17 00:00:00 2001 From: chengyongru <2755839590@qq.com> Date: Wed, 6 May 2026 21:11:26 +0800 Subject: [PATCH 1/6] refactor(logging): preserve tracebacks and add channel context MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - Preserve tracebacks: logger.error in except blocks → logger.exception - Channel context: BaseChannel injects self.logger = logger.bind(channel=name) - Third-party bridge: redirect_lib_logging() replaces ad-hoc stdlib-to-loguru bridges - Log levels: network timeouts downgraded from ERROR → WARNING - Fix --verbose flag to actually work with loguru (set handler to DEBUG) --- nanobot/agent/loop.py | 10 +- nanobot/agent/runner.py | 14 +-- nanobot/agent/subagent.py | 2 +- nanobot/agent/tools/mcp.py | 19 ++- nanobot/agent/tools/web.py | 4 +- nanobot/channels/base.py | 13 ++- nanobot/channels/dingtalk.py | 149 ++++++++++++------------ nanobot/channels/discord.py | 83 +++++++------ nanobot/channels/email.py | 50 ++++---- nanobot/channels/feishu.py | 134 ++++++++++----------- nanobot/channels/manager.py | 14 +-- nanobot/channels/matrix.py | 65 ++++------- nanobot/channels/mochat.py | 43 ++++--- nanobot/channels/msteams.py | 41 ++++--- nanobot/channels/qq.py | 61 +++++----- nanobot/channels/slack.py | 41 ++++--- nanobot/channels/telegram.py | 79 +++++++------ nanobot/channels/websocket.py | 42 +++---- nanobot/channels/wecom.py | 73 ++++++------ nanobot/channels/weixin.py | 68 ++++++----- nanobot/channels/whatsapp.py | 42 +++---- nanobot/cli/commands.py | 32 ++++- nanobot/cli/onboard.py | 2 +- nanobot/config/loader.py | 2 +- nanobot/cron/service.py | 13 +-- nanobot/heartbeat/service.py | 4 +- nanobot/providers/transcription.py | 8 +- nanobot/utils/document.py | 10 +- nanobot/utils/gitstore.py | 12 +- nanobot/utils/helpers.py | 6 +- nanobot/utils/logging_bridge.py | 47 ++++++++ tests/agent/test_runner.py | 2 +- tests/channels/test_telegram_channel.py | 21 ++-- tests/test_msteams.py | 2 +- tests/tools/test_mcp_tool.py | 2 +- 35 files changed, 631 insertions(+), 579 deletions(-) create mode 100644 nanobot/utils/logging_bridge.py diff --git a/nanobot/agent/loop.py b/nanobot/agent/loop.py index 46d4bc1ae..d5e7681f1 100644 --- a/nanobot/agent/loop.py +++ b/nanobot/agent/loop.py @@ -112,6 +112,11 @@ class _LoopHook(AgentHook): async def before_iteration(self, context: AgentHookContext) -> None: self._loop._current_iteration = context.iteration + logger.debug( + "Starting agent loop iteration {} for session {}", + context.iteration, + self._session_key, + ) async def before_execute_tools(self, context: AgentHookContext) -> None: if self._on_progress: @@ -417,7 +422,7 @@ class AgentLoop: logger.warning("MCP connection cancelled (will retry next message)") self._mcp_stacks.clear() except BaseException as e: - logger.error("Failed to connect MCP servers (will retry next message): {}", e) + logger.warning("Failed to connect MCP servers (will retry next message): {}", e) self._mcp_stacks.clear() finally: self._mcp_connecting = False @@ -907,6 +912,8 @@ class AgentLoop: self.sessions.save(session) session, pending = self.auto_compact.prepare_session(session, key) + if pending: + logger.info("Memory compact triggered for session {}", key) await self.consolidator.maybe_consolidate_by_tokens( session, @@ -919,6 +926,7 @@ class AgentLoop: # LLM via the merged prompt. See _persist_subagent_followup. is_subagent = msg.sender_id == "subagent" if is_subagent and self._persist_subagent_followup(session, msg): + logger.debug("Subagent result persisted for session {}", key) self.sessions.save(session) self._set_tool_context( channel, chat_id, msg.metadata.get("message_id"), diff --git a/nanobot/agent/runner.py b/nanobot/agent/runner.py index b9418045e..b81df4168 100644 --- a/nanobot/agent/runner.py +++ b/nanobot/agent/runner.py @@ -261,12 +261,11 @@ class AgentRunner: # Snipping may have created new orphans; clean them up. messages_for_model = self._drop_orphan_tool_results(messages_for_model) messages_for_model = self._backfill_missing_tool_results(messages_for_model) - except Exception as exc: - logger.warning( - "Context governance failed on turn {} for {}: {}; applying minimal repair", + except Exception: + logger.exception( + "Context governance failed on turn {} for {}; applying minimal repair", iteration, spec.session_key or "default", - exc, ) try: messages_for_model = self._drop_orphan_tool_results(messages) @@ -981,12 +980,11 @@ class AgentRunner: result, max_chars=spec.max_tool_result_chars, ) - except Exception as exc: - logger.warning( - "Tool result persist failed for {} in {}: {}; using raw result", + except Exception: + logger.exception( + "Tool result persist failed for {} in {}; using raw result", tool_call_id, spec.session_key or "default", - exc, ) content = result if isinstance(content, str) and len(content) > spec.max_tool_result_chars: diff --git a/nanobot/agent/subagent.py b/nanobot/agent/subagent.py index 6d64698a7..e418c2a7e 100644 --- a/nanobot/agent/subagent.py +++ b/nanobot/agent/subagent.py @@ -250,7 +250,7 @@ class SubagentManager: except Exception as e: status.phase = "error" status.error = str(e) - logger.error("Subagent [{}] failed: {}", task_id, e) + logger.exception("Subagent [{}] failed", task_id) await self._announce_result(task_id, label, task, f"Error: {e}", origin, "error", origin_message_id) async def _announce_result( diff --git a/nanobot/agent/tools/mcp.py b/nanobot/agent/tools/mcp.py index 580020a64..04b88386f 100644 --- a/nanobot/agent/tools/mcp.py +++ b/nanobot/agent/tools/mcp.py @@ -198,11 +198,10 @@ class MCPToolWrapper(Tool): await asyncio.sleep(1) # Brief backoff before retry continue # Second transient failure — give up with retry-specific message - logger.error( - "MCP tool '{}' failed after retry: {}: {}", + logger.exception( + "MCP tool '{}' failed after retry: {}", self._name, type(exc).__name__, - exc, ) return f"(MCP tool call failed after retry: {type(exc).__name__})" logger.exception( @@ -287,11 +286,10 @@ class MCPResourceWrapper(Tool): ) await asyncio.sleep(1) continue - logger.error( - "MCP resource '{}' failed after retry: {}: {}", + logger.exception( + "MCP resource '{}' failed after retry: {}", self._name, type(exc).__name__, - exc, ) return f"(MCP resource read failed after retry: {type(exc).__name__})" logger.exception( @@ -383,7 +381,7 @@ class MCPPromptWrapper(Tool): logger.warning("MCP prompt '{}' was cancelled by server/SDK", self._name) return "(MCP prompt call was cancelled)" except McpError as exc: - logger.error( + logger.exception( "MCP prompt '{}' failed: code={} message={}", self._name, exc.error.code, @@ -400,11 +398,10 @@ class MCPPromptWrapper(Tool): ) await asyncio.sleep(1) continue - logger.error( - "MCP prompt '{}' failed after retry: {}: {}", + logger.exception( + "MCP prompt '{}' failed after retry: {}", self._name, type(exc).__name__, - exc, ) return f"(MCP prompt call failed after retry: {type(exc).__name__})" logger.exception( @@ -608,7 +605,7 @@ async def connect_mcp_servers( " Hint: this looks like stdio protocol pollution. Make sure the MCP server writes " "only JSON-RPC to stdout and sends logs/debug output to stderr instead." ) - logger.error("MCP server '{}': failed to connect: {}{}", name, e, hint) + logger.exception("MCP server '{}': failed to connect: {}", name, hint) with suppress(Exception): await server_stack.aclose() return name, None diff --git a/nanobot/agent/tools/web.py b/nanobot/agent/tools/web.py index 6378a7979..aae40ac9c 100644 --- a/nanobot/agent/tools/web.py +++ b/nanobot/agent/tools/web.py @@ -500,10 +500,10 @@ class WebFetchTool(Tool): "untrusted": True, "text": text, }, ensure_ascii=False) except httpx.ProxyError as e: - logger.error("WebFetch proxy error for {}: {}", url, e) + logger.exception("WebFetch proxy error for {}", url) return json.dumps({"error": f"Proxy error: {e}", "url": url}, ensure_ascii=False) except Exception as e: - logger.error("WebFetch error for {}: {}", url, e) + logger.exception("WebFetch error for {}", url) return json.dumps({"error": str(e), "url": url}, ensure_ascii=False) def _to_markdown(self, html_content: str) -> str: diff --git a/nanobot/channels/base.py b/nanobot/channels/base.py index 6097b420f..087677494 100644 --- a/nanobot/channels/base.py +++ b/nanobot/channels/base.py @@ -38,6 +38,7 @@ class BaseChannel(ABC): bus: The message bus for communication. """ self.config = config + self.logger = logger.bind(channel=self.name) self.bus = bus self._running = False @@ -61,8 +62,8 @@ class BaseChannel(ABC): language=self.transcription_language or None, ) return await provider.transcribe(file_path) - except Exception as e: - logger.warning("{}: audio transcription failed: {}", self.name, e) + except Exception: + self.logger.exception("Audio transcription failed") return "" async def login(self, force: bool = False) -> bool: @@ -136,7 +137,7 @@ class BaseChannel(ABC): else: allow_list = getattr(self.config, "allow_from", []) if not allow_list: - logger.warning("{}: allow_from is empty — all access denied", self.name) + self.logger.warning("allow_from is empty — all access denied") return False if "*" in allow_list: return True @@ -165,10 +166,10 @@ class BaseChannel(ABC): session_key: Optional session key override (e.g. thread-scoped sessions). """ if not self.is_allowed(sender_id): - logger.warning( - "Access denied for sender {} on channel {}. " + self.logger.warning( + "Access denied for sender {}. " "Add them to allowFrom list in config to grant access.", - sender_id, self.name, + sender_id, ) return diff --git a/nanobot/channels/dingtalk.py b/nanobot/channels/dingtalk.py index 609a7fa54..72199fdf9 100644 --- a/nanobot/channels/dingtalk.py +++ b/nanobot/channels/dingtalk.py @@ -12,7 +12,6 @@ from typing import Any from urllib.parse import unquote, urljoin, urlparse import httpx -from loguru import logger from pydantic import Field from nanobot.bus.events import OutboundMessage @@ -113,7 +112,7 @@ class NanobotDingTalkHandler(CallbackHandler): content = content + "\n\nReceived files:\n" + file_list if not content: - logger.warning( + self.channel.logger.warning( "Received empty or unsupported message type: {}", chatbot_msg.message_type, ) @@ -128,7 +127,7 @@ class NanobotDingTalkHandler(CallbackHandler): or message.data.get("openConversationId") ) - logger.info("Received DingTalk message from {} ({}): {}", sender_name, sender_id, content) + self.channel.logger.info("Received message from {} ({}): {}", sender_name, sender_id, content) # Forward to Nanobot via _on_message (non-blocking). # Store reference to prevent GC before task completes. @@ -146,8 +145,8 @@ class NanobotDingTalkHandler(CallbackHandler): return AckMessage.STATUS_OK, "OK" - except Exception as e: - logger.error("Error processing DingTalk message: {}", e) + except Exception: + self.channel.logger.exception("Error processing message") # Return OK to avoid retry loop from DingTalk server return AckMessage.STATUS_OK, "Error" @@ -204,20 +203,20 @@ class DingTalkChannel(BaseChannel): """Start the DingTalk bot with Stream Mode.""" try: if not DINGTALK_AVAILABLE: - logger.error( - "DingTalk Stream SDK not installed. Run: pip install dingtalk-stream" + self.logger.error( + "Stream SDK not installed. Run: pip install dingtalk-stream" ) return if not self.config.client_id or not self.config.client_secret: - logger.error("DingTalk client_id and client_secret not configured") + self.logger.error("client_id and client_secret not configured") return self._running = True self._http = httpx.AsyncClient() - logger.info( - "Initializing DingTalk Stream Client with Client ID: {}...", + self.logger.info( + "Initializing Stream Client with Client ID: {}...", self.config.client_id, ) credential = Credential(self.config.client_id, self.config.client_secret) @@ -227,20 +226,20 @@ class DingTalkChannel(BaseChannel): handler = NanobotDingTalkHandler(self) self._client.register_callback_handler(ChatbotMessage.TOPIC, handler) - logger.info("DingTalk bot started with Stream Mode") + self.logger.info("bot started with Stream Mode") # Reconnect loop: restart stream if SDK exits or crashes while self._running: try: await self._client.start() except Exception as e: - logger.warning("DingTalk stream error: {}", e) + self.logger.warning("stream error: {}", e) if self._running: - logger.info("Reconnecting DingTalk stream in 5 seconds...") + self.logger.info("Reconnecting stream in 5 seconds...") await asyncio.sleep(5) - except Exception as e: - logger.exception("Failed to start DingTalk channel: {}", e) + except Exception: + self.logger.exception("Failed to start channel") async def stop(self) -> None: """Stop the DingTalk bot.""" @@ -266,7 +265,7 @@ class DingTalkChannel(BaseChannel): } if not self._http: - logger.warning("DingTalk HTTP client not initialized, cannot refresh token") + self.logger.warning("HTTP client not initialized, cannot refresh token") return None try: @@ -277,8 +276,8 @@ class DingTalkChannel(BaseChannel): # Expire 60s early to be safe self._token_expiry = time.time() + int(res_data.get("expireIn", 7200)) - 60 return self._access_token - except Exception as e: - logger.error("Failed to get DingTalk access token: {}", e) + except Exception: + self.logger.exception("Failed to get access token") return None @staticmethod @@ -317,8 +316,8 @@ class DingTalkChannel(BaseChannel): ) -> tuple[bytes, str, str | None]: ext = Path(filename).suffix.lower() if ext in self._ZIP_BEFORE_UPLOAD_EXTS or content_type == "text/html": - logger.info( - "DingTalk does not accept raw HTML attachments, zipping {} before upload", + self.logger.info( + "does not accept raw HTML attachments, zipping {} before upload", filename, ) return self._zip_bytes(filename, data) @@ -327,7 +326,7 @@ class DingTalkChannel(BaseChannel): def _validate_remote_media_url(self, media_ref: str) -> bool: ok, err = validate_url_target(media_ref) if not ok: - logger.warning("DingTalk remote media URL blocked ref={} reason={}", media_ref, err) + self.logger.warning("remote media URL blocked ref={} reason={}", media_ref, err) return False return True @@ -343,15 +342,15 @@ class DingTalkChannel(BaseChannel): def _next_remote_media_url(self, current_url: str, location: str | None) -> str | None: if not self.config.allow_remote_media_redirects: - logger.warning("DingTalk media download redirect refused ref={}", current_url) + self.logger.warning("media download redirect refused ref={}", current_url) return None if not location: - logger.warning("DingTalk media download redirect without Location ref={}", current_url) + self.logger.warning("media download redirect without Location ref={}", current_url) return None next_url = urljoin(current_url, location) if not self._redirect_host_allowed(current_url, next_url): - logger.warning( - "DingTalk media download cross-host redirect refused ref={} next={}", + self.logger.warning( + "media download cross-host redirect refused ref={} next={}", current_url, next_url, ) @@ -382,8 +381,8 @@ class DingTalkChannel(BaseChannel): async with stream("GET", current_url, follow_redirects=False) as resp: final_ok, final_err = validate_resolved_url(str(resp.url)) if not final_ok: - logger.warning( - "DingTalk remote media redirect blocked ref={} final={} reason={}", + self.logger.warning( + "remote media redirect blocked ref={} final={} reason={}", media_ref, resp.url, final_err, @@ -398,8 +397,8 @@ class DingTalkChannel(BaseChannel): current_url = next_url continue if resp.status_code >= 400: - logger.warning( - "DingTalk media download failed status={} ref={}", + self.logger.warning( + "media download failed status={} ref={}", resp.status_code, current_url, ) @@ -409,15 +408,15 @@ class DingTalkChannel(BaseChannel): async for chunk in resp.aiter_bytes(): total += len(chunk) if total > DINGTALK_MAX_REMOTE_MEDIA_BYTES: - logger.warning( - "DingTalk media download too large ref={} bytes>{}", + self.logger.warning( + "media download too large ref={} bytes>{}", current_url, DINGTALK_MAX_REMOTE_MEDIA_BYTES, ) return None, None chunks.append(chunk) return b"".join(chunks), (resp.headers.get("content-type") or "") - logger.warning("DingTalk media download exceeded redirect limit ref={}", media_ref) + self.logger.warning("media download exceeded redirect limit ref={}", media_ref) return None, None current_url = media_ref @@ -425,8 +424,8 @@ class DingTalkChannel(BaseChannel): resp = await self._http.get(current_url, follow_redirects=False) final_ok, final_err = validate_resolved_url(str(getattr(resp, "url", current_url))) if not final_ok: - logger.warning( - "DingTalk remote media redirect blocked ref={} final={} reason={}", + self.logger.warning( + "remote media redirect blocked ref={} final={} reason={}", media_ref, getattr(resp, "url", current_url), final_err, @@ -441,27 +440,27 @@ class DingTalkChannel(BaseChannel): current_url = next_url continue if resp.status_code >= 400: - logger.warning( - "DingTalk media download failed status={} ref={}", + self.logger.warning( + "media download failed status={} ref={}", resp.status_code, current_url, ) return None, None if len(resp.content) > DINGTALK_MAX_REMOTE_MEDIA_BYTES: - logger.warning( - "DingTalk media download too large ref={} bytes>{}", + self.logger.warning( + "media download too large ref={} bytes>{}", current_url, DINGTALK_MAX_REMOTE_MEDIA_BYTES, ) return None, None return resp.content, (resp.headers.get("content-type") or "") - logger.warning("DingTalk media download exceeded redirect limit ref={}", media_ref) + self.logger.warning("media download exceeded redirect limit ref={}", media_ref) return None, None - except httpx.TransportError as e: - logger.error("DingTalk media download network error ref={} err={}", media_ref, e) + except httpx.TransportError: + self.logger.exception("media download network error ref={}", media_ref) raise - except Exception as e: - logger.error("DingTalk media download error ref={} err={}", media_ref, e) + except Exception: + self.logger.exception("media download error ref={}", media_ref) return None, None async def _read_media_bytes( @@ -486,13 +485,13 @@ class DingTalkChannel(BaseChannel): else: local_path = Path(os.path.expanduser(media_ref)) if not local_path.is_file(): - logger.warning("DingTalk media file not found: {}", local_path) + self.logger.warning("media file not found: {}", local_path) return None, None, None data = await asyncio.to_thread(local_path.read_bytes) content_type = mimetypes.guess_type(local_path.name)[0] return data, local_path.name, content_type - except Exception as e: - logger.error("DingTalk media read error ref={} err={}", media_ref, e) + except Exception: + self.logger.exception("media read error ref={}", media_ref) return None, None, None async def _upload_media( @@ -514,23 +513,23 @@ class DingTalkChannel(BaseChannel): text = resp.text result = resp.json() if resp.headers.get("content-type", "").startswith("application/json") else {} if resp.status_code >= 400: - logger.error("DingTalk media upload failed status={} type={} body={}", resp.status_code, media_type, text[:500]) + self.logger.error("media upload failed status={} type={} body={}", resp.status_code, media_type, text[:500]) return None errcode = result.get("errcode", 0) if errcode != 0: - logger.error("DingTalk media upload api error type={} errcode={} body={}", media_type, errcode, text[:500]) + self.logger.error("media upload api error type={} errcode={} body={}", media_type, errcode, text[:500]) return None sub = result.get("result") or {} media_id = result.get("media_id") or result.get("mediaId") or sub.get("media_id") or sub.get("mediaId") if not media_id: - logger.error("DingTalk media upload missing media_id body={}", text[:500]) + self.logger.error("media upload missing media_id body={}", text[:500]) return None return str(media_id) - except httpx.TransportError as e: - logger.error("DingTalk media upload network error type={} err={}", media_type, e) + except httpx.TransportError: + self.logger.exception("media upload network error type={}", media_type) raise - except Exception as e: - logger.error("DingTalk media upload error type={} err={}", media_type, e) + except Exception: + self.logger.exception("media upload error type={}", media_type) return None async def _send_batch_message( @@ -541,7 +540,7 @@ class DingTalkChannel(BaseChannel): msg_param: dict[str, Any], ) -> bool: if not self._http: - logger.warning("DingTalk HTTP client not initialized, cannot send") + self.logger.warning("HTTP client not initialized, cannot send") return False headers = {"x-acs-dingtalk-access-token": token} @@ -568,7 +567,7 @@ class DingTalkChannel(BaseChannel): resp = await self._http.post(url, json=payload, headers=headers) body = resp.text if resp.status_code != 200: - logger.error("DingTalk send failed msgKey={} status={} body={}", msg_key, resp.status_code, body[:500]) + self.logger.error("send failed msgKey={} status={} body={}", msg_key, resp.status_code, body[:500]) return False try: result = resp.json() @@ -576,15 +575,15 @@ class DingTalkChannel(BaseChannel): result = {} errcode = result.get("errcode") if errcode not in (None, 0): - logger.error("DingTalk send api error msgKey={} errcode={} body={}", msg_key, errcode, body[:500]) + self.logger.error("send api error msgKey={} errcode={} body={}", msg_key, errcode, body[:500]) return False - logger.debug("DingTalk message sent to {} with msgKey={}", chat_id, msg_key) + self.logger.debug("message sent to {} with msgKey={}", chat_id, msg_key) return True - except httpx.TransportError as e: - logger.error("DingTalk network error sending message msgKey={} err={}", msg_key, e) + except httpx.TransportError: + self.logger.exception("network error sending message msgKey={}", msg_key) raise - except Exception as e: - logger.error("Error sending DingTalk message msgKey={} err={}", msg_key, e) + except Exception: + self.logger.exception("Error sending message msgKey={}", msg_key) return False async def _send_markdown_text(self, token: str, chat_id: str, content: str) -> bool: @@ -610,11 +609,11 @@ class DingTalkChannel(BaseChannel): ) if ok: return True - logger.warning("DingTalk image url send failed, trying upload fallback: {}", media_ref) + self.logger.warning("image url send failed, trying upload fallback: {}", media_ref) data, filename, content_type = await self._read_media_bytes(media_ref) if not data: - logger.error("DingTalk media read failed: {}", media_ref) + self.logger.error("media read failed: {}", media_ref) return False filename = filename or self._guess_filename(media_ref, upload_type) @@ -646,7 +645,7 @@ class DingTalkChannel(BaseChannel): ) if ok: return True - logger.warning("DingTalk image media_id send failed, falling back to file: {}", media_ref) + self.logger.warning("image media_id send failed, falling back to file: {}", media_ref) return await self._send_batch_message( token, @@ -668,7 +667,7 @@ class DingTalkChannel(BaseChannel): ok = await self._send_media_ref(token, msg.chat_id, media_ref) if ok: continue - logger.error("DingTalk media send failed for {}", media_ref) + self.logger.error("media send failed for {}", media_ref) # Send visible fallback so failures are observable by the user. filename = self._guess_filename(media_ref, self._guess_upload_type(media_ref)) await self._send_markdown_text( @@ -691,7 +690,7 @@ class DingTalkChannel(BaseChannel): permission checks before publishing to the bus. """ try: - logger.info("DingTalk inbound: {} from {}", content, sender_name) + self.logger.info("inbound: {} from {}", content, sender_name) is_group = conversation_type == "2" and conversation_id chat_id = f"group:{conversation_id}" if is_group else sender_id await self._handle_message( @@ -704,8 +703,8 @@ class DingTalkChannel(BaseChannel): "conversation_type": conversation_type, }, ) - except Exception as e: - logger.error("Error publishing DingTalk message: {}", e) + except Exception: + self.logger.exception("Error publishing message") async def _download_dingtalk_file( self, @@ -719,7 +718,7 @@ class DingTalkChannel(BaseChannel): try: token = await self._get_access_token() if not token or not self._http: - logger.error("DingTalk file download: no token or http client") + self.logger.error("file download: no token or http client") return None # Step 1: Exchange downloadCode for a temporary download URL @@ -728,19 +727,19 @@ class DingTalkChannel(BaseChannel): payload = {"downloadCode": download_code, "robotCode": self.config.client_id} resp = await self._http.post(api_url, json=payload, headers=headers) if resp.status_code != 200: - logger.error("DingTalk get download URL failed: status={}, body={}", resp.status_code, resp.text) + self.logger.error("get download URL failed: status={}, body={}", resp.status_code, resp.text) return None result = resp.json() download_url = result.get("downloadUrl") if not download_url: - logger.error("DingTalk download URL not found in response: {}", result) + self.logger.error("download URL not found in response: {}", result) return None # Step 2: Download the file content file_resp = await self._http.get(download_url, follow_redirects=True) if file_resp.status_code != 200: - logger.error("DingTalk file download failed: status={}", file_resp.status_code) + self.logger.error("file download failed: status={}", file_resp.status_code) return None # Save to media directory (accessible under workspace) @@ -748,8 +747,8 @@ class DingTalkChannel(BaseChannel): download_dir.mkdir(parents=True, exist_ok=True) file_path = download_dir / filename await asyncio.to_thread(file_path.write_bytes, file_resp.content) - logger.info("DingTalk file saved: {}", file_path) + self.logger.info("file saved: {}", file_path) return str(file_path) - except Exception as e: - logger.error("DingTalk file download error: {}", e) + except Exception: + self.logger.exception("file download error") return None diff --git a/nanobot/channels/discord.py b/nanobot/channels/discord.py index bb39b66b7..10d569692 100644 --- a/nanobot/channels/discord.py +++ b/nanobot/channels/discord.py @@ -10,7 +10,6 @@ from dataclasses import dataclass from pathlib import Path from typing import TYPE_CHECKING, Any, Literal -from loguru import logger from pydantic import Field from nanobot.bus.events import OutboundMessage @@ -86,12 +85,12 @@ if DISCORD_AVAILABLE: async def on_ready(self) -> None: self._channel._bot_user_id = str(self.user.id) if self.user else None - logger.info("Discord bot connected as user {}", self._channel._bot_user_id) + self._channel.logger.info("bot connected as user {}", self._channel._bot_user_id) try: synced = await self.tree.sync() - logger.info("Discord app commands synced: {}", len(synced)) + self._channel.logger.info("app commands synced: {}", len(synced)) except Exception as e: - logger.warning("Discord app command sync failed: {}", e) + self._channel.logger.warning("app command sync failed: {}", e) async def on_message(self, message: discord.Message) -> None: await self._channel._handle_discord_message(message) @@ -111,7 +110,7 @@ if DISCORD_AVAILABLE: await interaction.response.send_message(text, ephemeral=True) return True except Exception as e: - logger.warning("Discord interaction response failed: {}", e) + self._channel.logger.warning("interaction response failed: {}", e) return False async def _resolve_interaction_channel( @@ -126,7 +125,7 @@ if DISCORD_AVAILABLE: try: channel = await self.fetch_channel(channel_id) except Exception as e: - logger.warning("Discord interaction channel {} unavailable: {}", channel_id, e) + self._channel.logger.warning("interaction channel {} unavailable: {}", channel_id, e) return None self._channel._remember_channel(channel) return channel @@ -154,7 +153,7 @@ if DISCORD_AVAILABLE: channel_id = interaction.channel_id if channel_id is None: - logger.warning("Discord slash command missing channel_id: {}", command_text) + self._channel.logger.warning("slash command missing channel_id: {}", command_text) return if not self._channel.is_allowed(sender_id): @@ -226,8 +225,8 @@ if DISCORD_AVAILABLE: error: app_commands.AppCommandError, ) -> None: command_name = interaction.command.qualified_name if interaction.command else "?" - logger.warning( - "Discord app command failed user={} channel={} cmd={} error={}", + self._channel.logger.warning( + "app command failed user={} channel={} cmd={} error={}", interaction.user.id, interaction.channel_id, command_name, @@ -243,7 +242,7 @@ if DISCORD_AVAILABLE: try: channel = await self.fetch_channel(channel_id) except Exception as e: - logger.warning("Discord channel {} unavailable: {}", msg.chat_id, e) + self._channel.logger.warning("channel {} unavailable: {}", msg.chat_id, e) return reference, mention_settings = self._build_reply_context(channel, msg.reply_to) @@ -281,11 +280,11 @@ if DISCORD_AVAILABLE: """Send a file attachment via discord.py.""" path = Path(file_path) if not path.is_file(): - logger.warning("Discord file not found, skipping: {}", file_path) + self._channel.logger.warning("file not found, skipping: {}", file_path) return False if path.stat().st_size > MAX_ATTACHMENT_BYTES: - logger.warning("Discord file too large (>20MB), skipping: {}", path.name) + self._channel.logger.warning("file too large (>20MB), skipping: {}", path.name) return False try: @@ -294,10 +293,10 @@ if DISCORD_AVAILABLE: kwargs["reference"] = reference kwargs["allowed_mentions"] = mention_settings await channel.send(**kwargs) - logger.info("Discord file sent: {}", path.name) + self._channel.logger.info("file sent: {}", path.name) return True - except Exception as e: - logger.error("Error sending Discord file {}: {}", path.name, e) + except Exception: + self._channel.logger.exception("Error sending file {}", path.name) return False @staticmethod @@ -321,7 +320,7 @@ if DISCORD_AVAILABLE: try: message_id = int(reply_to) except ValueError: - logger.warning("Invalid Discord reply target: {}", reply_to) + self._channel.logger.warning("Invalid reply target: {}", reply_to) return None, mention_settings return channel.get_partial_message(message_id), mention_settings @@ -385,11 +384,11 @@ class DiscordChannel(BaseChannel): async def start(self) -> None: """Start the Discord client.""" if not DISCORD_AVAILABLE: - logger.error("discord.py not installed. Run: pip install nanobot-ai[discord]") + self.logger.error("discord.py not installed. Run: pip install nanobot-ai[discord]") return if not self.config.token: - logger.error("Discord bot token not configured") + self.logger.error("bot token not configured") return try: @@ -407,8 +406,8 @@ class DiscordChannel(BaseChannel): password=self.config.proxy_password, ) elif has_user != has_pass: - logger.warning( - "Discord proxy auth incomplete: both proxy_username and " + self.logger.warning( + "proxy auth incomplete: both proxy_username and " "proxy_password must be set; ignoring partial credentials", ) @@ -418,21 +417,21 @@ class DiscordChannel(BaseChannel): proxy=self.config.proxy, proxy_auth=proxy_auth, ) - except Exception as e: - logger.error("Failed to initialize Discord client: {}", e) + except Exception: + self.logger.exception("Failed to initialize client") self._client = None self._running = False return self._running = True - logger.info("Starting Discord client via discord.py...") + self.logger.info("Starting client via discord.py...") try: await self._client.start(self.config.token) except asyncio.CancelledError: raise - except Exception as e: - logger.error("Discord client startup failed: {}", e) + except Exception: + self.logger.exception("client startup failed") finally: self._running = False await self._reset_runtime_state(close_client=True) @@ -446,15 +445,15 @@ class DiscordChannel(BaseChannel): """Send a message through Discord using discord.py.""" client = self._client if client is None or not client.is_ready(): - logger.warning("Discord client not ready; dropping outbound message") + self.logger.warning("client not ready; dropping outbound message") return is_progress = bool((msg.metadata or {}).get("_progress")) try: await client.send_outbound(msg) - except Exception as e: - logger.error("Error sending Discord message: {}", e) + except Exception: + self.logger.exception("Error sending message") raise finally: if not is_progress: @@ -467,7 +466,7 @@ class DiscordChannel(BaseChannel): """Progressive Discord delivery: send once, then edit until the stream ends.""" client = self._client if client is None or not client.is_ready(): - logger.warning("Discord client not ready; dropping stream delta") + self.logger.warning("client not ready; dropping stream delta") return meta = metadata or {} @@ -497,7 +496,7 @@ class DiscordChannel(BaseChannel): target = await self._resolve_channel(chat_id) if target is None: - logger.warning("Discord stream target {} unavailable", chat_id) + self.logger.warning("stream target {} unavailable", chat_id) return now = time.monotonic() @@ -506,7 +505,7 @@ class DiscordChannel(BaseChannel): buf.message = await target.send(content=buf.text) buf.last_edit = now except Exception as e: - logger.warning("Discord stream initial send failed: {}", e) + self.logger.warning("stream initial send failed: {}", e) raise return @@ -517,7 +516,7 @@ class DiscordChannel(BaseChannel): await buf.message.edit(content=DiscordBotClient._build_chunks(buf.text, [], False)[0]) buf.last_edit = now except Exception as e: - logger.warning("Discord stream edit failed: {}", e) + self.logger.warning("stream edit failed: {}", e) raise async def _handle_discord_message(self, message: discord.Message) -> None: @@ -560,7 +559,7 @@ class DiscordChannel(BaseChannel): await message.add_reaction(self.config.read_receipt_emoji) self._pending_reactions[channel_id] = message except Exception as e: - logger.debug("Failed to add read receipt reaction: {}", e) + self.logger.debug("Failed to add read receipt reaction: {}", e) # Delayed working indicator (cosmetic — not tied to subagent lifecycle) async def _delayed_working_emoji() -> None: @@ -603,7 +602,7 @@ class DiscordChannel(BaseChannel): try: return await client.fetch_channel(channel_id) except Exception as e: - logger.warning("Discord channel {} unavailable: {}", chat_id, e) + self.logger.warning("channel {} unavailable: {}", chat_id, e) return None async def _finalize_stream(self, chat_id: str, buf: _StreamBuf) -> None: @@ -616,12 +615,12 @@ class DiscordChannel(BaseChannel): try: await buf.message.edit(content=chunks[0]) except Exception as e: - logger.warning("Discord final stream edit failed: {}", e) + self.logger.warning("final stream edit failed: {}", e) raise target = getattr(buf.message, "channel", None) or await self._resolve_channel(chat_id) if target is None: - logger.warning("Discord stream follow-up target {} unavailable", chat_id) + self.logger.warning("stream follow-up target {} unavailable", chat_id) self._stream_bufs.pop(chat_id, None) return @@ -673,7 +672,7 @@ class DiscordChannel(BaseChannel): media_paths.append(str(file_path)) markers.append(f"[attachment: {file_path.name}]") except Exception as e: - logger.warning("Failed to download Discord attachment: {}", e) + self.logger.warning("Failed to download attachment: {}", e) markers.append(f"[attachment: {filename} - download failed]") return media_paths, markers @@ -715,8 +714,8 @@ class DiscordChannel(BaseChannel): if bot_user_id is None and self._client and self._client.user: bot_user_id = str(self._client.user.id) if bot_user_id is None: - logger.debug( - "Discord message in {} ignored (bot identity unavailable)", message.channel.id + self.logger.debug( + "message in {} ignored (bot identity unavailable)", message.channel.id ) return False @@ -729,7 +728,7 @@ class DiscordChannel(BaseChannel): if self._references_bot_message(message, bot_user_id): return True - logger.debug("Discord message in {} ignored (bot not mentioned)", message.channel.id) + self.logger.debug("message in {} ignored (bot not mentioned)", message.channel.id) return False return True @@ -759,7 +758,7 @@ class DiscordChannel(BaseChannel): except asyncio.CancelledError: return except Exception as e: - logger.debug("Discord typing indicator failed for {}: {}", channel_id, e) + self.logger.debug("typing indicator failed for {}: {}", channel_id, e) return self._typing_tasks[channel_id] = asyncio.create_task(typing_loop()) @@ -803,6 +802,6 @@ class DiscordChannel(BaseChannel): try: await self._client.close() except Exception as e: - logger.warning("Discord client close failed: {}", e) + self.logger.warning("client close failed: {}", e) self._client = None self._bot_user_id = None diff --git a/nanobot/channels/email.py b/nanobot/channels/email.py index 401da7bb6..f729d18e4 100644 --- a/nanobot/channels/email.py +++ b/nanobot/channels/email.py @@ -128,7 +128,7 @@ class EmailChannel(BaseChannel): async def start(self) -> None: """Start polling IMAP for inbound emails.""" if not self.config.consent_granted: - logger.warning( + self.logger.warning( "Email channel disabled: consent_granted is false. " "Set channels.email.consentGranted=true after explicit user permission." ) @@ -139,12 +139,12 @@ class EmailChannel(BaseChannel): self._running = True if not self.config.verify_dkim and not self.config.verify_spf: - logger.warning( - "Email channel: DKIM and SPF verification are both DISABLED. " + self.logger.warning( + "DKIM and SPF verification are both DISABLED. " "Emails with spoofed From headers will be accepted. " "Set verify_dkim=true and verify_spf=true for anti-spoofing protection." ) - logger.info("Starting Email channel (IMAP polling mode)...") + self.logger.info("Starting Email channel (IMAP polling mode)...") poll_seconds = max(5, int(self.config.poll_interval_seconds)) while self._running: @@ -167,8 +167,8 @@ class EmailChannel(BaseChannel): media=item.get("media") or None, metadata=item.get("metadata", {}), ) - except Exception as e: - logger.error("Email polling error: {}", e) + except Exception: + self.logger.exception("Polling error") await asyncio.sleep(poll_seconds) @@ -179,16 +179,16 @@ class EmailChannel(BaseChannel): async def send(self, msg: OutboundMessage) -> None: """Send email via SMTP.""" if not self.config.consent_granted: - logger.warning("Skip email send: consent_granted is false") + self.logger.warning("Skip email send: consent_granted is false") return if not self.config.smtp_host: - logger.warning("Email channel SMTP host not configured") + self.logger.warning("SMTP host not configured") return to_addr = msg.chat_id.strip() if not to_addr: - logger.warning("Email channel missing recipient address") + self.logger.warning("Missing recipient address") return # Determine if this is a reply (recipient has sent us an email before) @@ -197,7 +197,7 @@ class EmailChannel(BaseChannel): # autoReplyEnabled only controls automatic replies, not proactive sends if is_reply and not self.config.auto_reply_enabled and not force_send: - logger.info("Skip automatic email reply to {}: auto_reply_enabled is false", to_addr) + self.logger.info("Skip automatic reply to {}: auto_reply_enabled is false", to_addr) return base_subject = self._last_subject_by_chat.get(to_addr, "nanobot reply") @@ -220,8 +220,8 @@ class EmailChannel(BaseChannel): try: await asyncio.to_thread(self._smtp_send, email_msg) - except Exception as e: - logger.error("Error sending email to {}: {}", to_addr, e) + except Exception: + self.logger.exception("Error sending to {}", to_addr) raise def _validate_config(self) -> bool: @@ -240,7 +240,7 @@ class EmailChannel(BaseChannel): missing.append("smtp_password") if missing: - logger.error("Email channel not configured, missing: {}", ', '.join(missing)) + self.logger.error("Channel not configured, missing: {}", ', '.join(missing)) return False return True @@ -321,7 +321,7 @@ class EmailChannel(BaseChannel): except Exception as exc: if attempt == 1 or not self._is_stale_imap_error(exc): raise - logger.warning("Email IMAP connection went stale, retrying once: {}", exc) + self.logger.warning("IMAP connection went stale, retrying once: {}", exc) return messages @@ -348,11 +348,11 @@ class EmailChannel(BaseChannel): status, _ = client.select(mailbox) except Exception as exc: if self._is_missing_mailbox_error(exc): - logger.warning("Email mailbox unavailable, skipping poll for {}: {}", mailbox, exc) + self.logger.warning("Mailbox unavailable, skipping poll for {}: {}", mailbox, exc) return messages raise if status != "OK": - logger.warning("Email mailbox select returned {}, skipping poll for {}", status, mailbox) + self.logger.warning("Mailbox select returned {}, skipping poll for {}", status, mailbox) return messages status, data = client.search(None, *search_criteria) @@ -382,7 +382,7 @@ class EmailChannel(BaseChannel): if not sender: continue if self._is_self_address(sender): - logger.info("Email from {} ignored: matches bot-owned address", sender) + self.logger.info("From {} ignored: matches bot-owned address", sender) self._remember_processed_uid(uid, dedupe, cycle_uids) if mark_seen: client.store(imap_id, "+FLAGS", "\\Seen") @@ -391,16 +391,16 @@ class EmailChannel(BaseChannel): # --- Anti-spoofing: verify Authentication-Results --- spf_pass, dkim_pass = self._check_authentication_results(parsed) if self.config.verify_spf and not spf_pass: - logger.warning( - "Email from {} rejected: SPF verification failed " + self.logger.warning( + "From {} rejected: SPF verification failed " "(no 'spf=pass' in Authentication-Results header)", sender, ) self._remember_processed_uid(uid, dedupe, cycle_uids) continue if self.config.verify_dkim and not dkim_pass: - logger.warning( - "Email from {} rejected: DKIM verification failed " + self.logger.warning( + "From {} rejected: DKIM verification failed " "(no 'dkim=pass' in Authentication-Results header)", sender, ) @@ -641,7 +641,7 @@ class EmailChannel(BaseChannel): content_type = part.get_content_type() if not any(fnmatch(content_type, pat) for pat in allowed_types): - logger.debug("Email attachment skipped (type {}): not in allowed list", content_type) + logger.debug("Attachment skipped (type {}): not in allowed list", content_type) continue payload = part.get_payload(decode=True) @@ -649,7 +649,7 @@ class EmailChannel(BaseChannel): continue if len(payload) > max_size: logger.warning( - "Email attachment skipped: size {} exceeds limit {}", + "Attachment skipped: size {} exceeds limit {}", len(payload), max_size, ) @@ -662,9 +662,9 @@ class EmailChannel(BaseChannel): try: dest.write_bytes(payload) saved.append(dest) - logger.info("Email attachment saved: {}", dest) + logger.info("Attachment saved: {}", dest) except Exception as exc: - logger.warning("Failed to save email attachment {}: {}", dest, exc) + logger.warning("Failed to save attachment {}: {}", dest, exc) return saved diff --git a/nanobot/channels/feishu.py b/nanobot/channels/feishu.py index 6fe8b9d5f..91022b9af 100644 --- a/nanobot/channels/feishu.py +++ b/nanobot/channels/feishu.py @@ -15,7 +15,6 @@ from typing import Any, Literal from lark_oapi.api.im.v1.model import MentionEvent, P2ImMessageReceiveV1 from lark_oapi.core.const import FEISHU_DOMAIN, LARK_DOMAIN -from loguru import logger from pydantic import Field from nanobot.bus.events import OutboundMessage @@ -23,6 +22,7 @@ from nanobot.bus.queue import MessageBus from nanobot.channels.base import BaseChannel from nanobot.config.paths import get_media_dir from nanobot.config.schema import Base +from nanobot.utils.logging_bridge import redirect_lib_logging FEISHU_AVAILABLE = importlib.util.find_spec("lark_oapi") is not None @@ -320,15 +320,17 @@ class FeishuChannel(BaseChannel): async def start(self) -> None: """Start the Feishu bot with WebSocket long connection.""" if not FEISHU_AVAILABLE: - logger.error("Feishu SDK not installed. Run: pip install lark-oapi") + self.logger.error("SDK not installed. Run: pip install lark-oapi") return if not self.config.app_id or not self.config.app_secret: - logger.error("Feishu app_id and app_secret not configured") + self.logger.error("app_id and app_secret not configured") return import lark_oapi as lark + redirect_lib_logging("Lark") + self._running = True self._loop = asyncio.get_running_loop() @@ -390,7 +392,7 @@ class FeishuChannel(BaseChannel): try: self._ws_client.start() except Exception as e: - logger.warning("Feishu WebSocket error: {}", e) + self.logger.warning("WebSocket error: {}", e) if self._running: time.sleep(5) finally: @@ -404,12 +406,12 @@ class FeishuChannel(BaseChannel): None, self._fetch_bot_open_id ) if self._bot_open_id: - logger.info("Feishu bot open_id: {}", self._bot_open_id) + self.logger.info("bot open_id: {}", self._bot_open_id) else: - logger.warning("Could not fetch bot open_id; @mention matching may be inaccurate") + self.logger.warning("Could not fetch bot open_id; @mention matching may be inaccurate") - logger.info("Feishu bot started with WebSocket long connection") - logger.info("No public IP required - using WebSocket to receive events") + self.logger.info("bot started with WebSocket long connection") + self.logger.info("No public IP required - using WebSocket to receive events") # Keep running until stopped while self._running: @@ -424,7 +426,7 @@ class FeishuChannel(BaseChannel): Reference: https://github.com/larksuite/oapi-sdk-python/blob/v2_main/lark_oapi/ws/client.py#L86 """ self._running = False - logger.info("Feishu bot stopped") + self.logger.info("bot stopped") def _fetch_bot_open_id(self) -> str | None: """Fetch the bot's own open_id via GET /open-apis/bot/v3/info.""" @@ -445,10 +447,10 @@ class FeishuChannel(BaseChannel): data = json.loads(response.raw.content) bot = (data.get("data") or data).get("bot") or data.get("bot") or {} return bot.get("open_id") - logger.warning("Failed to get bot info: code={}, msg={}", response.code, response.msg) + self.logger.warning("Failed to get bot info: code={}, msg={}", response.code, response.msg) return None except Exception as e: - logger.warning("Error fetching bot info: {}", e) + self.logger.warning("Error fetching bot info: {}", e) return None @staticmethod @@ -539,15 +541,15 @@ class FeishuChannel(BaseChannel): response = self._client.im.v1.message_reaction.create(request) if not response.success(): - logger.warning( + self.logger.warning( "Failed to add reaction: code={}, msg={}", response.code, response.msg ) return None else: - logger.debug("Added {} reaction to message {}", emoji_type, message_id) + self.logger.debug("Added {} reaction to message {}", emoji_type, message_id) return response.data.reaction_id if response.data else None except Exception as e: - logger.warning("Error adding reaction: {}", e) + self.logger.warning("Error adding reaction: {}", e) return None async def _add_reaction(self, message_id: str, emoji_type: str = "THUMBSUP") -> str | None: @@ -579,13 +581,13 @@ class FeishuChannel(BaseChannel): response = self._client.im.v1.message_reaction.delete(request) if response.success(): - logger.debug("Removed reaction {} from message {}", reaction_id, message_id) + self.logger.debug("Removed reaction {} from message {}", reaction_id, message_id) else: - logger.debug( + self.logger.debug( "Failed to remove reaction: code={}, msg={}", response.code, response.msg ) except Exception as e: - logger.debug("Error removing reaction: {}", e) + self.logger.debug("Error removing reaction: {}", e) async def _remove_reaction(self, message_id: str, reaction_id: str) -> None: """ @@ -607,7 +609,7 @@ class FeishuChannel(BaseChannel): try: task.result() except Exception as exc: - logger.warning("Background task failed: {}", exc) + self.logger.warning("Background task failed: {}", exc) def _on_reaction_added(self, message_id: str, task: asyncio.Task) -> None: """Callback: store reaction_id after background add-reaction completes.""" @@ -917,15 +919,15 @@ class FeishuChannel(BaseChannel): response = self._client.im.v1.image.create(request) if response.success(): image_key = response.data.image_key - logger.debug("Uploaded image {}: {}", os.path.basename(file_path), image_key) + self.logger.debug("Uploaded image {}: {}", os.path.basename(file_path), image_key) return image_key else: - logger.error( + self.logger.error( "Failed to upload image: code={}, msg={}", response.code, response.msg ) return None - except Exception as e: - logger.error("Error uploading image {}: {}", file_path, e) + except Exception: + self.logger.exception("Error uploading image {}", file_path) return None def _upload_file_sync(self, file_path: str) -> str | None: @@ -951,15 +953,15 @@ class FeishuChannel(BaseChannel): response = self._client.im.v1.file.create(request) if response.success(): file_key = response.data.file_key - logger.debug("Uploaded file {}: {}", file_name, file_key) + self.logger.debug("Uploaded file {}: {}", file_name, file_key) return file_key else: - logger.error( + self.logger.error( "Failed to upload file: code={}, msg={}", response.code, response.msg ) return None - except Exception as e: - logger.error("Error uploading file {}: {}", file_path, e) + except Exception: + self.logger.exception("Error uploading file {}", file_path) return None def _download_image_sync( @@ -984,12 +986,12 @@ class FeishuChannel(BaseChannel): file_data = file_data.read() return file_data, response.file_name else: - logger.error( + self.logger.error( "Failed to download image: code={}, msg={}", response.code, response.msg ) return None, None - except Exception as e: - logger.error("Error downloading image {}: {}", image_key, e) + except Exception: + self.logger.exception("Error downloading image {}", image_key) return None, None def _download_file_sync( @@ -1018,7 +1020,7 @@ class FeishuChannel(BaseChannel): file_data = file_data.read() return file_data, response.file_name else: - logger.error( + self.logger.error( "Failed to download {}: code={}, msg={}", resource_type, response.code, @@ -1026,7 +1028,7 @@ class FeishuChannel(BaseChannel): ) return None, None except Exception: - logger.exception("Error downloading {} {}", resource_type, file_key) + self.logger.exception("Error downloading {} {}", resource_type, file_key) return None, None async def _download_and_save_media( @@ -1055,10 +1057,10 @@ class FeishuChannel(BaseChannel): elif msg_type in ("audio", "file", "media"): file_key = content_json.get("file_key") if not file_key: - logger.warning("Feishu {} message missing file_key: {}", msg_type, content_json) + self.logger.warning("{} message missing file_key: {}", msg_type, content_json) return None, f"[{msg_type}: missing file_key]" if not message_id: - logger.warning("Feishu {} message missing message_id", msg_type) + self.logger.warning("{} message missing message_id", msg_type) return None, f"[{msg_type}: missing message_id]" data, filename = await loop.run_in_executor( @@ -1066,7 +1068,7 @@ class FeishuChannel(BaseChannel): ) if not data: - logger.warning("Feishu {} download failed: file_key={}", msg_type, file_key) + self.logger.warning("{} download failed: file_key={}", msg_type, file_key) return None, f"[{msg_type}: download failed]" if not filename: @@ -1082,7 +1084,7 @@ class FeishuChannel(BaseChannel): file_path = media_dir / filename file_path.write_bytes(data) path_str = str(file_path) - logger.debug("Downloaded {} to {}", msg_type, path_str) + self.logger.debug("Downloaded {} to {}", msg_type, path_str) return path_str, f"[{msg_type}: {path_str}]" return None, f"[{msg_type}: download failed]" @@ -1100,8 +1102,8 @@ class FeishuChannel(BaseChannel): request = GetMessageRequest.builder().message_id(message_id).build() response = self._client.im.v1.message.get(request) if not response.success(): - logger.debug( - "Feishu: could not fetch parent message {}: code={}, msg={}", + self.logger.debug( + "could not fetch parent message {}: code={}, msg={}", message_id, response.code, response.msg, @@ -1133,7 +1135,7 @@ class FeishuChannel(BaseChannel): text = text[: self._REPLY_CONTEXT_MAX_LEN] + "..." return f"[Reply to: {text}]" except Exception as e: - logger.debug("Feishu: error fetching parent message {}: {}", message_id, e) + self.logger.debug("error fetching parent message {}: {}", message_id, e) return None def _reply_message_sync(self, parent_message_id: str, msg_type: str, content: str, *, reply_in_thread: bool = False) -> bool: @@ -1157,18 +1159,18 @@ class FeishuChannel(BaseChannel): ) response = self._client.im.v1.message.reply(request) if not response.success(): - logger.error( - "Failed to reply to Feishu message {}: code={}, msg={}, log_id={}", + self.logger.error( + "Failed to reply to message {}: code={}, msg={}, log_id={}", parent_message_id, response.code, response.msg, response.get_log_id(), ) return False - logger.debug("Feishu reply sent to message {}", parent_message_id) + self.logger.debug("reply sent to message {}", parent_message_id) return True - except Exception as e: - logger.error("Error replying to Feishu message {}: {}", parent_message_id, e) + except Exception: + self.logger.exception("Error replying to message {}", parent_message_id) return False def _should_use_reply_in_thread(self, metadata: dict[str, Any]) -> bool: @@ -1207,8 +1209,8 @@ class FeishuChannel(BaseChannel): ) response = self._client.im.v1.message.create(request) if not response.success(): - logger.error( - "Failed to send Feishu {} message: code={}, msg={}, log_id={}", + self.logger.error( + "Failed to send {} message: code={}, msg={}, log_id={}", msg_type, response.code, response.msg, @@ -1216,10 +1218,10 @@ class FeishuChannel(BaseChannel): ) return None msg_id = getattr(response.data, "message_id", None) - logger.debug("Feishu {} message sent to {}: {}", msg_type, receive_id, msg_id) + self.logger.debug("{} message sent to {}: {}", msg_type, receive_id, msg_id) return msg_id - except Exception as e: - logger.error("Error sending Feishu {} message: {}", msg_type, e) + except Exception: + self.logger.exception("Error sending {} message", msg_type) return None def _create_streaming_card_sync( @@ -1259,7 +1261,7 @@ class FeishuChannel(BaseChannel): ) response = self._client.cardkit.v1.card.create(request) if not response.success(): - logger.warning( + self.logger.warning( "Failed to create streaming card: code={}, msg={}", response.code, response.msg ) return None @@ -1279,12 +1281,12 @@ class FeishuChannel(BaseChannel): ) is not None if sent: return card_id - logger.warning( + self.logger.warning( "Created streaming card {} but failed to send it to {}", card_id, chat_id ) return None except Exception as e: - logger.warning("Error creating streaming card: {}", e) + self.logger.warning("Error creating streaming card: {}", e) return None def _stream_update_text_sync(self, card_id: str, content: str, sequence: int) -> bool: @@ -1309,7 +1311,7 @@ class FeishuChannel(BaseChannel): ) response = self._client.cardkit.v1.card_element.content(request) if not response.success(): - logger.warning( + self.logger.warning( "Failed to stream-update card {}: code={}, msg={}", card_id, response.code, @@ -1318,7 +1320,7 @@ class FeishuChannel(BaseChannel): return False return True except Exception as e: - logger.warning("Error stream-updating card {}: {}", card_id, e) + self.logger.warning("Error stream-updating card {}: {}", card_id, e) return False def _close_streaming_mode_sync(self, card_id: str, sequence: int) -> bool: @@ -1346,7 +1348,7 @@ class FeishuChannel(BaseChannel): ) response = self._client.cardkit.v1.card.settings(request) if not response.success(): - logger.warning( + self.logger.warning( "Failed to close streaming on card {}: code={}, msg={}", card_id, response.code, @@ -1355,7 +1357,7 @@ class FeishuChannel(BaseChannel): return False return True except Exception as e: - logger.warning("Error closing streaming on card {}: {}", card_id, e) + self.logger.warning("Error closing streaming on card {}: {}", card_id, e) return False async def send_delta( @@ -1416,7 +1418,7 @@ class FeishuChannel(BaseChannel): buf.sequence, ) return - logger.warning( + self.logger.warning( "Streaming card {} final update failed, falling back to regular card", buf.card_id, ) @@ -1484,7 +1486,7 @@ class FeishuChannel(BaseChannel): async def send(self, msg: OutboundMessage) -> None: """Send a message through Feishu, including media (images/files) if present.""" if not self._client: - logger.warning("Feishu client not initialized") + self.logger.warning("client not initialized") return try: @@ -1566,7 +1568,7 @@ class FeishuChannel(BaseChannel): for file_path in msg.media: if not os.path.isfile(file_path): - logger.warning("Media file not found: {}", file_path) + self.logger.warning("Media file not found: {}", file_path) continue ext = os.path.splitext(file_path)[1].lower() if ext in self._IMAGE_EXTS: @@ -1622,8 +1624,8 @@ class FeishuChannel(BaseChannel): json.dumps(card, ensure_ascii=False), ) - except Exception as e: - logger.error("Error sending Feishu message: {}", e) + except Exception: + self.logger.exception("Error sending message") raise def _on_message_sync(self, data: Any) -> None: @@ -1641,8 +1643,8 @@ class FeishuChannel(BaseChannel): message = event.message sender = event.sender - logger.debug("Feishu raw message: {}", message.content) - logger.debug("Feishu mentions: {}", getattr(message, "mentions", None)) + self.logger.debug("raw message: {}", message.content) + self.logger.debug("mentions: {}", getattr(message, "mentions", None)) message_id = message.message_id @@ -1659,7 +1661,7 @@ class FeishuChannel(BaseChannel): return if chat_type == "group" and not self._is_group_message_for_bot(message): - logger.debug("Feishu: skipping group message (not mentioned)") + self.logger.debug("skipping group message (not mentioned)") return # Deduplication check @@ -1784,8 +1786,8 @@ class FeishuChannel(BaseChannel): session_key=session_key, ) - except Exception as e: - logger.error("Error processing Feishu message: {}", e) + except Exception: + self.logger.exception("Error processing message") def _on_reaction_created(self, data: Any) -> None: """Ignore reaction events so they do not generate SDK noise.""" @@ -1801,7 +1803,7 @@ class FeishuChannel(BaseChannel): def _on_bot_p2p_chat_entered(self, data: Any) -> None: """Ignore p2p-enter events when a user opens a bot chat.""" - logger.debug("Bot entered p2p chat (user opened chat window)") + self.logger.debug("Bot entered p2p chat (user opened chat window)") pass @staticmethod diff --git a/nanobot/channels/manager.py b/nanobot/channels/manager.py index 95806008a..783aac966 100644 --- a/nanobot/channels/manager.py +++ b/nanobot/channels/manager.py @@ -174,8 +174,8 @@ class ChannelManager: """Start a channel and log any exceptions.""" try: await channel.start() - except Exception as e: - logger.error("Failed to start channel {}: {}", name, e) + except Exception: + logger.exception("Failed to start channel {}", name) async def start_all(self) -> None: """Start all channels and the outbound dispatcher.""" @@ -230,8 +230,8 @@ class ChannelManager: try: await channel.stop() logger.info("Stopped {} channel", name) - except Exception as e: - logger.error("Error stopping {}: {}", name, e) + except Exception: + logger.exception("Error stopping {}", name) @staticmethod def _fingerprint_content(content: str) -> str: @@ -392,9 +392,9 @@ class ChannelManager: raise # Propagate cancellation for graceful shutdown except Exception as e: if attempt == max_attempts - 1: - logger.error( - "Failed to send to {} after {} attempts: {} - {}", - msg.channel, max_attempts, type(e).__name__, e + logger.exception( + "Failed to send to {} after {} attempts", + msg.channel, max_attempts ) return delay = _SEND_RETRY_DELAYS[min(attempt, len(_SEND_RETRY_DELAYS) - 1)] diff --git a/nanobot/channels/matrix.py b/nanobot/channels/matrix.py index 0d1989b03..6919be874 100644 --- a/nanobot/channels/matrix.py +++ b/nanobot/channels/matrix.py @@ -2,7 +2,6 @@ import asyncio import json -import logging import mimetypes import time from contextlib import suppress @@ -10,7 +9,6 @@ from dataclasses import dataclass from pathlib import Path from typing import Any, Literal, TypeAlias -from loguru import logger from pydantic import Field try: @@ -47,6 +45,7 @@ from nanobot.channels.base import BaseChannel from nanobot.config.paths import get_data_dir, get_media_dir from nanobot.config.schema import Base from nanobot.utils.helpers import safe_filename +from nanobot.utils.logging_bridge import redirect_lib_logging TYPING_NOTICE_TIMEOUT_MS = 30_000 # Must stay below TYPING_NOTICE_TIMEOUT_MS so the indicator doesn't expire mid-processing. @@ -178,28 +177,6 @@ def _build_matrix_text_content( return content -class _NioLoguruHandler(logging.Handler): - """Route matrix-nio stdlib logs into Loguru.""" - - def emit(self, record: logging.LogRecord) -> None: - try: - level = logger.level(record.levelname).name - except ValueError: - level = record.levelno - frame, depth = logging.currentframe(), 2 - while frame and frame.f_code.co_filename == logging.__file__: - frame, depth = frame.f_back, depth + 1 - logger.opt(depth=depth, exception=record.exc_info).log(level, record.getMessage()) - - -def _configure_nio_logging_bridge() -> None: - """Bridge matrix-nio logs to Loguru (idempotent).""" - nio_logger = logging.getLogger("nio") - if not any(isinstance(h, _NioLoguruHandler) for h in nio_logger.handlers): - nio_logger.handlers = [_NioLoguruHandler()] - nio_logger.propagate = False - - class MatrixConfig(Base): """Matrix (Element) channel configuration.""" @@ -259,7 +236,7 @@ class MatrixChannel(BaseChannel): """Start Matrix client and begin sync loop.""" self._running = True self._started_at_ms = int(time.time() * 1000) - _configure_nio_logging_bridge() + redirect_lib_logging("nio", level="WARNING") self.store_path = get_data_dir() / "matrix-store" self.store_path.mkdir(parents=True, exist_ok=True) @@ -283,15 +260,15 @@ class MatrixChannel(BaseChannel): self._register_response_callbacks() if not self.config.e2ee_enabled: - logger.warning("Matrix E2EE disabled; encrypted rooms may be undecryptable.") + self.logger.warning("E2EE disabled; encrypted rooms may be undecryptable.") if self.config.password: if self.config.access_token or self.config.device_id: - logger.warning("Password-based Matrix login active; access_token and device_id fields will be ignored.") + self.logger.warning("Password-based login active; access_token and device_id fields will be ignored.") create_new_session = True if self.session_path.exists(): - logger.info("Found session.json at {}; attempting to use existing session...", self.session_path) + self.logger.info("Found session.json at {}; attempting to use existing session...", self.session_path) try: with open(self.session_path, "r", encoding="utf-8") as f: session = json.load(f) @@ -299,20 +276,20 @@ class MatrixChannel(BaseChannel): self.client.access_token = session["access_token"] self.client.device_id = session["device_id"] self.client.load_store() - logger.info("Successfully loaded from existing session") + self.logger.info("Successfully loaded from existing session") create_new_session = False except Exception as e: - logger.warning("Failed to load from existing session: {}", e) - logger.info("Falling back to password login...") + self.logger.warning("Failed to load from existing session: {}", e) + self.logger.info("Falling back to password login...") if create_new_session: - logger.info("Using password login...") + self.logger.info("Using password login...") resp = await self.client.login(self.config.password) if isinstance(resp, LoginResponse): - logger.info("Logged in using a password; saving details to disk") + self.logger.info("Logged in using a password; saving details to disk") self._write_session_to_disk(resp) else: - logger.error("Failed to log in: {}", resp) + self.logger.error("Failed to log in: {}", resp) return elif self.config.access_token and self.config.device_id: @@ -321,12 +298,12 @@ class MatrixChannel(BaseChannel): self.client.access_token = self.config.access_token self.client.device_id = self.config.device_id self.client.load_store() - logger.info("Successfully loaded from existing session") + self.logger.info("Successfully loaded from existing session") except Exception as e: - logger.warning("Failed to load from existing session: {}", e) + self.logger.warning("Failed to load from existing session: {}", e) else: - logger.warning("Unable to load a Matrix session due to missing password, access_token, or device_id; encryption may not work") + self.logger.warning("Unable to load a session due to missing password, access_token, or device_id; encryption may not work") return self._sync_task = asyncio.create_task(self._sync_loop()) @@ -358,9 +335,9 @@ class MatrixChannel(BaseChannel): try: with open(self.session_path, "w", encoding="utf-8") as f: json.dump(session, f, indent=2) - logger.info("Session saved to {}", self.session_path) + self.logger.info("Session saved to {}", self.session_path) except Exception as e: - logger.warning("Failed to save session: {}", e) + self.logger.warning("Failed to save session: {}", e) def _is_workspace_path_allowed(self, path: Path) -> bool: """Check path is inside workspace (when restriction enabled).""" @@ -598,14 +575,14 @@ class MatrixChannel(BaseChannel): def _log_response_error(self, label: str, response: Any) -> None: """Log Matrix response errors — auth errors at ERROR level, rest at WARNING.""" is_fatal = self._is_fatal_auth_response(response) - (logger.error if is_fatal else logger.warning)("Matrix {} failed: {}", label, response) + (self.logger.error if is_fatal else self.logger.warning)("{} failed: {}", label, response) async def _on_sync_error(self, response: SyncError) -> None: self._log_response_error("sync", response) if self._is_fatal_auth_response(response): # Auth errors won't recover by retry; stop the sync loop instead of # spamming the homeserver every 2s (#1851). - logger.error("Matrix authentication failed irrecoverably; stopping sync loop") + self.logger.error("Authentication failed irrecoverably; stopping sync loop") self._running = False if self.client: with suppress(Exception): @@ -625,7 +602,7 @@ class MatrixChannel(BaseChannel): response = await self.client.room_typing(room_id=room_id, typing_state=typing, timeout=TYPING_NOTICE_TIMEOUT_MS) if isinstance(response, RoomTypingError): - logger.debug("Matrix typing failed for {}: {}", room_id, response) + self.logger.debug("typing failed for {}: {}", room_id, response) async def _start_typing_keepalive(self, room_id: str) -> None: """Start periodic typing refresh (spec-recommended keepalive).""" @@ -796,7 +773,7 @@ class MatrixChannel(BaseChannel): return None response = await self.client.download(mxc=mxc_url) if isinstance(response, DownloadError): - logger.warning("Matrix download failed for {}: {}", mxc_url, response) + self.logger.warning("download failed for {}: {}", mxc_url, response) return None body = getattr(response, "body", None) if isinstance(body, (bytes, bytearray)): @@ -821,7 +798,7 @@ class MatrixChannel(BaseChannel): try: return decrypt_attachment(ciphertext, key, sha256, iv) except (EncryptionError, ValueError, TypeError): - logger.warning("Matrix decrypt failed for event {}", getattr(event, "event_id", "")) + self.logger.warning("decrypt failed for event {}", getattr(event, "event_id", "")) return None async def _fetch_media_attachment( diff --git a/nanobot/channels/mochat.py b/nanobot/channels/mochat.py index 110b454cc..dfe225640 100644 --- a/nanobot/channels/mochat.py +++ b/nanobot/channels/mochat.py @@ -11,7 +11,6 @@ from datetime import datetime from typing import Any import httpx -from loguru import logger from nanobot.bus.events import OutboundMessage from nanobot.bus.queue import MessageBus @@ -303,7 +302,7 @@ class MochatChannel(BaseChannel): async def start(self) -> None: """Start Mochat channel workers and websocket connection.""" if not self.config.claw_token: - logger.error("Mochat claw_token not configured") + self.logger.error("claw_token not configured") return self._running = True @@ -348,7 +347,7 @@ class MochatChannel(BaseChannel): async def send(self, msg: OutboundMessage) -> None: """Send outbound message to session or panel.""" if not self.config.claw_token: - logger.warning("Mochat claw_token missing, skip send") + self.logger.warning("claw_token missing, skip send") return parts = ([msg.content.strip()] if msg.content and msg.content.strip() else []) @@ -360,7 +359,7 @@ class MochatChannel(BaseChannel): target = resolve_mochat_target(msg.chat_id) if not target.id: - logger.warning("Mochat outbound target is empty") + self.logger.warning("outbound target is empty") return is_panel = (target.is_panel or target.id in self._panel_set) and not target.id.startswith("session_") @@ -371,8 +370,8 @@ class MochatChannel(BaseChannel): else: await self._api_send("/api/claw/sessions/send", "sessionId", target.id, content, msg.reply_to) - except Exception as e: - logger.error("Failed to send Mochat message: {}", e) + except Exception: + self.logger.exception("Failed to send message") raise # ---- config / init helpers --------------------------------------------- @@ -395,7 +394,7 @@ class MochatChannel(BaseChannel): async def _start_socket_client(self) -> bool: if not SOCKETIO_AVAILABLE: - logger.warning("python-socketio not installed, Mochat using polling fallback") + self.logger.warning("python-socketio not installed, using polling fallback") return False serializer = "default" @@ -403,7 +402,7 @@ class MochatChannel(BaseChannel): if MSGPACK_AVAILABLE: serializer = "msgpack" else: - logger.warning("msgpack not installed but socket_disable_msgpack=false; using JSON") + self.logger.warning("msgpack not installed but socket_disable_msgpack=false; using JSON") client = socketio.AsyncClient( reconnection=True, @@ -416,7 +415,7 @@ class MochatChannel(BaseChannel): @client.event async def connect() -> None: self._ws_connected, self._ws_ready = True, False - logger.info("Mochat websocket connected") + self.logger.info("websocket connected") subscribed = await self._subscribe_all() self._ws_ready = subscribed await (self._stop_fallback_workers() if subscribed else self._ensure_fallback_workers()) @@ -426,12 +425,12 @@ class MochatChannel(BaseChannel): if not self._running: return self._ws_connected = self._ws_ready = False - logger.warning("Mochat websocket disconnected") + self.logger.warning("websocket disconnected") await self._ensure_fallback_workers() @client.event async def connect_error(data: Any) -> None: - logger.error("Mochat websocket connect error: {}", data) + self.logger.error("websocket connect error: {}", data) @client.on("claw.session.events") async def on_session_events(payload: dict[str, Any]) -> None: @@ -457,8 +456,8 @@ class MochatChannel(BaseChannel): wait_timeout=max(1.0, self.config.socket_connect_timeout_ms / 1000.0), ) return True - except Exception as e: - logger.error("Failed to connect Mochat websocket: {}", e) + except Exception: + self.logger.exception("Failed to connect websocket") with suppress(Exception): await client.disconnect() self._socket = None @@ -493,7 +492,7 @@ class MochatChannel(BaseChannel): "limit": self.config.watch_limit, }) if not ack.get("result"): - logger.error("Mochat subscribeSessions failed: {}", ack.get('message', 'unknown error')) + self.logger.error("subscribeSessions failed: {}", ack.get('message', 'unknown error')) return False data = ack.get("data") @@ -515,7 +514,7 @@ class MochatChannel(BaseChannel): return True ack = await self._socket_call("com.claw.im.subscribePanels", {"panelIds": panel_ids}) if not ack.get("result"): - logger.error("Mochat subscribePanels failed: {}", ack.get('message', 'unknown error')) + self.logger.error("subscribePanels failed: {}", ack.get('message', 'unknown error')) return False return True @@ -537,7 +536,7 @@ class MochatChannel(BaseChannel): try: await self._refresh_targets(subscribe_new=self._ws_ready) except Exception as e: - logger.warning("Mochat refresh failed: {}", e) + self.logger.warning("refresh failed: {}", e) if self._fallback_mode: await self._ensure_fallback_workers() @@ -551,7 +550,7 @@ class MochatChannel(BaseChannel): try: response = await self._post_json("/api/claw/sessions/list", {}) except Exception as e: - logger.warning("Mochat listSessions failed: {}", e) + self.logger.warning("listSessions failed: {}", e) return sessions = response.get("sessions") @@ -585,7 +584,7 @@ class MochatChannel(BaseChannel): try: response = await self._post_json("/api/claw/groups/get", {}) except Exception as e: - logger.warning("Mochat getWorkspaceGroup failed: {}", e) + self.logger.warning("getWorkspaceGroup failed: {}", e) return raw_panels = response.get("panels") @@ -647,7 +646,7 @@ class MochatChannel(BaseChannel): except asyncio.CancelledError: break except Exception as e: - logger.warning("Mochat watch fallback error ({}): {}", session_id, e) + self.logger.warning("watch fallback error ({}): {}", session_id, e) await asyncio.sleep(max(0.1, self.config.retry_delay_ms / 1000.0)) async def _panel_poll_worker(self, panel_id: str) -> None: @@ -674,7 +673,7 @@ class MochatChannel(BaseChannel): except asyncio.CancelledError: break except Exception as e: - logger.warning("Mochat panel polling error ({}): {}", panel_id, e) + self.logger.warning("panel polling error ({}): {}", panel_id, e) await asyncio.sleep(sleep_s) # ---- inbound event processing ------------------------------------------ @@ -885,7 +884,7 @@ class MochatChannel(BaseChannel): try: data = json.loads(self._cursor_path.read_text("utf-8")) except Exception as e: - logger.warning("Failed to read Mochat cursor file: {}", e) + self.logger.warning("Failed to read cursor file: {}", e) return cursors = data.get("cursors") if isinstance(data, dict) else None if isinstance(cursors, dict): @@ -901,7 +900,7 @@ class MochatChannel(BaseChannel): "cursors": self._session_cursor, }, ensure_ascii=False, indent=2) + "\n", "utf-8") except Exception as e: - logger.warning("Failed to save Mochat cursor file: {}", e) + self.logger.warning("Failed to save cursor file: {}", e) # ---- HTTP helpers ------------------------------------------------------ diff --git a/nanobot/channels/msteams.py b/nanobot/channels/msteams.py index f30b1af61..cdb0ae904 100644 --- a/nanobot/channels/msteams.py +++ b/nanobot/channels/msteams.py @@ -32,7 +32,6 @@ except ImportError: # pragma: no cover fcntl = None import httpx -from loguru import logger from pydantic import Field from nanobot.bus.events import OutboundMessage @@ -134,16 +133,16 @@ class MSTeamsChannel(BaseChannel): async def start(self) -> None: """Start the Teams webhook listener.""" if not MSTEAMS_AVAILABLE: - logger.error("PyJWT not installed. Run: pip install nanobot-ai[msteams]") + self.logger.error("PyJWT not installed. Run: pip install nanobot-ai[msteams]") return if not self.config.app_id or not self.config.app_password: - logger.error("MSTeams app_id/app_password not configured") + self.logger.error("app_id/app_password not configured") return if not self.config.validate_inbound_auth: - logger.warning( - "MSTeams inbound auth validation was explicitly DISABLED in config. " + self.logger.warning( + "Inbound auth validation was explicitly DISABLED in config. " "Anyone who knows the webhook URL can send messages as any user. " "Only disable this for local development or controlled testing." ) @@ -166,7 +165,7 @@ class MSTeamsChannel(BaseChannel): raw = self.rfile.read(length) if length > 0 else b"{}" payload = json.loads(raw.decode("utf-8")) except Exception as e: - logger.warning("MSTeams invalid request body: {}", e) + channel.logger.warning("Invalid request body: {}", e) self.send_response(400) self.end_headers() return @@ -180,7 +179,7 @@ class MSTeamsChannel(BaseChannel): ) fut.result(timeout=15) except Exception as e: - logger.warning("MSTeams inbound auth validation failed: {}", e) + channel.logger.warning("Inbound auth validation failed: {}", e) self.send_response(401) self.send_header("Content-Type", "application/json") self.end_headers() @@ -193,7 +192,7 @@ class MSTeamsChannel(BaseChannel): ) fut.result(timeout=15) except Exception as e: - logger.warning("MSTeams activity handling failed: {}", e) + channel.logger.warning("Activity handling failed: {}", e) self.send_response(200) self.send_header("Content-Type", "application/json") @@ -211,8 +210,8 @@ class MSTeamsChannel(BaseChannel): ) self._server_thread.start() - logger.info( - "MSTeams webhook listening on http://{}:{}{}", + self.logger.info( + "Webhook listening on http://{}:{}{}", self.config.host, self.config.port, self.config.path, @@ -261,10 +260,10 @@ class MSTeamsChannel(BaseChannel): try: resp = await self._http.post(base_url, headers=headers, json=payload) resp.raise_for_status() - logger.info("MSTeams message sent to {}", ref.conversation_id) + self.logger.info("Message sent to {}", ref.conversation_id) self._touch_conversation_ref(str(msg.chat_id), persist=True) - except Exception as e: - logger.error("MSTeams send failed: {}", e) + except Exception: + self.logger.exception("Send failed") raise async def _handle_activity(self, activity: dict[str, Any]) -> None: @@ -291,18 +290,18 @@ class MSTeamsChannel(BaseChannel): # DM-only MVP: ignore group/channel traffic for now if conversation_type and conversation_type not in ("personal", ""): - logger.debug("MSTeams ignoring non-DM conversation {}", conversation_type) + self.logger.debug("Ignoring non-DM conversation {}", conversation_type) return text = self._sanitize_inbound_text(activity) if not text: text = self.config.mention_only_response.strip() if not text: - logger.debug("MSTeams ignoring empty message after Teams text sanitization") + self.logger.debug("Ignoring empty message after Teams text sanitization") return if not self.is_allowed(sender_id): - logger.warning( + self.logger.warning( "Access denied for sender {} on channel {}. " "Add them to allowFrom list in config to grant access.", sender_id, self.name, @@ -554,7 +553,7 @@ class MSTeamsChannel(BaseChannel): if isinstance(loaded, dict): main_data = loaded except Exception as e: - logger.warning("Failed to load MSTeams conversation refs: {}", e) + self.logger.warning("Failed to load conversation refs: {}", e) if meta_exists: try: @@ -562,7 +561,7 @@ class MSTeamsChannel(BaseChannel): if isinstance(loaded_meta, dict): meta_data = loaded_meta except Exception as e: - logger.warning("Failed to load MSTeams conversation refs metadata: {}", e) + self.logger.warning("Failed to load conversation refs metadata: {}", e) return main_data, meta_data, meta_exists @@ -660,8 +659,8 @@ class MSTeamsChannel(BaseChannel): for key in keys_to_drop: self._conversation_refs.pop(key, None) - logger.info( - "MSTeams pruned {} stale/unsupported conversation refs (ttl={} days)", + self.logger.info( + "Pruned {} stale/unsupported conversation refs (ttl={} days)", len(keys_to_drop), ttl_days, ) @@ -742,7 +741,7 @@ class MSTeamsChannel(BaseChannel): self._write_json_atomically(self._refs_path, refs_data) self._write_json_atomically(self._refs_meta_path, refs_meta) except Exception as e: - logger.warning("Failed to save MSTeams conversation refs: {}", e) + self.logger.warning("Failed to save conversation refs: {}", e) def _save_refs(self, *, prune: bool = True) -> None: """Persist conversation references.""" diff --git a/nanobot/channels/qq.py b/nanobot/channels/qq.py index ef70cc943..4ef63238c 100644 --- a/nanobot/channels/qq.py +++ b/nanobot/channels/qq.py @@ -38,7 +38,7 @@ from nanobot.bus.events import OutboundMessage from nanobot.bus.queue import MessageBus from nanobot.channels.base import BaseChannel from nanobot.config.schema import Base -from nanobot.security.network import validate_url_target +from nanobot.utils.logging_bridge import redirect_lib_logging try: from nanobot.config.paths import get_media_dir @@ -187,24 +187,25 @@ class QQChannel(BaseChannel): root = Path.home() / ".nanobot" / "media" / "qq" root.mkdir(parents=True, exist_ok=True) - logger.info("QQ media directory: {}", str(root)) + self.logger.info("media directory: {}", str(root)) return root async def start(self) -> None: """Start the QQ bot with auto-reconnect loop.""" + redirect_lib_logging("botpy", level="WARNING") if not QQ_AVAILABLE: - logger.error("QQ SDK not installed. Run: pip install qq-botpy") + self.logger.error("SDK not installed. Run: pip install qq-botpy") return if not self.config.app_id or not self.config.secret: - logger.error("QQ app_id and secret not configured") + self.logger.error("app_id and secret not configured") return self._running = True self._http = aiohttp.ClientSession(timeout=aiohttp.ClientTimeout(total=120)) self._client = _make_bot_class(self)() - logger.info("QQ bot started (C2C & Group supported)") + self.logger.info("bot started (C2C & Group supported)") await self._run_bot() async def _run_bot(self) -> None: @@ -213,9 +214,9 @@ class QQChannel(BaseChannel): try: await self._client.start(appid=self.config.app_id, secret=self.config.secret) except Exception as e: - logger.warning("QQ bot error: {}", e) + self.logger.warning("bot error: {}", e) if self._running: - logger.info("Reconnecting QQ bot in 5 seconds...") + self.logger.info("Reconnecting bot in 5 seconds...") await asyncio.sleep(5) async def stop(self) -> None: @@ -231,7 +232,7 @@ class QQChannel(BaseChannel): await self._http.close() self._http = None - logger.info("QQ bot stopped") + self.logger.info("bot stopped") # --------------------------- # Outbound (send) @@ -241,7 +242,7 @@ class QQChannel(BaseChannel): """Send attachments first, then text.""" try: if not self._client: - logger.warning("QQ client not initialized") + self.logger.warning("client not initialized") return msg_id = msg.metadata.get("message_id") @@ -281,7 +282,7 @@ class QQChannel(BaseChannel): # Network / transport errors — propagate so ChannelManager can retry raise except Exception: - logger.exception("Error sending QQ message to chat_id={}", msg.chat_id) + self.logger.exception("Error sending message to chat_id={}", msg.chat_id) async def _send_text_only( self, @@ -339,7 +340,7 @@ class QQChannel(BaseChannel): srv_send_msg=False, ) if not media_obj: - logger.error("QQ media upload failed: empty response") + self.logger.error("media upload failed: empty response") return False self._msg_seq += 1 @@ -360,15 +361,15 @@ class QQChannel(BaseChannel): media=media_obj, ) - logger.info("QQ media sent: {}", filename) + self.logger.info("media sent: {}", filename) return True except (aiohttp.ClientError, OSError) as e: # Network / transport errors — propagate for retry by caller - logger.warning("QQ send media network error filename={} err={}", filename, e) + self.logger.warning("send media network error filename={} err={}", filename, e) raise - except Exception as e: + except Exception: # API-level or other non-network errors — return False so send() can fallback - logger.error("QQ send media failed filename={} err={}", filename, e) + self.logger.exception("send media failed filename={}", filename) return False async def _read_media_bytes(self, media_ref: str) -> tuple[bytes | None, str | None]: @@ -389,19 +390,19 @@ class QQChannel(BaseChannel): local_path = Path(os.path.expanduser(media_ref)) if not local_path.is_file(): - logger.warning("QQ outbound media file not found: {}", str(local_path)) + self.logger.warning("outbound media file not found: {}", str(local_path)) return None, None data = await asyncio.to_thread(local_path.read_bytes) return data, local_path.name except Exception as e: - logger.warning("QQ outbound media read error ref={} err={}", media_ref, e) + self.logger.warning("outbound media read error ref={} err={}", media_ref, e) return None, None # Remote URL ok, err = validate_url_target(media_ref) if not ok: - logger.warning("QQ outbound media URL validation failed url={} err={}", media_ref, err) + self.logger.warning("outbound media URL validation failed url={} err={}", media_ref, err) return None, None if not self._http: @@ -409,8 +410,8 @@ class QQChannel(BaseChannel): try: async with self._http.get(media_ref, allow_redirects=True) as resp: if resp.status >= 400: - logger.warning( - "QQ outbound media download failed status={} url={}", + self.logger.warning( + "outbound media download failed status={} url={}", resp.status, media_ref, ) @@ -421,7 +422,7 @@ class QQChannel(BaseChannel): filename = os.path.basename(urlparse(media_ref).path) or "file.bin" return data, filename except Exception as e: - logger.warning("QQ outbound media download error url={} err={}", media_ref, e) + self.logger.warning("outbound media download error url={} err={}", media_ref, e) return None, None # https://github.com/tencent-connect/botpy/issues/198 @@ -525,7 +526,7 @@ class QQChannel(BaseChannel): content=self.config.ack_message, ) except Exception: - logger.debug("QQ ack message failed for chat_id={}", chat_id) + self.logger.debug("ack message failed for chat_id={}", chat_id) await self._handle_message( sender_id=user_id, @@ -538,7 +539,7 @@ class QQChannel(BaseChannel): }, ) except Exception: - logger.exception("Error handling QQ inbound message id={}", getattr(data, "id", "?")) + self.logger.exception("Error handling inbound message id={}", getattr(data, "id", "?")) async def _handle_attachments( self, @@ -557,7 +558,7 @@ class QQChannel(BaseChannel): filename = getattr(att, "filename", None) or "" ctype = getattr(att, "content_type", None) or "" - logger.info("Downloading file from QQ: {}", filename or url) + self.logger.info("Downloading file: {}", filename or url) local_path = await self._download_to_media_dir_chunked(url, filename_hint=filename) att_meta.append( @@ -608,7 +609,7 @@ class QQChannel(BaseChannel): allow_redirects=True, ) as resp: if resp.status != 200: - logger.warning("QQ download failed: status={} url={}", resp.status, url) + self.logger.warning("download failed: status={} url={}", resp.status, url) return None ctype = (resp.headers.get("Content-Type") or "").lower() @@ -662,8 +663,8 @@ class QQChannel(BaseChannel): continue downloaded += len(chunk) if downloaded > max_bytes: - logger.warning( - "QQ download exceeded max_bytes={} url={} -> abort", + self.logger.warning( + "download exceeded max_bytes={} url={} -> abort", max_bytes, url, ) @@ -675,11 +676,11 @@ class QQChannel(BaseChannel): # Atomic rename await asyncio.to_thread(os.replace, tmp_path, target) tmp_path = None # mark as moved - logger.info("QQ file saved: {}", str(target)) + self.logger.info("file saved: {}", str(target)) return str(target) - except Exception as e: - logger.error("QQ download error: {}", e) + except Exception: + self.logger.exception("download error") return None finally: # Cleanup partial file diff --git a/nanobot/channels/slack.py b/nanobot/channels/slack.py index 0bdeedc78..dc8899861 100644 --- a/nanobot/channels/slack.py +++ b/nanobot/channels/slack.py @@ -6,7 +6,6 @@ from pathlib import Path from typing import Any import httpx -from loguru import logger from pydantic import Field from slack_sdk.socket_mode.request import SocketModeRequest from slack_sdk.socket_mode.response import SocketModeResponse @@ -84,10 +83,10 @@ class SlackChannel(BaseChannel): async def start(self) -> None: """Start the Slack Socket Mode client.""" if not self.config.bot_token or not self.config.app_token: - logger.error("Slack bot/app token not configured") + self.logger.error("bot/app token not configured") return if self.config.mode != "socket": - logger.error("Unsupported Slack mode: {}", self.config.mode) + self.logger.error("Unsupported mode: {}", self.config.mode) return self._running = True @@ -104,11 +103,11 @@ class SlackChannel(BaseChannel): try: auth = await self._web_client.auth_test() self._bot_user_id = auth.get("user_id") - logger.info("Slack bot connected as {}", self._bot_user_id) + self.logger.info("bot connected as {}", self._bot_user_id) except Exception as e: - logger.warning("Slack auth_test failed: {}", e) + self.logger.warning("auth_test failed: {}", e) - logger.info("Starting Slack Socket Mode client...") + self.logger.info("Starting Socket Mode client...") await self._socket_client.connect() while self._running: @@ -121,13 +120,13 @@ class SlackChannel(BaseChannel): try: await self._socket_client.close() except Exception as e: - logger.warning("Slack socket close failed: {}", e) + self.logger.warning("socket close failed: {}", e) self._socket_client = None async def send(self, msg: OutboundMessage) -> None: """Send a message through Slack.""" if not self._web_client: - logger.warning("Slack client not running") + self.logger.warning("client not running") return try: target_chat_id = await self._resolve_target_chat_id(msg.chat_id) @@ -162,16 +161,16 @@ class SlackChannel(BaseChannel): file=media_path, thread_ts=thread_ts_param, ) - except Exception as e: - logger.error("Failed to upload file {}: {}", media_path, e) + except Exception: + self.logger.exception("Failed to upload file {}", media_path) # Update reaction emoji when the final (non-progress) response is sent if not (msg.metadata or {}).get("_progress"): event = slack_meta.get("event", {}) await self._update_react_emoji(origin_chat_id, event.get("ts")) - except Exception as e: - logger.error("Error sending Slack message: {}", e) + except Exception: + self.logger.exception("Error sending message") raise async def _resolve_target_chat_id(self, target: str) -> str: @@ -328,8 +327,8 @@ class SlackChannel(BaseChannel): return # Debug: log basic event shape - logger.debug( - "Slack event: type={} subtype={} user={} channel={} channel_type={} text={}", + self.logger.debug( + "event: type={} subtype={} user={} channel={} channel_type={} text={}", event_type, subtype, sender_id, @@ -371,7 +370,7 @@ class SlackChannel(BaseChannel): timestamp=event.get("ts"), ) except Exception as e: - logger.debug("Slack reactions_add failed: {}", e) + self.logger.debug("reactions_add failed: {}", e) # Thread-scoped session key whenever the user is in a real thread # (raw_thread_ts is set). DM threads get their own session, separate @@ -420,7 +419,7 @@ class SlackChannel(BaseChannel): session_key=session_key, ) except Exception: - logger.exception("Error handling Slack message from {}", sender_id) + self.logger.exception("Error handling message from {}", sender_id) async def _download_slack_file(self, file_info: dict[str, Any]) -> tuple[str | None, str]: """Download a Slack private file to the local media directory.""" @@ -453,7 +452,7 @@ class SlackChannel(BaseChannel): path.write_bytes(response.content) return str(path), marker except Exception as e: - logger.warning("Failed to download Slack file {}: {}", file_id, e) + self.logger.warning("Failed to download file {}: {}", file_id, e) return None, self._download_failure_marker(marker_type, name, "download failed") @staticmethod @@ -500,7 +499,7 @@ class SlackChannel(BaseChannel): session_key=session_key, ) except Exception: - logger.exception("Error handling Slack button click from {}", sender_id) + self.logger.exception("Error handling button click from {}", sender_id) async def _with_thread_context( self, @@ -537,7 +536,7 @@ class SlackChannel(BaseChannel): limit=max(1, self.config.thread_context_limit), ) except Exception as e: - logger.warning("Slack thread context unavailable for {}: {}", key, e) + self.logger.warning("thread context unavailable for {}: {}", key, e) return text lines = self._format_thread_context( @@ -597,7 +596,7 @@ class SlackChannel(BaseChannel): timestamp=ts, ) except Exception as e: - logger.debug("Slack reactions_remove failed: {}", e) + self.logger.debug("reactions_remove failed: {}", e) if self.config.done_emoji: try: await self._web_client.reactions_add( @@ -606,7 +605,7 @@ class SlackChannel(BaseChannel): timestamp=ts, ) except Exception as e: - logger.debug("Slack done reaction failed: {}", e) + self.logger.debug("done reaction failed: {}", e) def _is_allowed(self, sender_id: str, chat_id: str, channel_type: str) -> bool: if channel_type == "im": diff --git a/nanobot/channels/telegram.py b/nanobot/channels/telegram.py index 492b3ef50..5c97cddf9 100644 --- a/nanobot/channels/telegram.py +++ b/nanobot/channels/telegram.py @@ -11,7 +11,6 @@ from dataclasses import dataclass from pathlib import Path from typing import Any, Literal -from loguru import logger from pydantic import Field from telegram import ( BotCommand, @@ -320,7 +319,7 @@ class TelegramChannel(BaseChannel): async def start(self) -> None: """Start the Telegram bot with long polling.""" if not self.config.token: - logger.error("Telegram bot token not configured") + self.logger.error("bot token not configured") return self._running = True @@ -382,11 +381,11 @@ class TelegramChannel(BaseChannel): if self.config.inline_keyboards: self._app.add_handler(CallbackQueryHandler(self._on_callback_query)) allowed_updates = ["message", "callback_query"] - logger.debug("Telegram inline keyboards enabled") + self.logger.debug("inline keyboards enabled") else: allowed_updates = ["message"] - logger.info("Starting Telegram bot (polling mode)...") + self.logger.info("Starting bot (polling mode)...") # Initialize and start polling await self._app.initialize() @@ -396,13 +395,13 @@ class TelegramChannel(BaseChannel): bot_info = await self._app.bot.get_me() self._bot_user_id = getattr(bot_info, "id", None) self._bot_username = getattr(bot_info, "username", None) - logger.info("Telegram bot @{} connected", bot_info.username) + self.logger.info("bot @{} connected", bot_info.username) try: await self._app.bot.set_my_commands(self.BOT_COMMANDS) - logger.debug("Telegram bot commands registered") + self.logger.debug("bot commands registered") except Exception as e: - logger.warning("Failed to register bot commands: {}", e) + self.logger.warning("Failed to register bot commands: {}", e) # Start polling (this runs until stopped) await self._app.updater.start_polling( @@ -429,7 +428,7 @@ class TelegramChannel(BaseChannel): self._media_group_buffers.clear() if self._app: - logger.info("Stopping Telegram bot...") + self.logger.info("Stopping bot...") await self._app.updater.stop() await self._app.stop() await self._app.shutdown() @@ -456,7 +455,7 @@ class TelegramChannel(BaseChannel): async def send(self, msg: OutboundMessage) -> None: """Send a message through Telegram.""" if not self._app: - logger.warning("Telegram bot not running") + self.logger.warning("bot not running") return # Only stop typing indicator and remove reaction for final responses @@ -469,7 +468,7 @@ class TelegramChannel(BaseChannel): try: chat_id = int(msg.chat_id) except ValueError: - logger.error("Invalid chat_id: {}", msg.chat_id) + self.logger.exception("Invalid chat_id: {}", msg.chat_id) return reply_to_message_id = msg.metadata.get("message_id") message_thread_id = msg.metadata.get("message_thread_id") @@ -533,9 +532,9 @@ class TelegramChannel(BaseChannel): **extra, **send_kwargs, ) - except Exception as e: + except Exception: filename = media_path.rsplit("/", 1)[-1] - logger.error("Failed to send media {}: {}", media_path, e) + self.logger.exception("Failed to send media {}", media_path) await self._app.bot.send_message( chat_id=chat_id, text=f"[Failed to send: {filename}]", @@ -572,8 +571,8 @@ class TelegramChannel(BaseChannel): if attempt == _SEND_MAX_RETRIES: raise delay = _SEND_RETRY_BASE_DELAY * (2 ** (attempt - 1)) - logger.warning( - "Telegram timeout (attempt {}/{}), retrying in {:.1f}s", + self.logger.warning( + "timeout (attempt {}/{}), retrying in {:.1f}s", attempt, _SEND_MAX_RETRIES, delay, ) await asyncio.sleep(delay) @@ -581,8 +580,8 @@ class TelegramChannel(BaseChannel): if attempt == _SEND_MAX_RETRIES: raise delay = float(e.retry_after) - logger.warning( - "Telegram Flood Control (attempt {}/{}), retrying in {:.1f}s", + self.logger.warning( + "Flood Control (attempt {}/{}), retrying in {:.1f}s", attempt, _SEND_MAX_RETRIES, delay, ) await asyncio.sleep(delay) @@ -607,7 +606,7 @@ class TelegramChannel(BaseChannel): **(thread_kwargs or {}), ) except BadRequest as e: - logger.warning("HTML parse failed, falling back to plain text: {}", e) + self.logger.warning("HTML parse failed, falling back to plain text: {}", e) try: await self._call_with_retry( self._app.bot.send_message, @@ -617,8 +616,8 @@ class TelegramChannel(BaseChannel): reply_markup=reply_markup, **(thread_kwargs or {}), ) - except Exception as e2: - logger.error("Error sending Telegram message: {}", e2) + except Exception: + self.logger.exception("Error sending message") raise @staticmethod @@ -666,10 +665,10 @@ class TelegramChannel(BaseChannel): # Network errors (TimedOut, NetworkError) should propagate immediately # to avoid doubling connection demand during pool exhaustion. if self._is_not_modified_error(e): - logger.debug("Final stream edit already applied for {}", chat_id) + self.logger.debug("Final stream edit already applied for {}", chat_id) self._stream_bufs.pop(chat_id, None) return - logger.debug("Final stream edit failed (HTML), trying plain: {}", e) + self.logger.debug("Final stream edit failed (HTML), trying plain: {}", e) # Fall back to raw markdown (not HTML) so users don't see raw tags. primary_plain = split_message(raw_text, TELEGRAM_MAX_MESSAGE_LEN)[0] if len(raw_text) > TELEGRAM_MAX_MESSAGE_LEN else raw_text try: @@ -680,9 +679,9 @@ class TelegramChannel(BaseChannel): ) except Exception as e2: if self._is_not_modified_error(e2): - logger.debug("Final stream plain edit already applied for {}", chat_id) + self.logger.debug("Final stream plain edit already applied for {}", chat_id) else: - logger.warning("Final stream edit failed: {}", e2) + self.logger.warning("Final stream edit failed: {}", e2) raise # Let ChannelManager handle retry for extra_html_chunk in extra_html_chunks: try: @@ -724,7 +723,7 @@ class TelegramChannel(BaseChannel): buf.message_id = sent.message_id buf.last_edit = now except Exception as e: - logger.warning("Stream initial send failed: {}", e) + self.logger.warning("Stream initial send failed: {}", e) raise # Let ChannelManager handle retry elif (now - buf.last_edit) >= self.config.stream_edit_interval: if len(buf.text) > TELEGRAM_MAX_MESSAGE_LEN: @@ -743,7 +742,7 @@ class TelegramChannel(BaseChannel): if self._is_not_modified_error(e): buf.last_edit = now return - logger.warning("Stream edit failed: {}", e) + self.logger.warning("Stream edit failed: {}", e) raise # Let ChannelManager handle retry async def _flush_stream_overflow( @@ -769,7 +768,7 @@ class TelegramChannel(BaseChannel): ) except Exception as e: if not self._is_not_modified_error(e): - logger.warning("Stream overflow edit failed: {}", e) + self.logger.warning("Stream overflow edit failed: {}", e) raise for chunk in chunks[1:-1]: await self._call_with_retry( @@ -903,12 +902,12 @@ class TelegramChannel(BaseChannel): if media_type in ("voice", "audio"): transcription = await self.transcribe_audio(file_path) if transcription: - logger.info("Transcribed {}: {}...", media_type, transcription[:50]) + self.logger.info("Transcribed {}: {}...", media_type, transcription[:50]) return [path_str], [f"[transcription: {transcription}]"] return [path_str], [f"[{media_type}: {path_str}]"] return [path_str], [f"[{media_type}: {path_str}]"] except Exception as e: - logger.warning("Failed to download message media: {}", e) + self.logger.warning("Failed to download message media: {}", e) if add_failure_content: return [], [f"[{media_type}: download failed]"] return [], [] @@ -1056,7 +1055,7 @@ class TelegramChannel(BaseChannel): media_paths.extend(current_media_paths) content_parts.extend(current_media_parts) if current_media_paths: - logger.debug("Downloaded message media to {}", current_media_paths[0]) + self.logger.debug("Downloaded message media to {}", current_media_paths[0]) # Reply context: text and/or media from the replied-to message reply = getattr(message, "reply_to_message", None) @@ -1065,13 +1064,13 @@ class TelegramChannel(BaseChannel): reply_media, reply_media_parts = await self._download_message_media(reply) if reply_media: media_paths = reply_media + media_paths - logger.debug("Attached replied-to media: {}", reply_media[0]) + self.logger.debug("Attached replied-to media: {}", reply_media[0]) tag = reply_ctx or (f"[Reply to: {reply_media_parts[0]}]" if reply_media_parts else None) if tag: content_parts.insert(0, tag) content = "\n".join(content_parts) if content_parts else "[empty message]" - logger.debug("Telegram message from {}: {}...", sender_id, content[:50]) + self.logger.debug("message from {}: {}...", sender_id, content[:50]) str_chat_id = str(chat_id) metadata = self._build_message_metadata(message, user) @@ -1150,7 +1149,7 @@ class TelegramChannel(BaseChannel): reaction=[ReactionTypeEmoji(emoji=emoji)], ) except Exception as e: - logger.debug("Telegram reaction failed: {}", e) + self.logger.debug("reaction failed: {}", e) async def _remove_reaction(self, chat_id: str, message_id: int) -> None: """Remove emoji reaction from a message (best-effort, non-blocking).""" @@ -1163,7 +1162,7 @@ class TelegramChannel(BaseChannel): reaction=[], ) except Exception as e: - logger.debug("Telegram reaction removal failed: {}", e) + self.logger.debug("reaction removal failed: {}", e) async def _typing_loop(self, chat_id: str) -> None: """Repeatedly send 'typing' action until cancelled.""" @@ -1173,7 +1172,7 @@ class TelegramChannel(BaseChannel): await self._app.bot.send_chat_action(chat_id=int(chat_id), action="typing") await asyncio.sleep(4) except Exception as e: - logger.debug("Typing indicator stopped for {}: {}", chat_id, e) + self.logger.debug("Typing indicator stopped for {}: {}", chat_id, e) @staticmethod def _format_telegram_error(exc: Exception) -> str: @@ -1193,18 +1192,18 @@ class TelegramChannel(BaseChannel): """Keep long-polling network failures to a single readable line.""" summary = self._format_telegram_error(exc) if isinstance(exc, (NetworkError, TimedOut)): - logger.warning("Telegram polling network issue: {}", summary) + self.logger.warning("polling network issue: {}", summary) else: - logger.error("Telegram polling error: {}", summary) + self.logger.error("polling error: {}", summary) async def _on_error(self, update: object, context: ContextTypes.DEFAULT_TYPE) -> None: """Log polling / handler errors instead of silently swallowing them.""" summary = self._format_telegram_error(context.error) if isinstance(context.error, (NetworkError, TimedOut)): - logger.warning("Telegram network issue: {}", summary) + self.logger.warning("network issue: {}", summary) else: - logger.error("Telegram error: {}", summary) + self.logger.error("error: {}", summary) def _get_extension( self, @@ -1265,7 +1264,7 @@ class TelegramChannel(BaseChannel): chat_id = query.message.chat_id if query.message else None sender_id = self._sender_id(user) if not chat_id: - logger.warning("Callback query without chat_id") + self.logger.warning("Callback query without chat_id") return if not self.is_allowed(sender_id): return @@ -1274,7 +1273,7 @@ class TelegramChannel(BaseChannel): if query.message: with suppress(Exception): await query.message.edit_reply_markup(reply_markup=None) - logger.debug("Inline button tap from {}: {}", sender_id, button_label) + self.logger.debug("Inline button tap from {}: {}", sender_id, button_label) self._start_typing(str(chat_id)) await self._handle_message( sender_id=sender_id, diff --git a/nanobot/channels/websocket.py b/nanobot/channels/websocket.py index f5477684b..0f60c63a8 100644 --- a/nanobot/channels/websocket.py +++ b/nanobot/channels/websocket.py @@ -448,7 +448,7 @@ class WebSocketChannel(BaseChannel): except ConnectionClosed: self._cleanup_connection(connection) except Exception as e: - logger.warning("websocket: failed to send {} event: {}", event, e) + self.logger.warning("failed to send {} event: {}", event, e) @classmethod def default_config(cls) -> dict[str, Any]: @@ -464,7 +464,7 @@ class WebSocketChannel(BaseChannel): return None if not cert or not key: raise ValueError( - "websocket: ssl_certfile and ssl_keyfile must both be set for WSS, or both left empty" + "ssl_certfile and ssl_keyfile must both be set for WSS, or both left empty" ) ctx = ssl.SSLContext(ssl.PROTOCOL_TLS_SERVER) ctx.minimum_version = ssl.TLSVersion.TLSv1_2 @@ -501,14 +501,14 @@ class WebSocketChannel(BaseChannel): if not _issue_route_secret_matches(request.headers, secret): return connection.respond(401, "Unauthorized") else: - logger.warning( - "websocket: token_issue_path is set but token_issue_secret is empty; " + self.logger.warning( + "token_issue_path is set but token_issue_secret is empty; " "any client can obtain connection tokens — set token_issue_secret for production." ) self._purge_expired_issued_tokens() if len(self._issued_tokens) >= self._MAX_ISSUED_TOKENS: - logger.error( - "websocket: too many outstanding issued tokens ({}), rejecting issuance", + self.logger.error( + "too many outstanding issued tokens ({}), rejecting issuance", len(self._issued_tokens), ) return _http_json_response({"error": "too many outstanding tokens"}, status=429) @@ -821,7 +821,7 @@ class WebSocketChannel(BaseChannel): staged = media_dir / f"{uuid.uuid4().hex[:12]}-{safe_name}" shutil.copyfile(path, staged) except OSError as exc: - logger.warning("websocket: failed to stage outbound media {}: {}", path, exc) + self.logger.warning("failed to stage outbound media {}: {}", path, exc) return None signed = self._sign_media_path(staged) if signed is None: @@ -917,7 +917,7 @@ class WebSocketChannel(BaseChannel): try: body = candidate.read_bytes() except OSError as e: - logger.warning("websocket static: failed to read {}: {}", candidate, e) + self.logger.warning("static: failed to read {}: {}", candidate, e) return _http_error(500, "Internal Server Error") ctype, _ = mimetypes.guess_type(candidate.name) if ctype is None: @@ -972,7 +972,7 @@ class WebSocketChannel(BaseChannel): async def handler(connection: ServerConnection) -> None: await self._connection_loop(connection) - logger.info( + self.logger.info( "WebSocket server listening on {}://{}:{}{}", scheme, self.config.host, @@ -980,7 +980,7 @@ class WebSocketChannel(BaseChannel): self.config.path, ) if self.config.token_issue_path: - logger.info( + self.logger.info( "WebSocket token issue route: {}://{}:{}{}", scheme, self.config.host, @@ -1014,7 +1014,7 @@ class WebSocketChannel(BaseChannel): if not client_id: client_id = f"anon-{uuid.uuid4().hex[:12]}" elif len(client_id) > 128: - logger.warning("websocket: client_id too long ({} chars), truncating", len(client_id)) + self.logger.warning("client_id too long ({} chars), truncating", len(client_id)) client_id = client_id[:128] default_chat_id = str(uuid.uuid4()) @@ -1039,7 +1039,7 @@ class WebSocketChannel(BaseChannel): try: raw = raw.decode("utf-8") except UnicodeDecodeError: - logger.warning("websocket: ignoring non-utf8 binary frame") + self.logger.warning("ignoring non-utf8 binary frame") continue envelope = _parse_envelope(raw) @@ -1057,7 +1057,7 @@ class WebSocketChannel(BaseChannel): metadata={"remote": getattr(connection, "remote_address", None)}, ) except Exception as e: - logger.debug("websocket connection ended: {}", e) + self.logger.debug("connection ended: {}", e) finally: self._cleanup_connection(connection) @@ -1097,8 +1097,8 @@ class WebSocketChannel(BaseChannel): try: Path(p).unlink(missing_ok=True) except OSError as exc: - logger.warning( - "websocket: failed to unlink partial media {}: {}", p, exc + self.logger.warning( + "failed to unlink partial media {}: {}", p, exc ) return [], reason @@ -1122,7 +1122,7 @@ class WebSocketChannel(BaseChannel): except FileSizeExceeded: return _abort("size") except Exception as exc: - logger.warning("websocket: media decode failed: {}", exc) + self.logger.warning("media decode failed: {}", exc) return _abort("decode") if saved is None: return _abort("decode") @@ -1204,7 +1204,7 @@ class WebSocketChannel(BaseChannel): try: await self._server_task except Exception as e: - logger.warning("websocket: server task error during shutdown: {}", e) + self.logger.warning("server task error during shutdown: {}", e) self._server_task = None self._subs.clear() self._conn_chats.clear() @@ -1218,16 +1218,16 @@ class WebSocketChannel(BaseChannel): await connection.send(raw) except ConnectionClosed: self._cleanup_connection(connection) - logger.warning("websocket{}connection gone", label) - except Exception as e: - logger.error("websocket{}send failed: {}", label, e) + self.logger.warning("connection gone{}", label) + except Exception: + self.logger.exception("send failed{}", label) raise async def send(self, msg: OutboundMessage) -> None: # Snapshot the subscriber set so ConnectionClosed cleanups mid-iteration are safe. conns = list(self._subs.get(msg.chat_id, ())) if not conns: - logger.warning("websocket: no active subscribers for chat_id={}", msg.chat_id) + self.logger.warning("no active subscribers for chat_id={}", msg.chat_id) return # Signal that the agent has fully finished processing the current turn. if msg.metadata.get("_turn_end"): diff --git a/nanobot/channels/wecom.py b/nanobot/channels/wecom.py index ce3e7ed51..2dd9f8856 100644 --- a/nanobot/channels/wecom.py +++ b/nanobot/channels/wecom.py @@ -10,7 +10,6 @@ from collections import OrderedDict from pathlib import Path from typing import Any -from loguru import logger from pydantic import Field from nanobot.bus.events import OutboundMessage @@ -103,11 +102,11 @@ class WecomChannel(BaseChannel): async def start(self) -> None: """Start the WeCom bot with WebSocket long connection.""" if not WECOM_AVAILABLE: - logger.error("WeCom SDK not installed. Run: pip install nanobot-ai[wecom]") + self.logger.error("SDK not installed. Run: pip install nanobot-ai[wecom]") return if not self.config.bot_id or not self.config.secret: - logger.error("WeCom bot_id and secret not configured") + self.logger.error("bot_id and secret not configured") return from wecom_aibot_sdk import WSClient, generate_req_id @@ -137,8 +136,8 @@ class WecomChannel(BaseChannel): self._client.on("message.mixed", self._on_mixed_message) self._client.on("event.enter_chat", self._on_enter_chat) - logger.info("WeCom bot starting with WebSocket long connection") - logger.info("No public IP required - using WebSocket to receive events") + self.logger.info("bot starting with WebSocket long connection") + self.logger.info("No public IP required - using WebSocket to receive events") # Connect await self._client.connect_async() @@ -152,24 +151,24 @@ class WecomChannel(BaseChannel): self._running = False if self._client: await self._client.disconnect() - logger.info("WeCom bot stopped") + self.logger.info("bot stopped") async def _on_connected(self, frame: Any) -> None: """Handle WebSocket connected event.""" - logger.info("WeCom WebSocket connected") + self.logger.info("WebSocket connected") async def _on_authenticated(self, frame: Any) -> None: """Handle authentication success event.""" - logger.info("WeCom authenticated successfully") + self.logger.info("authenticated successfully") async def _on_disconnected(self, frame: Any) -> None: """Handle WebSocket disconnected event.""" reason = frame.body if hasattr(frame, 'body') else str(frame) - logger.warning("WeCom WebSocket disconnected: {}", reason) + self.logger.warning("WebSocket disconnected: {}", reason) async def _on_error(self, frame: Any) -> None: """Handle error event.""" - logger.error("WeCom error: {}", frame) + self.logger.error("error: {}", frame) async def _on_text_message(self, frame: Any) -> None: """Handle text message.""" @@ -212,8 +211,8 @@ class WecomChannel(BaseChannel): "msgtype": "text", "text": {"content": self.config.welcome_message}, }) - except Exception as e: - logger.error("Error handling enter_chat: {}", e) + except Exception: + self.logger.exception("Error handling enter_chat") async def _process_message(self, frame: Any, msg_type: str) -> None: """Process incoming message and forward to bus.""" @@ -228,7 +227,7 @@ class WecomChannel(BaseChannel): # Ensure body is a dict if not isinstance(body, dict): - logger.warning("Invalid body type: {}", type(body)) + self.logger.warning("Invalid body type: {}", type(body)) return # Extract message info @@ -350,8 +349,8 @@ class WecomChannel(BaseChannel): } ) - except Exception as e: - logger.error("Error processing WeCom message: {}", e) + except Exception: + self.logger.exception("Error processing message") async def _download_and_save_media( self, @@ -370,12 +369,12 @@ class WecomChannel(BaseChannel): data, fname = await self._client.download_file(file_url, aes_key) if not data: - logger.warning("Failed to download media from WeCom") + self.logger.warning("Failed to download media") return None if len(data) > WECOM_UPLOAD_MAX_BYTES: - logger.warning( - "WeCom inbound media too large: {} bytes (max {})", + self.logger.warning( + "inbound media too large: {} bytes (max {})", len(data), WECOM_UPLOAD_MAX_BYTES, ) @@ -388,11 +387,11 @@ class WecomChannel(BaseChannel): file_path = media_dir / filename await asyncio.to_thread(file_path.write_bytes, data) - logger.debug("Downloaded {} to {}", media_type, file_path) + self.logger.debug("Downloaded {} to {}", media_type, file_path) return str(file_path) - except Exception as e: - logger.error("Error downloading media: {}", e) + except Exception: + self.logger.exception("Error downloading media") return None async def _upload_media_ws( @@ -445,11 +444,11 @@ class WecomChannel(BaseChannel): "md5": md5_hash, }, "aibot_upload_media_init") if resp.errcode != 0: - logger.warning("WeCom upload init failed ({}): {}", resp.errcode, resp.errmsg) + self.logger.warning("upload init failed ({}): {}", resp.errcode, resp.errmsg) return None, None upload_id = resp.body.get("upload_id") if resp.body else None if not upload_id: - logger.warning("WeCom upload init: no upload_id in response") + self.logger.warning("upload init: no upload_id in response") return None, None # Step 2: send chunks @@ -461,7 +460,7 @@ class WecomChannel(BaseChannel): "base64_data": base64.b64encode(chunk).decode(), }, "aibot_upload_media_chunk") if resp.errcode != 0: - logger.warning("WeCom upload chunk {} failed ({}): {}", i, resp.errcode, resp.errmsg) + self.logger.warning("upload chunk {} failed ({}): {}", i, resp.errcode, resp.errmsg) return None, None # Step 3: finish @@ -470,29 +469,29 @@ class WecomChannel(BaseChannel): "upload_id": upload_id, }, "aibot_upload_media_finish") if resp.errcode != 0: - logger.warning("WeCom upload finish failed ({}): {}", resp.errcode, resp.errmsg) + self.logger.warning("upload finish failed ({}): {}", resp.errcode, resp.errmsg) return None, None media_id = resp.body.get("media_id") if resp.body else None if not media_id: - logger.warning("WeCom upload finish: no media_id in response body={}", resp.body) + self.logger.warning("upload finish: no media_id in response body={}", resp.body) return None, None suffix = "..." if len(media_id) > 16 else "" - logger.debug("WeCom uploaded {} ({}) → media_id={}", fname, media_type, media_id[:16] + suffix) + self.logger.debug("uploaded {} ({}) → media_id={}", fname, media_type, media_id[:16] + suffix) return media_id, media_type except ValueError as e: - logger.warning("WeCom upload skipped for {}: {}", file_path, e) + self.logger.warning("upload skipped for {}: {}", file_path, e) return None, None - except Exception as e: - logger.error("WeCom _upload_media_ws error for {}: {}", file_path, e) + except Exception: + self.logger.exception("_upload_media_ws error for {}", file_path) return None, None async def send(self, msg: OutboundMessage) -> None: """Send a message through WeCom.""" if not self._client: - logger.warning("WeCom client not initialized") + self.logger.warning("client not initialized") return try: @@ -505,7 +504,7 @@ class WecomChannel(BaseChannel): # Send media files via WebSocket upload for file_path in msg.media or []: if not os.path.isfile(file_path): - logger.warning("WeCom media file not found: {}", file_path) + self.logger.warning("media file not found: {}", file_path) continue media_id, media_type = await self._upload_media_ws(self._client, file_path) if media_id: @@ -519,7 +518,7 @@ class WecomChannel(BaseChannel): "msgtype": media_type, media_type: {"media_id": media_id}, }) - logger.debug("WeCom sent {} → {}", media_type, msg.chat_id) + self.logger.debug("sent {} → {}", media_type, msg.chat_id) else: content += f"\n[file upload failed: {os.path.basename(file_path)}]" @@ -537,8 +536,8 @@ class WecomChannel(BaseChannel): content, finish=not is_progress, ) - logger.debug( - "WeCom {} sent to {}", + self.logger.debug( + "{} sent to {}", "progress" if is_progress else "message", msg.chat_id, ) @@ -548,7 +547,7 @@ class WecomChannel(BaseChannel): "msgtype": "markdown", "markdown": {"content": content}, }) - logger.info("WeCom proactive send to {}", msg.chat_id) + self.logger.info("proactive send to {}", msg.chat_id) except Exception: - logger.exception("Error sending WeCom message to chat_id={}", msg.chat_id) + self.logger.exception("Error sending message to chat_id={}", msg.chat_id) diff --git a/nanobot/channels/weixin.py b/nanobot/channels/weixin.py index af82984b2..698acc70e 100644 --- a/nanobot/channels/weixin.py +++ b/nanobot/channels/weixin.py @@ -366,14 +366,14 @@ class WeixinChannel(BaseChannel): if base_url: self.config.base_url = base_url self._save_state() - logger.info( - "WeChat login successful! bot_id={} user_id={}", + self.logger.info( + "login successful! bot_id={} user_id={}", bot_id, user_id, ) return True else: - logger.error("Login confirmed but no bot_token in response") + self.logger.error("Login confirmed but no bot_token in response") return False elif status == "scaned_but_redirect": redirect_host = str(status_data.get("redirect_host", "") or "").strip() @@ -387,7 +387,7 @@ class WeixinChannel(BaseChannel): elif status == "expired": refresh_count += 1 if refresh_count > MAX_QR_REFRESH_COUNT: - logger.warning( + self.logger.warning( "QR code expired too many times ({}/{}), giving up.", refresh_count - 1, MAX_QR_REFRESH_COUNT, @@ -401,8 +401,8 @@ class WeixinChannel(BaseChannel): await asyncio.sleep(1) - except Exception as e: - logger.error("WeChat QR login failed: {}", e) + except Exception: + self.logger.exception("QR login failed") return False @@ -469,11 +469,11 @@ class WeixinChannel(BaseChannel): self._token = self.config.token elif not self._load_state(): if not await self._qr_login(): - logger.error("WeChat login failed. Run 'nanobot channels login weixin' to authenticate.") + self.logger.error("login failed. Run 'nanobot channels login weixin' to authenticate.") self._running = False return - logger.info("WeChat channel starting with long-poll...") + self.logger.info("channel starting with long-poll...") consecutive_failures = 0 while self._running: @@ -551,8 +551,8 @@ class WeixinChannel(BaseChannel): if errcode == ERRCODE_SESSION_EXPIRED or ret == ERRCODE_SESSION_EXPIRED: self._pause_session() remaining = self._session_pause_remaining_s() - logger.warning( - "WeChat session expired (errcode {}). Pausing {} min.", + self.logger.warning( + "session expired (errcode {}). Pausing {} min.", errcode, max((remaining + 59) // 60, 1), ) @@ -759,8 +759,8 @@ class WeixinChannel(BaseChannel): if not content: return - logger.info( - "WeChat inbound: from={} items={} bodyLen={}", + self.logger.info( + "inbound: from={} items={} bodyLen={}", from_user_id, ",".join(str(i.get("type", 0)) for i in item_list), len(content), @@ -843,8 +843,8 @@ class WeixinChannel(BaseChannel): and self._is_retryable_media_download_error(e) ) if should_fallback: - logger.warning( - "WeChat media download failed via full_url, falling back to encrypt_query_param: type={} err={}", + self.logger.warning( + "media download failed via full_url, falling back to encrypt_query_param: type={} err={}", media_type, e, ) @@ -869,8 +869,8 @@ class WeixinChannel(BaseChannel): file_path.write_bytes(data) return str(file_path) - except Exception as e: - logger.error("Error downloading WeChat media: {}", e) + except Exception: + self.logger.exception("Error downloading media") return None # ------------------------------------------------------------------ @@ -940,7 +940,7 @@ class WeixinChannel(BaseChannel): async def send(self, msg: OutboundMessage) -> None: if not self._client or not self._token: - logger.warning("WeChat client not initialized or not authenticated") + self.logger.warning("client not initialized or not authenticated") return try: self._assert_session_active() @@ -954,8 +954,8 @@ class WeixinChannel(BaseChannel): content = msg.content.strip() ctx_token = self._context_tokens.get(msg.chat_id, "") if not ctx_token: - logger.warning( - "WeChat: no context_token for chat_id={}, cannot send", + self.logger.warning( + "no context_token for chat_id={}, cannot send", msg.chat_id, ) return @@ -980,14 +980,13 @@ class WeixinChannel(BaseChannel): for media_path in (msg.media or []): try: await self._send_media_file(msg.chat_id, media_path, ctx_token) - except (httpx.TimeoutException, httpx.TransportError) as net_err: + except (httpx.TimeoutException, httpx.TransportError): # Network/transport errors: do NOT fall back to text — # the text send would also likely fail, and the outer # except will re-raise so ChannelManager retries properly. - logger.error( - "Network error sending WeChat media {}: {}", + self.logger.opt(exception=True).warning( + "Network error sending media {}", media_path, - net_err, ) raise except httpx.HTTPStatusError as http_err: @@ -998,27 +997,26 @@ class WeixinChannel(BaseChannel): ) if status_code >= 500: # Server-side / retryable HTTP error — same as network. - logger.error( - "Server error ({} {}) sending WeChat media {}: {}", + self.logger.exception( + "Server error ({} {}) sending media {}", status_code, http_err.response.reason_phrase if http_err.response is not None else "", media_path, - http_err, ) raise # 4xx client errors are NOT retryable — fall back to text. filename = Path(media_path).name - logger.error("Failed to send WeChat media {}: {}", media_path, http_err) + self.logger.exception("Failed to send media {}", media_path) await self._send_text( msg.chat_id, f"[Failed to send: {filename}]", ctx_token, ) - except Exception as e: + except Exception: # Non-network errors (format, file-not-found, etc.): # notify the user via text fallback. filename = Path(media_path).name - logger.error("Failed to send WeChat media {}: {}", media_path, e) + self.logger.exception("Failed to send media {}", media_path) # Notify user about failure via text await self._send_text( msg.chat_id, f"[Failed to send: {filename}]", ctx_token, @@ -1031,8 +1029,8 @@ class WeixinChannel(BaseChannel): chunks = split_message(content, WEIXIN_MAX_MESSAGE_LEN) for chunk in chunks: await self._send_text(msg.chat_id, chunk, ctx_token) - except Exception as e: - logger.error("Error sending WeChat message: {}", e) + except Exception: + self.logger.exception("Error sending message") raise finally: if typing_keepalive_task: @@ -1056,7 +1054,7 @@ class WeixinChannel(BaseChannel): return await self._send_typing(chat_id, ticket, TYPING_STATUS_TYPING) except Exception as e: - logger.debug("WeChat typing indicator start failed for {}: {}", chat_id, e) + self.logger.debug("typing indicator start failed for {}: {}", chat_id, e) return stop_event = asyncio.Event() @@ -1095,7 +1093,7 @@ class WeixinChannel(BaseChannel): try: await self._send_typing(chat_id, ticket, TYPING_STATUS_CANCEL) except Exception as e: - logger.debug("WeChat typing clear failed for {}: {}", chat_id, e) + self.logger.debug("typing clear failed for {}: {}", chat_id, e) async def _send_text( self, @@ -1130,8 +1128,8 @@ class WeixinChannel(BaseChannel): data = await self._api_post("ilink/bot/sendmessage", body) errcode = data.get("errcode", 0) if errcode and errcode != 0: - logger.warning( - "WeChat send error (code {}): {}", + self.logger.warning( + "send error (code {}): {}", errcode, data.get("errmsg", ""), ) diff --git a/nanobot/channels/whatsapp.py b/nanobot/channels/whatsapp.py index 26869de18..bd0620334 100644 --- a/nanobot/channels/whatsapp.py +++ b/nanobot/channels/whatsapp.py @@ -99,15 +99,15 @@ class WhatsAppChannel(BaseChannel): """ try: bridge_dir = _ensure_bridge_setup() - except RuntimeError as e: - logger.error("{}", e) + except RuntimeError: + self.logger.exception("bridge setup failed") return False env = {**os.environ} env["BRIDGE_TOKEN"] = self._effective_bridge_token() env["AUTH_DIR"] = str(_bridge_token_path().parent) - logger.info("Starting WhatsApp bridge for QR login...") + self.logger.info("Starting WhatsApp bridge for QR login...") try: subprocess.run( [shutil.which("npm"), "start"], cwd=bridge_dir, check=True, env=env @@ -123,7 +123,7 @@ class WhatsAppChannel(BaseChannel): bridge_url = self.config.bridge_url - logger.info("Connecting to WhatsApp bridge at {}...", bridge_url) + self.logger.info("Connecting to WhatsApp bridge at {}...", bridge_url) self._running = True @@ -135,24 +135,24 @@ class WhatsAppChannel(BaseChannel): json.dumps({"type": "auth", "token": self._effective_bridge_token()}) ) self._connected = True - logger.info("Connected to WhatsApp bridge") + self.logger.info("Connected to WhatsApp bridge") # Listen for messages async for message in ws: try: await self._handle_bridge_message(message) - except Exception as e: - logger.error("Error handling bridge message: {}", e) + except Exception: + self.logger.exception("Error handling bridge message") except asyncio.CancelledError: break except Exception as e: self._connected = False self._ws = None - logger.warning("WhatsApp bridge connection error: {}", e) + self.logger.warning("WhatsApp bridge connection error: {}", e) if self._running: - logger.info("Reconnecting in 5 seconds...") + self.logger.info("Reconnecting in 5 seconds...") await asyncio.sleep(5) async def stop(self) -> None: @@ -167,7 +167,7 @@ class WhatsAppChannel(BaseChannel): async def send(self, msg: OutboundMessage) -> None: """Send a message through WhatsApp.""" if not self._ws or not self._connected: - logger.warning("WhatsApp bridge not connected") + self.logger.warning("WhatsApp bridge not connected") return chat_id = msg.chat_id @@ -176,8 +176,8 @@ class WhatsAppChannel(BaseChannel): try: payload = {"type": "send", "to": chat_id, "text": msg.content} await self._ws.send(json.dumps(payload, ensure_ascii=False)) - except Exception as e: - logger.error("Error sending WhatsApp message: {}", e) + except Exception: + self.logger.exception("Error sending message") raise for media_path in msg.media or []: @@ -191,8 +191,8 @@ class WhatsAppChannel(BaseChannel): "fileName": media_path.rsplit("/", 1)[-1], } await self._ws.send(json.dumps(payload, ensure_ascii=False)) - except Exception as e: - logger.error("Error sending WhatsApp media {}: {}", media_path, e) + except Exception: + self.logger.exception("Error sending media {}", media_path) raise async def _handle_bridge_message(self, raw: str) -> None: @@ -200,7 +200,7 @@ class WhatsAppChannel(BaseChannel): try: data = json.loads(raw) except json.JSONDecodeError: - logger.warning("Invalid JSON from bridge: {}", raw[:100]) + self.logger.warning("Invalid JSON from bridge: {}", raw[:100]) return msg_type = data.get("type") @@ -253,7 +253,7 @@ class WhatsAppChannel(BaseChannel): if phone_id and lid_id: self._lid_to_phone[lid_id] = phone_id - logger.info("Sender phone={} lid={} → sender_id={}", phone_id or "(empty)", lid_id or "(empty)", sender_id) + self.logger.info("Sender phone={} lid={} → sender_id={}", phone_id or "(empty)", lid_id or "(empty)", sender_id) # Extract media paths (images/documents/videos downloaded by the bridge) media_paths = data.get("media") or [] @@ -261,11 +261,11 @@ class WhatsAppChannel(BaseChannel): # Handle voice transcription if it's a voice message if content == "[Voice Message]": if media_paths: - logger.info("Transcribing voice message from {}...", sender_id) + self.logger.info("Transcribing voice message from {}...", sender_id) transcription = await self.transcribe_audio(media_paths[0]) if transcription: content = transcription - logger.info("Transcribed voice from {}: {}...", sender_id, transcription[:50]) + self.logger.info("Transcribed voice from {}: {}...", sender_id, transcription[:50]) else: content = "[Voice Message: Transcription failed]" else: @@ -294,7 +294,7 @@ class WhatsAppChannel(BaseChannel): elif msg_type == "status": # Connection status update status = data.get("status") - logger.info("WhatsApp status: {}", status) + self.logger.info("Status: {}", status) if status == "connected": self._connected = True @@ -303,10 +303,10 @@ class WhatsAppChannel(BaseChannel): elif msg_type == "qr": # QR code for authentication - logger.info("Scan QR code in the bridge terminal to connect WhatsApp") + self.logger.info("Scan QR code in the bridge terminal to connect WhatsApp") elif msg_type == "error": - logger.error("WhatsApp bridge error: {}", data.get("error")) + self.logger.error("Bridge error: {}", data.get("error")) def _ensure_bridge_setup() -> Path: diff --git a/nanobot/cli/commands.py b/nanobot/cli/commands.py index a062802a9..c54a2bc7c 100644 --- a/nanobot/cli/commands.py +++ b/nanobot/cli/commands.py @@ -21,6 +21,22 @@ if sys.platform == "win32": import typer from loguru import logger + +# Remove default handler and re-add with unified nanobot format +logger.remove() +_log_handler_id = logger.add( + sys.stderr, + format=( + "{time:YYYY-MM-DD HH:mm:ss} | " + "{level: <5} | " + "{extra[channel]} | " + "{message}" + ), + level="INFO", + colorize=None, + filter=lambda record: record["extra"].setdefault("channel", "-") or True, +) + from prompt_toolkit import PromptSession, print_formatted_text from prompt_toolkit.application import run_in_terminal from prompt_toolkit.formatted_text import ANSI, HTML @@ -597,9 +613,19 @@ def gateway( ): """Start the nanobot gateway.""" if verbose: - import logging - - logging.basicConfig(level=logging.DEBUG) + logger.remove(_log_handler_id) + logger.add( + sys.stderr, + format=( + "{time:YYYY-MM-DD HH:mm:ss} | " + "{level: <5} | " + "{extra[channel]} | " + "{message}" + ), + level="DEBUG", + colorize=None, + filter=lambda record: record["extra"].setdefault("channel", "-") or True, + ) cfg = _load_runtime_config(config, workspace) _run_gateway(cfg, port=port) diff --git a/nanobot/cli/onboard.py b/nanobot/cli/onboard.py index 4c5700892..5eadb43d9 100644 --- a/nanobot/cli/onboard.py +++ b/nanobot/cli/onboard.py @@ -840,7 +840,7 @@ def _get_channel_info() -> dict[str, tuple[str, type[BaseModel]]]: display_name = getattr(channel_cls, "display_name", name.capitalize()) result[name] = (display_name, config_cls) except Exception: - logger.warning(f"Failed to load channel module: {name}") + logger.warning("Failed to load channel module: {}", name) return result diff --git a/nanobot/config/loader.py b/nanobot/config/loader.py index d663105f5..e0808e107 100644 --- a/nanobot/config/loader.py +++ b/nanobot/config/loader.py @@ -49,7 +49,7 @@ def load_config(config_path: Path | None = None) -> Config: data = _migrate_config(data) config = Config.model_validate(data) except (json.JSONDecodeError, ValueError, pydantic.ValidationError) as e: - logger.warning(f"Failed to load config from {path}: {e}") + logger.warning("Failed to load config from {}: {}", path, e) logger.warning("Using default configuration.") _apply_ssrf_whitelist(config) diff --git a/nanobot/cron/service.py b/nanobot/cron/service.py index e5428c114..31c5b50a7 100644 --- a/nanobot/cron/service.py +++ b/nanobot/cron/service.py @@ -156,7 +156,7 @@ class CronService: updated_at_ms=j.get("updatedAtMs", 0), delete_after_run=j.get("deleteAfterRun", False), )) - except Exception as e: + except Exception: # Preserve the corrupt file for forensic recovery instead of # letting the next save overwrite it with an empty job list. backup = self.store_path.with_suffix( @@ -164,12 +164,11 @@ class CronService: ) with suppress(OSError): self.store_path.rename(backup) - logger.error( - "Failed to load cron store at {}: {}. " + logger.exception( + "Failed to load cron store at {}. " "Corrupt file preserved at {}. " "Refusing to overwrite to avoid data loss.", self.store_path, - e, backup, ) return None @@ -202,8 +201,8 @@ class CronService: else: _update(action.get("params", {})) changed = True - except Exception as exp: - logger.debug(f"load action line error: {exp}") + except Exception: + logger.exception("load action line error") continue self._store.jobs = list(jobs_map.values()) if self._running and changed: @@ -434,7 +433,7 @@ class CronService: except Exception as e: job.state.last_status = "error" job.state.last_error = str(e) - logger.error("Cron: job '{}' failed: {}", job.name, e) + logger.exception("Cron: job '{}' failed", job.name) end_ms = _now_ms() job.state.last_run_at_ms = start_ms diff --git a/nanobot/heartbeat/service.py b/nanobot/heartbeat/service.py index fea2c51b6..b41ee7a1e 100644 --- a/nanobot/heartbeat/service.py +++ b/nanobot/heartbeat/service.py @@ -144,8 +144,8 @@ class HeartbeatService: await self._tick() except asyncio.CancelledError: break - except Exception as e: - logger.error("Heartbeat error: {}", e) + except Exception: + logger.exception("Heartbeat error") @staticmethod def _is_deliverable(response: str) -> bool: diff --git a/nanobot/providers/transcription.py b/nanobot/providers/transcription.py index 10fcafd6d..456c09ea2 100644 --- a/nanobot/providers/transcription.py +++ b/nanobot/providers/transcription.py @@ -44,8 +44,8 @@ class OpenAITranscriptionProvider: ) response.raise_for_status() return response.json().get("text", "") - except Exception as e: - logger.error("OpenAI transcription error: {}", e) + except Exception: + logger.exception("OpenAI transcription error") return "" @@ -109,6 +109,6 @@ class GroqTranscriptionProvider: data = response.json() return data.get("text", "") - except Exception as e: - logger.error("Groq transcription error: {}", e) + except Exception: + logger.exception("Groq transcription error") return "" diff --git a/nanobot/utils/document.py b/nanobot/utils/document.py index 3a1ea9067..53039e97f 100644 --- a/nanobot/utils/document.py +++ b/nanobot/utils/document.py @@ -93,7 +93,7 @@ def _extract_pdf(path: Path) -> str: pages.append(f"--- Page {i} ---\n{text}") return _truncate("\n\n".join(pages), _MAX_TEXT_LENGTH) except Exception as e: - logger.error("Failed to extract PDF {}: {}", path, e) + logger.exception("Failed to extract PDF {}", path) return f"[error: failed to extract PDF: {e!s}]" @@ -108,7 +108,7 @@ def _extract_docx(path: Path) -> str: paragraphs: list[str] = [p.text for p in doc.paragraphs if p.text.strip()] return _truncate("\n\n".join(paragraphs), _MAX_TEXT_LENGTH) except Exception as e: - logger.error("Failed to extract DOCX {}: {}", path, e) + logger.exception("Failed to extract DOCX {}", path) return f"[error: failed to extract DOCX: {e!s}]" @@ -135,7 +135,7 @@ def _extract_xlsx(path: Path) -> str: finally: wb.close() except Exception as e: - logger.error("Failed to extract XLSX {}: {}", path, e) + logger.exception("Failed to extract XLSX {}", path) return f"[error: failed to extract XLSX: {e!s}]" @@ -156,7 +156,7 @@ def _extract_pptx(path: Path) -> str: slides.append(f"--- Slide {i} ---\n" + "\n".join(slide_text)) return _truncate("\n\n".join(slides), _MAX_TEXT_LENGTH) except Exception as e: - logger.error("Failed to extract PPTX {}: {}", path, e) + logger.exception("Failed to extract PPTX {}", path) return f"[error: failed to extract PPTX: {e!s}]" @@ -195,7 +195,7 @@ def _extract_text_file(path: Path) -> str: content = path.read_text(encoding="latin-1") return _truncate(content, _MAX_TEXT_LENGTH) except Exception as e: - logger.error("Failed to read text file {}: {}", path, e) + logger.exception("Failed to read text file {}", path) return f"[error: failed to read file: {e!s}]" diff --git a/nanobot/utils/gitstore.py b/nanobot/utils/gitstore.py index d9b528c97..6e05ca128 100644 --- a/nanobot/utils/gitstore.py +++ b/nanobot/utils/gitstore.py @@ -113,7 +113,7 @@ class GitStore: logger.info("Git store initialized at {}", self._workspace) return True except Exception: - logger.warning("Git store init failed for {}", self._workspace) + logger.exception("Git store init failed for {}", self._workspace) return False # -- daily operations ------------------------------------------------------ @@ -149,7 +149,7 @@ class GitStore: logger.debug("Git auto-commit: {} ({})", sha, message) return sha except Exception: - logger.warning("Git auto-commit failed: {}", message) + logger.exception("Git auto-commit failed: {}", message) return None # -- internal helpers ------------------------------------------------------ @@ -243,7 +243,7 @@ class GitStore: return entries except Exception: - logger.warning("Git log failed") + logger.exception("Git log failed") return [] def line_ages(self, file_path: str) -> list[LineAge]: @@ -266,7 +266,7 @@ class GitStore: annotated = porcelain.annotate(str(self._workspace), file_path) except Exception: - logger.warning("Git line_ages annotate failed for {}", file_path) + logger.exception("Git line_ages annotate failed for {}", file_path) return [] if not annotated: @@ -296,7 +296,7 @@ class GitStore: ) return out.getvalue().decode("utf-8", errors="replace") except Exception: - logger.warning("Git diff_commits failed") + logger.exception("Git diff_commits failed") return "" def find_commit(self, short_sha: str, max_entries: int = 20) -> CommitInfo | None: @@ -367,7 +367,7 @@ class GitStore: msg = f"revert: undo {commit}" return self.auto_commit(msg) except Exception: - logger.warning("Git revert failed for {}", commit) + logger.exception("Git revert failed for {}", commit) return None @staticmethod diff --git a/nanobot/utils/helpers.py b/nanobot/utils/helpers.py index 0afe193cc..b047e24d2 100644 --- a/nanobot/utils/helpers.py +++ b/nanobot/utils/helpers.py @@ -268,8 +268,8 @@ def maybe_persist_tool_result( bucket = ensure_dir(root / safe_filename(session_key or "default")) try: _cleanup_tool_result_buckets(root, bucket) - except Exception as exc: - logger.warning("Failed to clean stale tool result buckets in {}: {}", root, exc) + except Exception: + logger.exception("Failed to clean stale tool result buckets in {}", root) path = bucket / f"{safe_filename(tool_call_id)}.{suffix}" if not path.exists(): if suffix == "json" and isinstance(content, list): @@ -540,6 +540,6 @@ def sync_workspace_templates(workspace: Path, silent: bool = False) -> list[str] ) gs.init() except Exception: - logger.warning("Failed to initialize git store for {}", workspace) + logger.exception("Failed to initialize git store for {}", workspace) return added diff --git a/nanobot/utils/logging_bridge.py b/nanobot/utils/logging_bridge.py new file mode 100644 index 000000000..a20e2e888 --- /dev/null +++ b/nanobot/utils/logging_bridge.py @@ -0,0 +1,47 @@ +"""Utilities for redirecting stdlib logging to loguru.""" +from __future__ import annotations + +import logging + +from loguru import logger + + +class _LoguruBridge(logging.Handler): + """Route stdlib log records into loguru with consistent formatting.""" + + _LEVEL_MAP: dict[int, str] = { + logging.DEBUG: "DEBUG", + logging.INFO: "INFO", + logging.WARNING: "WARNING", + logging.ERROR: "ERROR", + logging.CRITICAL: "CRITICAL", + } + + def __init__(self, lib_name: str) -> None: + super().__init__() + self.lib_name = lib_name + + def emit(self, record: logging.LogRecord) -> None: + level = self._LEVEL_MAP.get(record.levelno, "INFO") + frame, depth = logging.currentframe(), 2 + while frame and frame.f_code.co_filename == logging.__file__: + frame, depth = frame.f_back, depth + 1 + logger.opt(depth=depth, exception=record.exc_info).log( + level, "[{lib}] {message}", lib=self.lib_name, message=record.getMessage() + ) + + +def redirect_lib_logging(name: str, level: str | None = None) -> None: + """Redirect stdlib logging from *name* into loguru. + + Adds a bridge handler if one is not already present and disables + propagation so messages are not duplicated. When *level* is None the + handler does not filter — loguru's own level controls visibility. + """ + lib_logger = logging.getLogger(name) + if not any(isinstance(h, _LoguruBridge) for h in lib_logger.handlers): + handler = _LoguruBridge(name) + if level is not None: + handler.setLevel(getattr(logging, level.upper(), logging.WARNING)) + lib_logger.handlers = [handler] + lib_logger.propagate = False diff --git a/tests/agent/test_runner.py b/tests/agent/test_runner.py index 0be615cb9..b821d9bab 100644 --- a/tests/agent/test_runner.py +++ b/tests/agent/test_runner.py @@ -643,7 +643,7 @@ def test_persist_tool_result_logs_cleanup_failures(monkeypatch, tmp_path): lambda *_args, **_kwargs: (_ for _ in ()).throw(OSError("busy")), ) monkeypatch.setattr( - "nanobot.utils.helpers.logger.warning", + "nanobot.utils.helpers.logger.exception", lambda message, *args: warnings.append(message.format(*args)), ) diff --git a/tests/channels/test_telegram_channel.py b/tests/channels/test_telegram_channel.py index 2ae5cce9f..95865096c 100644 --- a/tests/channels/test_telegram_channel.py +++ b/tests/channels/test_telegram_channel.py @@ -306,17 +306,19 @@ async def test_on_error_logs_network_issues_as_warning(monkeypatch) -> None: recorded: list[tuple[str, str]] = [] monkeypatch.setattr( - "nanobot.channels.telegram.logger.warning", + channel.logger, + "warning", lambda message, error: recorded.append(("warning", message.format(error))), ) monkeypatch.setattr( - "nanobot.channels.telegram.logger.error", + channel.logger, + "error", lambda message, error: recorded.append(("error", message.format(error))), ) await channel._on_error(object(), SimpleNamespace(error=NetworkError("proxy disconnected"))) - assert recorded == [("warning", "Telegram network issue: proxy disconnected")] + assert recorded == [("warning", "network issue: proxy disconnected")] @pytest.mark.asyncio @@ -330,13 +332,14 @@ async def test_on_error_summarizes_empty_network_error(monkeypatch) -> None: recorded: list[tuple[str, str]] = [] monkeypatch.setattr( - "nanobot.channels.telegram.logger.warning", + channel.logger, + "warning", lambda message, error: recorded.append(("warning", message.format(error))), ) await channel._on_error(object(), SimpleNamespace(error=NetworkError(""))) - assert recorded == [("warning", "Telegram network issue: NetworkError")] + assert recorded == [("warning", "network issue: NetworkError")] @pytest.mark.asyncio @@ -348,17 +351,19 @@ async def test_on_error_keeps_non_network_exceptions_as_error(monkeypatch) -> No recorded: list[tuple[str, str]] = [] monkeypatch.setattr( - "nanobot.channels.telegram.logger.warning", + channel.logger, + "warning", lambda message, error: recorded.append(("warning", message.format(error))), ) monkeypatch.setattr( - "nanobot.channels.telegram.logger.error", + channel.logger, + "error", lambda message, error: recorded.append(("error", message.format(error))), ) await channel._on_error(object(), SimpleNamespace(error=RuntimeError("boom"))) - assert recorded == [("error", "Telegram error: boom")] + assert recorded == [("error", "error: boom")] @pytest.mark.asyncio diff --git a/tests/test_msteams.py b/tests/test_msteams.py index 0671f9f58..fd71018b1 100644 --- a/tests/test_msteams.py +++ b/tests/test_msteams.py @@ -835,7 +835,7 @@ async def test_start_logs_install_hint_when_pyjwt_missing(make_channel, monkeypa ch = make_channel() errors = [] monkeypatch.setattr(msteams_module, "MSTEAMS_AVAILABLE", False) - monkeypatch.setattr(msteams_module.logger, "error", lambda message, *args: errors.append(message.format(*args))) + monkeypatch.setattr(ch.logger, "error", lambda message, *args: errors.append(message.format(*args))) await ch.start() diff --git a/tests/tools/test_mcp_tool.py b/tests/tools/test_mcp_tool.py index 66f7b19a8..de39d1a67 100644 --- a/tests/tools/test_mcp_tool.py +++ b/tests/tools/test_mcp_tool.py @@ -467,7 +467,7 @@ async def test_connect_mcp_servers_logs_stdio_pollution_hint( yield # pragma: no cover monkeypatch.setattr(sys.modules["mcp.client.stdio"], "stdio_client", _broken_stdio_client) - monkeypatch.setattr("nanobot.agent.tools.mcp.logger.error", _error) + monkeypatch.setattr("nanobot.agent.tools.mcp.logger.exception", _error) registry = ToolRegistry() stacks = await connect_mcp_servers({"gh": MCPServerConfig(command="github-mcp")}, registry) From 653de4a7efde76aead9de8e631df2c778c3a1460 Mon Sep 17 00:00:00 2001 From: hanyuanling Date: Wed, 6 May 2026 14:45:20 +0800 Subject: [PATCH 2/6] fix(agent): gate provider progress deltas --- nanobot/agent/loop.py | 1 + nanobot/agent/runner.py | 2 + tests/agent/test_loop_progress.py | 73 ++++++++++++++++---- tests/agent/test_runner_progress_deltas.py | 79 ++++++++++++++++++++++ 4 files changed, 142 insertions(+), 13 deletions(-) create mode 100644 tests/agent/test_runner_progress_deltas.py diff --git a/nanobot/agent/loop.py b/nanobot/agent/loop.py index d5e7681f1..07006b057 100644 --- a/nanobot/agent/loop.py +++ b/nanobot/agent/loop.py @@ -649,6 +649,7 @@ class AgentLoop: context_block_limit=self.context_block_limit, provider_retry_mode=self.provider_retry_mode, progress_callback=on_progress, + stream_progress_deltas=on_stream is not None, retry_wait_callback=on_retry_wait, checkpoint_callback=_checkpoint, injection_callback=_drain_pending, diff --git a/nanobot/agent/runner.py b/nanobot/agent/runner.py index b81df4168..7fe92ad51 100644 --- a/nanobot/agent/runner.py +++ b/nanobot/agent/runner.py @@ -76,6 +76,7 @@ class AgentRunSpec: context_block_limit: int | None = None provider_retry_mode: str = "standard" progress_callback: Any | None = None + stream_progress_deltas: bool = True retry_wait_callback: Any | None = None checkpoint_callback: Any | None = None injection_callback: Any | None = None @@ -615,6 +616,7 @@ class AgentRunner: wants_streaming = hook.wants_streaming() wants_progress_streaming = ( not wants_streaming + and spec.stream_progress_deltas and spec.progress_callback is not None and getattr(self.provider, "supports_progress_deltas", False) is True ) diff --git a/tests/agent/test_loop_progress.py b/tests/agent/test_loop_progress.py index d08448992..47a63ba02 100644 --- a/tests/agent/test_loop_progress.py +++ b/tests/agent/test_loop_progress.py @@ -130,11 +130,44 @@ class TestToolEventProgress: assert finish["result"] == "file.txt" @pytest.mark.asyncio - async def test_bus_progress_streams_provider_deltas_for_codex_style_provider( + async def test_non_streaming_channel_does_not_publish_codex_progress_deltas( self, tmp_path: Path, ) -> None: - """Providers that opt in can stream content deltas through _progress messages.""" + """Non-streaming channels should get one final reply, not token progress spam.""" + bus = MessageBus() + provider = MagicMock() + provider.supports_progress_deltas = True + provider.get_default_model.return_value = "openai-codex/gpt-5.5" + provider.chat_with_retry = AsyncMock(return_value=LLMResponse(content="Hello", tool_calls=[])) + provider.chat_stream_with_retry = AsyncMock() + loop = AgentLoop(bus=bus, provider=provider, workspace=tmp_path, model="openai-codex/gpt-5.5") + loop.tools.get_definitions = MagicMock(return_value=[]) + loop.consolidator.maybe_consolidate_by_tokens = AsyncMock(return_value=False) # type: ignore[method-assign] + + await loop._dispatch(InboundMessage( + channel="whatsapp", + sender_id="u1", + chat_id="chat1", + content="say hello", + )) + + outbound = [] + while bus.outbound_size > 0: + outbound.append(await bus.consume_outbound()) + + assert [m.content for m in outbound] == ["Hello"] + assert not any(m.metadata.get("_progress") for m in outbound) + assert not any(m.metadata.get("_streamed") for m in outbound) + provider.chat_stream_with_retry.assert_not_awaited() + provider.chat_with_retry.assert_awaited_once() + + @pytest.mark.asyncio + async def test_streaming_channel_streams_provider_deltas_for_codex_style_provider( + self, + tmp_path: Path, + ) -> None: + """Streaming channels still receive provider deltas through _stream_delta messages.""" bus = MessageBus() provider = MagicMock() provider.supports_progress_deltas = True @@ -156,18 +189,27 @@ class TestToolEventProgress: sender_id="u1", chat_id="chat1", content="say hello", + metadata={"_wants_stream": True}, )) outbound = [] while bus.outbound_size > 0: outbound.append(await bus.consume_outbound()) - progress = [m for m in outbound if m.metadata.get("_progress")] - final = [m for m in outbound if not m.metadata.get("_progress")] + deltas = [m for m in outbound if m.metadata.get("_stream_delta")] + stream_end = [m for m in outbound if m.metadata.get("_stream_end")] + final = [ + m for m in outbound + if not m.metadata.get("_stream_delta") + and not m.metadata.get("_stream_end") + and not m.metadata.get("_turn_end") + ] - assert [m.content for m in progress] == ["Hel", "lo"] - assert final[-2].content == "Hello" - assert (final[-1].metadata or {}).get("_turn_end") is True + assert [m.content for m in deltas] == ["Hel", "lo"] + assert len(stream_end) == 1 + assert final[-1].content == "Hello" + assert final[-1].metadata.get("_streamed") is True + assert outbound[-1].metadata.get("_turn_end") is True provider.chat_with_retry.assert_not_awaited() @pytest.mark.asyncio @@ -197,8 +239,12 @@ class TestToolEventProgress: loop.tools.prepare_call = MagicMock(return_value=(None, {"path": "foo.txt"}, None)) loop.tools.execute = AsyncMock(return_value="ok") + streamed: list[str] = [] progress: list[tuple[str, bool, list[dict] | None]] = [] + async def on_stream(delta: str) -> None: + streamed.append(delta) + async def on_progress( content: str, *, @@ -207,14 +253,15 @@ class TestToolEventProgress: ) -> None: progress.append((content, tool_hint, tool_events)) - final_content, _, _, _, _ = await loop._run_agent_loop([], on_progress=on_progress) + final_content, _, _, _, _ = await loop._run_agent_loop( + [], + on_progress=on_progress, + on_stream=on_stream, + ) assert final_content == "Done" - assert [item[0] for item in progress[:3]] == [ - "I will", - " inspect it.", - 'custom_tool("foo.txt")', - ] + assert streamed == ["I will", " inspect it."] + assert progress[0][0] == 'custom_tool("foo.txt")' assert all(item[0] != "I will inspect it." for item in progress) @pytest.mark.asyncio diff --git a/tests/agent/test_runner_progress_deltas.py b/tests/agent/test_runner_progress_deltas.py new file mode 100644 index 000000000..13d5ea799 --- /dev/null +++ b/tests/agent/test_runner_progress_deltas.py @@ -0,0 +1,79 @@ +"""Tests for provider progress delta routing in the shared runner.""" + +from unittest.mock import AsyncMock, MagicMock + +import pytest + +from nanobot.agent.runner import AgentRunner, AgentRunSpec +from nanobot.config.schema import AgentDefaults +from nanobot.providers.base import LLMResponse + +_MAX_TOOL_RESULT_CHARS = AgentDefaults().max_tool_result_chars + + +@pytest.mark.asyncio +async def test_runner_can_disable_provider_progress_delta_streaming(): + """AgentLoop disables token progress streaming for non-streaming channels.""" + provider = MagicMock() + provider.supports_progress_deltas = True + provider.chat_with_retry = AsyncMock( + return_value=LLMResponse(content="done", tool_calls=[], usage={}) + ) + provider.chat_stream_with_retry = AsyncMock() + tools = MagicMock() + tools.get_definitions.return_value = [] + progress_cb = AsyncMock() + + runner = AgentRunner(provider) + result = await runner.run(AgentRunSpec( + initial_messages=[ + {"role": "system", "content": "system"}, + {"role": "user", "content": "hi"}, + ], + tools=tools, + model="test-model", + max_iterations=1, + max_tool_result_chars=_MAX_TOOL_RESULT_CHARS, + progress_callback=progress_cb, + stream_progress_deltas=False, + )) + + assert result.final_content == "done" + provider.chat_with_retry.assert_awaited_once() + provider.chat_stream_with_retry.assert_not_awaited() + progress_cb.assert_not_awaited() + + +@pytest.mark.asyncio +async def test_runner_streams_provider_progress_deltas_by_default(): + """Direct runner users keep the existing opt-in provider progress behavior.""" + provider = MagicMock() + provider.supports_progress_deltas = True + + async def chat_stream_with_retry(*, on_content_delta, **kwargs): + await on_content_delta("he") + await on_content_delta("llo") + return LLMResponse(content="hello", tool_calls=[], usage={}) + + provider.chat_stream_with_retry = chat_stream_with_retry + provider.chat_with_retry = AsyncMock() + tools = MagicMock() + tools.get_definitions.return_value = [] + progress_cb = AsyncMock() + + runner = AgentRunner(provider) + result = await runner.run(AgentRunSpec( + initial_messages=[ + {"role": "system", "content": "system"}, + {"role": "user", "content": "hi"}, + ], + tools=tools, + model="test-model", + max_iterations=1, + max_tool_result_chars=_MAX_TOOL_RESULT_CHARS, + progress_callback=progress_cb, + )) + + assert result.final_content == "hello" + assert [call.args[0] for call in progress_cb.await_args_list] == ["he", "llo"] + provider.chat_with_retry.assert_not_awaited() From daa4a25c9b83d08eca93afacbbfd896cafe056df Mon Sep 17 00:00:00 2001 From: Tim O'Brien Date: Mon, 4 May 2026 17:56:49 +0000 Subject: [PATCH 3/6] feat(config): add toolHintMaxLength to control tool hint truncation MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Add to config (default: 40, range: 20-500). Controls how many characters of tool hints are shown in progress updates (e.g. '$ cd …/project && npm test'). Set to 120+ to see full commands instead of truncated hints: ```json { "agents": { "defaults": { "toolHintMaxLength": 120 } } } ``` - Thread max_length through format_tool_hints → _fmt_known/_fmt_mcp/_fmt_fallback - Make path abbreviation in _abbreviate_command proportional to max_length - Add TestToolHintMaxLength test class with 5 tests - All 41 existing tests pass --- nanobot/agent/loop.py | 6 +++--- nanobot/config/schema.py | 7 +++++++ nanobot/utils/tool_hints.py | 28 +++++++++++++------------ tests/agent/test_tool_hint.py | 39 +++++++++++++++++++++++++++++++++-- 4 files changed, 62 insertions(+), 18 deletions(-) diff --git a/nanobot/agent/loop.py b/nanobot/agent/loop.py index 07006b057..984711975 100644 --- a/nanobot/agent/loop.py +++ b/nanobot/agent/loop.py @@ -242,6 +242,7 @@ class AgentLoop: else defaults.max_tool_result_chars ) self.provider_retry_mode = provider_retry_mode + self.tool_hint_max_length = defaults.tool_hint_max_length self.web_config = web_config or WebToolsConfig() self.exec_config = exec_config or ExecToolConfig() self.cron_service = cron_service @@ -471,12 +472,11 @@ class AgentLoop: """Return the chat id shown in runtime metadata for the model.""" return str(msg.metadata.get("context_chat_id") or msg.chat_id) - @staticmethod - def _tool_hint(tool_calls: list) -> str: + def _tool_hint(self, tool_calls: list) -> str: """Format tool calls as concise hints with smart abbreviation.""" from nanobot.utils.tool_hints import format_tool_hints - return format_tool_hints(tool_calls) + return format_tool_hints(tool_calls, max_length=self.tool_hint_max_length) async def _dispatch_command_inline( self, diff --git a/nanobot/config/schema.py b/nanobot/config/schema.py index 2f20eb99e..aa8b0a5e5 100644 --- a/nanobot/config/schema.py +++ b/nanobot/config/schema.py @@ -81,6 +81,13 @@ class AgentDefaults(Base): max_concurrent_subagents: int = Field(default=1, ge=1) max_tool_result_chars: int = 16_000 provider_retry_mode: Literal["standard", "persistent"] = "standard" + tool_hint_max_length: int = Field( + default=40, + ge=20, + le=500, + validation_alias=AliasChoices("toolHintMaxLength"), + serialization_alias="toolHintMaxLength", + ) # Max characters for tool hint display (e.g. "$ cd …/project && npm test") reasoning_effort: str | None = None # low / medium / high / adaptive - enables LLM thinking mode timezone: str = "UTC" # IANA timezone, e.g. "Asia/Shanghai", "America/New_York" unified_session: bool = False # Share one session across all channels (single-user multi-device) diff --git a/nanobot/utils/tool_hints.py b/nanobot/utils/tool_hints.py index 9758700b1..75d3e3521 100644 --- a/nanobot/utils/tool_hints.py +++ b/nanobot/utils/tool_hints.py @@ -27,7 +27,7 @@ _PATH_IN_CMD_RE = re.compile( ) -def format_tool_hints(tool_calls: list) -> str: +def format_tool_hints(tool_calls: list, max_length: int = 40) -> str: """Format tool calls as concise hints with smart abbreviation.""" if not tool_calls: return "" @@ -36,11 +36,11 @@ def format_tool_hints(tool_calls: list) -> str: for tc in tool_calls: fmt = _TOOL_FORMATS.get(tc.name) if fmt: - formatted.append(_fmt_known(tc, fmt)) + formatted.append(_fmt_known(tc, fmt, max_length)) elif tc.name.startswith("mcp_"): - formatted.append(_fmt_mcp(tc)) + formatted.append(_fmt_mcp(tc, max_length)) else: - formatted.append(_fmt_fallback(tc)) + formatted.append(_fmt_fallback(tc, max_length)) hints = [] for hint in formatted: @@ -80,7 +80,7 @@ def _extract_arg(tc, key_args: list[str]) -> str | None: return None -def _fmt_known(tc, fmt: tuple) -> str: +def _fmt_known(tc, fmt: tuple, max_length: int = 40) -> str: """Format a registered tool using its template.""" val = _extract_arg(tc, fmt[0]) if val is None: @@ -88,18 +88,20 @@ def _fmt_known(tc, fmt: tuple) -> str: if fmt[2]: # is_path val = abbreviate_path(val) elif fmt[3]: # is_command - val = _abbreviate_command(val) + val = _abbreviate_command(val, max_len=max_length) return fmt[1].format(val) def _abbreviate_command(cmd: str, max_len: int = 40) -> str: """Abbreviate paths in a command string, then truncate.""" + path_max = max(max_len // 2, 25) + def _replace_path(match: re.Match[str]) -> str: if match.group("double") is not None: - return f'"{abbreviate_path(match.group("double"), max_len=25)}"' + return f'"{abbreviate_path(match.group("double"), max_len=path_max)}"' if match.group("single") is not None: - return f"'{abbreviate_path(match.group('single'), max_len=25)}'" - return abbreviate_path(match.group("bare"), max_len=25) + return f"'{abbreviate_path(match.group('single'), max_len=path_max)}'" + return abbreviate_path(match.group("bare"), max_len=path_max) abbreviated = _PATH_IN_CMD_RE.sub(_replace_path, cmd) if len(abbreviated) <= max_len: @@ -107,7 +109,7 @@ def _abbreviate_command(cmd: str, max_len: int = 40) -> str: return abbreviated[:max_len - 1] + "\u2026" -def _fmt_mcp(tc) -> str: +def _fmt_mcp(tc, max_length: int = 40) -> str: """Format MCP tool as server::tool.""" name = tc.name if "__" in name: @@ -125,13 +127,13 @@ def _fmt_mcp(tc) -> str: val = next((v for v in args.values() if isinstance(v, str) and v), None) if val is None: return f"{server}::{tool}" - return f'{server}::{tool}("{abbreviate_path(val, 40)}")' + return f'{server}::{tool}("{abbreviate_path(val, max_length)}")' -def _fmt_fallback(tc) -> str: +def _fmt_fallback(tc, max_length: int = 40) -> str: """Original formatting logic for unregistered tools.""" args = _get_args(tc) val = next(iter(args.values()), None) if isinstance(args, dict) else None if not isinstance(val, str): return tc.name - return f'{tc.name}("{abbreviate_path(val, 40)}")' if len(val) > 40 else f'{tc.name}("{val}")' + return f'{tc.name}("{abbreviate_path(val, max_length)}")' if len(val) > max_length else f'{tc.name}("{val}")' diff --git a/tests/agent/test_tool_hint.py b/tests/agent/test_tool_hint.py index b8ba99284..ff73fbb5c 100644 --- a/tests/agent/test_tool_hint.py +++ b/tests/agent/test_tool_hint.py @@ -8,9 +8,9 @@ def _tc(name: str, args) -> ToolCallRequest: return ToolCallRequest(id="c1", name=name, arguments=args) -def _hint(calls): +def _hint(calls, max_length=40): """Shortcut for format_tool_hints.""" - return format_tool_hints(calls) + return format_tool_hints(calls, max_length=max_length) class TestToolHintKnownTools: @@ -254,3 +254,38 @@ class TestToolHintMixedFolding: assert "\u00d7" not in result parts = result.split(", ") assert len(parts) == 5 + + +class TestToolHintMaxLength: + """Test max_length parameter controls truncation of tool hints.""" + + def test_exec_default_truncates_at_40(self): + cmd = "cd /very/long/path/to/some/project && npm run build && npm test" + result = _hint([_tc("exec", {"command": cmd})], max_length=40) + assert len(result) <= 50 # "$ " prefix + 40 + ellipsis + assert "\u2026" in result + + def test_exec_larger_max_length_shows_more(self): + cmd = "cd /very/long/path/to/some/project && npm run build && npm test" + short = _hint([_tc("exec", {"command": cmd})], max_length=40) + long = _hint([_tc("exec", {"command": cmd})], max_length=120) + assert len(long) > len(short) + assert "npm test" in long + + def test_exec_max_length_120_shows_full_command(self): + cmd = "cd /home/user/project && npm install && npm run build" + result = _hint([_tc("exec", {"command": cmd})], max_length=120) + assert "npm run build" in result + + def test_fallback_respects_max_length(self): + long_val = "a" * 100 + result = _hint([_tc("custom_tool", {"data": long_val})], max_length=60) + assert "\u2026" in result + result_40 = _hint([_tc("custom_tool", {"data": long_val})], max_length=40) + assert len(result) > len(result_40) + + def test_mcp_respects_max_length(self): + long_url = "https://example.com/very/long/path/to/resource" + result = _hint([_tc("mcp_github__fetch", {"url": long_url})], max_length=80) + result_40 = _hint([_tc("mcp_github__fetch", {"url": long_url})], max_length=40) + assert len(result) >= len(result_40) From 67875d7a15aeabb47d49a825ceb80995af7b9055 Mon Sep 17 00:00:00 2001 From: Tim O'Brien Date: Mon, 4 May 2026 18:14:45 +0000 Subject: [PATCH 4/6] fix: wire toolHintMaxLength through AgentLoop constructors The config field was added but never passed from config to AgentLoop. The value was always falling back to the default (40) regardless of what was set in config.json. Now passes tool_hint_max_length through all AgentLoop() call sites: - nanobot/nanobot.py (main bot) - nanobot/cli/commands.py (CLI agent, dev, webui commands) Also adds documentation in docs/configuration.md. --- docs/configuration.md | 20 ++++++++++++++++++++ nanobot/agent/loop.py | 6 +++++- nanobot/cli/commands.py | 3 +++ nanobot/nanobot.py | 1 + 4 files changed, 29 insertions(+), 1 deletion(-) diff --git a/docs/configuration.md b/docs/configuration.md index d0a7fe940..f5fb32cb7 100644 --- a/docs/configuration.md +++ b/docs/configuration.md @@ -1131,3 +1131,23 @@ Disabled skills are excluded from the main agent's skill summary, from always-on | Option | Default | Description | |--------|---------|-------------| | `agents.defaults.disabledSkills` | `[]` | List of skill directory names to exclude from loading. Applies to both built-in skills and workspace skills. | + +## Tool Hint Max Length + +Tool hints are the short progress messages shown when the agent calls tools (e.g. `$ cd …/project && npm test`). By default, these are truncated at 40 characters, which can make long commands hard to read. + +Set `agents.defaults.toolHintMaxLength` to control the truncation threshold: + +```json +{ + "agents": { + "defaults": { + "toolHintMaxLength": 120 + } + } +} +``` + +| Option | Default | Description | +|--------|---------|-------------| +| `agents.defaults.toolHintMaxLength` | `40` | Maximum characters for tool hint display. Range: 20–500. Higher values show more of the command or path; lower values keep hints compact. | diff --git a/nanobot/agent/loop.py b/nanobot/agent/loop.py index 984711975..784c4da13 100644 --- a/nanobot/agent/loop.py +++ b/nanobot/agent/loop.py @@ -198,6 +198,7 @@ class AgentLoop: context_block_limit: int | None = None, max_tool_result_chars: int | None = None, provider_retry_mode: str = "standard", + tool_hint_max_length: int | None = None, web_config: WebToolsConfig | None = None, exec_config: ExecToolConfig | None = None, cron_service: CronService | None = None, @@ -242,7 +243,10 @@ class AgentLoop: else defaults.max_tool_result_chars ) self.provider_retry_mode = provider_retry_mode - self.tool_hint_max_length = defaults.tool_hint_max_length + self.tool_hint_max_length = ( + tool_hint_max_length if tool_hint_max_length is not None + else defaults.tool_hint_max_length + ) self.web_config = web_config or WebToolsConfig() self.exec_config = exec_config or ExecToolConfig() self.cron_service = cron_service diff --git a/nanobot/cli/commands.py b/nanobot/cli/commands.py index c54a2bc7c..1f0186f1d 100644 --- a/nanobot/cli/commands.py +++ b/nanobot/cli/commands.py @@ -557,6 +557,7 @@ def serve( context_block_limit=runtime_config.agents.defaults.context_block_limit, max_tool_result_chars=runtime_config.agents.defaults.max_tool_result_chars, provider_retry_mode=runtime_config.agents.defaults.provider_retry_mode, + tool_hint_max_length=runtime_config.agents.defaults.tool_hint_max_length, web_config=runtime_config.tools.web, exec_config=runtime_config.tools.exec, restrict_to_workspace=runtime_config.tools.restrict_to_workspace, @@ -681,6 +682,7 @@ def _run_gateway( context_block_limit=config.agents.defaults.context_block_limit, max_tool_result_chars=config.agents.defaults.max_tool_result_chars, provider_retry_mode=config.agents.defaults.provider_retry_mode, + tool_hint_max_length=config.agents.defaults.tool_hint_max_length, exec_config=config.tools.exec, cron_service=cron, restrict_to_workspace=config.tools.restrict_to_workspace, @@ -1073,6 +1075,7 @@ def agent( context_block_limit=config.agents.defaults.context_block_limit, max_tool_result_chars=config.agents.defaults.max_tool_result_chars, provider_retry_mode=config.agents.defaults.provider_retry_mode, + tool_hint_max_length=config.agents.defaults.tool_hint_max_length, exec_config=config.tools.exec, cron_service=cron, restrict_to_workspace=config.tools.restrict_to_workspace, diff --git a/nanobot/nanobot.py b/nanobot/nanobot.py index 5e5857595..60c6dcdcb 100644 --- a/nanobot/nanobot.py +++ b/nanobot/nanobot.py @@ -76,6 +76,7 @@ class Nanobot: context_block_limit=defaults.context_block_limit, max_tool_result_chars=defaults.max_tool_result_chars, provider_retry_mode=defaults.provider_retry_mode, + tool_hint_max_length=defaults.tool_hint_max_length, web_config=config.tools.web, exec_config=config.tools.exec, restrict_to_workspace=config.tools.restrict_to_workspace, From 99209a806dcdff9537fd3caa7ac4e6794ef4b15a Mon Sep 17 00:00:00 2001 From: Tim O'Brien Date: Wed, 6 May 2026 05:39:55 +0000 Subject: [PATCH 5/6] fix(tool_hints): pass max_length to abbreviate_path for is_path tools The is_path branch in _fmt_known was not passing max_length to abbreviate_path, so read_file, write_file, edit, list_dir, and web_fetch always truncated paths at 40 chars regardless of config. Now all three branches (is_path, is_command, fallback) honor the configured toolHintMaxLength. --- nanobot/utils/tool_hints.py | 2 +- tests/agent/test_tool_hint.py | 21 +++++++++++++++++++++ 2 files changed, 22 insertions(+), 1 deletion(-) diff --git a/nanobot/utils/tool_hints.py b/nanobot/utils/tool_hints.py index 75d3e3521..289870665 100644 --- a/nanobot/utils/tool_hints.py +++ b/nanobot/utils/tool_hints.py @@ -86,7 +86,7 @@ def _fmt_known(tc, fmt: tuple, max_length: int = 40) -> str: if val is None: return tc.name if fmt[2]: # is_path - val = abbreviate_path(val) + val = abbreviate_path(val, max_len=max_length) elif fmt[3]: # is_command val = _abbreviate_command(val, max_len=max_length) return fmt[1].format(val) diff --git a/tests/agent/test_tool_hint.py b/tests/agent/test_tool_hint.py index ff73fbb5c..174eb208d 100644 --- a/tests/agent/test_tool_hint.py +++ b/tests/agent/test_tool_hint.py @@ -289,3 +289,24 @@ class TestToolHintMaxLength: result = _hint([_tc("mcp_github__fetch", {"url": long_url})], max_length=80) result_40 = _hint([_tc("mcp_github__fetch", {"url": long_url})], max_length=40) assert len(result) >= len(result_40) + + def test_path_type_respects_max_length(self): + """Path-type tools (read_file, write_file, etc.) should honor max_length.""" + long_path = "/home/user/.local/share/uv/tools/nanobot/agent/loop.py" + short = _hint([_tc("read_file", {"path": long_path})], max_length=40) + long = _hint([_tc("read_file", {"path": long_path})], max_length=120) + assert len(long) > len(short) + + def test_edit_path_respects_max_length(self): + """edit (is_path=True) should honor max_length, not stay hardcoded at 40.""" + long_path = "/home/user/projects/nanobot/src/agent/loop.py" + short = _hint([_tc("edit", {"file_path": long_path})], max_length=40) + long = _hint([_tc("edit", {"file_path": long_path})], max_length=120) + assert len(long) > len(short) + + def test_list_dir_path_respects_max_length(self): + """list_dir (is_path=True) should honor max_length.""" + long_path = "/home/user/.local/share/uv/tools/nanobot/" + short = _hint([_tc("list_dir", {"path": long_path})], max_length=40) + long = _hint([_tc("list_dir", {"path": long_path})], max_length=120) + assert len(long) > len(short) From 4fad19dc174768938e53e4bd7b2ea8c4d1a27f8b Mon Sep 17 00:00:00 2001 From: chengyongru Date: Wed, 6 May 2026 13:28:48 +0800 Subject: [PATCH 6/6] fix: use sequential MCP server connections to prevent CPU spin asyncio.create_task in connect_mcp_servers creates child tasks for each MCP server, but close_mcp calls stack.aclose() from the main task. anyio CancelScope requires enter/exit in the same task, so the cross-task exit raises RuntimeError which gets silently caught. The orphaned cancel scope keeps retrying via call_soon on every event loop tick, consuming 100% CPU. Fix: remove create_task/gather and connect servers sequentially in the caller task. MCP servers are typically 1-2, so parallel connection provides negligible benefit while introducing the cancel scope hazard. Closes #3638 --- nanobot/agent/tools/mcp.py | 22 ++++++++-------------- 1 file changed, 8 insertions(+), 14 deletions(-) diff --git a/nanobot/agent/tools/mcp.py b/nanobot/agent/tools/mcp.py index 04b88386f..6d4e7d6cd 100644 --- a/nanobot/agent/tools/mcp.py +++ b/nanobot/agent/tools/mcp.py @@ -436,8 +436,8 @@ async def connect_mcp_servers( """Connect to configured MCP servers and register their tools, resources, prompts. Returns a dict mapping server name -> its dedicated AsyncExitStack. - Each server gets its own stack and runs in its own task to prevent - cancel scope conflicts when multiple MCP servers are configured. + Each server gets its own stack to prevent cancel scope conflicts + when multiple MCP servers are configured. """ from mcp import ClientSession, StdioServerParameters from mcp.client.sse import sse_client @@ -612,19 +612,13 @@ async def connect_mcp_servers( server_stacks: dict[str, AsyncExitStack] = {} - tasks: list[asyncio.Task] = [] for name, cfg in mcp_servers.items(): - task = asyncio.create_task(connect_single_server(name, cfg)) - tasks.append(task) - - results = await asyncio.gather(*tasks, return_exceptions=True) - - for i, result in enumerate(results): - name = list(mcp_servers.keys())[i] - if isinstance(result, BaseException): - if not isinstance(result, asyncio.CancelledError): - logger.error("MCP server '{}' connection task failed: {}", name, result) - elif result is not None and result[1] is not None: + try: + result = await connect_single_server(name, cfg) + except Exception as e: + logger.error("MCP server '{}' connection failed: {}", name, e) + continue + if result is not None and result[1] is not None: server_stacks[result[0]] = result[1] return server_stacks