java.lang.Error in FML's ASMEventHandler

[davqvist]

MC 1.10.2
Forge 2254
Foamfix 0.6.1 Anarchy

A user of my modpack Age of Engineering setup a server and it crashed on startup:
https://pastebin.com/v4tfz0ff

As you can see, it crashes at a "random" time, the MT script line is fine, and it has nothing to do with Tinkers. This bug reminded another user of an error he got with another pack and removing Foamfix fixed it for him. The first user removed Foamfix and indeed this fixed it for him as well. He also tried using Lawful version which worked fine as well. Not sure if this log helps you, I just want to let you know.

[asiekierka]

Could you please try 0.6.2 beta 2?

[davqvist]

Oh there's a new version? Sorry, yes I will ask the user to try that one and report back.

[asiekierka]

Any updates?

[davqvist]

Sorry, didn't get any response. Thanks for asking again though.

[asiekierka]

In addition, this may be related to ClassCacheTweaker, in which case the only real solution is to remove it for the time being.

[asiekierka]

Could not be reproduced.

[davqvist]

Sorry for not reporting back but I had like at least 10 reports exactly like that for Age of Engineering from different people maybe even more, but I could never reproduce it myself either. But, disabling Foamfix fixed it everytime. I was pretty confident it is either a plugin or dependant on the operating systems, but there was no pattern, so I never could have given you any reasonable info. So fair enough to close it even though there cerainly is a problem.

[asiekierka]

No, "certainly is a problem" is the definition of "not fair enough to close it". If there's a problem, we're going to keep it open so someone can help track it down and find a solution (or prove it's not our fault).

[asiekierka]

@davqvist If you find the issue again, please try updating FoamFix. 0.7.0 rewrote how the ASM transforming system works and that might've influenced this.

[davqvist]

Foamfix is updated a while ago, I'm on 0.7.1

[davqvist]

Most recent crash log I found: https://pastebin.com/k54S3PxB

[asiekierka]

Thread: Server Watchdog

On dedicated servers, setting max-tick-time=0 can solve crashes related to "java.lang.Error: Watching server". Still looking into why this happens!

Try this.

[davqvist]

Okay will tell people when it comes up again. Thanks

[Barteks2x]

I'm not sure if this is similar issue, but with my mod (I'm not sure if it was with or without foamfix added to it) I'm consistently getting issues with server watchdog even when the server is running just fine with no TPS issue. I also still don't know what could cause it.

[asiekierka]

@Barteks2x I've seen this happen on a variety of setups. I have not managed to find the cause, though.

[Barteks2x]

Since I remember getting it with just my mod, I will try debugging it. I hope it also happens in dev environment.

[Barteks2x]

First, it was hard to get the server watchdog thread to not kill itself when starting the server. If starting server takes more than a minute, the thread throws IllegalArgumentException because of negative time for sleep.

But I see the issue now, and this is actually vanilla issue. The issue is in this code:

                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)", new Object[] {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.worlds[0].areAllPlayersAsleep()) {
                        this.tick();
                        i = 0L;
                    } else {
                        while (i > 50L) {
                            i -= 50L;
                            this.tick();
                        }
                    }

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

If the server tick time is more than 50ms on average for a longer amount of time, you get the Can't keep up messages. But it also means that this loop attempts to "fix" the issue by running many ticks at once before the message appears:

                        while (i > 50L) {
                            i -= 50L;
                            this.tick();
                        }

The message is shown only if the server is 2000 or more ms behind (40 or more ticks) and it's been more than 15 seconds since mast message.

But if the server is consistently lagging behind, then while the server attempts to run many ticks at once, it will get even more behind. If in that time it gets more than 60 seconds behind, which happens if it's already close to the 15 seconds behind and just about to show the next message, and the average tick time is >= 200ms (60000 / (15seconds*20TPS).

So the watchdog thread will kill the server if your average tick time is greater than 200ms (or in general timeout/(15*20))

[asiekierka]

You found it! Woah!

[Barteks2x]

Also the way I suspect foamfix may be involved:

• It either makes the server slower which is unlikely
• Or it makes the server start in less than a minute, thus making the watchdog thread not kill itself on the first tick

[asiekierka]

Both are rather unlikely. Hmm.

[Barteks2x]

By "starting the server" I mean only a specific part here: the part between initializing the MinecraftServer.currentTime field and right after net.minecraftforge.fml.common.FMLCommonHandler.instance().handleServerStarted(); is done.