Skip to content

Bug: 动态截图超时时 dyn_offset 已提前推进, 该条动态被静默丢弃且永不重推 #355

Description

@Nexvrek

操作系统

Linux (Ubuntu 22.04.5 LTS)

Python 版本

3.11.15

NoneBot 版本

2.5.0

Bilichat 版本

6.5.0 (bilichat-request 0.5.12, 本地部署)

描述问题

一句话content_dynamic 超时后, 那条动态会被静默丢弃且永远不会重推, 用户端毫无感知。

1. 主问题:offset 在截图之前就推进了

nonebot_plugin_bilichat/subscribe/fetch_and_push.pydynamic() 中:

for dyn in new_dyns:
    logger.info(f"[Dynamic] UP {up.name}({up.uid}) 发布了新动态: {dyn.dyn_id}")
    up.dyn_offset = dyn.dyn_id                                     # ← 先推进 offset
    content = await api.content_dynamic(dyn.dyn_id, ...)           # ← 这里抛异常
    dyn_img = Image(raw=content.img_bytes)
    ...

content_dynamic 抛出的异常会被函数最外层的 except Exception 捕获并 continue, 但此时 up.dyn_offset 已经等于这条动态的 ID。下一轮轮询时 dyn.dyn_id > up.dyn_offset 不再成立, 这条动态永久不会被重新处理

结果是:截图环节一旦失败, 用户端不会收到任何消息, 也没有任何降级提示, 只有翻日志才能发现漏了一条。

2. 加剧因素:插件的 60s 读超时与 bilichat-request 的重试机制不匹配

nonebot_plugin_bilichat/request_api/base.py:28

self._client = AsyncClient(base_url=str(api_base), headers=self._headers, timeout=60)

而 bilichat-request 侧 functions/render/dynamic.py 的截图流程是:

  • page.goto(url, wait_until="networkidle") — Playwright 默认导航超时 30s
  • 捕获 TimeoutError 后按 config.retry(默认 1) 重试一次, 第二次最坏又是 30s

于是最坏耗时约 30 + 30 = 60s+, 必然超过插件写死的 60s 读超时。也就是说, 只要第一次截图超时, 第二次重试的结果插件永远等不到 —— 在默认配置下 bilichat-request 的截图重试机制对插件而言等于失效, 而每一次失效都按上面第 1 点丢掉一条动态。

3. 实测数据

近 15 天日志统计:89 条新动态, 8 次该类超时, 丢推率约 9%

超时发生后手动 curl 同一条动态的 /content/dynamic, 11.3s 返回 HTTP 200 且正常出图, 说明不是动态内容本身的问题, 而是渲染时的瞬时网络抖动 —— 这类抖动本应由重试兜住, 但因为第 2 点重试没能生效。

4. 建议的修复方向

  1. 最小改动:把 up.dyn_offset = dyn.dyn_id 移到 content_dynamic 成功之后。
    风险:如果某条动态是永久性渲染失败(例如动态本身触发了截图断言错误), offset 会卡住不动, 导致每轮轮询都重试同一条并持续报错。

  2. 推荐:截图失败时降级为纯文本推送, offset 照常推进。
    #353 已经引入了 use_rich_media 开关和对应的纯文本消息分支, 这里可以直接复用那条路径:

    try:
        content = await api.content_dynamic(dyn.dyn_id, ConfigCTX.get().api.browser_shot_quality)
        dyn_img = Image(raw=content.img_bytes)
    except Exception as e:
        logger.warning(f"[Dynamic] 动态 {dyn.dyn_id} 内容获取失败, 降级为纯文本推送: {e}")
        dyn_img = None

    后面按 dyn_img is None 走已有的纯文本分支。这样既不丢消息, 也不会卡住 offset。

    注:#353 的诉求是"多次发送图片失败时使用纯文本消息来通知", 目前 use_rich_media 是静态全局开关;这里的失败降级正好是那个 issue 里"失败时自动降级"的另一半。

  3. 可选:把 base.py:28timeout=60 提取为配置项。当前它写死在构造函数里, 用户即使把 bilichat-request 的 timeout 调大也没有意义, 因为瓶颈在插件侧。

插件的配置项

api:
    browser_shot_quality: 75
    api_health_check_interval: 120
    request_api:
    -   api: http://127.0.0.1:<port>/bilichatapi
        enable: true
        note: local bilichat-request
        token: ''
        weight: 1
subs:
    dynamic_interval: 300
    live_interval: 60
    push_delay: 3
    use_rich_media: true

bilichat-request 侧 config.yaml:

timeout: 60

截图或日志

插件侧 (NoneBot):

01:00:53 [INFO ] nonebot_plugin_bilichat | [Dynamic] UP <UP名>(<uid>) 发布了新动态: <dyn_id>
01:01:53 [ERROR] nonebot_plugin_bilichat |
  File ".../nonebot_plugin_bilichat/subscribe/fetch_and_push.py", line 62, in dynamic
    content = await api.content_dynamic(dyn.dyn_id, ConfigCTX.get().api.browser_shot_quality)
  File ".../nonebot_plugin_bilichat/request_api/base.py", line 145, in content_dynamic
    (await self._get("/content/dynamic", params={"dynamic_id": dynamic_id, "quality": quality, "mobile_style": True})).json()
  File ".../nonebot_plugin_bilichat/request_api/base.py", line 127, in _get
  File ".../nonebot_plugin_bilichat/request_api/base.py", line 111, in _request
httpx.ReadTimeout
01:01:53 [ERROR] nonebot_plugin_bilichat | 请求错误: [], 错误计数: 0/10

bilichat-request 侧, 同一时间窗:

01:00:53|INFO   |bilichat_request.functions.render.dynamic:screenshot:123 - 正在截图动态: <dyn_id>
01:00:55|WARNING|bilichat_request.adapters.browser:network_requestfailed:99 - [RequestFailed] [GET NS_BINDING_ABORTED] << https://s1.hdslb.com/bfs/static/jinkela/mstation-h5-new/css/mstation.15.<hash>.css
01:00:55|WARNING|... 同类 CSS 请求失败 x5 ...
01:01:24|ERROR  |bilichat_request.functions.render.dynamic:screenshot:154 - 动态 <dyn_id> 截图超时, 重试...
01:01:24|INFO   |bilichat_request.functions.render.dynamic:screenshot:123 - 正在截图动态: <dyn_id>
01:01:26|WARNING|bilichat_request.adapters.browser:network_requestfailed:99 - [RequestFailed] [GET NS_BINDING_ABORTED] << 同一批 CSS
(01:01:53 插件侧 httpx 60s 到期断开连接, 此时容器内第二次截图才进行了 29s)

时序说明:00:53 开始第一次截图 → 01:24 第一次超时(31s)并重试 → 01:53 插件 60s 读超时断开。容器的第二次截图最早也要到 01:54 才可能出结果, 比插件断开晚 1 秒, 因此重试结果永远送不回插件。

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions