search

McJtyMods / RFToolsBuilder

The RFTools Builder, Shield, Projector, Scanner, ...
MIT License
8 stars 14 forks source link

Server lockup in parkNanos(), caused by ShapeCard trying to scan chunks #50

Open DBotThePony opened 3 years ago

DBotThePony commented 3 years ago

It works probably fine (I were experiencing mild lag when working with shape cards) in older Minecraft versions, but on newer Minecraft versions it does not.

---- Minecraft Crash Report ----
// Oh - I know what I did wrong!

Time: 13.04.21 7:26
Description: Watching Server

java.lang.Error: ServerHangWatchdog detected that a single server tick took 60,00 seconds (should be max 0.05)
    at sun.misc.Unsafe.park(Native Method) ~[?:1.8.0_282] {}
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) ~[?:1.8.0_282] {}
    at net.minecraft.util.concurrent.ThreadTaskExecutor.func_223705_bi(SourceFile:139) ~[?:?] {re:mixin,pl:accesstransformer:B,re:computing_frames,pl:accesstransformer:B,re:classloading,pl:accesstransformer:B}
    at net.minecraft.util.concurrent.ThreadTaskExecutor.func_213161_c(SourceFile:129) ~[?:?] {re:mixin,pl:accesstransformer:B,re:computing_frames,pl:accesstransformer:B,re:classloading,pl:accesstransformer:B}
    at net.minecraft.world.server.ServerChunkProvider.func_212849_a_(ServerChunkProvider.java:130) ~[?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:runtimedistcleaner:A}
    at net.minecraft.world.World.func_217353_a(World.java:167) ~[?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:runtimedistcleaner:A}
    at net.minecraft.world.IWorldReader.func_217348_a(IWorldReader.java:112) ~[?:?] {re:mixin,pl:runtimedistcleaner:A,re:classloading,pl:runtimedistcleaner:A}
    at net.minecraft.world.World.func_212866_a_(World.java:163) ~[?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:runtimedistcleaner:A}
    at net.minecraft.world.World.func_180495_p(World.java:379) ~[?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:runtimedistcleaner:A}
    at mcjty.rftoolsbuilder.modules.builder.blocks.BuilderTileEntity.isEmptyOrReplacable(BuilderTileEntity.java:1726) ~[rftoolsbuilder:1.16-3.0.16] {re:classloading}
    at mcjty.rftoolsbuilder.modules.builder.items.ShapeCardItem.placeBlockIfPossible(ShapeCardItem.java:658) ~[rftoolsbuilder:1.16-3.0.16] {re:classloading}
    at mcjty.rftoolsbuilder.modules.builder.items.ShapeCardItem.composeFormula(ShapeCardItem.java:760) ~[rftoolsbuilder:1.16-3.0.16] {re:classloading}
    at mcjty.rftoolsbuilder.modules.builder.blocks.BuilderTileEntity.clearSupportBlocksShaped(BuilderTileEntity.java:426) ~[rftoolsbuilder:1.16-3.0.16] {re:classloading}
    at mcjty.rftoolsbuilder.modules.builder.blocks.BuilderTileEntity.clearSupportBlocks(BuilderTileEntity.java:442) ~[rftoolsbuilder:1.16-3.0.16] {re:classloading}
    at mcjty.rftoolsbuilder.modules.builder.blocks.BuilderTileEntity.refreshSettings(BuilderTileEntity.java:2236) ~[rftoolsbuilder:1.16-3.0.16] {re:classloading}
    at mcjty.rftoolsbuilder.modules.builder.blocks.BuilderTileEntity.access$100(BuilderTileEntity.java:102) ~[rftoolsbuilder:1.16-3.0.16] {re:classloading}
    at mcjty.rftoolsbuilder.modules.builder.blocks.BuilderTileEntity$4.checkShapeCard(BuilderTileEntity.java:2505) ~[rftoolsbuilder:1.16-3.0.16] {re:classloading}
    at mcjty.rftoolsbuilder.modules.builder.blocks.BuilderTileEntity$4.extractItem(BuilderTileEntity.java:2474) ~[rftoolsbuilder:1.16-3.0.16] {re:classloading}
    at net.minecraftforge.items.SlotItemHandler.func_82869_a(SlotItemHandler.java:110) ~[forge:?] {re:classloading}
    at net.minecraft.inventory.container.Container.func_241440_b_(Container.java:280) ~[?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:mixin:APP:immersiveengineering.mixins.json:accessors.ContainerAccess,pl:mixin:A,pl:runtimedistcleaner:A}
    at net.minecraft.inventory.container.Container.func_184996_a(Container.java:160) ~[?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:mixin:APP:immersiveengineering.mixins.json:accessors.ContainerAccess,pl:mixin:A,pl:runtimedistcleaner:A}
    at mcjty.lib.container.GenericContainer.func_184996_a(GenericContainer.java:433) ~[mcjtylib:1.16-5.0.19] {re:classloading}
    at net.minecraft.network.play.ServerPlayNetHandler.func_147351_a(ServerPlayNetHandler.java:1265) ~[?:?] {re:mixin,pl:accesstransformer:B,re:classloading,pl:accesstransformer:B,pl:mixin:A}
    at net.minecraft.network.play.client.CClickWindowPacket.func_148833_a(CClickWindowPacket.java:34) ~[?:?] {re:classloading,pl:runtimedistcleaner:A}
    at net.minecraft.network.play.client.CClickWindowPacket.func_148833_a(CClickWindowPacket.java:12) ~[?:?] {re:classloading,pl:runtimedistcleaner:A}
    at net.minecraft.network.PacketThreadUtil.func_225383_a(SourceFile:21) ~[?:?] {re:classloading}
    at net.minecraft.network.PacketThreadUtil$$Lambda$19496/14585807.run(Unknown Source) ~[?:?] {}
    at net.minecraft.util.concurrent.TickDelayedTask.run(SourceFile:18) ~[?:?] {re:classloading}
    at net.minecraft.util.concurrent.ThreadTaskExecutor.func_213166_h(SourceFile:144) ~[?:?] {re:mixin,pl:accesstransformer:B,re:computing_frames,pl:accesstransformer:B,re:classloading,pl:accesstransformer:B}
    at net.minecraft.util.concurrent.RecursiveEventLoop.func_213166_h(SourceFile:23) ~[?:?] {re:mixin,re:computing_frames,re:classloading}
    at net.minecraft.server.MinecraftServer.func_213166_h(MinecraftServer.java:734) ~[?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:mixin:APP:charm.mixins.json:accessor.MinecraftServerAccessor,pl:mixin:APP:byg.mixins.json:server.MixinMinecraftServer,pl:mixin:APP:jaopca.mixins.json:MinecraftServerMixin,pl:mixin:A,pl:runtimedistcleaner:A}
    at net.minecraft.server.MinecraftServer.func_213166_h(MinecraftServer.java:159) ~[?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:mixin:APP:charm.mixins.json:accessor.MinecraftServerAccessor,pl:mixin:APP:byg.mixins.json:server.MixinMinecraftServer,pl:mixin:APP:jaopca.mixins.json:MinecraftServerMixin,pl:mixin:A,pl:runtimedistcleaner:A}
    at net.minecraft.util.concurrent.ThreadTaskExecutor.func_213168_p(SourceFile:118) ~[?:?] {re:mixin,pl:accesstransformer:B,re:computing_frames,pl:accesstransformer:B,re:classloading,pl:accesstransformer:B}
    at net.minecraft.server.MinecraftServer.func_213205_aW(MinecraftServer.java:717) ~[?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:mixin:APP:charm.mixins.json:accessor.MinecraftServerAccessor,pl:mixin:APP:byg.mixins.json:server.MixinMinecraftServer,pl:mixin:APP:jaopca.mixins.json:MinecraftServerMixin,pl:mixin:A,pl:runtimedistcleaner:A}
    at net.minecraft.server.MinecraftServer.func_213168_p(MinecraftServer.java:711) ~[?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:mixin:APP:charm.mixins.json:accessor.MinecraftServerAccessor,pl:mixin:APP:byg.mixins.json:server.MixinMinecraftServer,pl:mixin:APP:jaopca.mixins.json:MinecraftServerMixin,pl:mixin:A,pl:runtimedistcleaner:A}
    at net.minecraft.util.concurrent.ThreadTaskExecutor.func_213160_bf(SourceFile:103) ~[?:?] {re:mixin,pl:accesstransformer:B,re:computing_frames,pl:accesstransformer:B,re:classloading,pl:accesstransformer:B}
    at net.minecraft.server.MinecraftServer.func_213202_o(MinecraftServer.java:696) ~[?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:mixin:APP:charm.mixins.json:accessor.MinecraftServerAccessor,pl:mixin:APP:byg.mixins.json:server.MixinMinecraftServer,pl:mixin:APP:jaopca.mixins.json:MinecraftServerMixin,pl:mixin:A,pl:runtimedistcleaner:A}
    at net.minecraft.server.MinecraftServer.func_240802_v_(MinecraftServer.java:646) ~[?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:mixin:APP:charm.mixins.json:accessor.MinecraftServerAccessor,pl:mixin:APP:byg.mixins.json:server.MixinMinecraftServer,pl:mixin:APP:jaopca.mixins.json:MinecraftServerMixin,pl:mixin:A,pl:runtimedistcleaner:A}
    at net.minecraft.server.MinecraftServer.func_240783_a_(MinecraftServer.java:232) ~[?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:mixin:APP:charm.mixins.json:accessor.MinecraftServerAccessor,pl:mixin:APP:byg.mixins.json:server.MixinMinecraftServer,pl:mixin:APP:jaopca.mixins.json:MinecraftServerMixin,pl:mixin:A,pl:runtimedistcleaner:A}
    at net.minecraft.server.MinecraftServer$$Lambda$16607/1686064055.run(Unknown Source) ~[?:?] {}
    at java.lang.Thread.run(Thread.java:748) [?:1.8.0_282] {}
McJty commented 3 years ago

Version please

DBotThePony commented 3 years ago

RF Tools Builder: 3.0.16 Forge: 36.1.4

-- System Details --
Details:
    Minecraft Version: 1.16.5
    Minecraft Version ID: 1.16.5
    Operating System: Linux (amd64) version 5.9.1-050901-generic
    Java Version: 1.8.0_282, GraalVM Community
    Java VM Version: OpenJDK 64-Bit Server VM GraalVM CE 21.0.0.2 (mixed mode), GraalVM Community
    Memory: 1460467384 bytes (1392 MB) / 2691694592 bytes (2567 MB) up to 5726797824 bytes (5461 MB)
    CPUs: 8
    JVM Flags: 3 total; -Xmx6G -Xms128m -XX:UseSSE=4
McJty commented 3 years ago

And what were you doing exactly?

DBotThePony commented 3 years ago

Taking out/inserting shape card from/into builder?

McJty commented 3 years ago

Hmm I wonder why that's giving problems for you because that's an extremely common operation done by countless of people

DBotThePony commented 3 years ago

People tend to tolerate problems until they become completely game breaking.

McJty commented 3 years ago

No, I mean that it's not a problem for them at all. I also see no reason why it would be a problem. The code that is mentioned in the stacktrace is simply doing a simple test on a block. There is no reason for it to take that long and also not something that I can control anyway

DBotThePony commented 3 years ago

is simply doing a simple test on a block

But does it check if chunk was generated before doing the test? Or does getBlockState return "empty" value when chunk is not generated?

McJty commented 3 years ago

It will cause the chunk to be generated (which may be why it's taking so long) but that's ok. It has to be generated since the builder needs to be able to do that test. So yes, if this is happening on a new chunk then this delay is normal and to be expected

DBotThePony commented 3 years ago

So here is the problem: you cause all chunks in 512x512 block area generated in main thread in blocking way (on default config of rftools, which allow shapes of 512x512)

And the bigger is allowed area, the worse problem become, exponentially.

McJty commented 3 years ago

Yes but I need to do that. I have to quarry those areas after all. I don't see how I can avoid that

DBotThePony commented 3 years ago

Why would you need to check empty chunks for a block that won't end up there anyway?

McJty commented 3 years ago

Empty chunks? What do you mean?

DBotThePony commented 3 years ago

Chunks that are not generated. You check for an artificial block (support block? clearSupportBlocksShaped) in a chunk that was never generated ("empty"), a block that won't end up there under any conditions. So you basically cause server lag by doing a check that would never end up being true. And you could cut this check early by checking whenever is chunk present in first place, eliminating all the lag caused by block check.

McJty commented 3 years ago

Ah yes, that's a good point. I didn't realize this was about the support blocks. I'll see what I can do to avoid that