search

yyuueexxiinngg / onebot-kotlin

OneBot标准的Kotlin实现及mirai插件 - 原cqhttp-mirai
GNU Affero General Public License v3.0
584 stars 139 forks source link

反向WS方式建立连接后的首次消息不会被正确处理[BUG] #74

Closed LambdaYH closed 4 years ago

LambdaYH commented 4 years ago

在通过反向WS方式建立连接后，首次的指令不会得到响应，接下来的指令则会正常响应 以下以HoshinoBot为例

Mirai方面的控制台

 13:23:26 [DEBUG] [CQHTTPMirai] 127.0.0.1:9800-Client-Universal 开始启动
 13:23:26 [DEBUG] [CQHTTPMirai] 127.0.0.1:9800-Client-Universal Websocket Client启动完毕
 13:23:34 [INFO] [BOT 158xxx3439] [GS(85xxx4081)] -(1xxxxx74xx) -> [mirai:source:1432,555564720]help
 13:23:42 [INFO] [NETWORK] Send: Heartbeat.Alive
 13:23:42 [INFO] [NETWORK] Recv: Heartbeat.Alive.Response

HoshinoBot方面的控制台

[2020-08-27 13:23:25,194] Running on 127.0.0.1:9800 over http (CTRL + C to quit)
[2020-08-27 13:23:26,046] 127.0.0.1:32838 GET /ws 1.1 101 - 1017
[2020-08-27 13:23:34,183 nonebot] INFO: Self: 15xxxxx439, Message 1432 from 1xxxxxxx1@[群:8xxxxx81]: 'help'
[2020-08-27 13:23:34,183 _help_] INFO: Message 1432 triggered send_help by PrefixTrigger.

看到指令被正常触发,但是却没有响应，再输入一次则可以得到正确响应

复现

  1. 重启HoshinoBot(反向WS) 服务端
  2. mirai-cqhttp重新连接上服务端
  3. 发送指令
    断线自动重连后也会复现

    版本

    cqhttp-mirai- 0.2.3

mirai-core-1.2.2

mirai-console-0.5.2

LambdaYH commented 4 years ago

后续发现首次的消息会在好久后报错

[2020-08-27 14:04:33,044 nonebot] INFO: Self: 15xxxx39, Message 1482 from 12xxxxx81@[群:8xxxx81]: '/占卜'
[2020-08-27 14:04:33,046 EorzeaZhanbu] INFO: Message 1482 triggered zhanbu by PrefixTrigger.
[2020-08-27 14:05:33,049 EorzeaZhanbu] ERROR: <class 'aiocqhttp.exceptions.NetworkError'> occured when zhanbu handling message 1482.
[2020-08-27 14:05:33,049 EorzeaZhanbu] ERROR: WebSocket API call timeout
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/aiocqhttp/api_impl.py", line 118, in fetch
    return await asyncio.wait_for(future, timeout_sec)
  File "/usr/local/lib/python3.8/asyncio/tasks.py", line 490, in wait_for
    raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/root/HoshinoBot/hoshino/msghandler.py", line 28, in handle_message
    await sf.func(bot, event)
  File "/root/HoshinoBot/hoshino/service.py", line 218, in wrapper
    return await func(bot, event)
  File "/root/HoshinoBot/hoshino/modules/EorzeaZhanbu/EorzeaZhanbu.py", line 92, in zhanbu
    await bot.send(ev, '\n'.join(msg), at_sender=True)
  File "/usr/local/lib/python3.8/site-packages/aiocqhttp/__init__.py", line 256, in send
    return await self.send_msg(**params)
  File "/usr/local/lib/python3.8/site-packages/aiocqhttp/__init__.py", line 223, in call_action
    return await self._api.call_action(action=action, **params)
  File "/usr/local/lib/python3.8/site-packages/aiocqhttp/api_impl.py", line 186, in call_action
    result = await self._wsr_api.call_action(action, **params)
  File "/usr/local/lib/python3.8/site-packages/aiocqhttp/api_impl.py", line 162, in call_action
    await ResultStore.fetch(seq, self._timeout_sec))
  File "/usr/local/lib/python3.8/site-packages/aiocqhttp/api_impl.py", line 122, in fetch
    raise NetworkError('WebSocket API call timeout')
aiocqhttp.exceptions.NetworkError: WebSocket API call timeout
[2020-08-27 14:05:33,052 nonebot] INFO: Message 1482 is ignored
yyuueexxiinngg commented 4 years ago

8621e256f8b29426a9188390caba8b82db5022fc 中修复

LambdaYH commented 4 years ago

当服务端重启后，客户端重新连接，有几率发生如下情况导致无限重连失败 

15:05:13 [WARNING] [CQHTTPMirai] WS Reverse事件发送失败, 连接已被关闭, 尝试重连中 127.0.0.1:8080-Client-Universal
 15:05:13 [DEBUG] [CQHTTPMirai] 127.0.0.1:8080-Client-Universal 开始启动
 15:05:13 [WARNING] [CQHTTPMirai] Websocket session alredy exist, 127.0.0.1:8080-Client-Universal

cqhttpmirai版本： 8621e25