1.16.1: EntityEquipment_VarInt : Main thread panic: Failed to read all of packet 0x47, had 363 bytes left - enchants

Protonull commented 4 years ago

Compiled from most recent commit: 7869893038a4b5699f180ba6afa84bd1e29cc1f0

When connecting to a 1.16.1 server with no other procotols supported, it almost instantly panics when loading the world.

Packet: 0x47 (Clientbound - Entity Equipment)

Executed with: stevenarella.exe --network-debug --default-protocol-version 736

[protocol/mod.rs:1122][DEBUG] Decompressed threshold=256 len=233 uncompressed_size=424 to 424 bytes
[protocol/mod.rs:1141][DEBUG] about to parse id=47, dir=Clientbound state=Play
[protocol/mod.rs:1151][DEBUG] packet = Some(EntityEquipment_VarInt(EntityEquipment_VarInt { entity_id: 53, slot: 128, item: Some(Stack { id: 7, count: 1, damage: None, tag: Some(NamedTag("", Compound({"Charged": Byte(0), "Damage": Int(29), "ChargedProjectiles": List([])}))) }) }))
thread 'main' panicked at 'Err: Err("Failed to read all of packet 0x47, had 363 bytes left")', src\server\mod.rs:571:33
stack backtrace:
   0: <unknown>
   1: <unknown>
   2: <unknown>
   3: <unknown>
   4: <unknown>
   5: <unknown>
   6: <unknown>
   7: <unknown>
   8: <unknown>
   9: <unknown>
  10: <unknown>
  11: <unknown>
  12: <unknown>
  13: <unknown>
  14: <unknown>
  15: <unknown>
  16: <unknown>
  17: <unknown>
  18: <unknown>
  19: <unknown>
  20: BaseThreadInitThunk
  21: RtlUserThreadStart

Not sure how to get a full stack trace though since I'm not familiar with Rust.

iceiix commented 3 years ago

@Protonull can you attach the output of last-packet? (thanks for running with --network-debug!)

foxt commented 3 years ago

@iceiix not op, but same error, seems to be enchantments related

 ~  set RUST_BACKTRACE full; /Users/thelmgn/Downloads/stevenarella-macos-latest --network-debug > /dev/null                                                                                                         Wed  4 Nov 18:59:00 2020
thread 'main' panicked at 'Err: Err("Failed to read all of packet 0x47, had 363 bytes left")', src/server/mod.rs:571:33
stack backtrace:
   0: _rust_begin_unwind
   1: std::panicking::begin_panic_fmt
   2: stevenarella::server::Server::entity_tick
   3: stevenarella::server::Server::tick
   4: stevenarella::main2::{{closure}}
   5: <winit::platform_impl::platform::app_state::EventLoopHandler<T> as winit::platform_impl::platform::app_state::EventHandler>::handle_nonuser_event
   6: winit::platform_impl::platform::app_state::Handler::handle_nonuser_event
   7: winit::platform_impl::platform::app_state::AppState::cleared
   8: ____CFXPCCreateCFObjectFromXPCObject_block_invoke
   9: ___CFRunLoopObserverCancel
  10: ___CFRunLoopRun
  11: ___CFTSRToDispatchTime
  12: _RunCurrentEventLoopInMode
  13: _ReceiveNextEventCommon
  14: __BlockUntilNextEventMatchingListInModeWithFilter
  15: __DPSNextEvent
  16: -[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:]
  17: -[NSApplication run]
  18: winit::platform_impl::platform::event_loop::EventLoop<T>::run
  19: winit::event_loop::EventLoop<T>::run
  20: stevenarella::main2
  21: stevenarella::main
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
 !  ~  cat last-packet                                                                                                                                                                                    4863ms  Wed  4 Nov 18:59:06 2020
����

RepairCost
                Enchantments
idminecraft:depth_striderlvlDamage��

RepairCost
                Enchantments
idminecraft:blast_protectionlvlDamage��

RepairCost
                Enchantments
idminecraft:mendinglvidminecraft:protectionlvlDamage�

RepairCost
                Enchantments
idminecraft:aqua_affinitylvidminecraft:protectionlvlDamage⏎

Here's the raw file contents: http://lmgn.uk/UGz.last-packet

iceiix commented 3 years ago

Saving hex dump of http://lmgn.uk/UGz.last-packet here:

00000000  c7 00 88 01 82 01 85 05  01 0a 00 00 03 00 0a 52  |...............R|
00000010  65 70 61 69 72 43 6f 73  74 00 00 00 01 09 00 0c  |epairCost.......|
00000020  45 6e 63 68 61 6e 74 6d  65 6e 74 73 0a 00 00 00  |Enchantments....|
00000030  01 08 00 02 69 64 00 17  6d 69 6e 65 63 72 61 66  |....id..minecraf|
00000040  74 3a 64 65 70 74 68 5f  73 74 72 69 64 65 72 02  |t:depth_strider.|
00000050  00 03 6c 76 6c 00 03 00  03 00 06 44 61 6d 61 67  |..lvl......Damag|
00000060  65 00 00 00 00 00 83 01  84 05 01 0a 00 00 03 00  |e...............|
00000070  0a 52 65 70 61 69 72 43  6f 73 74 00 00 00 01 09  |.RepairCost.....|
00000080  00 0c 45 6e 63 68 61 6e  74 6d 65 6e 74 73 0a 00  |..Enchantments..|
00000090  00 00 01 08 00 02 69 64  00 1a 6d 69 6e 65 63 72  |......id..minecr|
000000a0  61 66 74 3a 62 6c 61 73  74 5f 70 72 6f 74 65 63  |aft:blast_protec|
000000b0  74 69 6f 6e 02 00 03 6c  76 6c 00 04 00 03 00 06  |tion...lvl......|
000000c0  44 61 6d 61 67 65 00 00  00 00 00 84 01 83 05 01  |Damage..........|
000000d0  0a 00 00 03 00 0a 52 65  70 61 69 72 43 6f 73 74  |......RepairCost|
000000e0  00 00 00 03 09 00 0c 45  6e 63 68 61 6e 74 6d 65  |.......Enchantme|
000000f0  6e 74 73 0a 00 00 00 02  08 00 02 69 64 00 11 6d  |nts........id..m|
00000100  69 6e 65 63 72 61 66 74  3a 6d 65 6e 64 69 6e 67  |inecraft:mending|
00000110  02 00 03 6c 76 6c 00 01  00 08 00 02 69 64 00 14  |...lvl......id..|
00000120  6d 69 6e 65 63 72 61 66  74 3a 70 72 6f 74 65 63  |minecraft:protec|
00000130  74 69 6f 6e 02 00 03 6c  76 6c 00 04 00 03 00 06  |tion...lvl......|
00000140  44 61 6d 61 67 65 00 00  00 00 00 05 01 82 05 01  |Damage..........|
00000150  0a 00 00 03 00 0a 52 65  70 61 69 72 43 6f 73 74  |......RepairCost|
00000160  00 00 00 03 09 00 0c 45  6e 63 68 61 6e 74 6d 65  |.......Enchantme|
00000170  6e 74 73 0a 00 00 00 02  08 00 02 69 64 00 17 6d  |nts........id..m|
00000180  69 6e 65 63 72 61 66 74  3a 61 71 75 61 5f 61 66  |inecraft:aqua_af|
00000190  66 69 6e 69 74 79 02 00  03 6c 76 6c 00 01 00 08  |finity...lvl....|
000001a0  00 02 69 64 00 14 6d 69  6e 65 63 72 61 66 74 3a  |..id..minecraft:|
000001b0  70 72 6f 74 65 63 74 69  6f 6e 02 00 03 6c 76 6c  |protection...lvl|
000001c0  00 04 00 03 00 06 44 61  6d 61 67 65 00 00 00 00  |......Damage....|
000001d0  00                                                |.|

iceiix commented 3 years ago

Testing with https://github.com/iceiix/stevenarella/pull/438, ~the packet parses without error~ incomplete parse:

cargo run  -- -N ~/Downloads/UGz.last-packet -p 736

about to parse id=47, dir=Clientbound state=Play
packet = Some(EntityEquipment_VarInt(EntityEquipment_VarInt { entity_id: 136, slot: 130, item: Some(Stack { id: 5, count: 1, damage: None, tag: Some(NamedTag("", Compound({"Enchantments": List([Compound({"id": String("minecraft:depth_strider"), "lvl": Short(3)})]), "Damage": Int(0), "RepairCost": Int(1)}))) }) }))

pos = 102
ibuf = [199, 0, 136, 1, 130, 1, 133, 5, 1, 10, 0, 0, 3, 0, 10, 82, 101, 112, 97, 105, 114, 67, 111, 115, 116, 0, 0, 0, 1, 9, 0, 12, 69, 110, 99, 104, 97, 110, 116, 109, 101, 110, 116, 115, 10, 0, 0, 0, 1, 8, 0, 2, 105, 100, 0, 23, 109, 105, 110, 101, 99, 114, 97, 102, 116, 58, 100, 101, 112, 116, 104, 95, 115, 116, 114, 105, 100, 101, 114, 2, 0, 3, 108, 118, 108, 0, 3, 0, 3, 0, 6, 68, 97, 109, 97, 103, 101, 0, 0, 0, 0, 0, 131, 1, 132, 5, 1, 10, 0, 0, 3, 0, 10, 82, 101, 112, 97, 105, 114, 67, 111, 115, 116, 0, 0, 0, 1, 9, 0, 12, 69, 110, 99, 104, 97, 110, 116, 109, 101, 110, 116, 115, 10, 0, 0, 0, 1, 8, 0, 2, 105, 100, 0, 26, 109, 105, 110, 101, 99, 114, 97, 102, 116, 58, 98, 108, 97, 115, 116, 95, 112, 114, 111, 116, 101, 99, 116, 105, 111, 110, 2, 0, 3, 108, 118, 108, 0, 4, 0, 3, 0, 6, 68, 97, 109, 97, 103, 101, 0, 0, 0, 0, 0, 132, 1, 131, 5, 1, 10, 0, 0, 3, 0, 10, 82, 101, 112, 97, 105, 114, 67, 111, 115, 116, 0, 0, 0, 3, 9, 0, 12, 69, 110, 99, 104, 97, 110, 116, 109, 101, 110, 116, 115, 10, 0, 0, 0, 2, 8, 0, 2, 105, 100, 0, 17, 109, 105, 110, 101, 99, 114, 97, 102, 116, 58, 109, 101, 110, 100, 105, 110, 103, 2, 0, 3, 108, 118, 108, 0, 1, 0, 8, 0, 2, 105, 100, 0, 20, 109, 105, 110, 101, 99, 114, 97, 102, 116, 58, 112, 114, 111, 116, 101, 99, 116, 105, 111, 110, 2, 0, 3, 108, 118, 108, 0, 4, 0, 3, 0, 6, 68, 97, 109, 97, 103, 101, 0, 0, 0, 0, 0, 5, 1, 130, 5, 1, 10, 0, 0, 3, 0, 10, 82, 101, 112, 97, 105, 114, 67, 111, 115, 116, 0, 0, 0, 3, 9, 0, 12, 69, 110, 99, 104, 97, 110, 116, 109, 101, 110, 116, 115, 10, 0, 0, 0, 2, 8, 0, 2, 105, 100, 0, 23, 109, 105, 110, 101, 99, 114, 97, 102, 116, 58, 97, 113, 117, 97, 95, 97, 102, 102, 105, 110, 105, 116, 121, 2, 0, 3, 108, 118, 108, 0, 1, 0, 8, 0, 2, 105, 100, 0, 20, 109, 105, 110, 101, 99, 114, 97, 102, 116, 58, 112, 114, 111, 116, 101, 99, 116, 105, 111, 110, 2, 0, 3, 108, 118, 108, 0, 4, 0, 3, 0, 6, 68, 97, 109, 97, 103, 101, 0, 0, 0, 0, 0]
Failed to read all of packet 0x47, had 363 bytes left

iceiix commented 3 years ago

1.16 changed slot/item to an array of slot/item (v1_16_1, v1_16_4+):

https://wiki.vg/index.php?title=Pre-release_protocol&oldid=15895 https://wiki.vg/index.php?title=Pre-release_protocol&oldid=15878

1.15.2 (v1_15) only had one slot/item, no array: https://wiki.vg/index.php?title=Protocol&oldid=16067#Entity_Equipment

How do we know the size of the array? "Also has the top bit set if another entry follows, and otherwise unset if this is the last item in the array."

for comparison: https://github.com/PrismarineJS/minecraft-data/blob/master/data/pc/1.15.2/protocol.json#L3073

        "packet_entity_equipment": [
          "container",
          [
            {
              "name": "entityId",
              "type": "varint"
            },
            {
              "name": "slot",
              "type": "varint"
            },
            {
              "name": "item",
              "type": "slot"

vs https://github.com/PrismarineJS/minecraft-data/blob/master/data/pc/1.16/protocol.json#L3100

       "packet_entity_equipment": [
          "container",
          [
            {
              "name": "entityId",
              "type": "varint"
            },
            {
              "name": "equipments",
              "type": ["topBitSetTerminatedArray", {
                "type": ["container", [
                  {
                    "name": "slot",
                    "type": "i8"
                  },
                  {
                    "name": "item",
                    "type": "slot"
                  }

It is a new "topBitSetTerminatedArray" array type. Interesting comment in https://github.com/andersonarc/mcpacket/blob/c1dfac0fe96ebc8be6f7324cd3936fdf9f729c81/mcd2packet/mcd2packet.py:

# This is not how topBitSetTerminatedArray works, but the real solution is hard
# and this solution is easy. As long as this type is only found in the Entity
# Equipment packet we're going to stick with this solution
@mc_data_name('topBitSetTerminatedArray')
class mc_entity_equipment(self_serializing_type):
    typename = 'mc_entity_equipment'

iceiix commented 3 years ago

Implemented the EntityEquipment_Array packet variant in #438, which was important, but it turns out this packet only has one array element, so there is another bug here.

packet = Some(EntityEquipment_Array(EntityEquipment_Array { entity_id: 136, equipments: EntityEquipments { equipments: [EntityEquipment { slot: 2, item: Some(Stack { id: 645, count: 1, damage: None, tag: Some(NamedTag("", Compound({"Damage": Int(0), "RepairCost": Int(1), "Enchantments": List([Compound({"id": String("minecraft:depth_strider"), "lvl": Short(3)})])}))) }) }] } }))

pos = 102 Failed to read all of packet 0x47, had 363 bytes left

The extra unparsed bytes:

'\x83\x01\x84\x05\x01\n\x00\x00\x03\x00\nRepairCost\x00\x00\x00\x01\t\x00\x0cEnchantments\n\x00\x00\x00\x01\x08\x00\x02id\x00\x1aminecraft:blast_protection\x02\x00\x03lvl\x00\x04\x00\x03\x00\x06Damage\x00\x00\x00\x00\x00\x84\x01\x83\x05\x01\n\x00\x00\x03\x00\nRepairCost\x00\x00\x00\x03\t\x00\x0cEnchantments\n\x00\x00\x00\x02\x08\x00\x02id\x00\x11minecraft:mending\x02\x00\x03lvl\x00\x01\x00\x08\x00\x02id\x00\x14minecraft:protection\x02\x00\x03lvl\x00\x04\x00\x03\x00\x06Damage\x00\x00\x00\x00\x00\x05\x01\x82\x05\x01\n\x00\x00\x03\x00\nRepairCost\x00\x00\x00\x03\t\x00\x0cEnchantments\n\x00\x00\x00\x02\x08\x00\x02id\x00\x17minecraft:aqua_affinity\x02\x00\x03lvl\x00\x01\x00\x08\x00\x02id\x00\x14minecraft:protection\x02\x00\x03lvl\x00\x04\x00\x03\x00\x06Damage\x00\x00\x00\x00\x00'

the parsed bytes:

'\xc7\x00\x88\x01\x82\x01\x85\x05\x01\n\x00\x00\x03\x00\nRepairCost\x00\x00\x00\x01\t\x00\x0cEnchantments\n\x00\x00\x00\x01\x08\x00\x02id\x00\x17minecraft:depth_strider\x02\x00\x03lvl\x00\x03\x00\x03\x00\x06Damage\x00\x00\x00\x00\x00'

The enchantments `"Enchantments": List([Compound({"id": String("minecraft:depth_strider"), "lvl": Short(3)`` is only the first enchantment (Depth Strider III), it parses up to Damage: 0, then stops parsing. https://wiki.vg/NBT https://wiki.vg/Slot_Data

Slot or NBT parsing bug?

Expected value, parsing with node-minecraft-protocol:

const mc=require('minecraft-protocol');
const d=mc.createDeserializer({version:"1.16.1", state:mc.states.PLAY});
//const d=mc.createDeserializer({version:"1.8", state:mc.states.PLAY});
d.on('data',(parsed)=>{
  //console.log('parsed',parsed);
  console.log(JSON.stringify(parsed, null, '  '));
});
d.write(Buffer.from([

  199, 0, 136, 1, 130, 1, 133, 5, 1, 10, 0, 0, 3, 0, 10, 82, 101, 112, 97, 105, 114, 67, 111, 115, 116, 0, 0, 0, 1, 9, 0, 12, 69, 110, 99, 104, 97, 110, 116, 109, 101, 110, 116, 115, 10, 0, 0, 0, 1, 8, 0, 2, 105, 100, 0, 23, 109, 105, 110, 101, 99, 114, 97, 102, 116, 58, 100, 101, 112, 116, 104, 95, 115, 116, 114, 105, 100, 101, 114, 2, 0, 3, 108, 118, 108, 0, 3, 0, 3, 0, 6, 68, 97, 109, 97, 103, 101, 0, 0, 0, 0, 0, 131, 1, 132, 5, 1, 10, 0, 0, 3, 0, 10, 82, 101, 112, 97, 105, 114, 67, 111, 115, 116, 0, 0, 0, 1, 9, 0, 12, 69, 110, 99, 104, 97, 110, 116, 109, 101, 110, 116, 115, 10, 0, 0, 0, 1, 8, 0, 2, 105, 100, 0, 26, 109, 105, 110, 101, 99, 114, 97, 102, 116, 58, 98, 108, 97, 115, 116, 95, 112, 114, 111, 116, 101, 99, 116, 105, 111, 110, 2, 0, 3, 108, 118, 108, 0, 4, 0, 3, 0, 6, 68, 97, 109, 97, 103, 101, 0, 0, 0, 0, 0, 132, 1, 131, 5, 1, 10, 0, 0, 3, 0, 10, 82, 101, 112, 97, 105, 114, 67, 111, 115, 116, 0, 0, 0, 3, 9, 0, 12, 69, 110, 99, 104, 97, 110, 116, 109, 101, 110, 116, 115, 10, 0, 0, 0, 2, 8, 0, 2, 105, 100, 0, 17, 109, 105, 110, 101, 99, 114, 97, 102, 116, 58, 109, 101, 110, 100, 105, 110, 103, 2, 0, 3, 108, 118, 108, 0, 1, 0, 8, 0, 2, 105, 100, 0, 20, 109, 105, 110, 101, 99, 114, 97, 102, 116, 58, 112, 114, 111, 116, 101, 99, 116, 105, 111, 110, 2, 0, 3, 108, 118, 108, 0, 4, 0, 3, 0, 6, 68, 97, 109, 97, 103, 101, 0, 0, 0, 0, 0, 5, 1, 130, 5, 1, 10, 0, 0, 3, 0, 10, 82, 101, 112, 97, 105, 114, 67, 111, 115, 116, 0, 0, 0, 3, 9, 0, 12, 69, 110, 99, 104, 97, 110, 116, 109, 101, 110, 116, 115, 10, 0, 0, 0, 2, 8, 0, 2, 105, 100, 0, 23, 109, 105, 110, 101, 99, 114, 97, 102, 116, 58, 97, 113, 117, 97, 95, 97, 102, 102, 105, 110, 105, 116, 121, 2, 0, 3, 108, 118, 108, 0, 1, 0, 8, 0, 2, 105, 100, 0, 20, 109, 105, 110, 101, 99, 114, 97, 102, 116, 58, 112, 114, 111, 116, 101, 99, 116, 105, 111, 110, 2, 0, 3, 108, 118, 108, 0, 4, 0, 3, 0, 6, 68, 97, 109, 97, 103, 101, 0, 0, 0, 0, 0

])); // end

Parsed packet:

{'entityId': 136, 'equipments': [

{'slot': 2, 'item': {'present': True, 'itemId': 645, 'itemCount': 1, 'nbtData': {'type': 'compound', 'name': '', 'value': {'RepairCost': {'type': 'int', 'value': 1}, 'Enchantments': {'type': 'list', 'value': {'type': 'compound', 'value': [{'id': {'type': 'string', 'value': 'minecraft:depth_strider'}, 'lvl': {'type': 'short', 'value': 3}}]}}, 'Damage': {'type': 'int', 'value': 0}}}}},

{'slot': 3, 'item': {'present': True, 'itemId': 644, 'itemCount': 1, 'nbtData': {'type': 'compound', 'name': '', 'value': {'RepairCost': {'type': 'int', 'value': 1}, 'Enchantments': {'type': 'list', 'value': {'type': 'compound', 'value': [{'id': {'type': 'string', 'value': 'minecraft:blast_protection'}, 'lvl': {'type': 'short', 'value': 4}}]}}, 'Damage': {'type': 'int', 'value': 0}}}}},

{'slot': 4, 'item': {'present': True, 'itemId': 643, 'itemCount': 1, 'nbtData': {'type': 'compound', 'name': '', 'value': {'RepairCost': {'type': 'int', 'value': 3}, 'Enchantments': {'type': 'list', 'value': {'type': 'compound', 'value': [{'id': {'type': 'string', 'value': 'minecraft:mending'}, 'lvl': {'type': 'short', 'value': 1}}, {'id': {'type': 'string', 'value': 'minecraft:protection'}, 'lvl': {'type': 'short', 'value': 4}}]}}, 'Damage': {'type': 'int', 'value': 0}}}}},

{'slot': 5, 'item': {'present': True, 'itemId': 642, 'itemCount': 1, 'nbtData': {'type': 'compound', 'name': '', 'value': {'RepairCost': {'type': 'int', 'value': 3}, 'Enchantments': {'type': 'list', 'value': {'type': 'compound', 'value': [{'id': {'type': 'string', 'value': 'minecraft:aqua_affinity'}, 'lvl': {'type': 'short', 'value': 1}}, {'id': {'type': 'string', 'value': 'minecraft:protection'}, 'lvl': {'type': 'short', 'value': 4}}]}}, 'Damage': {'type': 'int', 'value': 0}}}}}]}

iceiix commented 3 years ago

Now parses correctly with changes in #438 (it was the equipment array):

packet = Some(EntityEquipment_Array(EntityEquipment_Array { entity_id: 136, equipments: EntityEquipments { equipments: [EntityEquipment { slot: 2, item: Some(Stack { id: 645, count: 1, damage: None, tag: Some(NamedTag("", Compound({"Damage": Int(0), "RepairCost": Int(1), "Enchantments": List([Compound({"lvl": Short(3), "id": String("minecraft:depth_strider")})])}))) }) }, EntityEquipment { slot: 3, item: Some(Stack { id: 644, count: 1, damage: None, tag: Some(NamedTag("", Compound({"RepairCost": Int(1), "Enchantments": List([Compound({"lvl": Short(4), "id": String("minecraft:blast_protection")})]), "Damage": Int(0)}))) }) }, EntityEquipment { slot: 4, item: Some(Stack { id: 643, count: 1, damage: None, tag: Some(NamedTag("", Compound({"RepairCost": Int(3), "Enchantments": List([Compound({"id": String("minecraft:mending"), "lvl": Short(1)}), Compound({"id": String("minecraft:protection"), "lvl": Short(4)})]), "Damage": Int(0)}))) }) }, EntityEquipment { slot: 5, item: Some(Stack { id: 642, count: 1, damage: None, tag: Some(NamedTag("", Compound({"RepairCost": Int(3), "Enchantments": List([Compound({"lvl": Short(1), "id": String("minecraft:aqua_affinity")}), Compound({"lvl": Short(4), "id": String("minecraft:protection")})]), "Damage": Int(0)}))) }) }] } }))

iceiix / stevenarella

1.16.1: EntityEquipment_VarInt : Main thread panic: Failed to read all of packet 0x47, had 363 bytes left - enchants #408