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.
This commit is contained in:
chengyongru
2026-07-20 23:24:03 +08:00
committed by chengyongru
parent ab0d28103b
commit b67f4b1371
2 changed files with 66 additions and 105 deletions
+16 -46
View File
@@ -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(
+50 -59
View File
@@ -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(