From b67f4b1371c2692664bf96ef42fa1a91753c35ef Mon Sep 17 00:00:00 2001 From: chengyongru <2755839590@qq.com> Date: Mon, 20 Jul 2026 23:14:50 +0800 Subject: [PATCH] fix(qq): account for SDK reconnect pacing Use per-session retry deadlines so botpy's post-connect delay counts toward backoff, and keep unexpected failures on the channel logger. --- nanobot/channels/qq/runtime.py | 62 +++-------- tests/channels/test_qq_reconnect_backoff.py | 109 +++++++++----------- 2 files changed, 66 insertions(+), 105 deletions(-) diff --git a/nanobot/channels/qq/runtime.py b/nanobot/channels/qq/runtime.py index 3819b1f3..0fb30de1 100644 --- a/nanobot/channels/qq/runtime.py +++ b/nanobot/channels/qq/runtime.py @@ -106,9 +106,8 @@ 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 +_RECONNECT_BACKOFF_MAX = 300 def _is_network_error(exc: BaseException) -> bool: @@ -120,25 +119,15 @@ def _is_network_error(exc: BaseException) -> bool: def _make_bot_class(channel: QQChannel) -> type[botpy.Client]: - """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. - """ + """Create a botpy client with per-session reconnect backoff.""" 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} + self._ws_backoff: dict[int, int] = {} + self._ws_retry_at: dict[int, float] = {} async def on_ready(self): logger.info("QQ bot ready: {}", self.robot.name) @@ -153,45 +142,32 @@ def _make_bot_class(channel: QQChannel) -> type[botpy.Client]: 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 + """Connect a botpy session with exponential retry backoff.""" + session_id = id(session) + retry_at = self._ws_retry_at.pop(session_id, None) + if retry_at is not None: + remaining = retry_at - time.monotonic() + if remaining > 0: + await asyncio.sleep(remaining) 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) + # Count botpy's post-connect pacing toward the retry delay. + self._ws_retry_at[session_id] = time.monotonic() + 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 + channel.logger.exception("QQ bot WebSocket error: {}", e) - _tb.print_exc() - - # Re-queue the session (same as original on_error / on_closed) self._connection.add(session) return _Bot @@ -279,19 +255,13 @@ class QQChannel(BaseChannel): await self._run_bot() async def _run_bot(self) -> None: - """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. - """ + """Run botpy with fallback backoff for errors escaping start().""" 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 + backoff = 5 except Exception as e: if _is_network_error(e): self.logger.warning( diff --git a/tests/channels/test_qq_reconnect_backoff.py b/tests/channels/test_qq_reconnect_backoff.py index 37633fd4..f54658cc 100644 --- a/tests/channels/test_qq_reconnect_backoff.py +++ b/tests/channels/test_qq_reconnect_backoff.py @@ -1,10 +1,4 @@ -"""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. -""" +"""Regression tests for QQ WebSocket reconnect backoff.""" from __future__ import annotations @@ -13,12 +7,10 @@ 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 @@ -28,22 +20,24 @@ def _make_channel(): 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 + bot._ws_backoff = {} + bot._ws_retry_at = {} return bot @pytest.mark.asyncio -async def test_bot_connect_dns_error_applies_backoff(): - """bot_connect() should sleep with exponential backoff on DNS errors.""" +async def test_bot_connect_dns_error_accounts_for_sdk_pacing(): + import asyncio + + from botpy.connection import ConnectionSession + channel = _make_channel() bot = _make_bot(channel) @@ -52,33 +46,46 @@ async def test_bot_connect_dns_error_applies_backoff(): os_error=OSError("No address associated with hostname"), ) + clock = 0.0 + attempt_times = [] + + async def fail_connect(): + attempt_times.append(clock) + raise dns_error + + async def advance_clock(delay): + nonlocal clock + clock += delay + + connection = ConnectionSession( + max_async=1, + connect=bot.bot_connect, + dispatch=MagicMock(), + loop=asyncio.get_running_loop(), + ) + bot._connection = connection + session = {"session_id": "", "url": "wss://example.com/ws"} + connection.add(session) + with ( - patch( - "nanobot.channels.qq.runtime.BotWebSocket" - ) as mock_ws_cls, - patch("asyncio.sleep", new=AsyncMock()) as mock_sleep, + patch("nanobot.channels.qq.runtime.BotWebSocket") as mock_ws_cls, + patch("nanobot.channels.qq.runtime.time.monotonic", side_effect=lambda: clock), + patch("asyncio.sleep", side_effect=advance_clock), ): mock_client = MagicMock() - mock_client.ws_connect = AsyncMock(side_effect=dns_error) - mock_client._conn = None + mock_client.ws_connect = AsyncMock(side_effect=fail_connect) mock_ws_cls.return_value = mock_client - session = {"session_id": "", "url": "wss://example.com/ws"} - await bot.bot_connect(session) + for _ in range(3): + await connection.multi_run(session_interval=5) - # 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) + assert attempt_times == [0, 5, 15] + assert bot._ws_backoff[id(session)] == 40 + assert connection._session_list == [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) @@ -95,13 +102,11 @@ async def test_bot_connect_dns_error_no_traceback(capsys): ): 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 @@ -109,7 +114,6 @@ async def test_bot_connect_dns_error_no_traceback(capsys): @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) @@ -126,19 +130,17 @@ async def test_bot_connect_connector_error_applies_backoff(): ): 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) + mock_sleep.assert_not_awaited() 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() @@ -157,45 +159,42 @@ async def test_bot_connect_backoff_doubles_and_caps(): ): 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 + bot._ws_retry_at.pop(id(session), None) 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 + bot._ws_backoff[id(session)] = 80 + bot._ws_retry_at[id(session)] = 0.0 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_client.ws_connect = AsyncMock() 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 + assert id(session) not in bot._ws_backoff + assert id(session) not in bot._ws_retry_at 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() + channel.logger = MagicMock() bot = _make_bot(channel) runtime_error = RuntimeError("Unexpected error") @@ -208,22 +207,20 @@ async def test_bot_connect_non_network_error_still_requeues(): ): 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) + channel.logger.exception.assert_called_once_with( + "QQ bot WebSocket error: {}", runtime_error + ) @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) @@ -240,29 +237,23 @@ async def test_bot_connect_per_session_backoff_isolated(): ): 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 + assert bot._ws_backoff[id(session_b)] == 10 - # 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(