JMT-MCMT icon indicating copy to clipboard operation
JMT-MCMT copied to clipboard

ChunkProvider and TileEntity issues

Open apertureos opened this issue 3 years ago • 3 comments

Hey again, I'm running a 1.15.2-forge-31.2.45 server with MCMT 0.18.60, and I've encountered a few problems regarding the chunk provider and tile entity multithreading.

First off, glass item frames from the Quark mod (although it may occur with any item frame), generally those close to chunk borders, are broken randomly with both the frame and the item it contained falling to the ground whenever the chunks with those frames are unloaded and reloaded (either by restarting, leaving and joining the server, or by going into other chunks and returning). The item frames are unable to be placed back unless the chunks are unloaded and reloaded again, although /reload does not work. No message in console is displayed when this occurs (see image attached).

Next, iron doors or any other type of door placed next to a chunk border cannot be opened by pressure plate, button, or any other method when chunks are unloaded and reloaded. However, the items used to open these doors work on other items placed next to them that are not near the chunk border, and the doors themselves work when moved away from the border. The doors also seem to snap back to the border when placed on a block running alongside the border, until they are interacted with via fist, in which case they glitch. However, this issue stops whenever ChunkProvider is toggled off, and the doors work temporarily again even once it's reenabled. However, ChunkProvider being toggled results in heavy console spamming, usually about invalid tile entities and such (this doesn't occur when the command toggling off everything is run, though). This eventually results in the entire server crashing due to ticking world, and items in chests or tile entities vanish.

Finally, when loaded into a chunk with a lot of hoppers and other tile entities, console is spammed considerably, and TPS dips as well. This stops when TE multithreading is toggled off, though.

apertureos avatar Nov 03 '20 23:11 apertureos

Ok, so this is FUN

I guess I need to play with 1.15 more as there are a LOT of bugs there

Relevent points:

[02Nov2020 16:01:23.177] [ForkJoinPool-4-worker-6/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: java.lang.NullPointerException
[02Nov2020 16:01:23.178] [ForkJoinPool-4-worker-6/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at net.minecraft.world.server.TicketManager.func_219370_b(SourceFile:82)
[02Nov2020 16:01:23.178] [ForkJoinPool-4-worker-6/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at java.util.Collection.removeIf(Unknown Source)
[02Nov2020 16:01:23.178] [ForkJoinPool-4-worker-6/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at net.minecraft.world.server.TicketManager.func_219340_a(SourceFile:82)
[02Nov2020 16:01:23.178] [ForkJoinPool-4-worker-6/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at net.minecraft.world.server.ServerChunkProvider.func_217207_a(SourceFile:337)
[02Nov2020 16:01:23.178] [ForkJoinPool-4-worker-6/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at net.minecraft.world.server.ServerWorld.func_72835_b(ServerWorld.java:313)
[02Nov2020 16:01:23.178] [ForkJoinPool-4-worker-6/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at org.jmt.mcmt.asmdest.ASMHookTerminator.lambda$callTick$1(ASMHookTerminator.java:97)

Is something breaking WRT chunk loading, which could explain things loading improperly (TicketManager handles chunk loading tickets)

[02Nov2020 15:03:23.626] [ForkJoinPool-4-worker-2/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: java.util.NoSuchElementException
[02Nov2020 15:03:23.627] [ForkJoinPool-4-worker-2/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at java.util.AbstractQueue.remove(Unknown Source)
[02Nov2020 15:03:23.627] [ForkJoinPool-4-worker-2/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at net.minecraft.command.TimerCallbackManager.func_216331_a(SourceFile:62)
[02Nov2020 15:03:23.627] [ForkJoinPool-4-worker-2/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at net.minecraft.world.server.ServerWorld.func_82738_a(ServerWorld.java:1214)
[02Nov2020 15:03:23.628] [ForkJoinPool-4-worker-2/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at net.minecraft.world.World.func_217389_a(World.java:1011)
[02Nov2020 15:03:23.628] [ForkJoinPool-4-worker-2/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at net.minecraft.world.server.ServerWorld.func_72835_b(ServerWorld.java:311)
[02Nov2020 15:03:23.629] [ForkJoinPool-4-worker-2/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at org.jmt.mcmt.asmdest.ASMHookTerminator.lambda$callTick$1(ASMHookTerminator.java:97)

This happens on world load, so is FUN; am unsure what is causing this as I've not seen it in testing and that looks to be purely vanilla stuff

[02Nov2020 15:04:10.382] [ForkJoinPool-4-worker-3/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: java.util.ConcurrentModificationException
[02Nov2020 15:04:10.382] [ForkJoinPool-4-worker-3/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at java.util.ArrayList$Itr.checkForComodification(Unknown Source)
[02Nov2020 15:04:10.382] [ForkJoinPool-4-worker-3/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at java.util.ArrayList$ListItr.previous(Unknown Source)
[02Nov2020 15:04:10.383] [ForkJoinPool-4-worker-3/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at com.google.common.collect.Lists$ReverseList$1.next(Lists.java:951)
[02Nov2020 15:04:10.383] [ForkJoinPool-4-worker-3/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at java.lang.Iterable.forEach(Unknown Source)
[02Nov2020 15:04:10.384] [ForkJoinPool-4-worker-3/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at net.minecraft.advancements.FunctionManager.func_195447_a(SourceFile:120)
[02Nov2020 15:04:10.384] [ForkJoinPool-4-worker-3/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at net.minecraft.command.TimedFunction.func_216316_a(SourceFile:18)
[02Nov2020 15:04:10.384] [ForkJoinPool-4-worker-3/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at java.util.Optional.ifPresent(Unknown Source)
[02Nov2020 15:04:10.385] [ForkJoinPool-4-worker-3/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at net.minecraft.command.TimedFunction.func_212869_a_(SourceFile:18)
[02Nov2020 15:04:10.385] [ForkJoinPool-4-worker-3/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at net.minecraft.command.TimedFunction.func_212869_a_(SourceFile:8)
[02Nov2020 15:04:10.385] [ForkJoinPool-4-worker-3/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at net.minecraft.command.TimerCallbackManager.func_216331_a(SourceFile:65)
[02Nov2020 15:04:10.385] [ForkJoinPool-4-worker-3/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at net.minecraft.world.server.ServerWorld.func_82738_a(ServerWorld.java:1214)
[02Nov2020 15:04:10.386] [ForkJoinPool-4-worker-3/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at net.minecraft.world.World.func_217389_a(World.java:1011)
[02Nov2020 15:04:10.388] [ForkJoinPool-4-worker-3/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at net.minecraft.world.server.ServerWorld.func_72835_b(ServerWorld.java:311)
[02Nov2020 15:04:10.389] [ForkJoinPool-4-worker-3/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at org.jmt.mcmt.asmdest.ASMHookTerminator.lambda$callTick$1(ASMHookTerminator.java:97)

A comod exception, which oddly I don't often see

BTW the server log has a lot of Reloading! in it, is this being done by an op, or automagically?

[02Nov2020 16:01:23.177] [ForkJoinPool-4-worker-6/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: java.lang.NullPointerException
[02Nov2020 16:01:23.178] [ForkJoinPool-4-worker-6/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at net.minecraft.world.server.TicketManager.func_219370_b(SourceFile:82)
[02Nov2020 16:01:23.178] [ForkJoinPool-4-worker-6/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at java.util.Collection.removeIf(Unknown Source)
[02Nov2020 16:01:23.178] [ForkJoinPool-4-worker-6/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at net.minecraft.world.server.TicketManager.func_219340_a(SourceFile:82)
[02Nov2020 16:01:23.178] [ForkJoinPool-4-worker-6/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at net.minecraft.world.server.ServerChunkProvider.func_217207_a(SourceFile:337)
[02Nov2020 16:01:23.178] [ForkJoinPool-4-worker-6/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at net.minecraft.world.server.ServerWorld.func_72835_b(ServerWorld.java:313)
[02Nov2020 16:01:23.178] [ForkJoinPool-4-worker-6/INFO] [STDERR/]: [java.lang.ThreadGroup:uncaughtException:-1]: 	at org.jmt.mcmt.asmdest.ASMHookTerminator.lambda$callTick$1(ASMHookTerminator.java:97)

Second NPE in ticket manager; different thing tho

That happened right after this:

[02Nov2020 16:01:20.479] [ForkJoinPool-4-worker-6/WARN] [net.minecraft.tileentity.TileEntity/]: Block entity invalid: minecraft:skull @ BlockPos{x=-2521, y=39, z=4690}
[02Nov2020 16:01:20.579] [ForkJoinPool-4-worker-6/WARN] [net.minecraft.tileentity.TileEntity/]: Block entity invalid: quark:variant_chest @ BlockPos{x=-821, y=73, z=6119}
[02Nov2020 16:01:20.629] [ForkJoinPool-4-worker-6/WARN] [net.minecraft.tileentity.TileEntity/]: Block entity invalid: ironchest:diamond_chest @ BlockPos{x=-822, y=70, z=6121}
[02Nov2020 16:01:20.680] [ForkJoinPool-4-worker-6/WARN] [net.minecraft.tileentity.TileEntity/]: Block entity invalid: ironchest:diamond_chest @ BlockPos{x=-821, y=70, z=6121}
[02Nov2020 16:01:20.978] [ForkJoinPool-4-worker-6/WARN] [net.minecraft.tileentity.TileEntity/]: Block entity invalid: minecraft:hopper @ BlockPos{x=-822, y=69, z=6121}
[02Nov2020 16:01:21.027] [ForkJoinPool-4-worker-6/WARN] [net.minecraft.tileentity.TileEntity/]: Block entity invalid: minecraft:skull @ BlockPos{x=-2775, y=28, z=4764}
[02Nov2020 16:01:21.078] [ForkJoinPool-4-worker-6/WARN] [net.minecraft.tileentity.TileEntity/]: Block entity invalid: quark:variant_chest @ BlockPos{x=-820, y=69, z=6120}

Which means the removal of TE's might be due to a chunk loading issue

I'll add more later as I look at the logs more

jediminer543 avatar Nov 05 '20 14:11 jediminer543

Oh, another point for future me:

[03Nov2020 17:42:49.639] [ForkJoinPool-4-worker-4/INFO] [STDERR/]: [org.jmt.mcmt.asmdest.ASMHookTerminator:lambda$callTileEntityTick$4:184]: java.lang.NullPointerException
[03Nov2020 17:42:49.642] [ForkJoinPool-4-worker-4/INFO] [STDERR/]: [org.jmt.mcmt.asmdest.ASMHookTerminator:lambda$callTileEntityTick$4:184]: 	at java.util.HashSet.contains(Unknown Source)
[03Nov2020 17:42:49.643] [ForkJoinPool-4-worker-4/INFO] [STDERR/]: [org.jmt.mcmt.asmdest.ASMHookTerminator:lambda$callTileEntityTick$4:184]: 	at blusunrize.immersiveengineering.common.blocks.wooden.SorterTileEntity.canRoute(SorterTileEntity.java:78)
[03Nov2020 17:42:49.644] [ForkJoinPool-4-worker-4/INFO] [STDERR/]: [org.jmt.mcmt.asmdest.ASMHookTerminator:lambda$callTileEntityTick$4:184]: 	at blusunrize.immersiveengineering.common.blocks.wooden.SorterTileEntity.pullItem(SorterTileEntity.java:167)
[03Nov2020 17:42:49.644] [ForkJoinPool-4-worker-4/INFO] [STDERR/]: [org.jmt.mcmt.asmdest.ASMHookTerminator:lambda$callTileEntityTick$4:184]: 	at blusunrize.immersiveengineering.common.blocks.wooden.SorterTileEntity$SorterInventoryHandler.extractItem(SorterTileEntity.java:369)
......... (A lot of PullItem and Extract Item here)
[03Nov2020 17:42:49.629] [ForkJoinPool-4-worker-1/INFO] [STDERR/]: [org.jmt.mcmt.asmdest.ASMHookTerminator:lambda$callTileEntityTick$4:184]: 	at blusunrize.immersiveengineering.common.blocks.wooden.SorterTileEntity.pullItem(SorterTileEntity.java:180)
[03Nov2020 17:42:49.630] [ForkJoinPool-4-worker-1/INFO] [STDERR/]: [org.jmt.mcmt.asmdest.ASMHookTerminator:lambda$callTileEntityTick$4:184]: 	at blusunrize.immersiveengineering.common.blocks.wooden.SorterTileEntity$SorterInventoryHandler.extractItem(SorterTileEntity.java:369)
[03Nov2020 17:42:49.630] [ForkJoinPool-4-worker-1/INFO] [STDERR/]: [org.jmt.mcmt.asmdest.ASMHookTerminator:lambda$callTileEntityTick$4:184]: 	at net.minecraftforge.items.VanillaInventoryCodeHooks.lambda$extractHook$0(VanillaInventoryCodeHooks.java:57)
[03Nov2020 17:42:49.633] [ForkJoinPool-4-worker-1/INFO] [STDERR/]: [org.jmt.mcmt.asmdest.ASMHookTerminator:lambda$callTileEntityTick$4:184]: 	at net.minecraftforge.common.util.LazyOptional.lambda$map$0(LazyOptional.java:184)
[03Nov2020 17:42:49.633] [ForkJoinPool-4-worker-1/INFO] [STDERR/]: [org.jmt.mcmt.asmdest.ASMHookTerminator:lambda$callTileEntityTick$4:184]: 	at net.minecraftforge.common.util.LazyOptional.getValue(LazyOptional.java:116)
[03Nov2020 17:42:49.634] [ForkJoinPool-4-worker-1/INFO] [STDERR/]: [org.jmt.mcmt.asmdest.ASMHookTerminator:lambda$callTileEntityTick$4:184]: 	at net.minecraftforge.common.util.LazyOptional.orElse(LazyOptional.java:219)
[03Nov2020 17:42:49.634] [ForkJoinPool-4-worker-1/INFO] [STDERR/]: [org.jmt.mcmt.asmdest.ASMHookTerminator:lambda$callTileEntityTick$4:184]: 	at net.minecraftforge.items.VanillaInventoryCodeHooks.extractHook(VanillaInventoryCodeHooks.java:82)
[03Nov2020 17:42:49.635] [ForkJoinPool-4-worker-1/INFO] [STDERR/]: [org.jmt.mcmt.asmdest.ASMHookTerminator:lambda$callTileEntityTick$4:184]: 	at net.minecraft.tileentity.HopperTileEntity.func_145891_a(HopperTileEntity.java:181)
[03Nov2020 17:42:49.635] [ForkJoinPool-4-worker-1/INFO] [STDERR/]: [org.jmt.mcmt.asmdest.ASMHookTerminator:lambda$callTileEntityTick$4:184]: 	at net.minecraft.tileentity.HopperTileEntity.lambda$tick$0(HopperTileEntity.java:93)
[03Nov2020 17:42:49.635] [ForkJoinPool-4-worker-1/INFO] [STDERR/]: [org.jmt.mcmt.asmdest.ASMHookTerminator:lambda$callTileEntityTick$4:184]: 	at net.minecraft.tileentity.HopperTileEntity.func_200109_a(HopperTileEntity.java:109)
[03Nov2020 17:42:49.636] [ForkJoinPool-4-worker-1/INFO] [STDERR/]: [org.jmt.mcmt.asmdest.ASMHookTerminator:lambda$callTileEntityTick$4:184]: 	at net.minecraft.tileentity.HopperTileEntity.func_73660_a(HopperTileEntity.java:92)
[03Nov2020 17:42:49.636] [ForkJoinPool-4-worker-1/INFO] [STDERR/]: [org.jmt.mcmt.asmdest.ASMHookTerminator:lambda$callTileEntityTick$4:184]: 	at org.jmt.mcmt.asmdest.ASMHookTerminator.lambda$callTileEntityTick$4(ASMHookTerminator.java:180)

In the other log which have an absurdly large stack loop thing

jediminer543 avatar Nov 05 '20 14:11 jediminer543

The reloading was done by me as I tried to replicate the issue and see if it would also solve it temporarily, but reloading did neither unless I entered different chunks first.

apertureos avatar Nov 05 '20 15:11 apertureos

Hi, just to keep in mind that i'm running through the same problem with jmt_mcmt-1.16.1-0.18.60.jar (only entity parallelisation and parallelised chunk caching enabled).

So isn't exclusive to 1.15 version of the game.

My vanilla item frames drops on the ground randomly. By doing some testing I think that it only happens when placed on some modded blocks, quark blocks seems to work fine, but Oh The Biomes You'll Go blocks doesn't, for an example. Not sure about it, I'll keep testing here.

renandadalte avatar Jan 27 '21 21:01 renandadalte