PotatoCraft-Studio / QuickShop-Reremake

QuickShop-Reremake is a **FREE** shop plugin that allows players to easily sell/buy any items from a chest without any commands. In fact, none of the commands that QuickShop-Reremake provides are ever needed by a player.
GNU General Public License v3.0
70 stars 78 forks source link

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

Closed maeeeeee closed 1 year ago

maeeeeee commented 1 year ago

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

https://user-images.githubusercontent.com/52181624/201490494-7fb29f92-e23a-4707-81b7-b76f040abeee.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.

diademiemi commented 1 year ago

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.

diademiemi commented 1 year ago

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

diademiemi commented 1 year ago

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.

diademiemi commented 1 year ago

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

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 commented 1 year ago

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

diademiemi commented 1 year ago

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 commented 1 year ago

Unsure if relevant, but this issue previously occurred (and was fixed) in Denizen as described here.

sandtechnology commented 1 year ago

How about this build?https://ci.codemc.io/job/PotatoCraft-Studio/job/QuickShop-Reremake-SNAPSHOT/2405/artifact/target/QuickShop-5.1.0.10-SNAPSHOT.jar

maeeeeee commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

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

diademiemi commented 1 year ago

Can confirm it prevents the kicks for me too

sandtechnology commented 1 year ago

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

diademiemi commented 1 year ago

Yep can confirm this patch also fixes the issue

sandtechnology commented 1 year ago

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.