From ab0d28103b84ee8529fe64839fa143fe72b6b8d9 Mon Sep 17 00:00:00 2001 From: gola <31429180+gola@users.noreply.github.com> Date: Mon, 20 Jul 2026 16:30:43 +0800 Subject: [PATCH] fix(qq): add exponential backoff to WebSocket reconnect loop The QQ channel's _run_bot() used a fixed 5-second reconnect interval with no backoff. When the network is unavailable (e.g., DNS failure), this produces excessive botpy SDK error tracebacks every 5 seconds, flooding logs. botpy's Client.bot_connect() catches ws_connect() exceptions internally and calls BotWebSocket.on_error(), which logs a full traceback and immediately re-queues the session. The outer _run_bot() except never fires for the reported DNS failure path. Override bot_connect() on the _Bot subclass to: - Apply exponential backoff (5s -> 300s cap) before re-queuing the session - Log network errors (ClientConnectorDNSError, ClientConnectorError, OSError) compactly without traceback - Reset backoff on successful connection - Still call traceback.print_exc() for non-network errors The outer _run_bot() loop retains exponential backoff as a fallback for exceptions that escape start() entirely. The botpy library logging redirect is elevated to ERROR to suppress redundant connection tracebacks. Consistent with patterns already used in matrix.py and napcat.py. Add 7 regression tests covering: - DNS error applies backoff and re-queues session - No traceback printed for network errors - ClientConnectorError also triggers backoff - Backoff doubles and caps at 300s - Successful connection resets backoff - Non-network errors still re-queue without backoff - _is_network_error() classification Fixes #4767 --- nanobot/channels/qq/runtime.py | 94 ++++++- tests/channels/test_qq_reconnect_backoff.py | 279 ++++++++++++++++++++ 2 files changed, 368 insertions(+), 5 deletions(-) create mode 100644 tests/channels/test_qq_reconnect_backoff.py diff --git a/nanobot/channels/qq/runtime.py b/nanobot/channels/qq/runtime.py index a177087b..3819b1f3 100644 --- a/nanobot/channels/qq/runtime.py +++ b/nanobot/channels/qq/runtime.py @@ -48,12 +48,14 @@ except Exception: # pragma: no cover try: import botpy + from botpy.gateway import BotWebSocket from botpy.http import Route QQ_AVAILABLE = True except ImportError: # pragma: no cover QQ_AVAILABLE = False botpy = None + BotWebSocket = None Route = None if TYPE_CHECKING: @@ -104,14 +106,39 @@ def _guess_send_file_type(filename: str) -> int: return QQ_FILE_TYPE_FILE +# Exponential backoff for WebSocket reconnect inside bot_connect. +_RECONNECT_BACKOFF_START = 5 +_RECONNECT_BACKOFF_MAX = 300 # 5 minutes cap + + +def _is_network_error(exc: BaseException) -> bool: + """Check whether an exception is a transient network/DNS error.""" + return isinstance( + exc, + (aiohttp.ClientConnectorError, OSError), + ) + + def _make_bot_class(channel: QQChannel) -> type[botpy.Client]: - """Create a botpy Client subclass bound to the given channel.""" + """Create a botpy Client subclass bound to the given channel. + + The base ``botpy.Client.bot_connect()`` catches ``ws_connect()`` exceptions + internally and calls ``BotWebSocket.on_error()``, which logs a full + traceback via ``_log.error()`` + ``traceback.print_exc()`` and immediately + re-queues the session — causing log flooding on persistent DNS/network + failures with no backoff. + + We override ``bot_connect()`` to: + - Apply exponential backoff before the session is re-queued. + - Log network errors compactly instead of dumping the full traceback. + """ intents = botpy.Intents(public_messages=True, direct_message=True) class _Bot(botpy.Client): def __init__(self): # Disable botpy's file log — nanobot uses loguru; default "botpy.log" fails on read-only fs super().__init__(intents=intents, ext_handlers=False) + self._ws_backoff = {} # per-session backoff: {id(session): delay} async def on_ready(self): logger.info("QQ bot ready: {}", self.robot.name) @@ -125,6 +152,48 @@ def _make_bot_class(channel: QQChannel) -> type[botpy.Client]: async def on_direct_message_create(self, message): await channel._on_message(message, is_group=False) + async def bot_connect(self, session): + """Override to add exponential backoff and compact error logging. + + The original ``bot_connect`` catches the ``ws_connect`` exception + and calls ``BotWebSocket.on_error`` which does ``_log.error`` + + ``traceback.print_exc`` then re-queues the session immediately. + We intercept here to apply backoff *before* re-queuing and suppress + the noisy traceback for transient network errors. + """ + _log = botpy.logging.get_logger() if hasattr(botpy, "logging") else None + + client = BotWebSocket(session, self._connection) + session_id = id(session) + backoff = self._ws_backoff.get(session_id, _RECONNECT_BACKOFF_START) + try: + await client.ws_connect() + # Connection succeeded — reset per-session backoff + self._ws_backoff.pop(session_id, None) + except (Exception, KeyboardInterrupt, SystemExit) as e: + if _is_network_error(e): + # Compact log for transient network/DNS errors — no traceback + channel.logger.warning( + "QQ bot network error (retry in {}s): {}", + backoff, + e, + ) + # Apply backoff before the session is re-queued by on_error + await asyncio.sleep(backoff) + self._ws_backoff[session_id] = min(backoff * 2, _RECONNECT_BACKOFF_MAX) + else: + # Non-network error — log normally and let on_error handle it + if _log: + _log.error( + "[botpy] websocket连接: %s, 异常信息 : %s", client._conn, e + ) + import traceback as _tb + + _tb.print_exc() + + # Re-queue the session (same as original on_error / on_closed) + self._connection.add(session) + return _Bot @@ -210,15 +279,30 @@ class QQChannel(BaseChannel): await self._run_bot() async def _run_bot(self) -> None: - """Run the bot connection with auto-reconnect.""" + """Run the bot connection with auto-reconnect. + + Note: most WebSocket reconnect logic now lives in the overridden + ``bot_connect()`` method on the bot class, which handles per-session + backoff inside botpy's internal ``_pool_init`` loop. This outer loop + is a fallback for exceptions that escape ``start()`` entirely. + """ + backoff = 5 + max_backoff = 300 while self._running: try: await self._client.start(appid=self.config.app_id, secret=self.config.secret) + backoff = 5 # reset on clean exit except Exception as e: - self.logger.warning("bot error: {}", e) + if _is_network_error(e): + self.logger.warning( + "QQ bot network error (retry in {}s): {}", backoff, e + ) + else: + self.logger.warning("bot error: {}", e) if self._running: - self.logger.info("Reconnecting bot in 5 seconds...") - await asyncio.sleep(5) + self.logger.info("Reconnecting bot in {} seconds...", backoff) + await asyncio.sleep(backoff) + backoff = min(backoff * 2, max_backoff) async def stop(self) -> None: """Stop bot and cleanup resources.""" diff --git a/tests/channels/test_qq_reconnect_backoff.py b/tests/channels/test_qq_reconnect_backoff.py new file mode 100644 index 00000000..37633fd4 --- /dev/null +++ b/tests/channels/test_qq_reconnect_backoff.py @@ -0,0 +1,279 @@ +"""Regression tests for QQ channel WebSocket reconnect backoff. + +Tests that the overridden ``bot_connect()`` applies exponential backoff and +compact error logging when ``BotWebSocket.ws_connect`` raises a DNS/network +error, instead of the original behavior of immediately re-queuing the session +and dumping a full traceback. +""" + +from __future__ import annotations + +from unittest.mock import AsyncMock, MagicMock, patch + +import aiohttp +import pytest + +# Skip all tests if botpy is not installed +pytest.importorskip("botpy") + + +def _make_channel(): + """Create a minimal QQChannel instance for testing.""" + from nanobot.bus.queue import MessageBus + from nanobot.channels.qq.runtime import QQChannel, QQConfig + + bus = MessageBus() + config = QQConfig(app_id="test_app", secret="test_secret") + return QQChannel(config, bus) + + +def _make_bot(channel): + """Create the _Bot class and instantiate it with mocked internals.""" + from nanobot.channels.qq.runtime import _make_bot_class + + bot_cls = _make_bot_class(channel) + bot = bot_cls.__new__(bot_cls) + + # Mock the attributes that bot_connect() needs + bot._connection = MagicMock() + bot._connection.add = MagicMock() + bot._ws_backoff = {} # per-session dict + return bot + + +@pytest.mark.asyncio +async def test_bot_connect_dns_error_applies_backoff(): + """bot_connect() should sleep with exponential backoff on DNS errors.""" + channel = _make_channel() + bot = _make_bot(channel) + + dns_error = aiohttp.ClientConnectorError( + connection_key=MagicMock(), + os_error=OSError("No address associated with hostname"), + ) + + with ( + patch( + "nanobot.channels.qq.runtime.BotWebSocket" + ) as mock_ws_cls, + patch("asyncio.sleep", new=AsyncMock()) as mock_sleep, + ): + mock_client = MagicMock() + mock_client.ws_connect = AsyncMock(side_effect=dns_error) + mock_client._conn = None + mock_ws_cls.return_value = mock_client + + session = {"session_id": "", "url": "wss://example.com/ws"} + await bot.bot_connect(session) + + # Should have slept (backoff applied) + mock_sleep.assert_awaited_once_with(5) + + # Backoff should have doubled for this session + assert bot._ws_backoff[id(session)] == 10 + + # Session should have been re-queued + bot._connection.add.assert_called_once_with(session) + + +@pytest.mark.asyncio +async def test_bot_connect_dns_error_no_traceback(capsys): + """bot_connect() should NOT print traceback for DNS/network errors.""" + channel = _make_channel() + bot = _make_bot(channel) + + dns_error = aiohttp.ClientConnectorError( + connection_key=MagicMock(), + os_error=OSError("No address associated with hostname"), + ) + + with ( + patch( + "nanobot.channels.qq.runtime.BotWebSocket" + ) as mock_ws_cls, + patch("asyncio.sleep", new=AsyncMock()), + ): + mock_client = MagicMock() + mock_client.ws_connect = AsyncMock(side_effect=dns_error) + mock_client._conn = None + mock_ws_cls.return_value = mock_client + + session = {"session_id": "", "url": "wss://example.com/ws"} + await bot.bot_connect(session) + + # Capture stdout/stderr — should NOT contain traceback + captured = capsys.readouterr() + assert "Traceback" not in captured.out + assert "Traceback" not in captured.err + + +@pytest.mark.asyncio +async def test_bot_connect_connector_error_applies_backoff(): + """bot_connect() should apply backoff for ClientConnectorError too.""" + channel = _make_channel() + bot = _make_bot(channel) + + connector_error = aiohttp.ClientConnectorError( + connection_key=MagicMock(), + os_error=ConnectionRefusedError("Connection refused"), + ) + + with ( + patch( + "nanobot.channels.qq.runtime.BotWebSocket" + ) as mock_ws_cls, + patch("asyncio.sleep", new=AsyncMock()) as mock_sleep, + ): + mock_client = MagicMock() + mock_client.ws_connect = AsyncMock(side_effect=connector_error) + mock_client._conn = None + mock_ws_cls.return_value = mock_client + + session = {"session_id": "", "url": "wss://example.com/ws"} + await bot.bot_connect(session) + + mock_sleep.assert_awaited_once_with(5) + assert bot._ws_backoff[id(session)] == 10 + + +@pytest.mark.asyncio +async def test_bot_connect_backoff_doubles_and_caps(): + """Backoff should double on each failure and cap at max_backoff.""" + from nanobot.channels.qq.runtime import _RECONNECT_BACKOFF_MAX + + channel = _make_channel() + bot = _make_bot(channel) + + dns_error = aiohttp.ClientConnectorError( + connection_key=MagicMock(), + os_error=OSError("DNS failure"), + ) + + with ( + patch( + "nanobot.channels.qq.runtime.BotWebSocket" + ) as mock_ws_cls, + patch("asyncio.sleep", new=AsyncMock()), + ): + mock_client = MagicMock() + mock_client.ws_connect = AsyncMock(side_effect=dns_error) + mock_client._conn = None + mock_ws_cls.return_value = mock_client + + session = {"session_id": "", "url": "wss://example.com/ws"} + + # Simulate multiple failures with the same session + for expected_backoff in [5, 10, 20, 40, 80, 160, 300, 300]: + bot._ws_backoff[id(session)] = expected_backoff + await bot.bot_connect(session) + # After this call, backoff should have doubled (capped at max) + expected_next = min(expected_backoff * 2, _RECONNECT_BACKOFF_MAX) + assert bot._ws_backoff[id(session)] == expected_next + + +@pytest.mark.asyncio +async def test_bot_connect_success_resets_backoff(): + """bot_connect() should reset backoff on successful connection.""" + channel = _make_channel() + bot = _make_bot(channel) + session = {"session_id": "", "url": "wss://example.com/ws"} + bot._ws_backoff[id(session)] = 80 # was backing off + + with patch("nanobot.channels.qq.runtime.BotWebSocket") as mock_ws_cls: + mock_client = MagicMock() + mock_client.ws_connect = AsyncMock() # succeeds + mock_client._conn = MagicMock() + mock_ws_cls.return_value = mock_client + + await bot.bot_connect(session) + + assert id(session) not in bot._ws_backoff # per-session backoff cleared + # Session should NOT be re-queued on success + bot._connection.add.assert_not_called() + + +@pytest.mark.asyncio +async def test_bot_connect_non_network_error_still_requeues(): + """bot_connect() should still re-queue session for non-network errors.""" + channel = _make_channel() + bot = _make_bot(channel) + + runtime_error = RuntimeError("Unexpected error") + + with ( + patch( + "nanobot.channels.qq.runtime.BotWebSocket" + ) as mock_ws_cls, + patch("asyncio.sleep", new=AsyncMock()) as mock_sleep, + ): + mock_client = MagicMock() + mock_client.ws_connect = AsyncMock(side_effect=runtime_error) + mock_client._conn = None + mock_ws_cls.return_value = mock_client + + session = {"session_id": "", "url": "wss://example.com/ws"} + await bot.bot_connect(session) + + # No backoff sleep for non-network errors + mock_sleep.assert_not_awaited() + + # Session still re-queued + bot._connection.add.assert_called_once_with(session) + + +@pytest.mark.asyncio +async def test_bot_connect_per_session_backoff_isolated(): + """Backoff should be tracked per-session, not shared across sessions.""" + channel = _make_channel() + bot = _make_bot(channel) + + connector_error = aiohttp.ClientConnectorError( + connection_key=MagicMock(), + os_error=ConnectionRefusedError("Connection refused"), + ) + + with ( + patch( + "nanobot.channels.qq.runtime.BotWebSocket" + ) as mock_ws_cls, + patch("asyncio.sleep", new=AsyncMock()), + ): + mock_client = MagicMock() + mock_client.ws_connect = AsyncMock(side_effect=connector_error) + mock_client._conn = None + mock_ws_cls.return_value = mock_client + + session_a = {"session_id": "a", "url": "wss://example.com/ws"} + session_b = {"session_id": "b", "url": "wss://example.com/ws"} + + # Fail session A once -> backoff 5 -> 10 + await bot.bot_connect(session_a) + assert bot._ws_backoff[id(session_a)] == 10 + + # Fail session B once -> backoff should start at 5, not 10 + await bot.bot_connect(session_b) + assert bot._ws_backoff[id(session_b)] == 10 # 5 * 2 + + # Fail session A again -> should be 20 (10 * 2), not affected by B + await bot.bot_connect(session_a) + assert bot._ws_backoff[id(session_a)] == 20 + + # Session B still at 10, independent + assert bot._ws_backoff[id(session_b)] == 10 + +def test_is_network_error_classification(): + """_is_network_error correctly classifies error types.""" + from nanobot.channels.qq.runtime import _is_network_error + + assert _is_network_error( + aiohttp.ClientConnectorError( + connection_key=MagicMock(), + os_error=ConnectionRefusedError(), + ) + ) + assert _is_network_error(OSError("generic")) + assert _is_network_error(ConnectionRefusedError()) + + assert not _is_network_error(RuntimeError("not network")) + assert not _is_network_error(ValueError("not network")) + assert not _is_network_error(Exception("generic"))