Refined Storage

Refined Storage

77M Downloads

[1.16.5] Invalidating storage cache on server thread causes hang after startup

Column01 opened this issue ยท 22 comments

commented

Issue description:

To preface this:
We are running server software that works with forge and spigot to allow spigot plugins to load (Mohist). While I don't think a plugin could be the cause (as we are using an extremely small number of them that all load before the server finishes booting and it still happens without them), I feel it is relevant information as Mohist modifies aspects of forge to work to my understanding.

While my server is booting, there are approximately 2-3 minutes of the server thread being frozen while refined storage is invalidating storage caches. Most of them appear to happen due to a CONNECTED_STATE_CHANGED event or a REDSTONE_MODE_OR_NETWORK_ENERGY_CHANGE. I believe it is refined storage as the debug log only has output from refined storage in this time where the server is frozen and all this processing is happening on the main server thread

What happens:

Server freezes after it finishes loading up

What you expected to happen:

The server to not freeze for multiple minutes

Steps to reproduce:

  1. Install refined storage
  2. ...
  3. No idea why it happens.

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

  • Minecraft: 1.16.5
  • Forge: 36.2.0
  • Refined Storage: 1.9.13

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

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

Seems to start around the Network at position BlockPos... parts where it invalidates the cache of the networks. Each network appears to hang the server for ~30 seconds while processing.
Debug Log

commented

Yes. That is unfortunately very much a thing :/

There are craftbukkit and spigot things in the profile so I'm not sure if that is actually the case here

commented

I enabled ALL logging at one point and there isn't anything else going on at this time where the server was frozen

commented

It should also be noted that we noticed significant slowdowns after adding mohist to the server with refined storage's grids (Shift-clicking recipes, taking items in and out). Could it be related? Seems to only affect refined storage as all other containers seem unaffected.

commented

You could run some profiling to indentify the problem. Sounds to me like mohist is causing external storages to go a bit wild.

The first tick is there RS initializes the entire network (and other mods do too) as such it can take quite a while. If externalstorages are slowed down that significantly I can imagine 2-3 min easily.

commented

Is there an easy way to profile the server to share it with you? The pack I have has spark in it, but spark doesn't work if the server thread freezes before I can tell it to profile haha

commented

I'm going to test and see if removing my external storage fixes the grid speed issues

commented

If your server is running locally you can attach a profiler like visualvm to see what is happening.

It should also be noted that we noticed significant slowdowns after adding mohist to the server with refined storage's grids (Shift-clicking recipes, taking items in and out)

This however should be diagnosable via spark

commented

If your server is running locally you can attach a profiler like visualvm to see what is happening.

The server is running on a linux box and I connect over SSH, I'd have to set up some infrastructure to profile it remotely I believe.

This however should be diagnosable via spark

I plan to profile while doing it, will update with results when I have them

commented

Here's the profile for shift-clicking a recipe into a grid: https://spark.lucko.me/MGafTE3CEj

commented

Hmm. Inventory tweaks is also sorting the crafting grid for some reason? Otherwise nothing that indicates mohist, not that that would exclude is from being a potential culprit.

commented

Would it be possible spark cannot profile mohist it as it's outside its scope? Not sure if that's a thing.

commented

Yes. That is unfortunately very much a thing :/

commented

Forgot to mention this, but when we added mohist, we also got a forge update as a side effect. The previous version had forge 36.1.65. Could be relevant

commented

Would it help to run the Bukkit plugin version of Spark instead and use that to profile? I'm no expert on the hybrid server softwares; it's just a suggestion.

OT: A PSA worth reading about Mohist.

commented

OT: A PSA worth reading about Mohist.

It's currently the only working 1.16.5 forge bukkit bridge so that's why I'm using it. You also don't need their custom patched essentials version for the new version. As for their patching of stuff, it's usually done by community members and they link to the source in most cases where you can see what changes were made.

commented

Same issue, but increasing max tick time prevents a crash, instead causing the server to run at extremely low TPS for around 20 minutes. My server does not use Mohist.

commented

Same issue, but increasing max tick time prevents a crash, instead causing the server to run at extremely low TPS for around 20 minutes. My server does not use Mohist.

Happy it's not mohist doing it, sad that its an issue that needs to be fixed. Thanks for reassuring me I'm not crazy ๐Ÿ˜›

commented

RE: @egshels
Actually, I'm looking at your issue I'm not entirely sure they are related.

Mine is the server completely freezing at boot, absolutely nothing gets processed while the storage caches are invalidated. Yours seems to run, but slowly due to something else causing the lag. Do you have a debug log to share on your issue from around the time the lag is happening? Could help identify if it's the same logic causing it.

commented

RE: @Column01
I think you're correct. I did some investigating and it seems like some players storage systems didn't have enough power, so they were repeatedly turning off and on until they got unloaded? I'm unsure really, because it's stopped happening and so I can't find any more debug logs.

commented

Still having issues with this, any update? I'm still not able to profile my server properly as it's remote. I might be able to do it on a local instance but I'm not sure I'll be able to reproduce it easily since it seems to happen with servers with a lot of RS systems.

commented

I've disabled Mohist and the issue has gone away (it invalidates the cache way faster)... no idea what would cause this. I wonder if Mohist is clogging the event bus since I've started to notice general lag when crafting, not just in refined storage grids.

commented

The Eventbus seems to be causing various problems in 1.16...

Nothing we can do about Mohist though.