Player get kicked due to out-of-order chat when sending messages rapidly

[Glucy-2]

Velocity version: 3.1.2-SNAPSHOT-201

• No Velocity plugin installed
• No matter whether the value of force-key-authentication is true or false, the player will be kicked
• I've tested modern and none player info forwarding mode

Server: 1.19.3, fabric with mods: fabric-api, fabric-carpet, carpet-tis-addition, fabricproxy-lite
Velocity log:

[16:02:00 INFO]: [connected player] AnnaNo (/113.x.x.x:56524) has connected
[16:02:00 INFO]: [server connection] AnnaNo -> mirror has connected
[16:02:38 INFO]: [connected player] AnnaNo (/113.x.x.x:56524) -> executed command /gamerule sendCommandFeedback
[16:02:38 INFO]: [connected player] AnnaNo (/113.x.x.x:56524) -> executed command /fill 9 -32 256 10 -32 256 minecraft:iron_block replace air
[16:02:38 INFO]: [connected player] AnnaNo (/113.x.x.x:56524) -> executed command /setblock 9 -32 257 minecraft:observer[facing=south,powered=false]
[16:02:38 INFO]: [connected player] AnnaNo (/113.x.x.x:56524) -> executed command /fill 9 -29 256 9 -29 257 minecraft:redstone_wire[east=none,north=side,power=0,south=side,west=none] replace air
...
[16:02:38 INFO]: [connected player] AnnaNo (/113.x.x.x:56524) -> executed command /setblock 11 -29 256 minecraft:white_stained_glass
[16:02:38 INFO]: [connected player] AnnaNo (/113.x.x.x:56524): kicked from server mirror: multiplayer.disconnect.out_of_order_chat
[16:02:38 INFO]: [server connection] AnnaNo -> mirror has disconnected
[16:02:38 INFO]: [connected player] AnnaNo (/113.x.x.x:56524) has disconnected: You were kicked from mirror: multiplayer.disconnect.out_of_order_chat

fabric server log:

[16:02:00] [Server thread/INFO]: AnnaNo[/113.x.x.x:49340] logged in with entity id 142 at (-0.4497645856701771, -40.0, 248.48987400782113)
[16:02:00] [Server thread/INFO]: AnnaNo joined the game
[16:02:01] [Server thread/INFO]: Player AnnaNo joined with a matching carpet client
[16:02:38] [Netty Epoll Server IO #3/WARN]: AnnaNo sent out-of-order chat: 'fill 9 -29 256 9 -29 257 minecraft:redstone_wire[east=none,north=side,power=0,south=side,west=none] replace air'
[16:02:38] [Server thread/INFO]: [AnnaNo: Changed the block at 9, -32, 257]
[16:02:38] [Server thread/INFO]: [AnnaNo: Successfully filled 2 blocks]
[16:02:38] [Server thread/INFO]: [AnnaNo: Changed the block at 9, -34, 258]
[16:02:38] [Server thread/INFO]: [AnnaNo: Changed the block at 9, -33, 258]
[16:02:38] [Server thread/INFO]: [AnnaNo: Changed the block at 9, -32, 258]
[16:02:38] [Server thread/INFO]: [AnnaNo: Changed the block at 9, -31, 258]
[16:02:38] [Server thread/INFO]: [AnnaNo: Changed the block at 9, -30, 258]
[16:02:38] [Server thread/INFO]: [AnnaNo: Changed the block at 9, -29, 258]
[16:02:38] [Server thread/INFO]: [AnnaNo: Changed the block at 9, -28, 258]
[16:02:38] [Server thread/INFO]: [AnnaNo: Changed the block at 9, -27, 258]
[16:02:38] [Server thread/INFO]: AnnaNo lost connection: Out-of-order chat packet received. Did your system time change?
[16:02:38] [Server thread/INFO]: AnnaNo left the game
[16:02:38] [Server thread/INFO]: [AnnaNo: Changed the block at 9, -26, 258]
[16:02:38] [Server thread/INFO]: [AnnaNo: Changed the block at 9, -25, 258]
[16:02:38] [Server thread/INFO]: [AnnaNo: Changed the block at 9, -24, 258]
[16:02:38] [Server thread/INFO]: [AnnaNo: Changed the block at 9, -34, 259]
[16:02:38] [Server thread/INFO]: [AnnaNo: Changed the block at 9, -33, 259]
[16:02:38] [Server thread/INFO]: [AnnaNo: Changed the block at 9, -32, 259]
[16:02:38] [Server thread/INFO]: [AnnaNo: Changed the block at 9, -25, 259]
[16:02:38] [Server thread/INFO]: [AnnaNo: Changed the block at 9, -24, 259]
[16:02:38] [Server thread/WARN]: handleDisconnection() called twice

When directly connect to the fabric server or use Waterfall as proxy (delete fabricproxy-lite mod), player won't be kicked due to out-of-order chat

To reproduce:

1. Set-up a 1.19.3 fabric server and install mods: fabric-api, fabric-carpet, carpet-tis-addition, fabricproxy-lite
2. Start the fabric server and enter carpet antiSpamDisabled true to disable spamming checks on players
3. Set-up 3.1.2-SNAPSHOT-201 Velocity and start it
4. Connect using a client with litematica mod and paste a schematic (or maybe some other methods that can send more than about 50 messages per second)
5. Client get kicked due to out-of-order chat

[nothendev]

Change message frequency in litematica settings. You can't do anything else, unless a dev implements a config setting that toggles checking signed-ness of messages.

[nothendev]

Velocity/proxy/src/main/java/com/velocitypowered/proxy/connection/client/ClientPlaySessionHandler.java

Line 134 in c9e0e14

if (!this.timeKeeper.update(instant)) {

This condition could be (!this.timeKeeper.update(instant) && !config.allowMessageSpam) e.g. check if order is not preserved AND the message spam setting is not enabled (e.g. message spam is not allowed)

[electronicboy]

It's not velocity that's doing the kick, so adding a config option in velocity would be useless. It seems that there is a race condition in the logic somewhere

[CoreyShupeSLG]

I have a feeling it has to do with some line in velocity using Instant.now() in place of the provided packet's timestamp; I thought I got all the commands and chat covered in that pipeline but it seems not. Does it always happen on commands? Is it commands & chat? It seems like all the prior logs are showing command failures - maybe that's a lead for where the issue could sit.

[woshikedayaa]

also getting this error in 1.19.2
but when i using 1.18.2-minecraft-fabric-server
velocity performaned normally

[GLDYM]

Getting this error in 1.19.4&1.19.2 Paper, but this problem doesn't occur when don't connect to the server through Velocity.

I think this problem happens when the chat & command messages are sent to the fabric server from Velocity. The timestamps of messages are disarranged, so the fabric server receives out-of-order messages and ticks the player out. Maybe there are some bugs in Velocity when dealing with a lot of messages at one time.

[woshikedayaa]

you can use the tin3omod to ban the out-of-order

[CtrlAiDel]

Hello everyone. Sorry to bother

I have the same issue. I see that the branch LeavesMC fixed this, could you please try to implement the same to paper or velocity?

[electronicboy]

They didn’t fix it, they just tried to hack around it

there is a pr which looks to change some of the processing around the chat stuff, I don’t have hardware to look into it, but, if you can compile velocity probably worth testing

[not-3than]

I'm having the same issue. I'm able to replicate it by sending a chat message then immediately sending a random command. Connected on 1.19.2 to a 1.20.1 server (only happens for 1.19.1-3 clients, not 1.19.4 or any other)

[not-3than]

In a paper fork called pufferfish, the issue is resolved, but I'd rather stick to using Paper/Velocity.

[4drian3d]

Could you try the latest build? There is a pull request merge that can fix this error

[CtrlAiDel]

I will be able to try it probably tonight :) ! Thanks for the heads up

[electronicboy]

Should have been resolved by #1042

[CtrlAiDel]

Sorry if i wasn't able to test it right away, Had RAM problem with my server.

I confirm that this fix is working for us too!

We appreciate it a lot! :) Have a great day