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.

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

[BUG] Plugin causes "Invalid move player packet received" kicks upon teleports #255

Closed
maeeeeee opened this issue Nov 12, 2022 · 18 comments
Closed
Labels
bug Something isn't working

Comments

@maeeeeee
Copy link

maeeeeee commented Nov 12, 2022

Description

Upon teleporting some distance, players are occasionally kicked with an invalid move player packet error. This error was narrowed down to being caused by QuickShop after sequentially removing plugins from the server one by one until the kick no longer happened, and then adding QuickShop back to verify that the kick once again occurred after reinstalling it. Appears to only happen when one of the teleportation locations involved has shops nearby.

Minimum number of plugins installed that I tried while still getting the kick:
LWCX 2.2.7
EssentialsX
EssentialsX AntiBuild
EssentialsX Chat
EssentialsX Protect
EssentialsX Spawn
ProtocolLib
QuickShop 5.1.0.9

Console output during kick (/b is our server's alias for the Essentials /back command):

13:58:47
maeeeeee issued server command: /b
maeeeeee issued server command: /b
13:58:48
maeeeeee issued server command: /b
maeeeeee issued server command: /b
maeeeeee lost connection: Invalid move player packet received
-maeeeeee has left for now.

Steps to reproduce

  1. Teleport to a location. Several different plugins were used for teleporting, such as EssentialsX, MyWarp, and others, and each caused the issue.
  2. Player is occasionally kicked from the server.

To consistently reproduce using EssentialsX, teleport somewhere (/tpr works for this) and then spam /back until the issue occurs.

Expected Behaviour

Plugin should not be causing players to be kicked upon teleports.

Screenshots

Minecraft.2022.11.12.-.13.57.55.03.mp4

/qs paste URL

https://paste.helpch.at/ovodovafof

Additional Context

I can be reached on Discord at Mae#5439 if any additional information is needed regarding this issue.

@x86-39
Copy link

x86-39 commented Nov 12, 2022

Does not seem to happen with default Paper configs, had to copy our yml files to a test server to replicate.

Will narrow down which option(s) cause this bug.

@x86-39
Copy link

x86-39 commented Nov 12, 2022

Narrowed down the config file that causes it as config/paper-world-defaults.yml

@x86-39
Copy link

x86-39 commented Nov 12, 2022

Narrowed down the cause to enabling anti-xray in anticheat.
This is turned off by default, but is a common option and just setting this to enabled seems to cause this issue.

@x86-39
Copy link

x86-39 commented Nov 13, 2022

Can replicate with paper-1.19.2-265 with the following plugins:

  • Vault
  • QuickShop Reremake. Compiled from the master branch here.
  • Protocollib
  • EssentialsX

All configs set to default , except for:
Changed config/paper-world-defaults.yml and setting anticheat.anti-xray.enabled to true.

Spamming /back from EssentialsX between two areas far apart where at least one of the areas has a QuickShop shop loaded.
I'm using a mod Command Macros to send /back every 100ms.
Of course spamming it so much isn't representative, but this is a way to replicate the issue. This just often happens out of nowhere to players when teleporting. It seems to happen to some players more than others so connection speed could be a part of it, but I'm seeing it happen to about every player. Checking through logs we've had this happen 985 times since October 15th. This is when we updated to Paper 1.19 and Quickshop 5.1.0.9.

@sandtechnology
Copy link

Does it only happened with player skull shop or all shops?

@x86-39
Copy link

x86-39 commented Nov 13, 2022

Any shops, was able to replicate it on a fresh server like mentioned in my previous comment by using a chest as the item

@maeeeeee
Copy link
Author

Issue still occurs. Didn't get it in the recording, but I also got instantly kicked for the same invalid move player packet when trying to log in at this location as well. Client is completely vanilla.

https://youtu.be/YbeF3Yop0bk

@sandtechnology
Copy link

Issue still occurs. Didn't get it in the recording, but I also got instantly kicked for the same invalid move player packet when trying to log in at this location as well. Client is completely vanilla.

https://youtu.be/YbeF3Yop0bk

How about setting display-type to 0 in config.yml?

@maeeeeee
Copy link
Author

That appears to fix the issue, yes, or at least I'm unable to reproduce it after changing that setting. Seems the problem is related to the virtual display item type.

@sandtechnology
Copy link

That appears to fix the issue, yes, or at least I'm unable to reproduce it after changing that setting. Seems the problem is related to the virtual display item type.

That's weird but could be a workaround, I need to dig into server and client to see what happens there, it will needs lots of time.

@sandtechnology sandtechnology added the bug Something isn't working label Nov 13, 2022
@sandtechnology
Copy link

Process report:
After digging I found the reason is the server is sending duplicated teleport REQ packet with duplicated id (ClientboundPlayerPositionPacket), I write a mixin mod for client to see if it will solve this-and it works:

@net.minecraftforge.api.distmarker.OnlyIn(net.minecraftforge.api.distmarker.Dist.CLIENT)
@org.spongepowered.asm.mixin.Mixin(net.minecraft.client.multiplayer.ClientPacketListener.class)
public class MixinClientPacketListener {
    @org.spongepowered.asm.mixin.Final
    @org.spongepowered.asm.mixin.Shadow
    private static org.slf4j.Logger LOGGER;
    private final ThreadLocal<Integer> lastTeleportReqID= ThreadLocal.withInitial(() -> -1);

    @org.spongepowered.asm.mixin.injection.Inject(method = "handleMovePlayer",at = @org.spongepowered.asm.mixin.injection.At(value = "HEAD"), cancellable = true)
    public void onHandlePlayerMoves(net.minecraft.network.protocol.game.ClientboundPlayerPositionPacket p_105056_, org.spongepowered.asm.mixin.injection.callback.CallbackInfo ci){
        LOGGER.info("Recv teleport REQ Packet, id="+p_105056_.getId());
        if(lastTeleportReqID.get()!=p_105056_.getId()){
            lastTeleportReqID.set(p_105056_.getId());
        }else {
            LOGGER.warn("Found duplicated teleport REQ Packet, cancelled!");
            ci.cancel();
        }
    }
}

Logs:

[14Nov2022 08:13:44.145] [Netty Client IO #0/INFO] [net.minecraft.client.multiplayer.ClientPacketListener/]: Recv teleport REQ Packet, id=53
[14Nov2022 08:13:44.152] [Render thread/INFO] [net.minecraft.client.multiplayer.ClientPacketListener/]: Recv teleport REQ Packet, id=53
[14Nov2022 08:13:44.579] [Netty Client IO #0/INFO] [net.minecraft.client.multiplayer.ClientPacketListener/]: Recv teleport REQ Packet, id=54
[14Nov2022 08:13:44.580] [Render thread/INFO] [net.minecraft.client.gui.components.ChatComponent/]: [System] [CHAT] Back to previous location.
[14Nov2022 08:13:44.580] [Render thread/INFO] [net.minecraft.client.multiplayer.ClientPacketListener/]: Recv teleport REQ Packet, id=54
[14Nov2022 08:13:44.592] [Netty Client IO #0/INFO] [net.minecraft.client.multiplayer.ClientPacketListener/]: Recv teleport REQ Packet, id=55
[14Nov2022 08:13:44.592] [Render thread/INFO] [net.minecraft.client.multiplayer.ClientPacketListener/]: Recv teleport REQ Packet, id=55
[14Nov2022 08:13:44.595] [Netty Client IO #0/INFO] [net.minecraft.client.multiplayer.ClientPacketListener/]: Recv teleport REQ Packet, id=56
[14Nov2022 08:13:44.596] [Netty Client IO #0/INFO] [net.minecraft.client.multiplayer.ClientPacketListener/]: Recv teleport REQ Packet, id=56
[14Nov2022 08:13:44.596] [Netty Client IO #0/WARN] [net.minecraft.client.multiplayer.ClientPacketListener/]: Found duplicated teleport REQ Packet, cancelled!
[14Nov2022 08:13:44.607] [Render thread/INFO] [net.minecraft.client.multiplayer.ClientPacketListener/]: Recv teleport REQ Packet, id=56
[14Nov2022 08:13:45.790] [Netty Client IO #0/INFO] [net.minecraft.client.multiplayer.ClientPacketListener/]: Recv teleport REQ Packet, id=57

But I still need to found why server is sending duplicated teleport REQ packet, It seems all running in the main thread and should not duplicated.

@sandtechnology
Copy link

sandtechnology commented Nov 14, 2022

Found the issue in the paper end and PR has opened in paper side, the paper build for this PR is here, you can test if this paper build fix it (looks good to me in testing):
https://mega.nz/file/Y8oiAYwa#5a_L-Rvjj7qly4FM9tjNMlQp0A0OpxABDxplspvL2d4

@x86-39
Copy link

x86-39 commented Nov 14, 2022

Can confirm it prevents the kicks for me too

@sandtechnology
Copy link

sandtechnology commented Nov 15, 2022

Updated paper build for testing is here, should be solving this issue as well: https://mega.nz/file/BwA3HC7I#qZgM8b93X0NKiidE3prUFZkg7aqdetgS3jiLgu8r-K4

@x86-39
Copy link

x86-39 commented Nov 15, 2022

Yep can confirm this patch also fixes the issue

@sandtechnology
Copy link

Upstream have merged my PR, so just use build 297 and above will fix it: https://papermc.io/downloads, if still have issue feel free to reopen it.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

3 participants