MineColonies

MineColonies

53M Downloads

[1.12.2] [0.8.7712] Minecolonies server lag (Event subscribers)

Sandriell opened this issue · 22 comments

commented

Trying to determine the cause of lag on my server. Minecolonies is basically the only thing running. I only have a handful of other things going on the sever, none of which seem to be an issue.

2018-03-08_21 36 22

This is the result of Lag Goggles. The only thing showing any kind of impact is Minecolonies under Event Subscribers.

Using TickProfiler's lag spike detection it was routinely picking up the following:

https://gist.github.com/Sandriell/4be73e707f3b4551cc793eb372a509ea

And running WarmRoast, it seems to be indicating the same thing, but I'm not entirely sure I understand it.

warmroast

Finally, I forced a crash mostly for a mod-list, but also in case it may provide any other useful info.
https://gist.github.com/Sandriell/3ad4447f848d9dc84087a18369fa4bf4

commented

So let me explain what is going on here.
As of the initial design Minecolonies has been using an external storage mechanism, known as the colony.dat file. This file is updated every tick, which is to say the least not optimal. This updating of the file has several issues with it. The most notable are:

  • Lag each tick, since it is used to save the colony to disk, and IO takes time.
  • When the world crashes it is not saved to disk on purpose, however our colonies are. Causing them to become out of sync.
  • Depending on the size of the server this takes a lot of space. The world data is compressed and controlled by MC in a way that ensures the smallest footprint for the world using the AnvilFileFormat that worlds are saved in today.

On the other hand this also gives us some possibilities we would not have in any other case:

  • Creating and loading minecolonies data from backups.
  • Possibility to read the minecolonies data without having the world (especially handy for us developers when uses come to us with issues)

Back to the issue at hand:
@Raycoms It seems that, from the WarmRoast trace, we are saving twice in every tick: Once on Pre and once on Post. This seems to be very redundant to be honest. So it would already be better is somebody took a quick peek under the hood and checked why that is happening, we should only execute our code (and save for that matter) in Post, not in Pre. To solve this issue entirely I will create a new Issue that describes what we discussed yesterday evening with regards to capabilities and TileEntities.

commented

Would like to add that I am running MC on an top end Samsung 960 PRO m.2 SSD, so file I/O can't get much better than that.

I have also noticed at night the Event Subscriber percentage that Lag Goggles reports drops down to less than 1%, and then goes right back up during the day. Maybe it simply has less data to save every tick at night?

commented

It only saves when states change, during the night no citizens work so nothing changes -> Nothing needs to be saved. It does not matter if you have an SSD or not, yes it reduces the IO time, but the real problem is the conversion of the in memory data to inmemory NBT before. That is just heavy.

commented

I tried the latest version (0.8.7719), sadly it hasn't helped and performance is about the same.

commented
commented

New Warmroast.

warmroast2

I have also tried updating Java (144 to 162), switching to G1GC and upping the amount of memory allocated to the server (8gb to 10gb).

The issue does not present itself right away. When I first login, TPS is hovering around 20ms/tick and then it gets progressively worse- I'm not exploring or anything just staying in my colony, and i'm the only one on the server. After around 45 minutes it starts skipping 40-60 ticks and keeps getting worse over time. I have watched it go up to ~80ms/tick. I took the above Warmroast once it started skipping ticks.

commented

You seem to have a LOT of chicken around. Looking at your WarmRoast Updating the chicken takes 24% of your time.......

commented

You might want to consider running /kill @e[type==chicken] and /kill @e[type==item] after each other to kill them. Do you have a herder around?

commented

Ran the command (its only a single =, not 2) and it killed only 23 chickens. My TPS did drop way down to 21-22ms/tick though!

I did notice afterwards when I was looking around that there was an invisible mob (like glitched invisible not an effect, had to use a Ancient Warfare guard to kill it) inside the chicken's pen for my herder. Is it possible that could have been related? Freaking out the chicken herder?

I cannot figure out how 23 chickens alone (when none of them were showing any high times using Lag Goggles or TickProfiler could have been lagging my server so much.

This is before killing the chickens.

2018-03-10_03 58 50

And this is afterwards

2018-03-10_04 01 13

commented

TBH WarmRoast tells me more. It shows me the callstacks. But it might have.

commented

Here is another warmroast.. still shows the chickens allegedly taking up a lot but I'm not lagging and still at ~20ms/tick.

warmroast3

Does warmroast have an expand all? So much clicking! lol

commented

So okey that did not it. Since these are obfuscated names I have to deobfuscate them later today. Can you do me a favor. Destroy the Herder for the chickes and try again.
I want to see what happens. Cause it is weird that 33% of the code is ran in EntityChicken......

commented

Is firing her sufficient? Or should I actually kill her?

And if I try to kill chickens again.. says none found.

Sorry, I didnt understand the instructions warmroast gave to have it show deobfuscated names

commented

I fired her and then destroyed the herder hut block.

thread/INFO] [minecolonies]: Colony 1 - removed AbstractBuilding BlockPos{x=-988, y=81, z=367} of type ChickenHerder

warmroast4

commented

It is still running through it...... No idea why?

commented

I need to look at that function later and see if we are calling it.
Can you post a mod list?

commented

Mod list is in my original post in my forced crash report.

Thank you very much for your continued help in this, especially as it seems maybe this isn't even being caused by MineColonies.

commented

I'm not surprised, was figuring it wasn't a Minecolonies issue after all.

So if I am understanding warmroast correctly, it is the "EntityAITasks.func_75774_a()" function that is generating the lag. Can you tell me what the deobfuscated name is?

Thanks

commented
commented

This is something that has helped me in general with Minecraft linux server lagging:

echo 3 | sudo tee /proc/sys/vm/drop_caches

Clears out the file buffer cache so that java can request more memory to use. Can help if java is not getting enough memory even though there is plenty of memory available.

commented

So to follow up on this, I have removed the mod AI Improvements and that seems to have corrected my issue as far as I can tell.

My latest warmroast- just the relevant bit..

warmroast5

I am going to go ahead and close this now. Thanks everyone for your help.

commented

So I checked this again. And we are not calling that method as far as I can see.
This is not caused by Minecolonies.