Jump to content

Problems with world leaking and coinciding "Can't keep up" messages on SMP


Recommended Posts

I've been troubleshooting for some time on this issue and after being unable to pin this down to a specific mod, I'm coming here for any help/suggestions that can be offered.


In short:

Messages like these (from "latest.log"): [server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 2065ms behind, skipping 41 tick(s)


occur about 3 seconds after messages like these (from "fml-server-latest"): [server thread/DEBUG] [FML/]: Gathering id map for writing to world save Answer


which are then very shortly followed by messages like this (also from "fml-server-latest"): [server thread/DEBUG] [FML/]: The world 65ade8e7 (Answer) may have leaked: seen 3955 times.


This, when a player is online, is noticed as as lag in block placement/destruction in most cases, lasting anywhere between 2 to 10 seconds, and can happen every 45 seconds.  The tick rate (using server tools TPS command) on the server is generally 12-40ms, except when the spikes occur.


Originally I had thought this to be related to something like forestry butterflies on the server updating leaf blocks and causing many chunks to require disk writes quite often, but recently we've changed the config for forestry to turn off butterfly spawns entirely to dismiss this possibility.  Logs are here gist.github - links below.  No crashes are caused by this issue, and no memory leaks seem to be occurring that I can detect after letting the server run for a few days continuously.


If there are any ideas what the cause of this could be, or how to continue to troubleshoot this, I'm all ears.





Link to comment
Share on other sites

Sadly, with that much going on in your MC and with no pragmatic way to figure out what is holding a reference to what.

Your options are to attach a profiles, such as JProfiler {comes with your JRE} and dig into it.

One of the mods you have installed is not letting the worlds unload.

I do Forge for free, however the servers to run it arn't free, so anything is appreciated.
Consider supporting the team on Patreon

Link to comment
Share on other sites

I have, in the past, tried a profiler, and will see if I can spot anything happening with specific classes when these tick skips are occurring.  I'm pretty sure we can find by elimination which mod(s) may be causing world load/unload issues too.  I'll report my findings back once I try these ideas over the weekend.

Link to comment
Share on other sites

So attaching a profiler to the java instance during runtime showed that there is one common thread that gets run at the same moment the warnings about "Can't keep up" get thrown.  The File I/O thread.  It seems that, after running for several hours from a clean restart, these tick skips start to happen concurrently with the Filer I/O thread (in the logs this is read with the output "[server thread/DEBUG] [FML/]: Gathering id map for writing to world save Answer") My observation on the profiler times that thread as waiting for approximately 45 seconds before being activated and then waiting again.


My concern is that the world data being saved at this point might just be large enough in size that it actually causes the only source of lag I can see on the server (nominal tick timing during observations was approximately 10.2 ms ea).  Since I have no mods or available settings that I can see controlling how often world data is saved, or how much of it gets saved at these intervals, I don't think there is anything I can do about this (short of trimming the map size down or putting strict caps on chunkloading).


Does forge code that the map file be written every 45 seconds, or is this a vanilla "feature"? Is there any improvement that can be made to this process, such as writing smaller segments to disk per save operation and doing it more often (e.g. tag areas that require a disk write, but hold off on some of them until write time becomes less intrusive on the world tick)?


Latest log (snipped early startup stuff):


Latest log from "latest.log" showing when "tick skipping" begins relative to fml-server-latest.log:





We found the mod that was forcefully trying to unload the overworld (only chunkloaders were keeping it from suceeding): Too Much Time.

Unfortunately, running a second instance of the server map with identical setup (minus too much time) still had these tick skips happening concurrently with the disk writes after the same time passed since startup.

Link to comment
Share on other sites

Join the conversation

You can post now and register later. If you have an account, sign in now to post with your account.
Note: Your post will require moderator approval before it will be visible.

Unfortunately, your content contains terms that we do not allow. Please edit your content to remove the highlighted words below.
Reply to this topic...

×   Pasted as rich text.   Restore formatting

  Only 75 emoji are allowed.

×   Your link has been automatically embedded.   Display as a link instead

×   Your previous content has been restored.   Clear editor

×   You cannot paste images directly. Upload or insert images from URL.

  • Create New...

Important Information

By using this site, you agree to our Terms of Use.