Uploaded image for project: 'Minecraft: Java Edition'
  1. Minecraft: Java Edition
  2. MC-121196

Overloaded servers pointlessly wait up to 50 ms every couple ticks

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Fixed
    • Minecraft 1.13-pre6
    • Minecraft 1.12.2
    • None
    • macOS 10.13, Java: 1.8.0_74 64bit
    • Unconfirmed

      I will be writing about the code of the 1.12 server decompiled with mcp940-pre1. The same bug is still in 1.12.2, but mcp is not available for that version yet, making it a bit harder to read the decompiled code. The code is located in the method public void run() in MinecraftServer.java

      The server should try to call the tick() method every 50 ms to keep a constant 20 tps. To do that, it has to call Thread.sleep() with the right number of milliseconds so that both method calls combined take as close to 50 ms as possible.

      When the server is overloaded and can't keep up calling tick() often enough, the value of i will be some value that causes the Thread.sleep() method to be called with an unintentionally large value (at least most of the time). It should be called with a value of one, if at all, to try to keep up and not waste time.

      The reason this is happening is because when the two lines inside the inner while loop are executed more than once, which can be the case when the server is overloaded, the value of i after that while loop will be some value which is probably not 50. When that happens, the server will sleep for 50 - i milliseconds even though it is overloaded. In the worst case i could be zero and the server would sleep for 50 milliseconds.

      The suggested fix also improves on some less severe bugs and minor issues I did not yet make a bug report for. All differences to the current vanilla implementation I could think of are listed below.

      Things the suggested fix does better/different than the current vanilla code:

      • This bug is fixed.
      • The server no longer sleeps one millisecond for no apparent reason but only sleeps when it actually needs to sleep.
      • The number of skipped ticks in the log warning message is calculated correctly, the old number was two seconds to big.
      • The number of skipped ticks is rounded up so that it doesn't say that it skipped zero ticks when it is running behind for more than 2000 ms but less than 2051 ms. We need to round because the server actually skips a certain amount of time rather than a certain number of ticks.
      • One loop of while (this.serverRunning) corresponds to one tick, setting this.serverIsRunning to true every time one tick is executed, not just every couple ticks sometimes. this.currentTime is also updated more frequently. The warning messages (if there are any) are also written to the log in a more timely manner and the new code would allow an easy implementation of a tps limit when catching up after a lag spike if the developers see the need for it.
      • When a tick takes a different time to execute than the tick before it, the right time to sleep is calculated right after that tick rather than one tick later. This keeps the tickrate as stable as possible.

      Current implementation:

      this.currentTime = getCurrentTimeMillis();
long i = 0L;
this.statusResponse.setServerDescription(new TextComponentString(this.motd));
this.statusResponse.setVersion(new ServerStatusResponse.Version("1.12", 335));
this.applyServerIconToResponse(this.statusResponse);

while (this.serverRunning) {
    long k = getCurrentTimeMillis();
    long j = k - this.currentTime;

    if (j > 2000L && this.currentTime - this.timeOfLastWarning >= 15000L) {
        LOG.warn("Can't keep up! Did the system time change, or is the server overloaded? Running {}ms behind, skipping {} tick(s)", Long.valueOf(j), Long.valueOf(j / 50L));
        j = 2000L;
        this.timeOfLastWarning = this.currentTime;
    }

    if (j < 0L) {
        LOG.warn("Time ran backwards! Did the system time change?");
        j = 0L;
    }

    i += j;
    this.currentTime = k;

    if (this.worldServers[0].areAllPlayersAsleep()) {
        this.tick();
        i = 0L;
    } else {
        while (i > 50L) {
            i -= 50L;
            this.tick();
        }
    }

    Thread.sleep(Math.max(1L, 50L - i));
    this.serverIsRunning = true;
}

      Suggested fix:

      long referenceTime = getCurrentTimeMillis();
this.currentTime = referenceTime;
this.statusResponse.setServerDescription(new TextComponentString(this.motd));
this.statusResponse.setVersion(new ServerStatusResponse.Version("1.12", 335));
this.applyServerIconToResponse(this.statusResponse);

while (this.serverRunning) {
    long before = getCurrentTimeMillis();
    this.currentTime = before;
    this.tick();
    long after = getCurrentTimeMillis();
    long tickLength = after - before;
    long runningBehind = before - referenceTime;

    if (runningBehind > 2000L && after - this.timeOfLastWarning >= 15000L) {
        LOG.warn("Can\'t keep up! Did the system time change, or is the server overloaded? Running {}ms behind, skipping {} tick(s)", Long.valueOf(runningBehind), Long.valueOf((runningBehind - 2000L - 1L) / 50L + 1L));
        referenceTime = before - 2000L;
        runningBehind = 2000L;
        this.timeOfLastWarning = after;
    }

    if (tickLength < 0L || runningBehind < -50L) {
        LOG.warn("Time ran backwards! Did the system time change?");
        tickLength = 0L;
        runningBehind = 0L;
        referenceTime = before;
    }

    long sleepTime = 50L - tickLength - runningBehind;
    //if (sleepTime < 0L) {         // This piece of code is supposed so limit the tps to 25
    //    sleepTime = 0L;           // But I'm not 100% sure that it works as intended
    //    if (tickLength < 40L) {   // or if it even makes sense to do this
    //        sleepTime += 40L - tickLength;
    //    }
    //}
    if (sleepTime > 0L) {
        Thread.sleep(sleepTime);
    }
    referenceTime += 50L; // Keep track of what time it should be with the current number of executed ticks

    this.serverIsRunning = true;
}

            Unassigned Unassigned
            Luflosi Luflosi
            Votes:
            7 Vote for this issue
            Watchers:
            3 Start watching this issue

              Created:
              Updated:
              Resolved: