Much error when use velocity

[zhourui123]

forge 1.12.2 spongeforge 7.15 velocity latest plugin: bungeequack

The following problems are all generated after the use of velocity, So I think this has something to do with velocity.

1. Sometimes connect player from ServerA to ServerB , the ServerA will print "abc moved too quickly! 716.0050468618773,-18.5,-952.4585183223486",then print NPC exception, see gist "server A log" line 129.

2. Server B crash more easily when player connect from Server A. see gist "server B log". And player will kick back to server A: You were moved from the server you were on because you were kicked

The logs are all at the same time, so they can be viewed in combination

https://gist.github.com/zhourui123/d372e2dff1fee3ffe816826d9373d8ca

[astei]

What does "Velocity latest" even mean? Use the build number provided by /velocity version.

To me the most interesting (and bizarre parts) are:

[19:50:06] [Netty Epoll Server IO #1/INFO] [FML]: Client protocol version 2
[19:50:06] [Netty Epoll Server IO #1/INFO] [FML]: Client attempting to join with 5 mods : minecraft@1.12.2,mfbl@1.0.0.0,FML@8.0.99.99,forge@14.23.5.2768,mcp@9.42
[19:50:06] [Netty Epoll Server IO #1/INFO] [FML]: Attempting connection with missing mods [spongeapi, sponge, spongeforge, common, spongycord, war, mercurius_updater] at CLIENT
[19:50:06] [Netty Epoll Server IO #1/INFO] [FML]: Unexpected packet during modded negotiation - assuming vanilla or keepalives : net.minecraft.network.play.client.CPacketPlayer$Position
[19:50:06] [Netty Epoll Server IO #1/INFO] [FML]: Unexpected packet during modded negotiation - assuming vanilla or keepalives : net.minecraft.network.play.client.CPacketPlayer$Rotation
[19:50:06] [Server thread/WARN] [net.minecraft.network.NetHandlerPlayServer]: abc moved too quickly! 719.4082733512457,-20.5,-950.3579596036736
[19:50:06] [Server thread/FATAL] [net.minecraft.server.MinecraftServer]: Error executing task
java.util.concurrent.ExecutionException: java.lang.NullPointerException
    at java.util.concurrent.FutureTask.report(FutureTask.java:122) ~[?:1.8.0_202]
    at java.util.concurrent.FutureTask.get(FutureTask.java:192) ~[?:1.8.0_202]
    at net.minecraft.util.Util.func_181617_a(SourceFile:47) [h.class:?]
    at org.spongepowered.common.SpongeImplHooks.onUtilRunTask(SpongeImplHooks.java:297) [SpongeImplHooks.class:1.12.2-2768-7.1.5]
    at net.minecraft.server.MinecraftServer.redirect$onRun$zjm000(MinecraftServer.java:3963) [MinecraftServer.class:?]
    at net.minecraft.server.MinecraftServer.func_71190_q(MinecraftServer.java:723) [MinecraftServer.class:?]
    at net.minecraft.server.dedicated.DedicatedServer.func_71190_q(DedicatedServer.java:397) [nz.class:?]
    at net.minecraft.server.MinecraftServer.func_71217_p(MinecraftServer.java:668) [MinecraftServer.class:?]
    at net.minecraft.server.MinecraftServer.run(MinecraftServer.java:526) [MinecraftServer.class:?]
    at java.lang.Thread.run(Thread.java:748) [?:1.8.0_202]
Caused by: java.lang.NullPointerException
    at net.minecraft.network.NetHandlerPlayServer.func_175089_a(NetHandlerPlayServer.java:627) ~[pa.class:?]
    at net.minecraft.network.NetHandlerPlayServer.func_147364_a(NetHandlerPlayServer.java:598) ~[pa.class:?]
    at net.minecraft.network.NetHandlerPlayServer.func_147347_a(NetHandlerPlayServer.java:530) ~[pa.class:?]
    at net.minecraft.network.play.client.CPacketPlayer.func_148833_a(SourceFile:126) ~[lk.class:?]
    at net.minecraft.network.play.client.CPacketPlayer$Position.func_148833_a(SourceFile:57) ~[lk$a.class:?]
    at org.spongepowered.common.event.tracking.phase.packet.PacketPhaseUtil.onProcessPacket(PacketPhaseUtil.java:193) ~[PacketPhaseUtil.class:1.12.2-2768-7.1.5]
    at net.minecraft.network.PacketThreadUtil$1.redirect$onProcessPacket$zli000(SourceFile:539) ~[hv$1.class:?]
    at net.minecraft.network.PacketThreadUtil$1.run(SourceFile:13) ~[hv$1.class:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_202]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_202]
    at net.minecraft.util.Util.func_181617_a(SourceFile:46) ~[h.class:?]
    ... 7 more
[19:50:06] [Server thread/INFO] [FML]: [Server thread] Server side modded connection established
[19:50:06] [Server thread/INFO] [net.minecraft.server.management.PlayerList]: abc[/117.178.140.214:47192] logged in with entity id 236 in world(0) at (2.300000011920929, 67.0, 85.58872848479828)

and

[20:10:58] [Netty Epoll Server IO #4/INFO] [FML]: Client protocol version 2
[20:10:58] [Netty Epoll Server IO #4/INFO] [FML]: Client attempting to join with 5 mods : minecraft@1.12.2,mfbl@1.0.0.0,FML@8.0.99.99,forge@14.23.5.2768,mcp@9.42
[20:10:58] [Netty Epoll Server IO #4/INFO] [FML]: Attempting connection with missing mods [spongeapi, sponge, spongeforge, common, spongycord, war, mercurius_updater] at CLIENT
[20:10:58] [Netty Epoll Server IO #4/INFO] [FML]: Unexpected packet during modded negotiation - assuming vanilla or keepalives : net.minecraft.network.play.client.CPacketPlayer$Rotation
[20:10:58] [Netty Epoll Server IO #4/INFO] [FML]: Unexpected packet during modded negotiation - assuming vanilla or keepalives : net.minecraft.network.play.client.CPacketPlayer$Rotation
[20:10:58] [Server thread/FATAL] [net.minecraft.server.MinecraftServer]: Error executing task
java.util.concurrent.ExecutionException: java.lang.NullPointerException
    at java.util.concurrent.FutureTask.report(FutureTask.java:122) ~[?:1.8.0_202]
    at java.util.concurrent.FutureTask.get(FutureTask.java:192) ~[?:1.8.0_202]
    at net.minecraft.util.Util.func_181617_a(SourceFile:47) [h.class:?]
    at org.spongepowered.common.SpongeImplHooks.onUtilRunTask(SpongeImplHooks.java:297) [SpongeImplHooks.class:1.12.2-2768-7.1.5]
    at net.minecraft.server.MinecraftServer.redirect$onRun$zjm000(MinecraftServer.java:3963) [MinecraftServer.class:?]
    at net.minecraft.server.MinecraftServer.func_71190_q(MinecraftServer.java:723) [MinecraftServer.class:?]
    at net.minecraft.server.dedicated.DedicatedServer.func_71190_q(DedicatedServer.java:397) [nz.class:?]
    at net.minecraft.server.MinecraftServer.func_71217_p(MinecraftServer.java:668) [MinecraftServer.class:?]
    at net.minecraft.server.MinecraftServer.run(MinecraftServer.java:526) [MinecraftServer.class:?]
    at java.lang.Thread.run(Thread.java:748) [?:1.8.0_202]
Caused by: java.lang.NullPointerException
    at net.minecraft.server.management.PlayerChunkMapEntry.func_187278_c(PlayerChunkMapEntry.java:175) ~[ot.class:?]
    at net.minecraft.server.management.PlayerChunkMapEntry.func_187276_a(PlayerChunkMapEntry.java:74) ~[ot.class:?]
    at net.minecraft.server.management.PlayerChunkMap.func_72685_d(SourceFile:288) ~[ou.class:?]
    at net.minecraft.server.management.PlayerList.func_72358_d(PlayerList.java:383) ~[pl.class:?]
    at net.minecraft.network.NetHandlerPlayServer.func_147347_a(NetHandlerPlayServer.java:584) ~[pa.class:?]
    at net.minecraft.network.play.client.CPacketPlayer.func_148833_a(SourceFile:126) ~[lk.class:?]
    at net.minecraft.network.play.client.CPacketPlayer$Rotation.func_148833_a(SourceFile:88) ~[lk$c.class:?]
    at org.spongepowered.common.event.tracking.phase.packet.PacketPhaseUtil.onProcessPacket(PacketPhaseUtil.java:174) ~[PacketPhaseUtil.class:1.12.2-2768-7.1.5]
    at net.minecraft.network.PacketThreadUtil$1.redirect$onProcessPacket$zli000(SourceFile:539) ~[hv$1.class:?]
    at net.minecraft.network.PacketThreadUtil$1.run(SourceFile:13) ~[hv$1.class:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_202]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_202]
    at net.minecraft.util.Util.func_181617_a(SourceFile:46) ~[h.class:?]
... 7 more

I'm not sure why the first error happens. I'll try to investigate it. The other is even stranger, and I haven't run into this before with my own Forge testing. As a first step, try removing all your mods except for Sponge.

Paging @dualspiral since he wrote the Forge support for Velocity.

[zhourui123]

sorry, the version is: Velocity 1.0-SNAPSHOT (git-45574ce9-b79) , and command must without '/'

[dualspiral]

[19:50:06] [Netty Epoll Server IO #1/INFO] [FML]: Unexpected packet during modded negotiation - assuming vanilla or keepalives : net.minecraft.network.play.client.CPacketPlayer$Position
[19:50:06] [Netty Epoll Server IO #1/INFO] [FML]: Unexpected packet during modded negotiation - assuming vanilla or keepalives : net.minecraft.network.play.client.CPacketPlayer$Rotation

then

func_175089_a => setPlayerLocation func_187278_c => sendToPlayer

From a very cursory glance, it looks like it's because position/rotation packets are getting through from the client (which still thinks its on the old world) and the new server doesn't handle this well - trying to act upon this information that shouldn't have been destined for it coupled with the fact the player has yet to spawn in the new world - my guess is that the player object has not been fully created yet and so the server goes "nope".

I imagine that there are many mods involved so there is a fair amount of processing before the FML handshake completes (lots to do during the final step), and so these packets are being sent as the player is moving before switch occurs. Maybe, at least as a diagnostic, try to prvent position and rotation packets from getting through until Join/Respawn is sent?

[zhourui123]

Sorry i don't know how to prevent position and rotation packet? Is just comment player.setLocation at loginEvent?

[dualspiral]

It was directed at @astei as to what might be going on, nothing for you to do at this stage.

[electronicboy]

The NPE is seemingly due to the player being incorrectly added to the world, while handshaking, FML will set the players connection handler to null, to prevent sending packets (This is expected forge behavior), if you are teleporting a player before they've actually joined the world, that will be causing that, as it will add their Player to the world before it's expected

When we hit handshaking, the client is in PLAY, which means that if you are in fact teleporting the player, this could be causing the client to send packets before expected

[zhourui123]

Would you also focus on the crash issue? because there are not happend with waterfall. The crash was too frequently when connect player to B-server to A-server. The crash happens in destination. the full log also include at gist above:

net.minecraft.util.ReportedException: Exception ticking world
        at net.minecraft.server.MinecraftServer.func_71190_q(MinecraftServer.java:762) ~[MinecraftServer.class:?]
        at net.minecraft.server.dedicated.DedicatedServer.func_71190_q(DedicatedServer.java:397) ~[nz.class:?]
        at net.minecraft.server.MinecraftServer.func_71217_p(MinecraftServer.java:668) ~[MinecraftServer.class:?]
        at net.minecraft.server.MinecraftServer.run(MinecraftServer.java:526) [MinecraftServer.class:?]
        at java.lang.Thread.run(Unknown Source) [?:1.8.0_181]
Caused by: java.lang.NullPointerException
        at net.minecraft.server.management.PlayerChunkMapEntry.func_187272_b(PlayerChunkMapEntry.java:161) ~[ot.class:?]

[dualspiral]

It's the same issue.

[astei]

I'd like to isolate this issue. Can you remove all your Forge mods, keeping just Sponge?

[astei]

Also going to ask you to update to the latest Velocity which may have fixed this issue.

[zhourui123]

ok, at first, i will update to the latest velocity and not remove forge mod, test it for a while. If problem still, then i will remove all forgemod( there's actually only one mod that I developed myself)

[astei]

That sounds like a good plan to me 👍

179 may have actually fixed this issue. If so, then this wasn't a Forge issue in so much as it was Velocity not properly handling packets around the time of server switches.

[zhourui123]

version 81, plugin: bungeequack Some connect test between 3 server include forge mod, there were still some errors but no crashes, further tests are needed to see if it will crash. https://gist.github.com/zhourui123/0ed1e120128c630b49594cd244af4f37

[14:32:36] [Server thread/WARN] [net.minecraft.network.NetHandlerPlayServer]: abc moved too quickly! 716.607148978498,-20.0,-950.1999999880791
[14:32:36] [Server thread/FATAL] [net.minecraft.server.MinecraftServer]: Error executing task
java.util.concurrent.ExecutionException: java.lang.NullPointerException
    at java.util.concurrent.FutureTask.report(FutureTask.java:122) ~[?:1.8.0_202]

[astei]

Okay, so the worst of it appears to be out of the way. What happens if you don't have your mod on the server and client?

[zhourui123]

Recently I have been changing from eclipse to idea, and I will test after the adjustment

[zhourui123]

I removed forgemod but include spongeforgePlugin tested today, I wrote a repeately task on the server and sent all player to another server, during 40 minute, server crashed. Shall I remove all of the sponge plug tests? If so, testing might be difficult because I don't know how to connect a player to another server all the time.....

version: velocity81 (git-2c5a6d0f-b81) spongeforge-1.12.2-2768-7.1.6-RC3627 velocity plugin: bungeequack-1.0-SNAPSHOT.jar

[zhourui123]

When I remove all mod only include spongeforge.jar(I found it impossible to remove it because it was needed again to support the proxy), I tried create a velocity plugin to connect player

 @Subscribe
    public void onProxyInitialize(ProxyInitializeEvent event) {

        server.getScheduler().buildTask(this,()->{
            server.getAllPlayers().forEach(ply->{
                @MaybePresent Optional<RegisteredServer> optServerInfo;
                if (to_lobby) {
                    optServerInfo = server.getServer("lobby");

                } else {
                    optServerInfo=server.getServer("mg_3");
                }

                optServerInfo.ifPresent(serverInfo->{
                    ply.createConnectionRequest(serverInfo).fireAndForget();
                   // System.out.println(serverInfo.getServerInfo().getName()+","+ply.getUsername());
                });
            });
            to_lobby=!to_lobby;

        }).repeat(5, TimeUnit.SECONDS).schedule();

    }

The first and second runs crashed, and the rest of the time everything was fine. https://gist.github.com/zhourui123/3dec409a47646516f3f04653bdb1cf83

[astei]

I am currently working on a rework of the Velocity server-switching logic, which may resolve this issue (amongst others).

[astei]

Can you please try the latest version of Velocity?

[zhourui123]

sure, but it could be a few day later.

[astei]

This issue has been inactive for some time, so I'm closing this. If this is still an issue, please let us know.