Unhandled exception occurred in onPacketSending(PacketEvent)
haroldrc opened this issue · 30 comments
- This issue is not solved in a development build
Describe the bug
I have a problem with this "interactive chat" plugin, they told me to contact you to find out if it was your problem
https://pastebin.com/raw/idGZjhRm
To Reproduce
Steps to reproduce the behavior:
- Go to '...'
- Click on '....'
- Scroll down to '....'
- See error
Expected behavior
A clear and concise description of what you expected to happen.
Screenshots
If applicable, add screenshots to help explain your problem.
Version Info
https://pastebin.com/raw/5Uq2BEBJ
Additional context
Add any other context about the problem here.
I didn't really have time to look into this, I tried once and cloning worked which means that I have to dig deeper...
Perhaps it has something to do with server implementation, of how they patched certain things, the few instances where I have received this error report, they seemed to be on some fork of Spigot but not Spigot or Paper itself. Just a guess tho.
XD well.. But then there are a lot who use these same forks but have no problem at all. So my hypothesis might be wrong.
I once tried Purpur quite some time ago and it worked :/
Hm, I justed looked into the code and
at com.loohp.interactivechat.listeners.OutChatPacket$1.onPacketSending(OutChatPacket.java:135) ~[InteractiveChat.jar:?]
seems to be outdated... Did the code move into OutMessagePacket.java?
Hm, I justed looked into the code and
at com.loohp.interactivechat.listeners.OutChatPacket$1.onPacketSending(OutChatPacket.java:135) ~[InteractiveChat.jar:?]
seems to be outdated... Did the code move into OutMessagePacket.java?
It should be here
https://github.com/LOOHP/InteractiveChat/blob/master/src/main/java/com/loohp/interactivechat/listeners/OutMessagePacket.java#L375
I tried it again on Pufferfish-72
, using different methods to send the message (plain text, adventure and via spigot component) and I cannot reproduce the issue...
Ok I found it. Bit of background to understand the issue: The serializable cloner is basically encoding the packet, and then decoding a fresh version of it. BUT when using the bungee component api, there seems to be some issue with how md5 is encoding the object. The Component serializer outputs
[{"color":"white"},{"color":"white","text":"§aDownload it now!"},{"color":"white","clickEvent":{"action":"open_url","value":"https://www.spigotmc.org/resources/55883"},"text":" §7[§3Click Here§7]"}]
As you can see the first component has no text attribute, causing the server to fail to deserialize the component (Error is something like Don't know how to turn "{"color":"white"}" into a component
).
So the issue (in that case) doesn't seem to be related to ProtocolLib 🤷
Hey both!
To add in case it was lost, this doesn't happen on every message, but starts to occur (seemingly) randomly as the server stays online. Sometimes it happens after an hour, sometimes two hours which is likely going to make it hard to replicate in a dev environment. There could also be an aspect of player count at play (e.g. maybe it doesn't happen with one player but when you get 20-40 on it starts). Once the issue starts it doesn't 'resolve' itself till a reboot, and then comes back again.
For our setup we're using:
Arclight (https://github.com/IzzelAliz/Arclight) which uses forge-1.16.5-36.2.26.jar(note this forge is older than recommended but I tested with that as well and the issue still occurs) - This uses mixins in it so could be related to the cause potentially, but would be odd given everything works for a little while after the server is booted. Do yall know what specific classes to look for changes that might be effecting this? Just searching for chat in the git repo I can see a few occurrences of it mixing into chat related packets (here is one).
And latest of both Interactive chat and protocol lib. I removed every other plugin using protocol lib other than interactive chat to eliminate them from being the cause and have switched between multiple chat plugins as well (EssentialsXChat, chat manager, etc) and the same occurs no matter what is used there.
Appreciate the help / effort to look into this!
It probably isn't related to online time or online players directly. If it does, it would be an indirect cause, like a specific message that only appears in chat that you've set up which only shows when the server is online for long enough, or a message that only appears when there are more players online. Try to look for those. @nicholasrobertm
This error can only be triggered when a chat / title / subtitle / actionbar message is sent to a player.
Note: I've also seen reports of it on Purpur and another fork of paper which I don't remember.
Yea, the initial issue is not printed out... If deep cloning fails, the packet type is added to a list and only the serializer cloner (which cannot clone the packet) is used. Maybe we should print out the original issue as well, that would at least help to find these issues easier... (on the other hand that reports issues which are not considered issues...)
Two edits:
- Looking at how the serializable cloning works - we can and should improve that asap
- I made a special build which prints out the original cloning exception. You can download it from here (<- this is a zip, you need to unpack it first). Please watch for a message
UNABLE TO FAST-DEEP CLONE PACKET OF TYPE CHAT
(or similar) and post the stack trace here (@LOOHP @haroldrc @nicholasrobertm )
Edit 3: I'm actually stupid, the whole message is right there under the exception and I am able to reproduce the issue with this:
TextComponent[] components = new TextComponent[3];
components[0] = new TextComponent((String) null);
components[0].setColor(ChatColor.WHITE);
components[1] = new TextComponent("§aDownload it now!");
components[1].setColor(ChatColor.WHITE);
components[2] = new TextComponent(" §7[§3Click Here§7]");
components[2].setColor(ChatColor.WHITE);
components[2].setClickEvent(new ClickEvent(Action.OPEN_URL, "https://www.spigotmc.org/resources/55883"));
event.getPlayer().spigot().sendMessage(ChatMessageType.SYSTEM, new UUID(0, 0), components);
(Don't try the bungee component api at home please)
Thanks for looking into it. It would be great if the error ProtocolLib throws is clearer as to what part of the cloning process had gone wrong.
Seems like you will have to report to the bungeecord chat api.
However, don't bet on that. It would probably be quicker to report this to the plugin that sent this message and tell them to avoid sending these "text-less" "type-less" chat components.
@nicholasrobertm @haroldrc
Seems like WolfyUtils (which caused the issue originally) already implemented a fix: WolfyScript/WolfyUtils-Spigot@3ac8f3e (since v4.16.1.0)
@haroldrc try updating that, seems like you're currently on 4.16.0.0
I will take a look at the issue in the next days, for now please ask them to not deep clone each outbound chat packet.
The reason I deep cloned each chat packet is that I would like to keep a copy of the original chat packet and send that in case something goes wrong when editing it.
Yea I understand. That was just a temporary suggestion until we found a fix for the issue.
Can confirm this myself too, here is debug info if you would like another source
Error: https://paste.gg/p/Zax71/999bc4a414e94b34b5cc94c4acd4b19a
Logs: https://mclo.gs/skV1AuL
Can confirm this myself too, here is debug info if you would like another source
Error: https://paste.gg/p/Zax71/999bc4a414e94b34b5cc94c4acd4b19a Logs: https://mclo.gs/skV1AuL
That issue is not related to ProtocolLib at all ;)
Can confirm this myself too, here is debug info if you would like another source
Error: https://paste.gg/p/Zax71/999bc4a414e94b34b5cc94c4acd4b19a Logs: https://mclo.gs/skV1AuLThat issue is not related to ProtocolLib at all ;)
Thaught It was the same issue! Sorry...
Hey both!
On my end it looks like it may be coming from one of the pixelmon mod's commands (If I'm reading this right, log below). I'll get a PR together for the pixelmon side to try and sort this out there! I've sent yall both some lunch on me, appreciate the response to this so quick!
Is there a way the deserialization exception could be caught to prevent them from breaking chat that happens after this occurs?
[21Jul2022 00:16:53.937] [Server thread/ERROR] [ProtocolLib/]: UNABLE TO FAST-DEEP CLONE PACKET OF TYPE CHAT[class=PacketPlayOutChat, id=48] java.lang.IllegalArgumentException: handle cannot be NULL. at com.comphenix.protocol.wrappers.AbstractWrapper.setHandle(AbstractWrapper.java:29) ~[?:?] at com.comphenix.protocol.wrappers.WrappedChatComponent.<init>(WrappedChatComponent.java:80) ~[?:?] at com.comphenix.protocol.wrappers.WrappedChatComponent.fromJson(WrappedChatComponent.java:99) ~[?:?] at com.comphenix.protocol.wrappers.WrappedChatComponent.deepClone(WrappedChatComponent.java:179) ~[?:?] at com.comphenix.protocol.wrappers.WrappedChatComponent.deepClone(WrappedChatComponent.java:20) ~[?:?] at com.comphenix.protocol.reflect.cloning.BukkitCloner.lambda$fromWrapper$0(BukkitCloner.java:49) ~[?:?] at com.comphenix.protocol.reflect.cloning.BukkitCloner.clone(BukkitCloner.java:122) ~[?:?] at com.comphenix.protocol.reflect.cloning.AggregateCloner.clone(AggregateCloner.java:261) ~[?:?] at com.comphenix.protocol.reflect.cloning.NullableCloner.clone(NullableCloner.java:43) ~[?:?] at com.comphenix.protocol.reflect.cloning.FieldCloner.defaultTransform(FieldCloner.java:67) ~[?:?] at com.comphenix.protocol.events.PacketContainer$2$1.access$000(PacketContainer.java:254) ~[?:?] at com.comphenix.protocol.events.PacketContainer$2$1$1.transformField(PacketContainer.java:263) ~[?:?] at com.comphenix.protocol.reflect.ObjectWriter.copyToInternal(ObjectWriter.java:115) ~[?:?] at com.comphenix.protocol.reflect.ObjectWriter.copyTo(ObjectWriter.java:80) ~[?:?] at com.comphenix.protocol.reflect.cloning.FieldCloner.clone(FieldCloner.java:91) ~[?:?] at com.comphenix.protocol.reflect.cloning.AggregateCloner.clone(AggregateCloner.java:261) ~[?:?] at com.comphenix.protocol.events.PacketContainer.deepClone(PacketContainer.java:233) ~[?:?] at com.loohp.interactivechat.listeners.OutMessagePacket$1.onPacketSending(OutMessagePacket.java:375) ~[?:?] at com.comphenix.protocol.injector.SortedPacketListenerList.invokeSendingListener(SortedPacketListenerList.java:195) ~[?:?] at com.comphenix.protocol.injector.SortedPacketListenerList.invokePacketSending(SortedPacketListenerList.java:149) ~[?:?] at com.comphenix.protocol.injector.PacketFilterManager.postPacketToListeners(PacketFilterManager.java:547) ~[?:?] at com.comphenix.protocol.injector.PacketFilterManager.invokePacketSending(PacketFilterManager.java:521) ~[?:?] at com.comphenix.protocol.injector.netty.manager.NetworkManagerInjector.onPacketSending(NetworkManagerInjector.java:94) ~[?:?] at com.comphenix.protocol.injector.netty.channel.NettyChannelInjector.processOutbound(NettyChannelInjector.java:528) ~[?:?] at com.comphenix.protocol.injector.netty.channel.NettyChannelInjector$2.proxyRunnable(NettyChannelInjector.java:470) ~[?:?] at com.comphenix.protocol.injector.netty.channel.NettyEventLoopProxy.execute(NettyEventLoopProxy.java:220) ~[?:?] at net.minecraft.network.NetworkManager.func_150732_b(NetworkManagerMixin.java:191) ~[?:?] at net.minecraft.network.NetworkManager.func_201058_a(NetworkManagerMixin.java:163) ~[?:?] at net.minecraft.network.play.ServerPlayNetHandler.func_211148_a(ServerPlayNetHandlerMixin.java:1052) ~[?:?] at net.minecraft.entity.player.ServerPlayerEntity.func_241151_a_(ServerPlayerEntityMixin.java:1195) ~[?:?] at net.minecraft.entity.player.ServerPlayerEntity.func_145747_a(ServerPlayerEntityMixin.java:1191) ~[?:?] at net.minecraft.command.CommandSource.func_197030_a(CommandSourceMixin.java:215) ~[?:?] at com.pixelmonmod.pixelmon.api.spawning.archetypes.algorithms.checkspawns.PlayerTrackingCheckSpawns.lambda$checkSpawns$1(PlayerTrackingCheckSpawns.java:74) ~[pixelmon:1.16.5-9.0.5] at net.minecraft.util.concurrent.TickDelayedTask.run(SourceFile:18) ~[?:?] at net.minecraft.util.concurrent.ThreadTaskExecutor.func_213166_h(SourceFile:144) ~[?:?] at net.minecraft.util.concurrent.RecursiveEventLoop.func_213166_h(SourceFile:23) ~[?:?] at net.minecraft.server.MinecraftServer.func_213166_h(MinecraftServerMixin.java:734) ~[?:?] at net.minecraft.server.MinecraftServer.func_213166_h(MinecraftServerMixin.java:159) ~[?:?] at net.minecraft.util.concurrent.ThreadTaskExecutor.func_213168_p(SourceFile:118) ~[?:?] at net.minecraft.server.MinecraftServer.func_213205_aW(MinecraftServerMixin.java:717) ~[?:?] at net.minecraft.server.MinecraftServer.func_213168_p(MinecraftServerMixin.java:711) ~[?:?] at net.minecraft.util.concurrent.ThreadTaskExecutor.func_213161_c(SourceFile:127) ~[?:?] at net.minecraft.server.MinecraftServer.func_213202_o(MinecraftServerMixin.java:697) ~[?:?] at net.minecraft.server.MinecraftServer.func_240802_v_(MinecraftServerMixin.java:1903) ~[?:?] at net.minecraft.server.MinecraftServer.func_240783_a_(MinecraftServerMixin.java:232) ~[?:?] at java.lang.Thread.run(Thread.java:829) [?:?]
Is there a way the deserialization exception could be caught to prevent them from breaking chat that happens after this occurs?
I could try to catch the error and send the original packet.
That would be amazing and very appreciated, happy to test it out for ya if need be
Okay, thanks for catching the issue, but there is nothing new from this. The chat component cannot be cloned as the chat component sent via the api is invalid...
I've left further replication info on #1755 - If any other info is needed and so it doesn't get lost I'm wiling to donate with anyone who can come up with a fix for this! Appreciate the help!