Duplicate portal create messages were sent for interserver
Thorinwasher opened this issue ยท 5 comments
Bug Description
Duplicate portal create messages were sent for interserver
Reproduction Steps
Create an interserver portal ijn one server (do all preparatory step to be able to do this of course)
Desired Behaviour
no stacktrace
Observed Behaviour
[17:48:19 WARN]: [Stargate] org.sgrewritten.stargate.exception.name.NameConflictException : portal of name 'alsdn' already exist in network 'inter'
[17:48:19 WARN]: [Stargate] at Stargate-1.0.0.14-ALPHA.jar//org.sgrewritten.stargate.network.StargateNetwork.addPortal(StargateNetwork.java:148)
[17:48:19 WARN]: [Stargate] at Stargate-1.0.0.14-ALPHA.jar//org.sgrewritten.stargate.manager.StargateBungeeManager.portalAddOrRemove(StargateBungeeManager.java:109)
[17:48:19 WARN]: [Stargate] at Stargate-1.0.0.14-ALPHA.jar//org.sgrewritten.stargate.manager.StargateBungeeManager.updateNetwork(StargateBungeeManager.java:56)
[17:48:19 WARN]: [Stargate] at Stargate-1.0.0.14-ALPHA.jar//org.sgrewritten.stargate.listener.StargateBungeePluginMessageListener.onPluginMessageReceived(StargateBungeePluginMessageListener.java:100)
[17:48:19 WARN]: [Stargate] at org.bukkit.plugin.messaging.StandardMessenger.dispatchIncomingMessage(StandardMessenger.java:455)
[17:48:19 WARN]: [Stargate] at net.minecraft.server.network.ServerCommonPacketListenerImpl.a(ServerCommonPacketListenerImpl.java:163)
[17:48:19 WARN]: [Stargate] at net.minecraft.network.protocol.common.ServerboundCustomPayloadPacket.a(ServerboundCustomPayloadPacket.java:46)
[17:48:19 WARN]: [Stargate] at net.minecraft.network.protocol.common.ServerboundCustomPayloadPacket.a(ServerboundCustomPayloadPacket.java:12)
[17:48:19 WARN]: [Stargate] at net.minecraft.network.protocol.PlayerConnectionUtils.lambda$ensureRunningOnSameThread$0(PlayerConnectionUtils.java:53)
[17:48:19 WARN]: [Stargate] at net.minecraft.server.TickTask.run(TickTask.java:18)
[17:48:19 WARN]: [Stargate] at net.minecraft.util.thread.IAsyncTaskHandler.d(IAsyncTaskHandler.java:153)
[17:48:19 WARN]: [Stargate] at net.minecraft.util.thread.IAsyncTaskHandlerReentrant.d(IAsyncTaskHandlerReentrant.java:24)
[17:48:19 WARN]: [Stargate] at net.minecraft.server.MinecraftServer.b(MinecraftServer.java:1324)
[17:48:19 WARN]: [Stargate] at net.minecraft.server.MinecraftServer.d(MinecraftServer.java:193)
[17:48:19 WARN]: [Stargate] at net.minecraft.util.thread.IAsyncTaskHandler.x(IAsyncTaskHandler.java:126)
[17:48:19 WARN]: [Stargate] at net.minecraft.server.MinecraftServer.bg(MinecraftServer.java:1301)
[17:48:19 WARN]: [Stargate] at net.minecraft.server.MinecraftServer.x(MinecraftServer.java:1294)
[17:48:19 WARN]: [Stargate] at net.minecraft.util.thread.IAsyncTaskHandler.c(IAsyncTaskHandler.java:136)
[17:48:19 WARN]: [Stargate] at net.minecraft.server.MinecraftServer.a(MinecraftServer.java:1371)
[17:48:19 WARN]: [Stargate] at net.minecraft.server.MinecraftServer.w(MinecraftServer.java:1156)
[17:48:19 WARN]: [Stargate] at net.minecraft.server.MinecraftServer.lambda$spin$0(MinecraftServer.java:315)
[17:48:19 WARN]: [Stargate] at java.base/java.lang.Thread.run(Unknown Source)
Trace Logs
Nein
Other Information
Seems very similar to #305
Easiest way to avoid this is just to hide the stack trace, it really is harmless. But it's good to keep for debug purposes
or if it's that the servers answer each other (that's not clear without knowing the output of all connected servers).
There was only output like this on one server.
I have had it in the back of my head since I made a refactor (removed all database code away from the registry) that I somehow made a mistake and that the servers are sending the portal create messages in a loop. But I haven't found it to be real.
This is definitely unusual behavior, could it also have something to do with the unreliability of bungee?
Whatever it is, it's not critical (except for maybe infinite creation loops if that were a thing). But it is definitely a bug.
or if it's that the servers answer each other (that's not clear without knowing the output of all connected servers).
There was only output like this on one server.
I have had it in the back of my head since I made a refactor (removed all database code away from the registry) that I somehow made a mistake and that either the servers are sending the portal create messages in a loop. But I haven't found it to be real.
This is definitely unusual behavior, could it also have something to do with the unreliability of bungee?
Whatever it is, it's not critical (except for maybe infinite creation loops if that were a thing). But it is definitely a bug.
Then it's definitely responding to its own BungeeCord messages. I believe BungeeCord messages should have some kind of sending server id, so a server won't respond/listen to BungeeCord messages it has sent to the other servers.
It isn't a direct fix to this issue, but it should fix this issue as well.
Then it's definitely responding to its own BungeeCord messages. I believe BungeeCord messages should have some kind of sending server id, so a server won't respond/listen to BungeeCord messages it has sent to the other servers.
It isn't a direct fix to this issue, but it should fix this issue as well.
That could definitely fix the issue, I would rather find the real problem behind this first though. It might be something completely different than one expects. I would agree, this is probably not a bungee bug, I would be surprised if that were the case
Similar behavior can be seen for teleportation requests as well:
[18:13:14 INFO]: [Stargate] trying to read player join json msg
[18:13:14 INFO]: [Stargate] {"PLAYER":"LegetimateUser2","PORTAL":"inter2","NETWORK":"inter"}
[18:13:14 INFO]: [Stargate] Player was not null; trying to teleport
[18:13:14 INFO]: [Stargate] Formatted TranslatableMessage 'TELEPORT' to 'Teleported!'
[18:13:14 INFO]: [Stargate] Checking permissions for entity CraftPlayer{name=LegetimateUser2}
[18:13:14 INFO]: [Stargate] Adding action org.sgrewritten.stargate.action.SupplierAction@7afb7f96
[18:13:14 INFO]: [Stargate] Received plugin-message
[18:13:14 INFO]: [Stargate] trying to read player join json msg
[18:13:14 INFO]: [Stargate] {"PLAYER":"LegetimateUser2","PORTAL":"inter2","NETWORK":"inter"}
[18:13:14 INFO]: [Stargate] Player was not null; trying to teleport
[18:13:14 INFO]: [Stargate] Formatted TranslatableMessage 'TELEPORT' to 'Teleported!'
[18:13:14 INFO]: [Stargate] Checking permissions for entity CraftPlayer{name=LegetimateUser2}
[18:13:14 INFO]: [Stargate] Adding action org.sgrewritten.stargate.action.SupplierAction@7ef80b6b
[18:13:14 INFO]: [Stargate] Received plugin-message
[18:13:14 INFO]: [Stargate] trying to read player join json msg
[18:13:14 INFO]: [Stargate] {"PLAYER":"LegetimateUser2","PORTAL":"inter2","NETWORK":"inter"}
[18:13:14 INFO]: [Stargate] Player was not null; trying to teleport
[18:13:14 INFO]: [Stargate] Formatted TranslatableMessage 'TELEPORT' to 'Teleported!'
[18:13:14 INFO]: [Stargate] Checking permissions for entity CraftPlayer{name=LegetimateUser2}
[18:13:14 INFO]: [Stargate] Adding action org.sgrewritten.stargate.action.SupplierAction@11e14352
[18:13:14 INFO]: [Stargate] Received plugin-message
[18:13:14 INFO]: [Stargate] trying to read player join json msg
[18:13:14 INFO]: [Stargate] {"PLAYER":"LegetimateUser2","PORTAL":"inter2","NETWORK":"inter"}
[18:13:14 INFO]: [Stargate] Player was not null; trying to teleport
[18:13:14 INFO]: [Stargate] Formatted TranslatableMessage 'TELEPORT' to 'Teleported!'
[18:13:14 INFO]: [Stargate] Checking permissions for entity CraftPlayer{name=LegetimateUser2}
[18:13:14 INFO]: [Stargate] Adding action org.sgrewritten.stargate.action.SupplierAction@be79c6c
This comes from entering a portal once, somehow the messages got sent multiple times
It seems there are loops in the logic of inter-server messages, but I'm unsure whether part of the problem is that an inter-server responds to its own message, or if it's that the servers answer each other (that's not clear without knowing the output of all connected servers).
For the teleportation message, it seems likely that the receival of a teleportation message calls VirtualPortal's teleportHere message (instead of/in addition to AbstractPortal's teleportHere), which sends a new teleportation message to BungeeCord. In StargateBungeeManager.playerConnect(String message), the fetched destination portal might be a virtual portal, causing the VirtualPortal's teleportHere message to be sent.