EOF during deserialization in minetest-protocol

[l-koehler]

Attempting to use minetest-protocol (both 0.1.4 from crates.io and the latest git version) for a server fails when connecting with a minetest client (5.9.1, but I also tried using the latest on arch linux).
The client shows "Connecting to server..." for a moment, then "Access denied. Reason: Connection aborted (protocol error?)."

(maybe) relevant log from minetest --trace:

2025-01-01 22:45:47: INFO[Main]: Connecting to server at 127.0.0.1:30000
2025-01-01 22:45:47: TRACE[ConnectionReceive]: con(68/0)ConnectionReceive thread started
2025-01-01 22:45:47: TRACE[ConnectionSend]: con(68/0) UDP processing CONNCMD_CONNECT
2025-01-01 22:45:47: TRACE[ConnectionSend]: con(68/0) connecting to 127.0.0.1:30000
2025-01-01 22:45:47: TRACE[ConnectionSend]: con(68/0)UDP processing reliable CONNCMD_SEND
2025-01-01 22:45:47: TRACE[ConnectionSend]: con(68/0) processing reliable command for peer id: 1 data size: 0
2025-01-01 22:45:47: TRACE[ConnectionSend]: con(68/0)	channel: 0, peer quota:1024
2025-01-01 22:45:47: TRACE[ConnectionSend]: 			reliables on wire: 0, waiting for ack for 0
2025-01-01 22:45:47: TRACE[ConnectionSend]: 			incoming_reliables: 0, next reliable packet: 65500, next queued: 0
2025-01-01 22:45:47: TRACE[ConnectionSend]: 			reliables queued : 1
2025-01-01 22:45:47: TRACE[ConnectionSend]: 			queued commands  : 0
2025-01-01 22:45:47: TRACE[ConnectionSend]: con(68/0) INFO: sending a queued reliable packet  channel: 0, seqnum: 65500
2025-01-01 22:45:47: TRACE[ConnectionReceive]: con(68/0) got packet from unknown peer_id: 0 Ignoring.
2025-01-01 22:45:47: TRACE[Main]: con(68/0): Receive: got event: CONNEVENT_PEER_ADDED
2025-01-01 22:45:47: INFO[Main]: Client::peerAdded(): peer->id=1
2025-01-01 22:45:47: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2025-01-01 22:45:47: TRACE[ConnectionSend]: con(68/0) UDP processing CONNCMD_SEND
2025-01-01 22:45:47: TRACE[ConnectionSend]: con(68/0) sending to peer_id=1, channel 1, size: 17
2025-01-01 22:45:47: TRACE[ConnectionSend]: con(68/0) Handle non reliable queue (1 pkts)
2025-01-01 22:45:47: TRACE[ConnectionReceive]: con(68/0) Queuing ACK command to peer_id: 1 channel: 0 seqnum: 65500
2025-01-01 22:45:47: TRACE[ConnectionReceive]: con(68/0)RECURSIVE, TYPE_RELIABLE peer_id: 1, channel: 0, seqnum: 65500
2025-01-01 22:45:47: TRACE[ConnectionReceive]: con(68/0)Got new peer id: 40310... 
2025-01-01 22:45:47: TRACE[ConnectionReceive]: con(68/0)changing own peer id
2025-01-01 22:45:47: TRACE[ConnectionSend]: con(68/0) UDP processing CONCMD_ACK
2025-01-01 22:45:47: TRACE[ConnectionSend]: con(68/40310) Handle non reliable queue (1 pkts)
2025-01-01 22:45:47: VERBOSE[ConnectionSend]: con(68/40310)RE-SENDING timed-out RELIABLE to 127.0.0.1(t/o=0.5): count=1, channel=0, seqnum=65500
2025-01-01 22:45:47: TRACE[ConnectionReceive]: con(68/40310)DISCO: Removing peer 1
2025-01-01 22:45:47: TRACE[Main]: con(68/40310): Receive: got event: CONNEVENT_PEER_REMOVED
2025-01-01 22:45:47: INFO[Main]: Client::deletingPeer(): Server Peer is getting deleted (timeout=0)
2025-01-01 22:45:47: ERROR[Main]: Access denied. Reason: Connection aborted (protocol error?).
2025-01-01 22:45:47: TRACE[ConnectionSend]: con(68/40310) UDP processing CONNCMD_DISCONNECT
2025-01-01 22:45:47: TRACE[ConnectionSend]: con(68/40310) disconnecting

This line seems to indicate the server sends a disconnect (after failing to parse a packet?): 2025-01-01 22:45:47: TRACE[ConnectionReceive]: con(68/40310)DISCO: Removing peer 1
Relevant log from just printing all packets (and the code that generated this):

Starting...
MinetestServer starting on 0.0.0.0:30000
MinetestServer started
MinetestServer accepted connection
[Minetest] Client connected from 127.0.0.1:43022

Err(EOF during deserialization)
Err(Internal Peer error) (repeated 361458 times)
MinetestServer accepted connection
Err(Internal Peer error) (repeated 6932146 times)

use minetest_protocol::MinetestServer;

#[tokio::main]
async fn main() {
    println!("Starting...");
    let mt_server_addr = String::from("0.0.0.0:30000");
    let mut mt_server = MinetestServer::new(mt_server_addr.parse().unwrap());
    tokio::select! {
        mut conn = mt_server.accept() => {
            println!("[Minetest] Client connected from {:?}", conn.remote_addr());
            let mut last_message = String::from("");
            let mut repeat: u32 = 1;
            loop {
                let t = conn.recv().await;
                // just print the packets without writing thousands of lines of the same error
                let current_message = format!("{:?}", t);
                if current_message == last_message {
                    repeat += 1;
                    print!("\r{} (repeated {} times)", current_message, repeat);
                } else {
                    repeat = 1;
                    print!("\n{}", current_message);
                    last_message = current_message;
                }
            }
        }
    }
}

[l-koehler]

The exact packet that fails to parse for me (and that is sent by the stable client) is:
[0x4F, 0x45, 0x74, 0x03, 0x00, 0x00, 0x00, 0x03, 0xFF, 0xDC, 0x01]

It gets deserialized into (wire/packet.rs line 401):
protocol_id: u32
sender_peer_id: PeerId (u16)
channel: u8
body: PacketBody

This leads to:
sender_peer_id = 0
channel = 0
body = [0x03, 0xFF, 0xDC, 0x01]

It consumes the tag (0x03) and the seqnum (0xFF 0xDC), deserializing 0x01 as a InnerBody.
That consumes the final 0x01, decides it is a "OriginalBody" (wire/packet.rs line 297) and tries to deserialize the empty buffer.

This causes it to be deserialized as a ToServerCommand while the packet has been fully consumed.

could be that the issue is in minetest, i don't know enough about the protocol for that
actually i get the issue in versions i am sure worked before, so idk what causes it anymore.
minetest-protocol didn't update in the meantime, old minetest versions have the same issue. maybe a dependency thing (or every device/OS i tried this on is broken in some weird and specific way)

[l-koehler]

It works just fine when changing InnerBody::deserialize:

impl Deserialize for InnerBody {
    type Output = Self;

    fn deserialize(deser: &mut Deserializer) -> DeserializeResult<Self> {
        use InnerBody::*;
        // HACK this is probably a bad idea
        if deser.remaining() == 1 {
            return Ok(Control(ControlBody::Ping)) // the only ControlBody without extra data (except Disconnect)
        }
        let packet_type = u8::deserialize(deser)?;
        match packet_type {
            0 => Ok(Control(ControlBody::deserialize(deser)?)),
            1 => Ok(Original(OriginalBody::deserialize(deser)?)),
            2 => Ok(Split(SplitBody::deserialize(deser)?)),
            _ => bail!(DeserializeError::InvalidPacketKind(packet_type)),
        }
    }
}

Of course not a real fix, but it does work with this.