Chunk loading lag

Question

Chunk loading lag

someaddons opened this issue 4 years ago · 24 comments

someaddons commented 4 years ago

Issue description:

Refined storage loads chunks on worldtick when updating energy usage, captured this lagspikes >200ms tick with spark.
https://spark.lucko.me/#ZO0jbZmutb

What happens:

Lag due to loading chunk

What you expected to happen:

Check if chunk is loaded and do nothing

Steps to reproduce:

...

Version (make sure you are on the latest version before reporting):

Minecraft:1.15.2
Forge:31.2.5
Refined Storage: refinedstorage-1.8.4.jar

Does this issue occur on a server? [yes/no]

If a (crash)log is relevant for this issue, link it here:

[pastebin/gist/etc link here]

someaddons commented 4 years ago

ye

someaddons commented 4 years ago

yes

someaddons · Answer 1 · 2020-06-26T11:38:58.000Z

Still happens, relevant stacktrace:

java.lang.Exception: Chunk load debug
        at net.minecraft.world.server.ServerChunkProvider.func_217233_c(SourceFile:1177) [?:?] {re:mixin,pl:accesstransformer:B,re:classloading,pl:accesstransformer:B,pl:mixin:APP:performant.mixins.json:world.chunk.ServerChunkProviderMixin,pl:mixin:APP:performant.mixins.json:world.chunk.ServerChunkProviderThreadsMixin,pl:mixin:A}
        at net.minecraft.world.server.ServerChunkProvider.func_212849_a_(SourceFile:138) [?:?] {re:mixin,pl:accesstransformer:B,re:classloading,pl:accesstransformer:B,pl:mixin:APP:performant.mixins.json:world.chunk.ServerChunkProviderMixin,pl:mixin:APP:performant.mixins.json:world.chunk.ServerChunkProviderThreadsMixin,pl:mixin:A}
        at net.minecraft.world.World.func_217353_a(World.java:149) [?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:mixin:APP:performant.mixins.json:world.WorldMixin,pl:mixin:A,pl:runtimedistcleaner:A}
        at net.minecraft.world.IWorldReader.func_217348_a(IWorldReader.java:101) [?:?] {re:mixin,pl:runtimedistcleaner:A,re:classloading,pl:runtimedistcleaner:A}
        at net.minecraft.world.World.func_212866_a_(World.java:145) [?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:mixin:APP:performant.mixins.json:world.WorldMixin,pl:mixin:A,pl:runtimedistcleaner:A}
        at net.minecraft.world.World.func_180495_p(World.java:361) [?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:mixin:APP:performant.mixins.json:world.WorldMixin,pl:mixin:A,pl:runtimedistcleaner:A}
        at net.minecraft.world.World.func_175651_c(World.java:949) [?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:mixin:APP:performant.mixins.json:world.WorldMixin,pl:mixin:A,pl:runtimedistcleaner:A}
        at net.minecraft.world.World.func_175640_z(World.java:954) [?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:mixin:APP:performant.mixins.json:world.WorldMixin,pl:mixin:A,pl:runtimedistcleaner:A}
        at com.raoulvdberge.refinedstorage.tile.config.RedstoneMode.isEnabled(RedstoneMode.java:22) [?:1.8.4] {re:classloading}
        at com.raoulvdberge.refinedstorage.apiimpl.network.Network.updateEnergyUsage(Network.java:528) [?:1.8.4] {re:classloading}
        at com.raoulvdberge.refinedstorage.apiimpl.network.Network.update(Network.java:137) [?:1.8.4] {re:classloading}
        at com.raoulvdberge.refinedstorage.apiimpl.network.NetworkListener.onWorldTick(NetworkListener.java:17) [?:1.8.4] {re:classloading}
        at net.minecraftforge.eventbus.ASMEventHandler_665_NetworkListener_onWorldTick_WorldTickEvent.invoke(.dynamic) [?:?] {}
        at net.minecraftforge.eventbus.ASMEventHandler.invoke(ASMEventHandler.java:80) [eventbus-2.2.0-service.jar:?] {}
        at net.minecraftforge.eventbus.EventBus.post(EventBus.java:258) [eventbus-2.2.0-service.jar:?] {}
        at net.minecraftforge.fml.hooks.BasicEventHooks.onPostWorldTick(BasicEventHooks.java:99) [?:?] {re:classloading}
        at net.minecraft.server.MinecraftServer.func_71190_q(MinecraftServer.java:855) [?:?] {re:classloading,pl:accesstransformer:B,pl:runtimedistcleaner:A}
        at net.minecraft.server.dedicated.DedicatedServer.func_71190_q(DedicatedServer.java:330) [?:?] {re:classloading,pl:accesstransformer:B}
        at net.minecraft.server.MinecraftServer.func_71217_p(MinecraftServer.java:784) [?:?] {re:classloading,pl:accesstransformer:B,pl:runtimedistcleaner:A}
        at net.minecraft.server.MinecraftServer.run(MinecraftServer.java:637) [?:?] {re:classloading,pl:accesstransformer:B,pl:runtimedistcleaner:A}
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_252] {}```

tth05 · Answer 2 · 2020-06-26T16:31:28.000Z

Chunk loading is entirely handled by minecraft. RS just gets a block at a position and the server does everything else after that.

raoulvdberge · Answer 3 · 2020-06-27T11:25:41.000Z

RS is getting the redstone mode. That shouldn't cause any perf issues.

Darkere · Answer 4 · 2020-06-27T12:05:07.000Z

I believe in this case RS is loading? an unloaded chunk. See spark report.

I can only imagine this happens if the system is only partially loaded.
I've had this issue in an early 1.14 world but haven't seen it since (I don't tend to use redstone mode much).

Going to do a quick test.

Darkere · Answer 5 · 2020-06-27T12:45:18.000Z

Ok. I've been unable to reproduce the issue.

Had an exporter running far away in an unloaded chunk. The chunk does get loaded. However, it stays loaded without any performance issues.

@someaddons any chance you can figure out what the setup is? It's a chunk with some barrels and a mekanism PRC. Otherwise, a world download would be a last attempt at figuring out what's wrong.

someaddons · Answer 6 · 2020-06-28T07:38:11.000Z

as far as I can tell refined storage is plain getting the position from the world without previously checking if that position is loaded at all, if it is unloaded the world will force load that chunk on access. Can't really download the world its a big server world

And the performance issue comes from triggering a chunk load on the world, not from the actual redstone check itself

Darkere · Answer 7 · 2020-06-28T08:11:16.000Z

I can tell refined storage is plain getting the position from the world without previously checking if that position is loaded

Yes. It partially loads the chunk just so much as to allow working for the network part.
I could imagine a performance mod might be unloading that chunk causing it to be reloaded quite often?

someaddons · Answer 8 · 2020-06-28T08:33:07.000Z

though I'd like if RS wouldnt load chunks at all if its not asked to

someaddons · Answer 9 · 2020-06-28T08:32:11.000Z

I think there was some kind of limit of total loaded chunks where vanilla then starts unloading chunks quicker or so

someaddons · Answer 10 · 2020-06-30T12:47:49.000Z

Report from 0 players online, server ticks at 46ms. Main usage in spark is RS loading chunks through this stuff
https://spark.lucko.me/#CiZpi7iH69

tth05 · Answer 11 · 2020-06-30T12:50:41.000Z

Nope, the real lag here comes from World#isBlockPowered which has nothing to do with RS.

RS is NOT responsible for loading chunks. All of that is handled by the server.

someaddons · Answer 12 · 2020-06-30T12:59:56.000Z

RS is checking block powered on an unloaded chunk. Which in turn triggers the chunk.

Darkere · Answer 13 · 2020-06-30T13:41:56.000Z

@someaddons are you still on version 1.8.4?

someaddons · Answer 14 · 2020-06-30T15:04:05.000Z

btw if your network updates has to load the whole network then you got some design issue on hand

raoulvdberge · Answer 15 · 2020-06-30T15:09:33.000Z

@someaddons Can we focus on the problem here? Let us know what the custom jar does for you.

someaddons · Answer 16 · 2020-06-30T15:13:11.000Z

The custom jar seems to help, at least at 0 players it no longer running at 100% cpu

Darkere · Answer 17 · 2020-06-30T15:27:48.000Z

The network might need to be loaded once for the issue to start to appear. Not certain but would make sense.

someaddons · Answer 18 · 2020-06-30T15:32:45.000Z

gonna check what happens once someone logged in and off again

someaddons · Answer 19 · 2020-06-30T16:07:11.000Z

ye seems its fixed, server is at 29ms with a player online and down to 13ms at 0

tth05 · Answer 20 · 2020-06-30T13:47:40.000Z

The problem is that RS just can't ignore half of the network as if it wouldn't exist. For example if an exporter ticks, it has to know if the network controller still has power and is enabled. You can't just ignore it.

Darkere · Answer 21 · 2020-06-30T13:55:34.000Z

Can you check if the problem persists with this version?
Just needs to be replaced serverside.
refinedstorage-1.8.4.custom.jar.zip

raoulvdberge · Answer 22 · 2020-07-17T00:59:52.000Z

After a first pass, I fixed cases I could find where RS unwillingly loads chunks.

Relevant commits:
e78cade
9cbc25e
c3a3927

There are (for sure) some corner cases present. I will do more passes soon to find those too, but this should help a lot already.

Share to

Issue description:

What happens:

What you expected to happen:

Steps to reproduce:

Version (make sure you are on the latest version before reporting):

If a (crash)log is relevant for this issue, link it here: