[1.10.2] Ridiculously Low Performance

[Rasgnarok]

By now, I am aware that Spongeforge is in development and that it has quite a few ways before it goes out of 'bleeding' state. However, in using spongeforge-1772 I have noticed quite a lot of lag as soon as a server goes above 30 players.

With 24G allocated, for example, it takes about 8 minutes to stop a server or the mean tick time nears 360 ms.. I am only noticing this after finally updating from an async build (which was against 1692). Has there been any improvements since 1772? The changelog mentions little of this. My timings report is inconclusive - block change/block updating is a major cause.

Notes:
-Map is pre-generated
-Using Pixelmon BETA9 (with the lowest possible settings)

[Aaron1011]

@Rasgnarok: Make sure you're always running the latest build of Sponge (currently 1787).

My timings report is inconclusive - block change/block updating is a major cause.

Can you please provide it? It's difficult to determine what the cause is with only reports of lag.

[Rasgnarok]

https://timings.aikar.co/v2/?id=47eb6441eeca4c93ab073c8a7e20291c

as you can see, there is little on the actual report. Most often than not, it spikes (as you can see at the beginning of the report) then it drops down. Normally, this is accompanied by massive spam in the console, and dozens of players disconnecting. This was after one of those cases - lost around 20 players to it.

EDIT: I am testing the latest, but it has done nothing to improve the issue - it's on my test server currently. The errors that get spammed still happen regardless.

[Rasgnarok]

Errors that spam it:
http://pastebin.com/FRF1yEFA
http://pastebin.com/MNq1pv7U

I have others, including non-tracked entities, inventory issues, but those two I see frequently when this happens. Another major killer is the speed limit on player's movements. I am aware this is a Minecraft vanilla issue, but it does create lag throughout the server, especially with 30+ players using mounts (can be pokemon, but also boats, horses).
https://gyazo.com/fb7ebf71d63ed198e59273fd0021b203

[Aaron1011]

http://pastebin.com/MNq1pv7U

That's a clear Sponge issue - I'll look into it.

EDIT: From what I can see, it appears to be related to interacting with a shopkeeper. Can you try to find out how to consistently reproduce that stacktrace?

[Rasgnarok]

I can... would imply that it is in part due to interacting in a certain way with Pixelmon's shopkeepers. Does it specify what action caused the error?

[Aaron1011]

It's kind of a bizarre exception, but it seems to be caused by right-clicking the shopkeeper at x=-609.80, y=46.00,z=-178.49 However, there's definitely something weird going on - it almost looks like the interaction is recursively happening over and over again.

[Rasgnarok]

I can see and track down what entity is there later today. I'll let you know, but I doubt that I can find anything bizarre about it.

[Aaron1011]

@Rasgnarok: The only thing I need to know is if you can cause that stacktrace consistently - and if it happens with any other shopkeepers.

[Rasgnarok]

Seems to happen intermittently whenever we interact with them. There's also this error; might it be connected?
https://gyazo.com/06a9d80d4e1566f22de5d3bf467a0a35

[Aaron1011]

@Rasgnarok: I'll look into these issues. Can you see if you can reproduce them on a fresh world, with just pixelmon and sponge?

[Rasgnarok]

I could see that yes. The channel pipeline one might be impossible to, as well as the entity tracking error. I'll see what I can do on my test one; using the latest possible.

[Deathwhitch]

i can confirm this issue as well. same exact issue. if it helps when i interact with a move tutor or shop npc sometimes it triggers a battle instead of opening the shop menu then shortly after players start timing out of the server and getting disconnected. they still show as in the server and can't then reconnect until i force a restart

[Aaron1011]

@Rasgnarok @Deathwhitch: Can you both use build 1798, and enable the new verbose-errors config option, which will be automatically inserted into your config (it requires a restart to apply). Once you get another tracker error, please pastebin it here.

[Rasgnarok]

@Deathwhitch Didn't you get an error already that crashed the server on 1798? Post it up mate

[Deathwhitch]

i have the verbose on now, problem is the server doesn't crash or produce an error it just stops responding to everything. players lag out and can't log back in cause it says they are still in the server. server won't respond to stop command or any commands. i have to force close it to restart. not sure what's causing it or how to fix it but server is unplayable in this state

[Deathwhitch]

heres the paste from my last server run, its not an error log its the whole console but you can see where it stopped responding and how long the server ran.

http://pastebin.com/DCVHFnRW

[Deathwhitch]

it finally logged an error when the stop porcess kicked in.No idea if it is related to the issue here or not but here it is

http://pastebin.com/hrJVk6YT

[Aaron1011]

@Deathwhitch: Can you pastebin your entire fml-server-latest.log file?

[Deathwhitch]

https://drive.google.com/file/d/0B5A00RnWKl-tNHRsWUNMQ0VpaWc/view?usp=sharing

[Aaron1011]

@Deathwhitch: The error stacktrace you posted is just related to a log file - is it possible that you moved/deleted/did something to a log file while the server was running?

Nothing is standing out in your server log that would cause a slowdown. Can you paste us a timings report and WarmRoast from when the lag is occuring?

[Deathwhitch]

I would love to, but every time i have tried the link it generates leads to a 404 page

[Deathwhitch]

so here is something weird. I have a pastebin of my console while the server unresponsive and players cannot log in, however rcon CAN still log in and run commands that the server responds to. I ran the TPS command while the server was in this unresponsive state and took a screenshot. However the server still did not respond to the stop command and would not shut down until force closed. Here is the pastebin of the console during this time and a screen of the TPS command ran from the remote connection using my cell phone

http://pastebin.com/enqVMjjc

http://imgur.com/a/elfU5

[Aaron1011]

@Deathwhitch: Can you open a separate issue for the problem with creating timings?

[Deathwhitch]

sure

My last post was still relevant to this issue though.

[Deathwhitch]

UPDATE: Issue stopped for me on 1798 if I remove griefprevention from my mod folder. This narrows it down to a GP related issue and I will post on that thread about it.

[Rasgnarok]

I did find that land protection plugins (in my case, Polis) are making it harder, performance wise. Will be posting a timings soon when I get to 60 players on, to illustrate my point. What does it for me is chunk loading/unloading, and entity ticking. Pixelmon in this case creates so much clogging that furnaces, apricorns, and other items relying on ticks do not function properly. For example, I spent a good 30 minutes waiting for a tree to finally completely decay.

[bloodmc]

@Deathwhitch The issue isn't with GP but something occuring in Sponge AFTER specific events get cancelled. GP also has timings for everything it does which will show up in a timings report. This issue is probably caused due to the CauseTracker getting in a bad state. Once the entity event fix branch is merged, it should resolve it.

I'm also running a 1.10.2 server with over 30 mods(No pixelmon) and no issues with latest GP.

[Rasgnarok]

@bloodmc How many players? I think there is a large difference in that sense - often enough I cannot reproduce most of the spammed errors I get unless I achieve that playercount... makes it hard to be able to stress-test builds in terms of performance.

[Deathwhitch]

@bloodmc I'll try updating sponge after work tomorrow and see if it gets better, if not think you can help me figure out what flag or event from my spawn city admin claim could be causing the lock up lag here. I try timings report but the server is unresponsive when it happens. When I try it when it doesnt happen the "/sponge timings" ccommand returns invalid argument, but the tps command shows 20.00. No idea what those timings or numbers are when the issue happens as the server does not respond to anything, not even a stop command and must be force closed to restart. Some flag I set but be whats causing the issue, something sponge can't track properly but I have no idea which one it could be as all flags seem to be working fine.

[Deathwhitch]

here is a paste of the permissions file for my server. pretty basic but hope it can help you narrow down what what happens after the cancel event is called as blood mentioned

http://pastebin.com/tyarYDP6

[bloodmc]

@Rasgnarok @Deathwhitch Please test the following build

https://www.dropbox.com/s/ra3hrlz5uw7xbhf/spongeforge-1.10.2-2098-bleeding-BETA-TEST1.jar?dl=0

This fixes another ticket with a similar performance issue #948

Make sure to set "chunk-gc-tick-interval" back to 1. Also, please test to make sure chunks are unloading properly. If it works, I'll push to bleeding.

Note: This won't solve the pixelmon issue where players may be unable to toss a pokemon but it should help performance. @gabizou is pushing a fix for that soon

[bloodmc]

Please test latest SF which should resolve the pixelmon toss issue as well.

[ProsperCraft]

The stopping the server taking minutes is now resolved thank you @bloodmc!
You are amazing!

Also the TPS issues have improved drastically.

[bloodmc]

@ProsperCraft thanks, closing as this ticket should be resolved with latest builds.