mojira.dev
MC-66750

player duplicate/phantom/de-sync..."An existing connection was forcibly closed by the remote host"

Description


Randomly it seems that the player de-syncs from the server, when they re-log into the server there are a phantom player and the real one, then the there begins spamming the same trace over and over again. The server must be restarted to continue playing. It is repeatable however I am not sure what triggers it exactly. I am playing localhost and Lynn1077 is playing on another network.


Crash Report


S:\minecraft>java -Xmx1G -Xms1G -jar minecraft_server.jar --nogui

[13:45:06] [Server thread/INFO]: Starting minecraft server version 14w32d
[13:45:06] [Server thread/INFO]: Loading properties
[13:45:06] [Server thread/INFO]: Default game type: SURVIVAL
[13:45:06] [Server thread/INFO]: Generating keypair
[13:45:06] [Server thread/INFO]: Starting Minecraft server on *:25565
[13:45:07] [Server thread/INFO]: Preparing level "world"
[13:45:07] [Server thread/INFO]: Preparing start region for level 0
[13:45:08] [Server thread/INFO]: Preparing spawn area: 42%
[13:45:09] [Server thread/INFO]: Done (1.816s)! For help, type "help" or "?"
[13:45:12] [User Authenticator #1/INFO]: UUID of player Lynn1077 is 132ef156-0cff-4641-a636-63151b5f0d88
[13:45:12] [User Authenticator #2/INFO]: UUID of player MegaSniperB is 3f4da0c6-0d7a-44cf-ae91-818e4fea5476
[13:45:12] [Server thread/INFO]: Lynn1077[/198.14.219.94:50878] logged in with entity id 472 at (-312.7406288542708, 86.0, 264.6424078447125)
[13:45:12] [Server thread/INFO]: Lynn1077 joined the game
[13:45:12] [Server thread/INFO]: MegaSniperB[/127.0.0.1:54437] logged in with entity id 485 at (-317.1232393824896, 71.0, 247.69058494797173)
[13:45:12] [Server thread/INFO]: MegaSniperB joined the game
[13:45:45] [User Authenticator #3/INFO]: UUID of player MegaSniperB is 3f4da0c6-0d7a-44cf-ae91-818e4fea5476
[13:45:45] [Server thread/INFO]: MegaSniperB[/127.0.0.1:54457] logged in with entity id 2093 at (-317.1232393824896, 71.0, 247.69058494797173)
[13:45:45] [Server thread/INFO]: MegaSniperB joined the game

Aug 11, 2014 1:45:46 PM io.netty.channel.AbstractChannelHandlerContext invokeExceptionCaught
WARNING: An exception was thrown by a user handler's exceptionCaught() method while handling the following exception:
java.io.IOException: An existing connection was forcibly closed by the remote host
        at sun.nio.ch.SocketDispatcher.writev0(Native Method)
        at sun.nio.ch.SocketDispatcher.writev(SocketDispatcher.java:55)
        at sun.nio.ch.IOUtil.write(IOUtil.java:148)
        at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:524)
        at io.netty.channel.socket.nio.NioSocketChannel.doWrite(NioSocketChannel.java:267)
        at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:694)
        at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.forceFlush(AbstractNioChannel.java:321)
        at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:515)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:464)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:378)
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:350)
        at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:116)
        at java.lang.Thread.run(Thread.java:745)

Aug 11, 2014 1:45:46 PM io.netty.channel.AbstractChannelHandlerContext invokeExceptionCaught
WARNING: An exception was thrown by a user handler's exceptionCaught() method while handling the following exception:
java.io.IOException: An existing connection was forcibly closed by the remote host
        at sun.nio.ch.SocketDispatcher.writev0(Native Method)
        at sun.nio.ch.SocketDispatcher.writev(SocketDispatcher.java:55)
        at sun.nio.ch.IOUtil.write(IOUtil.java:148)
        at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:524)
        at io.netty.channel.socket.nio.NioSocketChannel.doWrite(NioSocketChannel.java:267)
        at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:694)
        at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.forceFlush(AbstractNioChannel.java:321)
        at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:515)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:464)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:378)
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:350)
        at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:116)
        at java.lang.Thread.run(Thread.java:745)

Aug 11, 2014 1:45:46 PM io.netty.channel.AbstractChannelHandlerContext invokeExceptionCaught
WARNING: An exception was thrown by a user handler's exceptionCaught() method while handling the following exception:
java.io.IOException: An existing connection was forcibly closed by the remote host
        at sun.nio.ch.SocketDispatcher.writev0(Native Method)
        at sun.nio.ch.SocketDispatcher.writev(SocketDispatcher.java:55)
        at sun.nio.ch.IOUtil.write(IOUtil.java:148)
        at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:524)
        at io.netty.channel.socket.nio.NioSocketChannel.doWrite(NioSocketChannel.java:267)
        at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:694)
        at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.forceFlush(AbstractNioChannel.java:321)
        at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:515)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:464)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:378)
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:350)
        at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:116)
        at java.lang.Thread.run(Thread.java:745)

Crash Report 2 (Commented)


## A generic good start
S:\minecraft>java -Xmx1G -Xms1G -jar minecraft_server.jar --nogui

[20:01:50] [Server thread/INFO]: Starting minecraft server version 14w33a
[20:01:50] [Server thread/INFO]: Loading properties
[20:01:50] [Server thread/INFO]: Default game type: SURVIVAL
[20:01:50] [Server thread/INFO]: Generating keypair
[20:01:50] [Server thread/INFO]: Starting Minecraft server on *:25565
[20:01:50] [Server thread/INFO]: Preparing level "world"
[20:01:51] [Server thread/INFO]: Preparing start region for level 0
[20:01:52] [Server thread/INFO]: Preparing spawn area: 42%
[20:01:53] [Server thread/INFO]: Preparing spawn area: 98%
[20:01:53] [Server thread/INFO]: Done (2.192s)! For help, type "help" or "?"

## Log onto the server for the fist time since the server restart
[20:05:32] [User Authenticator #1/INFO]: UUID of player MegaSniperB is 3f4da0c6-0d7a-44cf-ae91-818e4fea5476
[20:05:32] [Server thread/INFO]: MegaSniperB[/127.0.0.1:52464] logged in with entity id 549 at (-321.45184881157775, 67.0, 263.7129469049785)
[20:05:32] [Server thread/INFO]: MegaSniperB joined the game

## Loss of connection, Player leaves the game
[21:09:40] [Server thread/INFO]: MegaSniperB lost connection: TranslatableComponent{key='disconnect.genericReason', args=[Internal Exception: java.io.IOException: An existing connection was forcibly closed by the remote host], siblings=[], style=Style{hasParent=false, color=null, bold=null, italic=null, underlined=null, obfuscated=null, clickEvent=null, hoverEvent=null, insertion=null}}
[21:09:40] [Server thread/INFO]: MegaSniperB left the game

## Player tries to join the game but the server thinks 2 players with the same UUID joined,
## causing there to be a phantom player, and the real player, the the server breaks and spams it's stack
[21:12:30] [User Authenticator #2/INFO]: UUID of player MegaSniperB is 3f4da0c6-0d7a-44cf-ae91-818e4fea5476
[21:12:30] [Server thread/INFO]: MegaSniperB[/127.0.0.1:54610] logged in with entity id 799552 at (-375.4334363097938, 57.24918707874468, 222.0369253542067)
[21:12:30] [Server thread/INFO]: MegaSniperB joined the game
[21:13:01] [User Authenticator #3/INFO]: UUID of player MegaSniperB is 3f4da0c6-0d7a-44cf-ae91-818e4fea5476
[21:13:02] [Server thread/INFO]: MegaSniperB[/127.0.0.1:54633] logged in with entity id 806330 at (-375.4334363097938, 57.24918707874468, 222.0369253542067)
[21:13:02] [Server thread/INFO]: MegaSniperB joined the game

## Infite spam of the same stack, goes on forever
Aug 13, 2014 9:13:02 PM io.netty.channel.AbstractChannelHandlerContext invokeExceptionCaught
WARNING: An exception was thrown by a user handler's exceptionCaught() method while handling the following exception:
java.io.IOException: An existing connection was forcibly closed by the remote host
        at sun.nio.ch.SocketDispatcher.writev0(Native Method)
        at sun.nio.ch.SocketDispatcher.writev(SocketDispatcher.java:55)
        at sun.nio.ch.IOUtil.write(IOUtil.java:148)
        at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:524)
        at io.netty.channel.socket.nio.NioSocketChannel.doWrite(NioSocketChannel.java:267)
        at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:694)
        at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.forceFlush(AbstractNioChannel.java:321)
        at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:515)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:464)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:378)
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:350)
        at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:116)
        at java.lang.Thread.run(Thread.java:745)

Aug 13, 2014 9:13:02 PM io.netty.channel.AbstractChannelHandlerContext invokeExceptionCaught
WARNING: An exception was thrown by a user handler's exceptionCaught() method while handling the following exception:
java.io.IOException: An existing connection was forcibly closed by the remote host
        at sun.nio.ch.SocketDispatcher.writev0(Native Method)
        at sun.nio.ch.SocketDispatcher.writev(SocketDispatcher.java:55)
        at sun.nio.ch.IOUtil.write(IOUtil.java:148)
        at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:524)
        at io.netty.channel.socket.nio.NioSocketChannel.doWrite(NioSocketChannel.java:267)
        at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:694)
        at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.forceFlush(AbstractNioChannel.java:321)
        at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:515)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:464)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:378)
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:350)
        at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:116)
        at java.lang.Thread.run(Thread.java:745)

Linked issues

Comments 8

Your pc is causing this issue. Please read the comments of MC-38565

This should be re-opened, a client being disconnected should not cause item duplication or the server to become corrupted, both of which happen with this bug.
This is unrelated to MC38565, and is new in 14w32d. I am experiencing this on two different 14w32d servers with clients on windows 7, windows 8.1 and Mac. I have player-idle-timeout set to 0.

That's a different issue which is hidden from view for security reasons.

This bug I described is exactly the bug being described above, hence it should not be closed as a duplicate of an unrelated issue. I found this bug report through searching for the problem I'm having. Their PC is NOT causing this issue, the server causes this issue once any player disconnects "unexpectedly". If you are going to hide the "other" security issue, then you should also hide this one as the current resolution is simply incorrect.

This is a new bug I can only reproduce in the snapshots. I have whitelist and online mode on and time idle timer set to 0, I can run the other versions of the server without any hassle so it is not the bug described in MC-38565

This is not a duplicate of MC-38565.

So it appears that the issue is that Minecraft can take a long time (minutes some times) to notice that a player has disconnected, and if the player reconnects before that happens, bad things happen:
1) Minecraft will now never notice that the original connection failed, spam the log with the "forcibly closed" message, and hang at shutdown.
2) The player will now be in the server twice.
3) [redacted] badness derived from problem 2.

This definitely never happens in 1.7, and has only recently started (for me) in the 1.8 snapshots.

This is not a duplicate of https://bugs.mojang.com/browse/MC-38565 it is a duplicate of several other bugs that have been closed as duplicates of https://bugs.mojang.com/browse/MC-38565 but that's what happens if you dismiss valid bug reports as duplicates.

Thank You @unknown, for explaining how the bug occurs and verifying that it is not a duplicate. Could a mod reopen this on this basis

Brandon Staab

(Unassigned)

Unconfirmed

crash, players, server

Minecraft 14w32d

Retrieved