Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[BUG] ConcurrentModificationException causing server crash #1256

Open
Dexton opened this issue Sep 27, 2020 · 20 comments · May be fixed by #1648
Open

[BUG] ConcurrentModificationException causing server crash #1256

Dexton opened this issue Sep 27, 2020 · 20 comments · May be fixed by #1648
Labels
status: unverified type: bug Something isn't working

Comments

@Dexton
Copy link

Dexton commented Sep 27, 2020

Describe the bug
Server crashes on startup with java.util.ConcurrentModificationException after calling gregtech.api.util.GTUtility.getRedstonePower(GTUtility.java:686)

Versions
Forge: 14.23.5.2847
GTCE: 1.10.0.546
FTB Interactions: 2.0.9 https://www.curseforge.com/minecraft/modpacks/ftb-interactions

Setup
Server

Steps To Reproduce

  1. This happened randomly after restarting the server.
    Tried running from multiple backups and to have forge remove any erroring blocks but get the same resultss

Expected behavior
Server should start up without crashing

Additional context
Crash log: https://pastebin.com/Xd8T6hhB
Another users issue on FTB Interactions issue tracker: FTBTeam/FTB-Interactions#1263

Tried updating GregtechCE to newest version, running on multiple backups, setting forge to remove erroring entities and tile entities. All with the same results.

@Dexton Dexton added status: unverified type: bug Something isn't working labels Sep 27, 2020
@LAGIdiot
Copy link
Member

Thank you creating this issue.
I have checked our code and all we do is calling standard Vanilla MC function to get information regarding strength of Redstone signal. There is nothing special about it.

What I can see from crash log is cascade world loading. When we ask for Redstone power it has to check additional blocks which in this case lay in not loaded chunk which means loading it. When new chunk is loaded all tileentities are loaded and some of ours starts checking for Redstone signal... This happens 3x times and dies on fourth which probably happens because chunk being loaded is same as first one on which whole circle of getting Redstone strength started. (But that does not make sense as that one is already loaded and should be cached)

I am seeing this for first time and all our MetaTileentities are calling this so it definitely can't be common problem. And it is probably not even caused just by GTCE. But it is in combination with other mod probably one that is doing something with world loading order (maybe optimizing it? but that is just guessing).

I don't even have suggestion for this as there is not enough data.

@Enjoyed
Copy link

Enjoyed commented Nov 14, 2020

Hello there. Somehow i got to get the same error, altho it happened on a server with sponge, but i cloned the DIM119 (void) that was causing the crash to a singleplayer with base OmniFactory 1.2.2, and getting the same issue:
Crash log: https://pastebin.com/jDfdAg8U

Some extra info about mine:
GTCE: 1.12.2-1.8.4.419
Forge: 14.23.5.2847
OmniFactory 1.2.2

With mcedit i removed some chunks and it didnt crash, so it's definetely some tileentity not corrupted thingy.
EDIT: i have a save so that you can replicate if needed. (altho i should clean it as it sizes 1gb)
Here you have the save (i only kept the base which is causing the crash):
DIM119.zip

@PrototypeTrousers
Copy link
Contributor

the zip provided does not contain the level.dat from the world containing the world seed and block ids

@Enjoyed
Copy link

Enjoyed commented Nov 17, 2020

There is no need for that. Here are the steps for reproducing the error:

  1. Have OmniFactory 1.2.2 installed.
  2. Create a fresh new world
  3. save/disconnect (return to main menu) - no need to restart minecraft
  4. Replace DIM119 folder (its void world btw) on your saves -> whatever name you put - with the zip provided
  5. Start the world again, and use a < Void Cake > to teleport to said Dimension.
  • As the base conflicting is just right at the spawn, it will crash instantly.

@LAGIdiot
Copy link
Member

Thank you for providing us with new crashlog which is not that much convoluted and with reproduction steps. It still looks like Forge/Vanilla MC bug to me but further analysis is required.

@Enjoyed
Copy link

Enjoyed commented Nov 18, 2020

A pleasure. Anything you need you can ping me on Discord to not spam the issue ^^

@Keridos
Copy link

Keridos commented Nov 23, 2020

There is also this issue: FTBTeam/FTB-Interactions#1306
I also had the same issue with enderio conduits. That one was in a Compact Machine though, that may have triggered something too.

@Keridos
Copy link

Keridos commented Nov 23, 2020

Update: this seems to happen when you chunkload the inside of Compact machines via an external mod and somehow a GT machine might be at the other side of one of its tunnels this can happen.

A workaround is to set chunk loading to false in the FTBUtilities and then deselect that chunk inside of the CM.

I suspect this might as well happen when you do not completely chunkload your base. e.g. GT machine is chunkloaded, the cable, pipe or whatever connecting to it is not or vice versa.

/edit: more weirdness, in that compact machine of ours was no gregtech machine or block at all.
crash-2020-11-23_18.22.59-server.txt

@serenibyss
Copy link
Collaborator

@Enjoyed Do you know exactly what was in the chunk that caused the crash? You said you removed a chunk and it fixed the issue

@warjort
Copy link
Contributor

warjort commented Jan 26, 2021

Since I was asked about this on a different bug report, I decided to do a little investigation.
What I did was modify the GTUtility.getRedstonePower() method to print the requests and what errors.
For the DIM19 file provided, a cutdown version of the output is:

-- snip --
[14:35:20] [Server thread/INFO]: BlockPos{x=-36, y=72, z=15} -> BlockPos{x=-35, y=72, z=15}
[14:35:20] [Server thread/INFO]: BlockPos{x=-35, y=72, z=15} -> BlockPos{x=-35, y=71, z=15}
[14:35:20] [Server thread/INFO]: BlockPos{x=-35, y=72, z=15} -> BlockPos{x=-35, y=73, z=15}
[14:35:20] [Server thread/INFO]: BlockPos{x=-35, y=72, z=15} -> BlockPos{x=-35, y=72, z=14}
[14:35:20] [Server thread/INFO]: BlockPos{x=-35, y=72, z=15} -> BlockPos{x=-35, y=72, z=16}
[14:35:20] [Server thread/INFO]: BlockPos{x=-35, y=72, z=15} -> BlockPos{x=-36, y=72, z=15}
[14:35:20] [Server thread/INFO]: BlockPos{x=-35, y=72, z=15} -> BlockPos{x=-34, y=72, z=15}
[14:35:20] [Server thread/INFO]: BlockPos{x=-34, y=72, z=15} -> BlockPos{x=-34, y=71, z=15}
[14:35:20] [Server thread/INFO]: BlockPos{x=-34, y=72, z=15} -> BlockPos{x=-34, y=73, z=15}
[14:35:20] [Server thread/INFO]: BlockPos{x=-34, y=72, z=15} -> BlockPos{x=-34, y=72, z=14}
[14:35:20] [Server thread/INFO]: BlockPos{x=-34, y=72, z=15} -> BlockPos{x=-34, y=72, z=16}
[14:35:20] [Server thread/INFO]: BlockPos{x=-34, y=72, z=15} -> BlockPos{x=-35, y=72, z=15}
[14:35:20] [Server thread/INFO]: BlockPos{x=-34, y=72, z=15} -> BlockPos{x=-33, y=72, z=15}
[14:35:20] [Server thread/INFO]: BlockPos{x=-32, y=75, z=15} -> BlockPos{x=-32, y=74, z=15}
--snip--
[14:35:20] [Server thread/INFO]: BlockPos{x=-28, y=72, z=16} -> BlockPos{x=-29, y=72, z=16}
[14:35:20] [Server thread/INFO]: BlockPos{x=-28, y=72, z=16} -> BlockPos{x=-27, y=72, z=16}
[14:35:21] [Server thread/INFO]: error=BlockPos{x=-32, y=75, z=15} -> BlockPos{x=-32, y=74, z=15}
[14:35:21] [Server thread/INFO]: error=BlockPos{x=-34, y=72, z=15} -> BlockPos{x=-33, y=72, z=15}
[14:35:21] [Server thread/INFO]: error=BlockPos{x=-34, y=72, z=16} -> BlockPos{x=-34, y=71, z=16}
[14:35:21] [Server thread/ERROR]: Encountered an unexpected exception
net.minecraft.util.ReportedException: Ticking memory connection
        at net.minecraft.network.NetworkSystem.func_151269_c(NetworkSystem.java:195) ~[oz.class:?]
        at net.minecraft.server.MinecraftServer.func_71190_q(MinecraftServer.java:790) ~[MinecraftServer.class:?]
        at net.minecraft.server.MinecraftServer.func_71217_p(MinecraftServer.java:668) ~[MinecraftServer.class:?]
        at net.minecraft.server.integrated.IntegratedServer.func_71217_p(IntegratedServer.java:185) ~[chd.class:?]
        at net.minecraft.server.MinecraftServer.run(MinecraftServer.java:526) [MinecraftServer.class:?]
        at java.lang.Thread.run(Thread.java:745) [?:1.8.0_51]
Caused by: java.util.ConcurrentModificationException
        at java.util.HashMap$HashIterator.nextNode(HashMap.java:1429) ~[?:1.8.0_51]
        at java.util.HashMap$ValueIterator.next(HashMap.java:1458) ~[?:1.8.0_51]
        at net.minecraft.world.World.func_147448_a(World.java:1949) ~[amu.class:?]
        at net.minecraft.world.chunk.Chunk.func_76631_c(Chunk.java:856) ~[axw.class:?]
        at net.minecraftforge.common.chunkio.ChunkIOProvider.syncCallback(ChunkIOProvider.java:109) ~[ChunkIOProvider.class:?]
        at net.minecraftforge.common.chunkio.ChunkIOExecutor.syncChunkLoad(ChunkIOExecutor.java:94) ~[ChunkIOExecutor.class:?]
        at net.minecraft.world.gen.ChunkProviderServer.loadChunk(ChunkProviderServer.java:118) ~[on.class:?]
        at net.minecraft.world.gen.ChunkProviderServer.func_186028_c(ChunkProviderServer.java:89) ~[on.class:?]
        at net.minecraft.world.gen.ChunkProviderServer.func_186025_d(ChunkProviderServer.java:135) ~[on.class:?]
        at net.minecraft.world.World.func_72964_e(World.java:310) ~[amu.class:?]
        at net.minecraft.world.World.func_175726_f(World.java:305) ~[amu.class:?]
        at net.minecraft.world.World.func_180495_p(World.java:911) ~[amu.class:?]
        at net.minecraft.world.World.func_175627_a(World.java:3203) ~[amu.class:?]
        at net.minecraft.world.World.func_175676_y(World.java:3238) ~[amu.class:?]
        at net.minecraft.world.World.func_175651_c(World.java:3271) ~[amu.class:?]
        at gregtech.api.util.GTUtility.getRedstonePower(GTUtility.java:639) ~[GTUtility.class:?]
        at gregtech.api.pipenet.tile.PipeCoverableImplementation.onLoad(PipeCoverableImplementation.java:119) ~[PipeCoverableImplementation.class:?]
        at gregtech.api.pipenet.tile.TileEntityPipeBase.onLoad(TileEntityPipeBase.java:289) ~[TileEntityPipeBase.class:?]
        at net.minecraft.world.World.func_175700_a(World.java:1924) ~[amu.class:?]

This is basically following a cable that leads to a machine in a new chunk.
Something in that new chunk is causing the chunk's tile entities to get concurrently modified during loading.

There is no duplicate loading of a chunk.

i.e. minecraft/forge is loading the chunk and then iterating over the tile entities. While it is doing that, something is adding or removing a tile entity.

Some of things in that chunk are some gregtech machines including a pyrolase oven, cables, enderio conduits with facades, AE2 interfaces, a couple of small (non-gregtech) fluid tanks and a fluid garbage bin.

@warjort
Copy link
Contributor

warjort commented Jan 26, 2021

GT is getting the blame because it is the one that initiates the chunk load.

What is weird, is that to actually see what is in the chunk, I modified getRedstonePower() to always return 0 and not
initiate the chunk load. The world loaded fine.

AND, when I put back the original gregtech jar, the world also loaded fine. Just being able to load and save the world once fixed the problem,

This suggests to me that something in that world save is in a corrupt state? Or there is an inconsistent state between 2 of the saved chunks/regions?

@Enjoyed
Copy link

Enjoyed commented Jan 26, 2021

@Enjoyed Do you know exactly what was in the chunk that caused the crash? You said you removed a chunk and it fixed the issue

Yes, i spent a whole evening with mcedit removing chunk -> restoring -> removing chunk... (Even deleting by Y axis.), but the issue wasn't with a single chunk.
For example, when not restoring (deleting chunk by chunk without restoring), when stopped crashing, restored and only deleted the latest chunk, it kept crashin. So there's no exact chunk i could find culprit.

Hope this information helps you

@warjort
Copy link
Contributor

warjort commented Jan 26, 2021

One thing I will add to the discussion, is that if this cable were hundreds of blocks long. The stacktrace would be massive with lots of "recursive" calls to getRedstonePower() along the cable and this also would lead to many chunk loads, possibly cascading into other cables that need to be followed.

Moving this initialisation of the redstone power caching into something more lazy during the initial tick of each block would stop this from happening and would also remove any potential of a cascade of chunk loading requests.

The redstone power cache could even potentially be saved in the tile/cover state to be used if the neighbouring block is not loaded? That is what vanilla does with its redstone. e.g. see the comparator's ouput signal.

@serenibyss
Copy link
Collaborator

serenibyss commented Jan 27, 2021

Someone else had this error. They were changing ID's of things around, and when they changed the ID of a cable that was already in the world to something else, they had this crash. I think it might be related to the script-generated cables, or its related to meta shifts in cables.

Their crashlog: https://paste.gg/p/anonymous/5714aa7dcfab4725ab3c119783313daf

@some-guy3
Copy link

https://drive.google.com/drive/folders/17CzVzFgOxW7Dt3SdHObIjXyb8ZVSLadp?usp=sharing
Here's the level.dat/level.dat_old of the world; it might help.

@lordmuff
Copy link

lordmuff commented May 7, 2021

ive been getting this error too, on a pretty old world that's been through a lot of mod changes and such; it's only began manifesting relatively recently, though. crash log attached, let me know if you need world files or a mod list or anything.
crash-2021-05-07_18.06.41-server.txt

@warjort
Copy link
Contributor

warjort commented May 7, 2021

Your crash report shows the same issue, something is adding, replacing or removing a tile entity during chunk loading.

I still think the correct fix is move that initialisation of the redstone cache from onLoad() into the first tick handling.
This will stop GTCE causing any cascade during chunk loading.

This does not mean the real problem will be fixed (whatever is changing/corrupting the tile entities).
It just means GTCE is less likely to get the blame because it started the chunk load.

@hjae78
Copy link
Collaborator

hjae78 commented Oct 7, 2021

We have an open PR to fix this, shame that people still have to have corrupt worlds from this when it's such an easy fix

@warjort
Copy link
Contributor

warjort commented Oct 7, 2021

We have an open PR to fix this, shame that people still have to have corrupt worlds from this when it's such an easy fix

If you are referring to #1623 see my critique in #1648

As I understand the issue, the actual error is caused by other mods triggering tile entity changes during chunk loading which runs into CCME errors in forge's rewritten tile entity loading code. Forge does not expect these updates.
Since 1.12 forge is no longer supported, this is unlikely to ever get fixed.

Where GTCE comes into play is that it wrongly gets blamed because it is the one that starts the chunk loading.

You can argue that the way GTCE starts the chunk loading is wrong since it leads to cascading chunk loading and this makes the error more likely (more chunks being loading means more concurrency*). But this does not change the fact that GTCE is not the one causing the underlying error.

The above mentioned PRs attempt to remove the cascading chunk loading by deferring the redstone cache calculation.
This hopefully reduces the chance of the error happening, but it cannot totally eliminate it since it is outside GTCE's control.

(*) When I use concurrency here I don't mean multiple threads but instead it is CCME errors caused by data structures getting modified from within loops over their iterators.

@warjort
Copy link
Contributor

warjort commented Oct 7, 2021

Since 1.12 forge is no longer supported, this is unlikely to ever get fixed.

Another way to fix it would be introduce a core mod or mixin that modifies forge's tile entity loading code.

A simple change would be to make it iterate over a cloned copy of the data structure.
This would eliminate the CCME, but whether it introduces other problems is another question.

A more complicated alternate would be to somehow trap where the data structure is incorrectly modified during chunk loading and report the offending block/mod so the real error can be fixed.
Coming up with the logic for this check might be quite difficult, since it needs to differentiate modifications that are legitimate ,e.g. loading from the save file and normal processing, versus those that will later on cause the CCME error during chunk loading.

Rongmario added a commit to LoliKingdom/LoliASM that referenced this issue Oct 7, 2021
- Easy patch, but doesn't exactly fix the root of the issue
- But seems like entities loading were done in the same way...
Exaxxion added a commit to Nomifactory/Nomifactory that referenced this issue Jan 28, 2022
Remove patch from GregTechCE/GregTech#1623

Add mod "CensoredASM" 4.4
- Add its config file
  * disable reuseBucketQuads

- Among other things, should patch the cause of the redstone first-tick
  bug throwing a ConcurrentModificationException in rare circumstances
  on world loads (GregTechCE/GregTech#1256).

Add mod MixinBooter 2.0 (library/dependency)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
status: unverified type: bug Something isn't working
Projects
None yet
10 participants