mojira.dev

Brandon Enright

Assigned

No issues.

Reported

MC-71334 Terrible 1.8 server performance even with the watchdog disabled Incomplete MC-71234 Severe performance issues with 1.8 server Duplicate MC-68904 2-high flowers broken in world conversion from 1.7 to 1.8 Duplicate MC-56743 Linux Fullscreen drawing only part of the screen Incomplete MC-30245 Ocean and Deep Ocean generating with gravel bottom Works As Intended MC-10846 Advanced OpenGL causing some regions to not render in certain views Duplicate MC-3507 Level up sound for (level % 5) == 0 not playing on local client Duplicate MC-1067 Fullscreen is different than F11 setting Duplicate MC-830 Desert Temple TNT trap may detonate prematurely Works As Intended

Comments

@Pierre Waldén

Saying that a "cant keep up" message has nothing to do with any mob is just stupid and can be explored by putting 10000000 mobs in a world and see what happens.

Turning off mob spawning and killing all mobs still results in the problem. Therefore mobs aren't the root cause of the issue even if they may make it worse.

You've committed a logical fallacy known as "affirming the consequent" (look it up). Next time try not to be an idiot.

@StevenNL2000 except that the first bug is about zombies and the second is about animals and other mobs and plenty of people have tested this bug and the load has nothing to do with any mobs. Turning off mob spawning and killing all mobs has no effect.

Don't be fooled by idiots posting in this bug about how they tracked the issue down to <simple fix here> because it isn't mobs or nogui.

I have always run with nogui. The performance problems are intolerable even with nogui specified.

I decided to explore garbage collector options and I've found that using the G1 garbage collector (using the flag -XX:+UseG1GC) makes the problem significantly better.

I think garbage collection is the source of the terrible performance and very long lags. What's probably happening is that the server now requires more CPU and memory than it used to require. When a garbage collection happens it takes so long that the server gets behind. When the garbage collection finishes the server detects that it's behind and tries to "catch up" by skipping ticks. This in turn probably causes another garbage collection and so the server gets stuck in an vicious loop where garbage collections cause the server to do work that causes another garbage collection and so forth. Instead of getting useful work done it spend almost all of its time in garbage collection cycles.

The G1 garbage collector is designed to spread the garbage collection work out and not cause long delays which seems to prevent the vicious garbage collection cycle from killing performance.

With G1 now my server just runs slowly with lag at all times. It is now playable, but just barely.

I doubt it's just one thing that needs fixing. I suspect a lot of effort needs to go into using less memory and probably also less CPU so that garbage collection isn't needed so often and when it does happen, there is enough spare CPU left for the garbage collection to not get the server too behind. Right now I think the server can't even keep up without garbage collection so any time spent doing garbage collection means the server gets behind.

I decided to explore garbage collector options and I've found that using the G1 garbage collector (using the flag -XX:+UseG1GC) makes the problem significantly better.

I think garbage collection is the source of the terrible performance and very long lags. What's probably happening is that the server now requires more CPU and memory than it used to require. When a garbage collection happens it takes so long that the server gets behind. When the garbage collection finishes the server detects that it's behind and tries to "catch up" by skipping ticks. This in turn probably causes another garbage collection and so the server gets stuck in an vicious loop where garbage collections cause the server to do work that causes another garbage collection and so forth. Instead of getting useful work done it spend almost all of its time in garbage collection cycles.

The G1 garbage collector is designed to spread the garbage collection work out and not cause long delays which seems to prevent the vicious garbage collection cycle from killing performance.

With G1 now my server just runs slowly with lag at all times. It is now playable, but just barely.

I doubt it's just one thing that needs fixing. I suspect a lot of effort needs to go into using less memory and probably also less CPU so that garbage collection isn't needed so often and when it does happen, there is enough spare CPU left for the garbage collection to not get the server too behind. Right now I think the server can't even keep up without garbage collection so any time spent doing garbage collection means the server gets behind.

I always launch with nogui. My script runs:

java -Xms1280M -Xmx1280M -jar minecraft_server.jar nogui

The previous comments mentioning turning off mob spawning have no effect on my server. It lags just as much on peaceful and with mob spawning off.

I was wondering if the performance change was due to some syscall latency like a change in disk reads or something. I used strace to track system calls and track the time spent in them with the following command:

strace -tt -T -ff -o traces/trace_start java -Xms1280M -Xmx1280M -jar minecraft_server.jar nogui

I then wrote a script to process the results. There is no meaningful difference in the syscall activity between 1.7.10 and 1.8. Here is 1.7.10:

$ cat ~/backup_1.7.10_world/current_world/traces/* | ~/current_world/sort_strace.pl | head -n 10
func: futex; total time: 2135.280352 (82.832%); count: 37192 (6.159%); median time: 0.000081; average time: 0.05741236
func: read; total time: 228.799741 (8.876%); count: 236153 (39.105%); median time: 0.000020; average time: 0.00096886
func: epoll_wait; total time: 181.589652 (7.044%); count: 184 (0.030%); median time: 1.001637; average time: 0.98690028
func: clock_gettime; total time: 23.074748 (0.895%); count: 265244 (43.922%); median time: 0.000018; average time: 0.00008699
func: gettimeofday; total time: 4.432616 (0.172%); count: 18010 (2.982%); median time: 0.000019; average time: 0.00024612
func: lseek; total time: 1.448669 (0.056%); count: 10587 (1.753%); median time: 0.000019; average time: 0.00013683
func: sched_yield; total time: 1.058822 (0.041%); count: 19273 (3.191%); median time: 0.000017; average time: 0.00005494
func: write; total time: 0.418092 (0.016%); count: 8584 (1.421%); median time: 0.000022; average time: 0.00004871
func: open; total time: 0.389138 (0.015%); count: 1260 (0.209%); median time: 0.000025; average time: 0.00030884
func: mprotect; total time: 0.345825 (0.013%); count: 3010 (0.498%); median time: 0.000026; average time: 0.00011489

And here is the syscall activity for 1.8:
$ cat traces/* | ~/current_world/sort_strace.pl | head -n 10
func: futex; total time: 2794.826033 (84.472%); count: 51580 (7.825%); median time: 0.000079; average time: 0.05418430
func: read; total time: 266.182423 (8.045%); count: 232272 (35.237%); median time: 0.000020; average time: 0.00114599
func: epoll_wait; total time: 206.683876 (6.247%); count: 211 (0.032%); median time: 1.002230; average time: 0.97954444
func: clock_gettime; total time: 28.869215 (0.873%); count: 302261 (45.855%); median time: 0.000018; average time: 0.00009551
func: gettimeofday; total time: 4.980315 (0.151%); count: 17446 (2.647%); median time: 0.000019; average time: 0.00028547
func: madvise; total time: 2.402947 (0.073%); count: 1430 (0.217%); median time: 0.000052; average time: 0.00168038
func: sched_yield; total time: 1.280591 (0.039%); count: 30288 (4.595%); median time: 0.000017; average time: 0.00004228
func: open; total time: 1.029462 (0.031%); count: 973 (0.148%); median time: 0.000028; average time: 0.00105803
func: lseek; total time: 0.730414 (0.022%); count: 10620 (1.611%); median time: 0.000018; average time: 0.00006878
func: mprotect; total time: 0.554859 (0.017%); count: 2083 (0.316%); median time: 0.000025; average time: 0.00026637

I ran each server until the world was fully loaded and the CPU usage dropped down to idle levels.

So the performance issue doesn't appear to be the result of disk reads or other OS-dependent activities.

EDIT: Yuck, the formatting got destroyed when I pasted it into Jira. Sorry. I will attach a screenshot.

If I leave the watchdog timer at the default 60 seconds sometimes my server will kill itself in a few minutes, before any player has attempted to join. I've also noticed that upon starting, the 1.8 server sits at 100% CPU for much, much longer than the 1.7.10 server did.

No, this is a report saying the server doesn't function even with the watchdog timer disabled (max-tick-time=-1).

That is, the report is not about the server crashing due to the watchdog, the report is the server performance change in 1.8

@Sonic No, it's not a dupe. Read the whole report please.

My 1.8 (release version) server is experiencing the same issue. The 1.7.10 release ran great but now the same world in 1.8 is unplayable. The server can't keep up and the console is flooded with:

[05:16:19] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 18861ms behind, skipping 377 tick(s)
[05:16:21] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 2176ms behind, skipping 43 tick(s)
[05:17:06] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 26332ms behind, skipping 526 tick(s)
[05:17:08] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 2384ms behind, skipping 47 tick(s)
[05:18:00] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 32211ms behind, skipping 644 tick(s)
[05:18:02] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 2818ms behind, skipping 56 tick(s)
[05:19:08] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 39414ms behind, skipping 788 tick(s)
[05:19:10] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 2278ms behind, skipping 45 tick(s)
[05:20:17] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 39530ms behind, skipping 790 tick(s)
[05:20:19] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 2267ms behind, skipping 45 tick(s)
[05:21:07] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 29640ms behind, skipping 592 tick(s)
[05:21:09] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 2595ms behind, skipping 51 tick(s)
[05:21:54] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 25908ms behind, skipping 518 tick(s)
[05:21:56] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 2195ms behind, skipping 43 tick(s)

My 1.8 (release version) server is experiencing the same issue. The 1.7.10 release ran great but now the same world in 1.8 is unplayable. The server can't keep up and the console is flooded with:

[05:16:19] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 18861ms behind, skipping 377 tick(s)
[05:16:21] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 2176ms behind, skipping 43 tick(s)
[05:17:06] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 26332ms behind, skipping 526 tick(s)
[05:17:08] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 2384ms behind, skipping 47 tick(s)
[05:18:00] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 32211ms behind, skipping 644 tick(s)
[05:18:02] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 2818ms behind, skipping 56 tick(s)
[05:19:08] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 39414ms behind, skipping 788 tick(s)
[05:19:10] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 2278ms behind, skipping 45 tick(s)
[05:20:17] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 39530ms behind, skipping 790 tick(s)
[05:20:19] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 2267ms behind, skipping 45 tick(s)
[05:21:07] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 29640ms behind, skipping 592 tick(s)
[05:21:09] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 2595ms behind, skipping 51 tick(s)
[05:21:54] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 25908ms behind, skipping 518 tick(s)
[05:21:56] [Server thread/WARN]: Can't keep up! Did the system time change, or is the server overloaded? Running 2195ms behind, skipping 43 tick(s)

I reported what sounds like the same issue in MC-56743

Yes I saw https://twitter.com/Dinnerbone/status/491953005776748544 this morning "We'll release a 'b' snapshot soon to fix the chunk-vanishing issue (and some crashes)". I will test and report back in a day or two.

figured out how to add myself with the new UUID lol just used the server commands in the server console to add myself and others on my server as OP and whitelist... works perfect now for ONLINE... I'm not sure about offline

I have the same issue as well. I've tried Player Names, UUID, and IP addresses... nothing. Do I have to put inside those new brackets that show up if you do a clean server install, or what?

Hi Grum, please ignore how rude Alex was.

These days, most programming languages are using SipHash (Google it) for their hashtables / associate arrays / dictionaries. It's secure against even malicious manipulation.

Since your input to the hash is very small (an int) this is overkill. Instead I'd suggest a simple affine transform on X and Z and then XOR them together. If look up "Linear congruential generator" the Xn = (A* X(n-1) + C) mod M transform works well, especially if you choose A and C so that the transform is a bijective mapping. You can use the "Numerical Recipies" constants of A = 1664525; C = 1013904223; M = 2^32

I'd suggest XORing X and Y before the transform, and then XORing the transformed results:

hash = ((1664525 * (X ^ 0xdeadbeef) + 1013904223) & 0xFFFFFFFF) ^ ((1664525 * (Y ^ 0xbabecafe) + 1013904223) & 0xFFFFFFFF)

You can truncate this hash to however many bits you actually need for your table.

It's not clear if this really is "works as intended" / "won't fix". It's entirely likely that gravel is just a placeholder until they figure out what they want to do with the ocean floor. I think this should be left open until a dev chimes in. The worst that can happen is a dev has to spend 10 second closing the bug.

This is still easily reproducible in the latest snapshot (13w38c) in the same location as my screenshot and previous tests. "Advanced OpenGL" still toggles it. The other changes in rendering don't seem to have any effect.