search

stargate-rewritten / Stargate-Bukkit

The original, and still the best, survival-friendly portal plugin.
https://sgrewritten.org/paper
GNU Lesser General Public License v3.0
28 stars 13 forks source link

Duplicate portal create messages were sent for interserver #313

Open Thorinwasher opened 4 months ago

Thorinwasher commented 4 months ago

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

Thorinwasher commented 4 months ago

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

EpicKnarvik97 commented 4 months ago

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.

Thorinwasher commented 4 months ago

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.

EpicKnarvik97 commented 4 months ago

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.

Thorinwasher commented 4 months ago

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