Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

发生PacketCodecException: java.lang.IllegalStateException: Received packet returnCode = -10008导致 BotOfflineEvent.Dropped并自动重连后，无法发送消息，每次发送会导致一段异常日志，不会自动纠正 #2853

Open
MrY-Cat opened this issue Jun 19, 2024 · 1 comment
Open

发生PacketCodecException: java.lang.IllegalStateException: Received packet returnCode = -10008导致 BotOfflineEvent.Dropped并自动重连后，无法发送消息，每次发送会导致一段异常日志，不会自动纠正 #2853

MrY-Cat opened this issue Jun 19, 2024 · 1 comment

Comments

@MrY-Cat
Copy link
Contributor

MrY-Cat commented Jun 19, 2024

问题描述

机器人是ANDROID_PAD协议，使用签名服务，长期稳定工作，但偶尔在未知原因下，发送消息时出现Received packet returnCode = -10008，导致Connection lost, reconnecting... ，而后可能导致NetworkHandler is already closed，后续只能正常收到消息（日志也显示收到的消息），却无法发送消息（发送时可能会继续returnCode = -10008），关掉MCL重启后恢复正常。

复现

我也不太清楚什么原因导致的，就是挂着长期没事，偶尔会出现Received packet returnCode = -10008

mirai-core 版本

2.15.0

bot-protocol

ANDROID_PAD

其他组件版本

No response

系统日志

2024-06-19 15:23:48 V/Bot.2305339556: [复读喵星球官方群(1027488229)] 真·灵光虫之母(1310160545) -> [mirai:at:2305339556] 签到
2024-06-19 15:23:48 V/Bot.2305339556: Event: BotOfflineEvent.Dropped(bot=Bot(2305339556), cause=net.mamoe.mirai.internal.network.components.PacketCodecException: java.lang.IllegalStateException: Received packet returnCode = -10008, which may mean session expired., reconnect=true)
2024-06-19 15:23:48 W/Bot.2305339556: Connection lost, reconnecting... (net.mamoe.mirai.internal.network.components.PacketCodecException: java.lang.IllegalStateException: Received packet returnCode = -10008, which may mean session expired.)
2024-06-19 15:23:49 I/UnidbgFetchQsign: Bot(2305339556) initialize by http://127.0.0.1:9063
2024-06-19 15:23:49 I/UnidbgFetchQsign: Bot(2305339556) initialize complete
2024-06-19 15:23:50 I/Bot.2305339556: Saved account secrets to local cache for fast login.
2024-06-19 15:23:50 I/Bot.2305339556: Login successful.
2024-06-19 15:23:50 V/Bot.2305339556: Event: BotOnlineEvent(bot=Bot(2305339556))
2024-06-19 15:23:50 V/Bot.2305339556: Event: BotReloginEvent(bot=Bot(2305339556), cause=null)
2024-06-19 15:23:50 I/Bot.2305339556: Reconnected successfully in 1.491s.
2024-06-19 15:23:53 E/复读喵星球: Exception in coroutine Plugin yyd.mrycat.bot.mirai-cat of 复读喵星球
java.lang.IllegalStateException: NetworkHandler is already closed.
	at net.mamoe.mirai.internal.network.handler.CommonNetworkHandler$StateClosed.sendPacketImpl(CommonNetworkHandler.kt:396)
	at net.mamoe.mirai.internal.network.handler.CommonNetworkHandler.sendPacketImpl(CommonNetworkHandler.kt:37)
	at net.mamoe.mirai.internal.network.handler.NetworkHandlerSupport.sendAndExpect(NetworkHandlerSupport.kt:123)
	at net.mamoe.mirai.internal.network.handler.NetworkHandlerSupport$sendAndExpect$1.invokeSuspend(NetworkHandlerSupport.kt)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
	at kotlinx.coroutines.internal.ScopeCoroutine.afterResume(Scopes.kt:33)
	at kotlinx.coroutines.AbstractCoroutine.resumeWith(AbstractCoroutine.kt:102)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:46)
	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:104)
	at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:570)
	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:750)
	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:677)
	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:664)
	Suppressed: kotlinx.coroutines.TimeoutCancellationException: Timed out waiting for 5000 ms
		at kotlinx.coroutines.TimeoutKt.TimeoutCancellationException(Timeout.kt:184)
		at kotlinx.coroutines.TimeoutCoroutine.run(Timeout.kt:154)
		at kotlinx.coroutines.EventLoopImplBase$DelayedRunnableTask.run(EventLoop.common.kt:508)
		at kotlinx.coroutines.EventLoopImplBase.processNextEvent(EventLoop.common.kt:284)
		at kotlinx.coroutines.DefaultExecutor.run(DefaultExecutor.kt:108)
		at java.base/java.lang.Thread.run(Thread.java:829)


中间是收到的消息，略...

2024-06-19 15:41:50 V/Bot.2305339556: Event: BotOfflineEvent.Dropped(bot=Bot(2305339556), cause=net.mamoe.mirai.internal.network.components.PacketCodecException: java.lang.IllegalStateException: Received packet returnCode = -10008, which may mean session expired., reconnect=true)
2024-06-19 15:41:50 W/Bot.2305339556: Connection lost, reconnecting... (net.mamoe.mirai.internal.network.components.PacketCodecException: java.lang.IllegalStateException: Received packet returnCode = -10008, which may mean session expired.)
2024-06-19 15:41:50 I/UnidbgFetchQsign: Bot(2305339556) initialize by http://127.0.0.1:9063
2024-06-19 15:41:50 I/UnidbgFetchQsign: Bot(2305339556) initialize complete
2024-06-19 15:41:51 I/Bot.2305339556: Saved account secrets to local cache for fast login.
2024-06-19 15:41:51 I/Bot.2305339556: Login successful.
2024-06-19 15:41:51 V/Bot.2305339556: Event: BotOnlineEvent(bot=Bot(2305339556))
2024-06-19 15:41:51 V/Bot.2305339556: Event: BotReloginEvent(bot=Bot(2305339556), cause=null)
2024-06-19 15:41:51 I/Bot.2305339556: Reconnected successfully in 0.989s.

网络日志

�[0m2024-06-19 15:23:48 V/: Send: MessageSvc.PbSendMsg(MessageSvc.PbSendMsg)�[0m
�[91m2024-06-19 15:23:48 E/: Error while decoding packet 'ByteReadPacket(0 bytes remaining)'
net.mamoe.mirai.internal.network.components.PacketCodecException: java.lang.IllegalStateException: Received packet returnCode = -10008, which may mean session expired.
	at net.mamoe.mirai.internal.network.components.PacketCodecImpl.parseSsoFrame(PacketCodec.kt:250)
	at net.mamoe.mirai.internal.network.components.PacketCodecImpl.decodeRaw(PacketCodec.kt:156)
	at net.mamoe.mirai.internal.network.handler.CommonNetworkHandler$PacketDecodePipeline.decodePacket(CommonNetworkHandler.kt:149)
	at net.mamoe.mirai.internal.network.handler.CommonNetworkHandler$PacketDecodePipeline.access$decodePacket(CommonNetworkHandler.kt:103)
	at net.mamoe.mirai.internal.network.handler.CommonNetworkHandler$PacketDecodePipeline$1.invokeSuspend(CommonNetworkHandler.kt:126)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:106)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.lang.IllegalStateException: Received packet returnCode = -10008, which may mean session expired.
	at net.mamoe.mirai.internal.network.components.PacketCodecException.<init>(PacketCodec.kt:76)
	... 14 more
�[0m
�[93m2024-06-19 15:23:48 W/: Exception in resumeConnection.
net.mamoe.mirai.internal.network.components.PacketCodecException: java.lang.IllegalStateException: Received packet returnCode = -10008, which may mean session expired.
	at net.mamoe.mirai.internal.network.components.PacketCodecImpl.parseSsoFrame(PacketCodec.kt:250)
	at net.mamoe.mirai.internal.network.components.PacketCodecImpl.decodeRaw(PacketCodec.kt:156)
	at net.mamoe.mirai.internal.network.handler.CommonNetworkHandler$PacketDecodePipeline.decodePacket(CommonNetworkHandler.kt:149)
	at net.mamoe.mirai.internal.network.handler.CommonNetworkHandler$PacketDecodePipeline.access$decodePacket(CommonNetworkHandler.kt:103)
	at net.mamoe.mirai.internal.network.handler.CommonNetworkHandler$PacketDecodePipeline$1.invokeSuspend(CommonNetworkHandler.kt:126)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:106)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.lang.IllegalStateException: Received packet returnCode = -10008, which may mean session expired.
	at net.mamoe.mirai.internal.network.components.PacketCodecException.<init>(PacketCodec.kt:76)
	... 14 more
�[0m
�[0m2024-06-19 15:23:48 V/: Validated caches.�[0m
�[0m2024-06-19 15:23:48 V/: Loading server list from cache.�[0m
�[0m2024-06-19 15:23:48 V/: Server list: 122.193.7.205:80, msfwifi.3g.qq.com:8080, 59.83.207.254:443, 157.148.63.88:443, 123.125.0.194:80, 123.125.0.195:443, 157.148.63.107:8080, 112.86.230.139:14000, 111.206.149.85:80, 123.125.0.210:80.�[0m
�[92m2024-06-19 15:23:49 I/: ECDH key is invalid, start to fetch ecdh public key from server.�[0m
�[92m2024-06-19 15:23:49 I/: Successfully fetched ecdh public key from server.�[0m
�[0m2024-06-19 15:23:50 V/: Send: wtlogin.exchange_emp(10:fast-login)�[0m
�[0m2024-06-19 15:23:50 V/: Recv: wtlogin.exchange_emp�[0m
�[0m2024-06-19 15:23:50 V/: Send: StatSvc.register(online)�[0m
�[92m2024-06-19 15:23:50 I/: Server time updated, serverTime: 1718781830, diff: 0ms=0.0s�[0m
�[0m2024-06-19 15:23:50 V/: Recv: StatSvc.register�[0m
�[92m2024-06-19 15:23:50 I/: Scheduled key refresh in 23h 55min 0.0s.�[0m
�[92m2024-06-19 15:23:50 I/: Scheduled refresh login session in 19d 23h 55min 0.0s.�[0m
�[0m2024-06-19 15:23:53 V/: Server list: msfwifi.3g.qq.com:8080, 112.86.230.139:14000, 182.50.8.188:443, 111.206.149.85:80, 157.148.54.16:8080, 60.29.238.126:80, 123.125.0.195:443, 157.148.63.107:443, 60.29.238.126:80, 153.3.244.48:80.�[0m
�[0m2024-06-19 15:23:53 V/: Saving bdh session to cache�[0m
�[0m2024-06-19 15:23:53 V/: Saving server list to cache�[0m
�[0m2024-06-19 15:23:53 V/: Send: ConfigPushSvc.PushResp(ConfigPushSvc.PushResp)�[0m
�[0m2024-06-19 15:23:53 V/: Recv: ConfigPushSvc.PushReq�[0m
�[0m2024-06-19 15:23:53 V/: Saving bdh session to cache�[0m
�[0m2024-06-19 15:23:53 V/: Send: ConfigPushSvc.PushResp(ConfigPushSvc.PushResp)�[0m
�[0m2024-06-19 15:23:53 V/: Recv: ConfigPushSvc.PushReq�[0m
�[0m2024-06-19 15:23:53 V/: Send: MessageSvc.PbSendMsg(MessageSvc.PbSendMsg)�[0m
�[91m2024-06-19 15:39:17 E/: Exception in coroutine 'unnamed'
ExceptionInPacketCodecException(cause=net.mamoe.mirai.internal.utils.crypto.DecryptionFailedException)
	at net.mamoe.mirai.internal.network.handler.CommonNetworkHandler.handleExceptionInDecoding$passToExceptionHandler(CommonNetworkHandler.kt:58)
	at net.mamoe.mirai.internal.network.handler.CommonNetworkHandler.handleExceptionInDecoding(CommonNetworkHandler.kt:75)
	at net.mamoe.mirai.internal.network.handler.CommonNetworkHandler$PacketDecodePipeline$1.invokeSuspend(CommonNetworkHandler.kt:130)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:106)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: net.mamoe.mirai.internal.utils.crypto.DecryptionFailedException
	at net.mamoe.mirai.internal.utils.crypto.TEA.fail(TEA.kt:299)
	at net.mamoe.mirai.internal.utils.crypto.TEA.doOption$decrypt(TEA.kt:275)
	at net.mamoe.mirai.internal.utils.crypto.TEA.doOption(TEA.kt:295)
	at net.mamoe.mirai.internal.utils.crypto.TEA.decrypt(TEA.kt:319)
	at net.mamoe.mirai.internal.network.components.PacketCodecImpl.decodeRaw(PacketCodec.kt:141)
	at net.mamoe.mirai.internal.network.handler.CommonNetworkHandler$PacketDecodePipeline.decodePacket(CommonNetworkHandler.kt:149)
	at net.mamoe.mirai.internal.network.handler.CommonNetworkHandler$PacketDecodePipeline.access$decodePacket(CommonNetworkHandler.kt:103)
	at net.mamoe.mirai.internal.network.handler.CommonNetworkHandler$PacketDecodePipeline$1.invokeSuspend(CommonNetworkHandler.kt:126)
	... 9 more


后续试图发送消息时，网络日志中反复出现Error while decoding packet 'ByteReadPacket(0 bytes remaining)'
net.mamoe.mirai.internal.utils.crypto.DecryptionFailedException的一段（此处提交的网络日志里没有保留后续重复段）

补充信息

不知道Received packet returnCode = -10008的发生原因以及有没有预防措施，以及它导致NetworkHandler is already closed.之后，有没有什么方法能在插件代码里检查到，让NetworkHandler 重启或者让mcl重启。

主要是发生之后没有任何预兆，机器人正常接收消息正常走业务流程但是没有办法发送消息反馈，直到被发现才能重启解决
@MrY-Cat
Copy link
Contributor Author

MrY-Cat commented Jun 19, 2024

似乎很久之前有几个类似的ISSUE，被解决了，好像和 #2450 Handle rare case on packet pipeline 有关

@MrY-Cat MrY-Cat changed the title Received packet returnCode = -10008导致NetworkHandler is already closed.后续不能发送消息，无法自动纠正 发生PacketCodecException: java.lang.IllegalStateException: Received packet returnCode = -10008导致 BotOfflineEvent.Dropped并自动重连后，无法发送消息，每次发送会导致一段异常日志，不会自动纠正 Aug 7, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@MrY-Cat