Serverside connection error - java.io.IOException: Bad packet id 22

[Pokechu22]

I've got a local server which I use for testing and bukkit plugin development. When I connect, I often get this error (in the server console):

[15:20:07 INFO]: TestUser lost connection: Internal Exception: net.minecraft.util.io.netty.handler.codec.DecoderException: java.io.IOException: Bad packet id 22

In the client, it doesn't display anything. That includes the server connection welcome message. If I try to execute a command, nothing happens the first time, and then on the second time I get the text Connection has been lost..

CraftBukkit version string:
[15:26:00 INFO]: This server is running CraftBukkit version git-Bukkit-1.7.9-R0.1-10-g8688bd4-b3092jnks (MC: 1.7.9) (Implementing API version 1.7.9-R0.2)
[15:26:01 WARN]: Could not get information about this CraftBukkit version; perhaps you are running a custom one?: IOException

This only seems to happen to the first player to join the server. If I connect to the server, then close the client, then connect again (with the same username), it joins fine, as does using /reco.

Switching users does cause an issue, but it allows joining fine - When disconnecting, I get this:

[15:34:47 INFO]: TestUser lost connection: Internal Exception: net.minecraft.util.io.netty.handler.codec.DecoderException: java.io.IOException: Bad packet id 64

---

Here's some snippets from logs:

Snippet 1 - General issue

Serverside

[15:20:07 INFO]: TestUser[/0:0:0:0:0:0:0:1:50554] logged in with entity id 474 a
t ([skyworld] 8.0, 119.0, 118.0)
[15:20:07 INFO]: TestUser lost connection: Internal Exception: net.minecraft.uti
l.io.netty.handler.codec.DecoderException: java.io.IOException: Bad packet id 22

[15:20:07 INFO]: Removing player from memory: TestUser
[15:20:07 INFO]: TestUser left the game.
[15:20:16 INFO]: Loaded player file for TestUser
[15:20:16 INFO]: TestUser[/0:0:0:0:0:0:0:1:50559] logged in with entity id 475 a
t ([skyworld] 8.0, 119.0, 118.0)

Clientside

Console Client for MC 1.7.2 to 1.7.9 - v1.7.3 - By ORelio & Contributors
Username : TestUser
Password : <******>
You chose to run in offline mode.
Success. (session ID: 0)
Server IP : localhost
Retrieving Server Info...
Server version : CraftBukkit 1.7.9 (protocol v5).
Translations file loaded.
Version is supported.
Logging in...
Server is in offline mode.
Server was successfully joined.
Type '/quit' to leave the server.
>/reco
Restarting Minecraft Console Client...
You chose to run in offline mode.
Success. (session ID: 0)
Retrieving Server Info...
Server version : CraftBukkit 1.7.9 (protocol v5).
Version is supported.
Logging in...
Login rejected by Server :
Connection throttled! Please wait before reconnecting.
Login failed.
/reco
Restarting Minecraft Console Client...
You chose to run in offline mode.
Success. (session ID: 0)
Retrieving Server Info...
Server version : CraftBukkit 1.7.9 (protocol v5).
Version is supported.
Logging in...
Server is in offline mode.
Server was successfully joined.
Type '/quit' to leave the server.
TestUser joined the game.
Welcome, TestUser!
Type /help for a list of commands.
Type /list to see who else is online.
Players online: 1 - World time: 3:51 AM
You have no new mail.
>

Snippet 2 - Using commands

Serverside

I did not record serverside logs for this instance

Clientside

Console Client for MC 1.7.2 to 1.7.9 - v1.7.3 - By ORelio & Contributors
Username : TestUser
Password : <******>
You chose to run in offline mode.
Success. (session ID: 0)
Server IP : localhost
Retrieving Server Info...
Server version : CraftBukkit 1.7.9 (protocol v5).
Translations file loaded.
Version is supported.
Logging in...
Server is in offline mode.
Server was successfully joined.
Type '/quit' to leave the server.
>/help
>/help
Connection has been lost.
/reco
Restarting Minecraft Console Client...
You chose to run in offline mode.
Success. (session ID: 0)
Retrieving Server Info...
Server version : CraftBukkit 1.7.9 (protocol v5).
Version is supported.
Logging in...
Server is in offline mode.
Server was successfully joined.
Type '/quit' to leave the server.
TestUser joined the game.
Welcome, TestUser!
Type /help for a list of commands.
Type /list to see who else is online.
Players online: 1 - World time: 10:30 AM
You have no new mail.
>

Snippet 3 - Switching Users

Serverside

[15:34:22 INFO]: Loaded player file for pokechu22
[15:34:23 INFO]: pokechu22[/0:0:0:0:0:0:0:1:50802] logged in with entity id 441
at ([skyworld] -28.666453722079936, 126.48908861246204, 116.5253485127625)
[15:34:23 INFO]: pokechu22 lost connection: Internal Exception: net.minecraft.ut
il.io.netty.handler.codec.DecoderException: java.io.IOException: Bad packet id 2
2
[15:34:23 INFO]: Removing player from memory: pokechu22
[15:34:23 INFO]: pokechu22 left the game.
[15:34:39 INFO]: Loaded player file for TestUser
[15:34:39 INFO]: TestUser[/0:0:0:0:0:0:0:1:50804] logged in with entity id 442 a
t ([skyworld] 8.0, 119.0, 118.0)
[15:34:45 INFO]: <TestUser> Hello.
[15:34:47 INFO]: TestUser lost connection: Internal Exception: net.minecraft.uti
l.io.netty.handler.codec.DecoderException: java.io.IOException: Bad packet id 64

[15:34:47 INFO]: Removing player from memory: TestUser
[15:34:48 INFO]: TestUser left the game.

Clientside

I did not record clientside logs for this instance. But nothing unusual was shown.

---

As a side note, bukkit is unavailable due to a DCMA Takedown. I also haven't tested this with a vanilla server. Vanilla clients connect to my server fine. The server is in offline mode.

[ORelio]

Hello,

Packet ID 64 (0x40) is a kick packet.
Packet ID 22 (0x16) is a respawn packet.

The issue is that the server has to switch from "login mode" to "play mode" once login is successful. Minecraft Console Client waits ~500ms before sending it, which works most of the time. If your test server takes too long for switching, it receives packet 0x16 while still in login mode and does not process it properly (unknown packet). I'll make some changes in order to send this packet once some "play mode" packets have been received from the server, it should solve the issue.

The same way, since 1.7 the packet for disconnecting from the server does not seems documented so I tried to use a kick packet, which was the one to use before 1.7, it but does not seems to be the correct one since 1.7 so bad packet ID 64. Don't know which packet to send for disconnecting properly...

[Pokechu22]

Well, according to the same site, one uses Packet 0. But this doesn't seem right, as it is the update thing.

So I decided to look in the decompilation, based off of what happens when the "Quit game" button is clicked in-game.

---

Here's the game's process. (Note: I'm not good with networking. So this probably isn't useful at all):
net.minecraft.client.gui.GuiIngameMenu's protected void actionPerformed(GuiButton p_146284_1_):

        case 1:
                p_146284_1_.enabled = false;
                this.mc.theWorld.sendQuittingDisconnectingPacket();
                this.mc.loadWorld((WorldClient)null);
                this.mc.displayGuiScreen(new GuiMainMenu());

Then, in net.minecraft.client.multiplayer.WorldClient, sendQuittingDisconnectingPacket():

    /**
     * If on MP, sends a quitting packet.
     */
    public void sendQuittingDisconnectingPacket()
    {
        this.sendQueue.getNetworkManager().closeChannel(new ChatComponentText("Quitting"));
    }

And then in net.minecraft.network.NetworkManager's closeChannel(IChatComponent p_150718_1_):

    /**
     * Closes the channel, the parameter can be used for an exit message (not certain how it gets sent)
     */
    public void closeChannel(IChatComponent p_150718_1_)
    {
        if (this.channel.isOpen())
        {
            this.channel.close();
            this.terminationReason = p_150718_1_;
        }
    }

Where channel was defined earlier as

    /** The active channel */
    private Channel channel;

and is a io.netty.channel.Channel.

---

So as far as I can tell, there isn't actually a disconnecting packet... Which is odd. But the kick packet probably isn't correct here.

[ORelio]

Nice investigation! We need to go deeper by browsing the netty source code since disconnecting seems to be handled at Netty level. Channel is an interface, need to find the implementation hidden behind it.

[Pokechu22]

Alrighty, so far this:
Starting off in network manager, this is the only thing that sets this.

    public void channelActive(ChannelHandlerContext p_channelActive_1_) throws Exception
    {
        super.channelActive(p_channelActive_1_);
        this.channel = p_channelActive_1_.channel();
        this.socketAddress = this.channel.remoteAddress();
        this.setConnectionState(EnumConnectionState.HANDSHAKING);
    }

Deciding that playing a game of find the caller wouldn't be worthwhile here, I do this:

    public void channelActive(ChannelHandlerContext p_channelActive_1_) throws Exception
    {
        System.out.println(p_channelActive_1_.channel().getClass().toString());
        super.channelActive(p_channelActive_1_);
        this.channel = p_channelActive_1_.channel();
        this.socketAddress = this.channel.remoteAddress();
        this.setConnectionState(EnumConnectionState.HANDSHAKING);
    }

and this appears in the console:

[17:00:17] [Client thread/INFO]: Connecting to localhost, 25565
class io.netty.channel.socket.nio.NioSocketChannel
[17:00:19] [Client thread/INFO]: [CHAT] Player62 joined the game.
[17:00:19] [Client thread/INFO]: [CHAT] Welcome, Player62!

At least something can be done with that. Here's the javadoc.

[ORelio]

Nice! After digging up, looks like NioSocketChannel calls a javaChannel().close() located in the superclass AbstractNioChannel returning an internal java.nio.channels.SelectableChannel (Source). Still need to find what's doing Java for closing its channels.

[Pokechu22]

I know that this has been a while, but I did a quick bit of testing, and it seems that all you need to do to disconnect is just close the channel (and that's what other custom clients seem to be doing).

[ORelio]

Understood, however, how do I close a Java channel in C# without knowing how Java channels work? ^^

[Pokechu22]

Oops, I meant close the TcpClient. (That seemed to work in practice). But I'll continue trying stuff out, since I just realized that I can figure out the type of the javaChannel via reflection.

[Pokechu22]

Here's some new code:

    @Override
    public void channelActive(ChannelHandlerContext p_channelActive_1_)
    throws Exception {
        super.channelActive(p_channelActive_1_);
        this.channel = p_channelActive_1_.channel();
        this.socketAddress = this.channel.remoteAddress();

        Class c = channel.getClass();
        System.out.println(c);
        // Use reflection to call method.
        Method method = c.getDeclaredMethod("javaChannel");
        method.setAccessible(true);
        SocketChannel sc = (SocketChannel)method.invoke(channel);

        System.out.println(sc);
        System.out.println(sc.getClass());

        try {
            this.setConnectionState(EnumConnectionState.HANDSHAKING);
        } catch (Throwable var3) {
            logger.fatal(var3);
        }
    }

And it prints:

class io.netty.channel.socket.nio.NioSocketChannel
java.nio.channels.SocketChannel[connected local=/127.0.0.1:63467 remote=localhost/127.0.0.1:25565]
class sun.nio.ch.SocketChannelImpl

The implementation for sun.nio.ch.SocketChannelImpl is here, but that doesn't have a close() method. Nor does java.nio.channels.SocketChannel (found in the source included with the JDK). SocketChannel extends java.nio.channels.spi.AbstractSelectableChannel, which extends java.nio.channels.SelectableChannel, which extends java.nio.channels.spi.AbstractInterruptibleChannel. Forutnately, AbstractInterruptibleChannel has an implementation of close:

    /**
     * Closes this channel.
     *
     * <p> If the channel has already been closed then this method returns
     * immediately.  Otherwise it marks the channel as closed and then invokes
     * the {@link #implCloseChannel implCloseChannel} method in order to
     * complete the close operation.  </p>
     *
     * @throws  IOException
     *          If an I/O error occurs
     */
    public final void close() throws IOException {
        synchronized (closeLock) {
            if (!open)
                return;
            open = false;
            implCloseChannel();
        }
    }

    /**
     * Closes this channel.
     *
     * <p> This method is invoked by the {@link #close close} method in order
     * to perform the actual work of closing the channel.  This method is only
     * invoked if the channel has not yet been closed, and it is never invoked
     * more than once.
     *
     * <p> An implementation of this method must arrange for any other thread
     * that is blocked in an I/O operation upon this channel to return
     * immediately, either by throwing an exception or by returning normally.
     * </p>
     *
     * @throws  IOException
     *          If an I/O error occurs while closing the channel
     */
    protected abstract void implCloseChannel() throws IOException;

... but that's pretty useless, since implCloseChannel is abstract. So, back up the chain to AbstractSelectableChannel:

    /**
     * Closes this channel.
     *
     * <p> This method, which is specified in the {@link
     * AbstractInterruptibleChannel} class and is invoked by the {@link
     * java.nio.channels.Channel#close close} method, in turn invokes the
     * {@link #implCloseSelectableChannel implCloseSelectableChannel} method in
     * order to perform the actual work of closing this channel.  It then
     * cancels all of this channel's keys.  </p>
     */
    protected final void implCloseChannel() throws IOException {
        implCloseSelectableChannel();
        synchronized (keyLock) {
            int count = (keys == null) ? 0 : keys.length;
            for (int i = 0; i < count; i++) {
                SelectionKey k = keys[i];
                if (k != null)
                    k.cancel();
            }
        }
    }

    /**
     * Closes this selectable channel.
     *
     * <p> This method is invoked by the {@link java.nio.channels.Channel#close
     * close} method in order to perform the actual work of closing the
     * channel.  This method is only invoked if the channel has not yet been
     * closed, and it is never invoked more than once.
     *
     * <p> An implementation of this method must arrange for any other thread
     * that is blocked in an I/O operation upon this channel to return
     * immediately, either by throwing an exception or by returning normally.
     * </p>
     *
     * @throws  IOException
     *          If an I/O error occurs
     */
    protected abstract void implCloseSelectableChannel() throws IOException;

implCloseSelectableChannel isn't implemented in SocketChannel, but it is in SocketChannelImpl.

    // AbstractInterruptibleChannel synchronizes invocations of this method
    // using AbstractInterruptibleChannel.closeLock, and also ensures that this
    // method is only ever invoked once.  Before we get to this method, isOpen
    // (which is volatile) will have been set to false.
    //
    protected void implCloseSelectableChannel() throws IOException {
        synchronized (stateLock) {
            isInputOpen = false;
            isOutputOpen = false;

            // Close the underlying file descriptor and dup it to a known fd
            // that's already closed.  This prevents other operations on this
            // channel from using the old fd, which might be recycled in the
            // meantime and allocated to an entirely different channel.
            //
            nd.preClose(fd);

            // Signal native threads, if needed.  If a target thread is not
            // currently blocked in an I/O operation then no harm is done since
            // the signal handler doesn't actually do anything.
            //
            if (readerThread != 0)
                NativeThread.signal(readerThread);

            if (writerThread != 0)
                NativeThread.signal(writerThread);

            // If this channel is not registered then it's safe to close the fd
            // immediately since we know at this point that no thread is
            // blocked in an I/O operation upon the channel and, since the
            // channel is marked closed, no thread will start another such
            // operation.  If this channel is registered then we don't close
            // the fd since it might be in use by a selector.  In that case
            // closing this channel caused its keys to be cancelled, so the
            // last selector to deregister a key for this channel will invoke
            // kill() to close the fd.
            //
            if (!isRegistered())
                kill();
        }
    }

    public void kill() throws IOException {
        synchronized (stateLock) {
            if (state == ST_KILLED)
                return;
            if (state == ST_UNINITIALIZED) {
                state = ST_KILLED;
                return;
            }
            assert !isOpen() && !isRegistered();

            // Postpone the kill if there is a waiting reader
            // or writer thread. See the comments in read() for
            // more detailed explanation.
            if (readerThread == 0 && writerThread == 0) {
                nd.close(fd);
                state = ST_KILLED;
            } else {
                state = ST_KILLPENDING;
            }
        }
    }

nd is a NativeDispatcher, and is abstract (of course). However, implementations are listed on its javadoc page. And SocketDispatcher, which I'm guessing (but am not sure) is the implementation that is being used, goes into native system calls at that point.

So, since it's going to that level, I'm guessing you won't need to handle this yourself (and just closing the TcpClient will work).

[ORelio]

Thanks for all this research, I'll do that instead.

[ORelio]

Now that I'm silently closing TCP connection, I'm getting server-side:

[INFO]: ORelio lost connection: Disconnected
[INFO]: ORelio left the game.

Seems better indeed.

[ORelio]

Seems like the issue is fixed, do not hesitate to reopen if needed ;)