No Play mode packets being received

[Powana]

Using SimpleClient, I can connect to an online server, but after the ClientboundLoginSuccess event is emitted, signalling that the client should swap to Play mode, no more events are emitted. The next expected packet/event should be the "Join Game" event (which I think is called "login" in python-minecraft-data).

Setup: running both client and vanilla server (online_mode=True) on Arch, using mc 1.16.5

edit: Same behaviour if online_mode=False

[nickelpro]

Very strange, can I get a minimum repro example of what your run script looks like? I think this is a plugin loading issue but can't reproduce without more info

[Powana]

It's just the ExamplePlugin file, with the "main" -> "__main__" typo fixed,

[nickelpro]

Thanks I'll check this out

[nickelpro]

I can't repro this using the example plugin unfortunately, can you try running using this DebugPlugin at the bottom of the ExamplePlugin script and posting the relevant part of the log?

class DebugPlugin(PluginBase):
  def __init__(self, ploader, settings):
    super().__init__(ploader, settings)
    event = ploader.require("Event")

    for key in proto.__dict__:
      if 'Clientbound' in key or 'Serverbound' in key:
        event.register_callback(key, self.print_packet)

    def l(name):
      return lambda _, __: logger.trace(name)

    for i in ('init', 'kill', 'tick', 'io_connect', 'auth_session_success',
              'auth_login_success', 'auth_login_failure'):
      event.register_callback(i, l(i))

  def print_packet(self, _, data):
    name = type(data).__name__
    if 'Serverbound' in name:
      logger.trace(f"Sent Packet: {name}")
    else:
      logger.trace(f"Recieved Packet: {name}")

if __name__ == "__main__":
  from rikerbot import SimpleClient
  # Settings dicts map a name to a dictionary of settings
  settings = {
      'example': {
          'greeting_string': input("Please provide a greeting: ")
      }
  }
  # Plugin lists are lists of tuples that provide a name (to be looked up in
  # the settings dict), and a plugin associated with that name. The plugin will
  # be provided with the settings associated with its name.
  plugins = [('example', ExamplePlugin), ('debug', DebugPlugin)]
  client = SimpleClient(plugins, settings, online_mode=True)
  client.start(host="localhost", port=25565)

If everything is working you should see a spam of packets, if not we'll see what's choking

[Powana]

Online mode:

[2021-06-05 03:36:48.585680] [0x00007f3267b74740] [info]    Successful Login, username is: spela1
[2021-06-05 03:36:48.585848] [0x00007f3267b74740] [trace]   auth_login_success
[2021-06-05 03:36:48.588331] [0x00007f3267b74740] [trace]   init
[2021-06-05 03:36:48.588923] [0x00007f3267b74740] [trace]   Sent Packet: ServerboundSetProtocol
[2021-06-05 03:36:48.589265] [0x00007f3267b74740] [trace]   Sent Packet: ServerboundLoginStart
[2021-06-05 03:36:48.589333] [0x00007f3267b74740] [trace]   io_connect
[2021-06-05 03:36:49.184839] [0x00007f3267b74740] [info]    Successful Session Auth
[2021-06-05 03:36:49.188386] [0x00007f3267b74740] [trace]   Sent Packet: ServerboundEncryptionBegin
[2021-06-05 03:36:49.188600] [0x00007f3267b74740] [trace]   auth_session_success
[2021-06-05 03:36:49.188658] [0x00007f3267b74740] [trace]   Recieved Packet: ClientboundEncryptionBegin
[2021-06-05 03:36:49.981638] [0x00007f3267b74740] [trace]   Recieved Packet: ClientboundCompress
[2021-06-05 03:36:49.982912] [0x00007f3267b74740] [trace]   Recieved Packet: ClientboundSuccess

Offline:

[2021-06-05 03:24:40.496781] [0x00007f5595c5d740] [trace]   init
[2021-06-05 03:24:40.496981] [0x00007f5595c5d740] [trace]   Sent Packet: ServerboundSetProtocol
[2021-06-05 03:24:40.497078] [0x00007f5595c5d740] [trace]   Sent Packet: ServerboundLoginStart
[2021-06-05 03:24:40.497094] [0x00007f5595c5d740] [trace]   io_connect
[2021-06-05 03:24:40.522233] [0x00007f5595c5d740] [trace]   Recieved Packet: ClientboundCompress
[2021-06-05 03:24:40.522314] [0x00007f5595c5d740] [trace]   Recieved Packet: ClientboundSuccess

[nickelpro]

This is an IO Core bug. Error handling is really bad in IO Core. I'll work on making reporting errors better and hopefully that will flush out what's happening here.

[nickelpro]

24f0aa5451fb38c31cfe704c8c5926cb902a0fec won't fix whatever this bug is, but it should hopefully error out instead of spin locking

[Powana]

With 24f0aa5 I can confirm that it fails on the Login packet:

[2021-06-05 15:31:13.976606] [0x00007f386688d740] [fatal] Failed to decode packet, suspect ID: 36 suspect name: ClientboundLogin

[nickelpro]

Welp that makes not a lick of damn sense. Don't get my wrong, I'm sure my code is bugged, just don't know how.

Couple questions to narrow it down:

What kind of world is this? Possibly could be a bug in the NBT parser that I've never hit messing around in standard survival

What install/run process are you using? Are you installing with pip? Or just building with cmake and running from the project folder? It's a long shot, but maybe this is a cmake cache issue.

[Powana]

The world is standard survival, fresh vanilla server.

It might be me messing up the install process now that you mention it, I couldn't get pip install . to work, it didn't generate the files needed, and I ended up with the same as #4. So I use cmake + make, then pip to install it to my venv in a separate directory. I also tried building a wheel and installing that, but the behaviour is the same.

Logging the exception thrown in the IO core shows basic_ios::clear: iostream error

[nickelpro]

Ya we're draining the packet buffer, that's the intended exception to be thrown. I don't know exactly how an install issue could cause that problem but it is worth exploring and I want to fix problems with the pip install . path anyway. Could you use a fresh project root and describe the error with the install? Also thank you so much for engaging with this troubleshooting process.

[Powana]

np :)

I removed all the old stuff, created a new venv (python 3.9.5), installed minecraft-data and wheel. Cloned the repo into a new dir, and ran pip install . in the root. No error messages (until its imported). Shouldn't be a permissions thing either.

[nickelpro]

Excellent! I hadn't been building in a venv, but I can repro this problem. Going to explore it, maybe we get lucky

[nickelpro]

Great news! I fixed the pip install . build and I can repro the decode fail in the virtual env. Bad news, the build wasn't the problem. Going to investigate further.

[nickelpro]

The bug is caused by building in release mode, ie with optimizations turned on. I removed the couple UB tricks I pull in IO and have a clean build with -Wall -Wextra -Wpedantic, and also added sanitizers, but that did not fix the bug. Unsure on how to proceed, will investigate more tomorrow.

[nickelpro]

Locally this works for me, can you confirm 8e48c63 fixes this bug for you @Powana?

[Powana]

@nickelpro I pulled the latest version, created a new venv, used pip install ., and my laptop froze completely while building the wheel. ): Probably unrelated though.

Deleted everything and tried again, the pip install fails, citing many errors in nbt.hpp and io_core.cpp, am I missing a dependency or something?

Looks like the same error as in the github linux build job.

[nickelpro]

Ah, need to update the docs. Ya this requires GCC 11, which Arch is shipping so I assumed you were on

[Powana]

Ah ok, can confirm it works great after updating to GCC 11.

In my defence the gcc package was only updated a few weeks ago d:

[nickelpro]

Excellent! What a bug, closing.