search

NapNeko / NapCatQQ

现代化的基于 NTQQ 的 Bot 协议端实现
https://napcat.napneko.icu
Other
2.68k stars 196 forks source link

[BUG] NapCat卡顿（线程？）造成收发消息延迟，导致bot端一直发送超时 #130

Closed Yuri-YuzuChaN closed 4 months ago

Yuri-YuzuChaN commented 4 months ago

系统版本

Windows Server 2019 Datacenter

QQNT 版本

9.9.11.24815

NapCat 版本

1.6.3

OneBot 客户端

hoshinobot 和 nonebot2

发生了什么?

前提：我的bot拥有190+的群组，同时运行nonebot1的hoshinobot和nonebot2，不知是否能承受这个群组量

napcat会时不时卡线程（？），收到一部分消息后就卡住了，然后过了两三分钟就继续收到消息，收完后就继续卡住一直循环这个状况，期间napcat端log发生错误，无其它信息，hoshino端log一直发送超时，nonebot2 log一直断开连接重新连接，最极端的时候直接不收发消息，只能重新启动napcat

如何复现

不知何时能触发，一时正常一时卡死，现在只能归咎于消息量非常多时候

期望的结果?

正常低延迟的收发消息，不会卡顿

NapCat 运行日志

日志并未提供有效的信息，卡顿后发生的log都是卡顿期间的信息，ERROR log只有 "发生错误，发送超时"

2024-07-16 00:03:50 [ERROR] Sakura BOT（寄）(1444683668) | 发生错误 发送超时 
2024-07-16 00:03:50 [DEBUG] Sakura BOT（寄）(1444683668) | ws 消息上报 ws://127.0.0.1:5261/ws/ {"status":"failed","retcode":1200,"data":null,"message":"发送超时","wording":"发送超时","echo":{"seq":7}} 

2024-07-17 13:28:01 [DEBUG] Sakura BOT（寄）(1444683668) | ws 消息上报 ws://127.0.0.1:5261/ws/ {"time":1721194081,"self_id":1444683668,"post_type":"meta_event","meta_event_type":"heartbeat","status":{"online":true,"good":true},"interval":3000} 
2024-07-17 13:28:01 [DEBUG] Sakura BOT（寄）(1444683668) | ws 消息上报 ws://127.0.0.1:6666/onebot/v11/ws {"time":1721194081,"self_id":1444683668,"post_type":"meta_event","meta_event_type":"heartbeat","status":{"online":true,"good":true},"interval":3000} 
2024-07-17 13:28:04 [DEBUG] Sakura BOT（寄）(1444683668) | ws 消息上报 ws://127.0.0.1:5261/ws/ {"time":1721194084,"self_id":1444683668,"post_type":"meta_event","meta_event_type":"heartbeat","status":{"online":true,"good":true},"interval":3000} 
2024-07-17 13:28:04 [DEBUG] Sakura BOT（寄）(1444683668) | ws 消息上报 ws://127.0.0.1:6666/onebot/v11/ws {"time":1721194084,"self_id":1444683668,"post_type":"meta_event","meta_event_type":"heartbeat","status":{"online":true,"good":true},"interval":3000} 
2024-07-17 13:28:07 [DEBUG] Sakura BOT（寄）(1444683668) | ws 消息上报 ws://127.0.0.1:5261/ws/ {"time":1721194087,"self_id":1444683668,"post_type":"meta_event","meta_event_type":"heartbeat","status":{"online":true,"good":true},"interval":3000} 
2024-07-17 13:28:07 [DEBUG] Sakura BOT（寄）(1444683668) | ws 消息上报 ws://127.0.0.1:6666/onebot/v11/ws {"time":1721194087,"self_id":1444683668,"post_type":"meta_event","meta_event_type":"heartbeat","status":{"online":true,"good":true},"interval":3000} 
2024-07-17 13:28:10 [DEBUG] Sakura BOT（寄）(1444683668) | ws 消息上报 ws://127.0.0.1:5261/ws/ {"time":1721194090,"self_id":1444683668,"post_type":"meta_event","meta_event_type":"heartbeat","status":{"online":true,"good":true},"interval":3000} 
2024-07-17 13:28:10 [DEBUG] Sakura BOT（寄）(1444683668) | ws 消息上报 ws://127.0.0.1:6666/onebot/v11/ws {"time":1721194090,"self_id":1444683668,"post_type":"meta_event","meta_event_type":"heartbeat","status":{"online":true,"good":true},"interval":3000} 
2024-07-17 13:28:13 [DEBUG] Sakura BOT（寄）(1444683668) | ws 消息上报 ws://127.0.0.1:5261/ws/ {"time":1721194093,"self_id":1444683668,"post_type":"meta_event","meta_event_type":"heartbeat","status":{"online":true,"good":true},"interval":3000} 
2024-07-17 13:28:13 [DEBUG] Sakura BOT（寄）(1444683668) | ws 消息上报 ws://127.0.0.1:6666/onebot/v11/ws {"time":1721194093,"self_id":1444683668,"post_type":"meta_event","meta_event_type":"heartbeat","status":{"online":true,"good":true},"interval":3000} 
2024-07-17 13:28:15 [ERROR] Sakura BOT（寄）(1444683668) | 发生错误 发送超时 
2024-07-17 13:28:15 [DEBUG] Sakura BOT（寄）(1444683668) | ws 消息上报 ws://127.0.0.1:5261/ws/ {"status":"failed","retcode":1200,"data":null,"message":"发送超时","wording":"发送超时","echo":{"seq":4781}} 
2024-07-17 13:28:16 [DEBUG] Sakura BOT（寄）(1444683668) | ws 消息上报 ws://127.0.0.1:5261/ws/ {"time":1721194096,"self_id":1444683668,"post_type":"meta_event","meta_event_type":"heartbeat","status":{"online":true,"good":true},"interval":3000} 
2024-07-17 13:28:16 [DEBUG] Sakura BOT（寄）(1444683668) | ws 消息上报 ws://127.0.0.1:6666/onebot/v11/ws {"time":1721194096,"self_id":1444683668,"post_type":"meta_event","meta_event_type":"heartbeat","status":{"online":true,"good":true},"interval":3000} 
2024-07-17 13:28:19 [DEBUG] Sakura BOT（寄）(1444683668) | ws 消息上报 ws://127.0.0.1:5261/ws/ {"time":1721194099,"self_id":1444683668,"post_type":"meta_event","meta_event_type":"heartbeat","status":{"online":true,"good":true},"interval":3000} 
2024-07-17 13:28:19 [DEBUG] Sakura BOT（寄）(1444683668) | ws 消息上报 ws://127.0.0.1:6666/onebot/v11/ws {"time":1721194099,"self_id":1444683668,"post_type":"meta_event","meta_event_type":"heartbeat","status":{"online":true,"good":true},"interval":3000}

OneBot 客户端运行日志

Hoshino端：

[2024-07-17 14:24:37,296 maimaiDX] ERROR: <class 'aiocqhttp.exceptions.NetworkError'> occured when _ handling message -2144694517.
[2024-07-17 14:24:37,296 maimaiDX] ERROR: WebSocket API call timeout
Traceback (most recent call last):
  File "C:\Program Files\Python38\lib\site-packages\aiocqhttp\api_impl.py", line 104, in fetch
    return await asyncio.wait_for(future, timeout_sec)
  File "C:\Program Files\Python38\lib\asyncio\tasks.py", line 501, in wait_for
    raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "C:\HoshinoBot-1\hoshino\msghandler.py", line 28, in handle_message
    await sf.func(bot, event)
  File "C:\HoshinoBot-1\hoshino\modules\maimaiDX\command\mai_table.py", line 67, in _
    await bot.send(ev, pic, at_sender=True)
  File "C:\Program Files\Python38\lib\site-packages\aiocqhttp\__init__.py", line 271, in send
    return await self.send_msg(**params)
  File "C:\Program Files\Python38\lib\site-packages\aiocqhttp\__init__.py", line 238, in call_action
    return await self._api.call_action(action=action, **params)
  File "C:\Program Files\Python38\lib\site-packages\aiocqhttp\api_impl.py", line 178, in call_action
    result = await self._wsr_api.call_action(action, **params)
  File "C:\Program Files\Python38\lib\site-packages\aiocqhttp\api_impl.py", line 153, in call_action
    return _handle_api_result(await
  File "C:\Program Files\Python38\lib\site-packages\aiocqhttp\api_impl.py", line 108, in fetch
    raise NetworkError('WebSocket API call timeout')
aiocqhttp.exceptions.NetworkError: WebSocket API call timeout

nonebot2端：

07-17 14:17:36 [WARNING] nonebot | OneBot V11 | WebSocket for Bot 1444683668 closed by peer
07-17 14:17:36 [INFO] websockets | connection closed
07-17 14:18:55 [INFO] uvicorn | ('127.0.0.1', 62974) - "WebSocket /onebot/v11/ws" [accepted]
07-17 14:18:55 [INFO] nonebot | OneBot V11 | Bot 1444683668 connected
07-17 14:18:55 [INFO] websockets | connection open
07-17 14:19:45 [WARNING] nonebot | OneBot V11 | WebSocket for Bot 1444683668 closed by peer
07-17 14:19:45 [INFO] websockets | connection closed
07-17 14:20:31 [INFO] uvicorn | ('127.0.0.1', 63014) - "WebSocket /onebot/v11/ws" [accepted]
07-17 14:20:31 [INFO] nonebot | OneBot V11 | Bot 1444683668 connected
07-17 14:20:31 [INFO] websockets | connection open
07-17 14:21:21 [WARNING] nonebot | OneBot V11 | WebSocket for Bot 1444683668 closed by peer
07-17 14:21:21 [INFO] websockets | connection closed
07-17 14:21:57 [INFO] uvicorn | ('127.0.0.1', 63062) - "WebSocket /onebot/v11/ws" [accepted]
07-17 14:21:58 [INFO] nonebot | OneBot V11 | Bot 1444683668 connected
07-17 14:21:58 [INFO] websockets | connection open
07-17 14:22:43 [WARNING] nonebot | OneBot V11 | WebSocket for Bot 1444683668 closed by peer
07-17 14:22:43 [INFO] websockets | connection closed
07-17 14:22:46 [INFO] uvicorn | ('127.0.0.1', 63084) - "WebSocket /onebot/v11/ws" [accepted]
07-17 14:22:46 [INFO] nonebot | OneBot V11 | Bot 1444683668 connected
07-17 14:22:46 [INFO] websockets | connection open
Yuri-YuzuChaN commented 4 months ago

可录制视频看现状

MliKiowa commented 4 months ago

好的 问题已开始尝试优化

airdm commented 4 months ago

我也是同样问题,也上报给作者了.因为此类问题已经冻结好几个BOT了,就是因为卡住后恢复一瞬间发了好多信息导致的. 希望尽快修复.

wling-art commented 4 months ago

我也遇到了这个问题，群有500+ 线程卡顿真的特别影响Nonebot v2的接收

MliKiowa commented 4 months ago

下个版本修复

MliKiowa commented 4 months ago

尝试下action的版本

Yuri-YuzuChaN commented 4 months ago

尝试下action的版本

那napcat后续更新的版本QQ是不是必须得使用9.9.12以上的，因为目前使用的账号给tx锁定不能登录低版本QQ，是否能自己构建QQ9.9.11使用的napcat

MliKiowa commented 4 months ago

QQ版本不升 应该可以直接使用nc的 但是最好还是升级 如果嫌麻烦 可以试试 nc desktop 就是组织里面的nc桌面管理工具

Yuri-YuzuChaN commented 4 months ago

好的，我尝试一下

Yuri-YuzuChaN commented 4 months ago

好像并没有改善，还是存在卡住的问题。不过在卡住的情况下关闭 bot客户端后napcat就非常正常了，感觉像是反向websocket的问题

xiaoxsui commented 4 months ago

我也遇到了这个问题，开启bot时发送图片信息就会导致napcat卡住很长时间，每天凌晨零点准时掉号。询问发现其他人似乎没有这种问题，甚至我更换了一个账号再测试都能正常使用（） 但是更新了刚才的1.6.7版本+nc desktop之后问题就解决了！好耶

Yuri-YuzuChaN commented 4 months ago

情况更严重了

image

Yuri-YuzuChaN commented 4 months ago

目前换了台机器已更换成Linux版本非常流畅，暂时没有出现这个情况，怀疑是win版本的QQNT比较烂或者是机器带不动