Sponge: [1.10.2] Server crash, caused by Chunk Generator/Loader

Created on 31 Aug 2016 · 9Comments · Source: SpongePowered/Sponge

Hey !

It's me again :D

Since a few days now, we've been "randomly crashing", after a while we figured out that when one specific player was connecting. I teleported him back at spawn, and tried to teleport to the coordinates myself, and bam, crash.

Unable to find the corrupted chunk, we called it a day, but now, ANOTHER player found the same (or another) corrupted regions, and everytime this player join, the server crash.

I'm a bit stuck on this one ... hope you guys can do something about it, I have a "few" logs :D

Thanks for your awesome work !

bug

Source

Pymous

Most helpful comment

For the developers, here's a (shortened) stack trace with the fully deobfuscated names:

java.lang.StackOverflowError: Exception ticking world
    at net.minecraft.world.gen.ChunkProviderServer.canDenyChunkRequest(ChunkProviderServer.java:175)
    at net.minecraft.world.gen.ChunkProviderServer.redirect$onProvideChunkHead$0(ChunkProviderServer.java:143)
    at net.minecraft.world.gen.ChunkProviderServer.provideChunk(ChunkProviderServer.java:132)
    at net.minecraft.world.World.getChunkFromChunkCoords(World.java:303)
    at net.minecraft.world.World.getChunkFromBlockCoords(World.java:298)
    at org.spongepowered.common.event.tracking.CauseTracker.setBlockState(CauseTracker.java:335)
// START REPEAT
    at net.minecraft.world.WorldServer.setBlockState(WorldServer.java:1032)
    at net.minecraft.block.BlockChest.checkForSurroundingChests(BlockChest.java:237)
    at net.minecraft.block.BlockChest.onBlockAdded(BlockChest.java:74)
    at net.minecraft.world.chunk.Chunk.setBlockState(Chunk.java:630)
    at net.minecraft.world.chunk.Chunk.setBlockState(Chunk.java:500)
    at org.spongepowered.common.event.tracking.CauseTracker.setBlockState(CauseTracker.java:381)
// END REPEAT, Java doesn't give anything beyond this

Here's what I think the problem is:

Minecraft loads a chest.
The chest looks around, and finds another chest block beside it that it's not merged with. It tries to merge with the other chest block into a double chest.
The chest asks the world to change its state.
Sponge marks the change as "about to occur", but prevents the world from actually being modified (yet).

(I assume this is where the problem happens)

Minecraft tells the chest block that it's been changed, despite the actual change not being saved.
The chest looks around, and finds another chest block beside it that it's not merged with (because Sponge is delaying the change). It tries to merge with the other chest block into a double chest.
The chest asks the world to change its state.
Sponge marks the change as "about to occur", but prevents the world from actually being modified (yet).
Minecraft tells the chest block that it's been changed, despite the actual change not being saved.
The chest looks around, and finds another chest block beside it that it's not merged with (because Sponge is delaying the change). It tries to merge with the other chest block into a double chest.

And so on until the server gives up and crashes.

JBYoshi on 1 Sep 2016

❤3

All 9 comments

For the developers, here's a (shortened) stack trace with the fully deobfuscated names:

java.lang.StackOverflowError: Exception ticking world
    at net.minecraft.world.gen.ChunkProviderServer.canDenyChunkRequest(ChunkProviderServer.java:175)
    at net.minecraft.world.gen.ChunkProviderServer.redirect$onProvideChunkHead$0(ChunkProviderServer.java:143)
    at net.minecraft.world.gen.ChunkProviderServer.provideChunk(ChunkProviderServer.java:132)
    at net.minecraft.world.World.getChunkFromChunkCoords(World.java:303)
    at net.minecraft.world.World.getChunkFromBlockCoords(World.java:298)
    at org.spongepowered.common.event.tracking.CauseTracker.setBlockState(CauseTracker.java:335)
// START REPEAT
    at net.minecraft.world.WorldServer.setBlockState(WorldServer.java:1032)
    at net.minecraft.block.BlockChest.checkForSurroundingChests(BlockChest.java:237)
    at net.minecraft.block.BlockChest.onBlockAdded(BlockChest.java:74)
    at net.minecraft.world.chunk.Chunk.setBlockState(Chunk.java:630)
    at net.minecraft.world.chunk.Chunk.setBlockState(Chunk.java:500)
    at org.spongepowered.common.event.tracking.CauseTracker.setBlockState(CauseTracker.java:381)
// END REPEAT, Java doesn't give anything beyond this

Here's what I think the problem is:

Minecraft loads a chest.
The chest looks around, and finds another chest block beside it that it's not merged with. It tries to merge with the other chest block into a double chest.
The chest asks the world to change its state.
Sponge marks the change as "about to occur", but prevents the world from actually being modified (yet).

(I assume this is where the problem happens)

Minecraft tells the chest block that it's been changed, despite the actual change not being saved.
The chest looks around, and finds another chest block beside it that it's not merged with (because Sponge is delaying the change). It tries to merge with the other chest block into a double chest.
The chest asks the world to change its state.
Sponge marks the change as "about to occur", but prevents the world from actually being modified (yet).
Minecraft tells the chest block that it's been changed, despite the actual change not being saved.
The chest looks around, and finds another chest block beside it that it's not merged with (because Sponge is delaying the change). It tries to merge with the other chest block into a double chest.

And so on until the server gives up and crashes.

JBYoshi on 1 Sep 2016

❤3

@JBYoshi Thank you so much for looking into it and providing a very detailed response as to what is going on. I'm curious though since the current method

    at net.minecraft.world.gen.ChunkProviderServer.canDenyChunkRequest(ChunkProviderServer.java:175)

is commented out whether this build that is having this issue is one of the few test builds that @bloodmc has been pushing out with his changes, at which point this is still a potential thing to look into, if not re-test on whatever the latest test build is.

gabizou on 1 Sep 2016

@gabizou : We're using the latest build blood gave on IRC (so it's probably even ahead from the git for a few things), but the first time this happened, we were on Build 1689.

@JBYoshi : Thanks for the work, blood kinda got the same thinking as far as I can understand :)

To help, here is the map we have, and the coordinates were the issue happen :
Map => http://mc.clapity.eu/blood.zip
Coordinates => /tppos 13531 44 12581 -f

You will need Pixelmon 5 (Beta 6) to load the map properly :)

Pymous on 1 Sep 2016

@JBYoshi Did you deobfuscate the stack trace manually? or is there some tool that can do it?

ryantheleach on 1 Sep 2016

@ryantheleach Manually. If you want to do it, the necessary file is in ~/.gradle/caches/minecraft/de/oceanlabs/mcp/mcp_<either release or snapshot>/<mappings version>/srgs/srg-mcp.srg.

JBYoshi on 1 Sep 2016

I know that Pymous wasn't able to identify the exact chunk with error and blood hasn't been able to replicate, but based on JBYoshi's info, would it be most likely that you'd be looking for a chest that is on a chunk-boundary, loading one half of a doublechest in one chunk, doing a look around while the other half in in a different chunk... somehow to try checking the nbt data in surrounding chunks around his coordinate given to find a chest tile on an x or z coordinate that is exactly at a boundary line or setting up a test for exactly-on-boundary line and approaching that region from different directions with maxed out view radiuses to make the process take longer before the second half happens?