From 0000000000000000000000000000000000000000 Mon Sep 17 00:00:00 2001 From: Aikar Date: Sun, 12 Apr 2020 15:50:48 -0400 Subject: [PATCH] Improved Watchdog Support Forced Watchdog Crash support and Improve Async Shutdown If the request to shut down the server is received while we are in a watchdog hang, immediately treat it as a crash and begin the shutdown process. Shutdown process is now improved to also shutdown cleanly when not using restart scripts either. If a server is deadlocked, a server owner can send SIGUP (or any other signal the JVM understands to shut down as it currently does) and the watchdog will no longer need to wait until the full timeout, allowing you to trigger a close process and try to shut the server down gracefully, saving player and world data. Previously there was no way to trigger this outside of waiting for a full watchdog timeout, which may be set to a really long time... Additionally, fix everything to do with shutting the server down asynchronously. Previously, nearly everything about the process was fragile and unsafe. Main might not have actually been frozen, and might still be manipulating state. Or, some reuest might ask main to do something in the shutdown but main is dead. Or worse, other things might start closing down items such as the Console or Thread Pool before we are fully shutdown. This change tries to resolve all of these issues by moving everything into the stop method and guaranteeing only one thread is stopping the server. We then issue Thread Death to the main thread of another thread initiates the stop process. We have to ensure Thread Death propagates correctly though to stop main completely. This is to ensure that if main isn't truely stuck, it's not manipulating state we are trying to save. This also moves all plugins who register "delayed init" tasks to occur just before "Done" so they are properly accounted for and wont trip watchdog on init. diff --git a/src/main/java/com/destroystokyo/paper/Metrics.java b/src/main/java/com/destroystokyo/paper/Metrics.java index 6aaed8e8bf8c721fc834da5c76ac72a4c3e92458..4b002e8b75d117b726b0de274a76d3596fce015b 100644 --- a/src/main/java/com/destroystokyo/paper/Metrics.java +++ b/src/main/java/com/destroystokyo/paper/Metrics.java @@ -92,7 +92,12 @@ public class Metrics { * Starts the Scheduler which submits our data every 30 minutes. */ private void startSubmitting() { - final Runnable submitTask = this::submitData; + final Runnable submitTask = () -> { + if (MinecraftServer.getServer().hasStopped()) { + return; + } + submitData(); + }; // Many servers tend to restart at a fixed time at xx:00 which causes an uneven distribution of requests on the // bStats backend. To circumvent this problem, we introduce some randomness into the initial and second delay. diff --git a/src/main/java/io/papermc/paper/util/LogManagerShutdownThread.java b/src/main/java/io/papermc/paper/util/LogManagerShutdownThread.java new file mode 100644 index 0000000000000000000000000000000000000000..183e141d0c13190c6905dc4510d891992afef878 --- /dev/null +++ b/src/main/java/io/papermc/paper/util/LogManagerShutdownThread.java @@ -0,0 +1,26 @@ +package io.papermc.paper.util; + +public class LogManagerShutdownThread extends Thread { + + static LogManagerShutdownThread INSTANCE = new LogManagerShutdownThread(); + public static final void hook() { + if (INSTANCE == null) { + throw new IllegalStateException("Cannot re-hook after being unhooked"); + } + Runtime.getRuntime().addShutdownHook(INSTANCE); + } + + public static final void unhook() { + Runtime.getRuntime().removeShutdownHook(INSTANCE); + INSTANCE = null; + } + + private LogManagerShutdownThread() { + super("Log4j2 Shutdown Thread"); + } + + @Override + public void run() { + org.apache.logging.log4j.LogManager.shutdown(); + } +} diff --git a/src/main/java/net/minecraft/CrashReport.java b/src/main/java/net/minecraft/CrashReport.java index 589a8bf75be6ccc59f1e5dd5d8d9afed41c4772d..b24265573fdef5d9a964bcd76146f34542c420cf 100644 --- a/src/main/java/net/minecraft/CrashReport.java +++ b/src/main/java/net/minecraft/CrashReport.java @@ -237,6 +237,7 @@ public class CrashReport { } public static CrashReport forThrowable(Throwable cause, String title) { + if (cause instanceof ThreadDeath) com.destroystokyo.paper.util.SneakyThrow.sneaky(cause); // Paper while (cause instanceof CompletionException && cause.getCause() != null) { cause = cause.getCause(); } diff --git a/src/main/java/net/minecraft/server/Main.java b/src/main/java/net/minecraft/server/Main.java index e114e687f2f4503546687fd6792226a643af8793..90ca25c4aaf92a5639839a7cdaee2ffcdb75efa7 100644 --- a/src/main/java/net/minecraft/server/Main.java +++ b/src/main/java/net/minecraft/server/Main.java @@ -77,6 +77,7 @@ public class Main { @DontObfuscate public static void main(final OptionSet optionset) { // CraftBukkit - replaces main(String[] astring) + io.papermc.paper.util.LogManagerShutdownThread.hook(); // Paper SharedConstants.tryDetectVersion(); /* CraftBukkit start - Replace everything OptionParser optionparser = new OptionParser(); diff --git a/src/main/java/net/minecraft/server/MinecraftServer.java b/src/main/java/net/minecraft/server/MinecraftServer.java index e0b80b23197307d156ade8427a5227acbc45eb92..7a671772760152f26e5bb60ea2f2a7765c017c37 100644 --- a/src/main/java/net/minecraft/server/MinecraftServer.java +++ b/src/main/java/net/minecraft/server/MinecraftServer.java @@ -317,7 +317,7 @@ public abstract class MinecraftServer extends ReentrantBlockableEventLoop processQueue = new java.util.concurrent.ConcurrentLinkedQueue(); public int autosavePeriod; // Paper - don't store the vanilla dispatcher - private boolean forceTicks; + public boolean forceTicks; // Paper - Improved watchdog support // CraftBukkit end // Spigot start public static final int TPS = 20; @@ -329,6 +329,9 @@ public abstract class MinecraftServer extends ReentrantBlockableEventLoop S spin(Function serverFactory) { AtomicReference atomicreference = new AtomicReference(); Thread thread = new ca.spottedleaf.moonrise.common.util.TickThread(() -> { // Paper - rewrite chunk system @@ -503,6 +506,7 @@ public abstract class MinecraftServer extends ReentrantBlockableEventLoop {}; + } + // Paper end return new TickTask(this.tickCount, runnable); } @@ -2309,7 +2351,15 @@ public abstract class MinecraftServer extends ReentrantBlockableEventLoop implements Profiler public static boolean isNonRecoverable(Throwable exception) { return exception instanceof ReportedException reportedException ? isNonRecoverable(reportedException.getCause()) - : exception instanceof OutOfMemoryError || exception instanceof StackOverflowError; + : exception instanceof OutOfMemoryError || exception instanceof StackOverflowError || exception instanceof ThreadDeath; // Paper } } diff --git a/src/main/java/net/minecraft/world/level/Level.java b/src/main/java/net/minecraft/world/level/Level.java index 86cd6e1b8f68dd0564ee2a7c60f02d7af287af67..022de445bbbb869c38be4972c98dcf1c665539ec 100644 --- a/src/main/java/net/minecraft/world/level/Level.java +++ b/src/main/java/net/minecraft/world/level/Level.java @@ -1488,6 +1488,7 @@ public abstract class Level implements LevelAccessor, AutoCloseable, ca.spottedl try { tickConsumer.accept(entity); } catch (Throwable throwable) { + if (throwable instanceof ThreadDeath) throw throwable; // Paper // Paper start - Prevent block entity and entity crashes final String msg = String.format("Entity threw exception at %s:%s,%s,%s", entity.level().getWorld().getName(), entity.getX(), entity.getY(), entity.getZ()); MinecraftServer.LOGGER.error(msg, throwable); diff --git a/src/main/java/net/minecraft/world/level/chunk/LevelChunk.java b/src/main/java/net/minecraft/world/level/chunk/LevelChunk.java index 01cfb478764b8deb38be5692390dd9f014b8999f..4640baec5bed6c2d53cc0f8ca1d273cc115abe9b 100644 --- a/src/main/java/net/minecraft/world/level/chunk/LevelChunk.java +++ b/src/main/java/net/minecraft/world/level/chunk/LevelChunk.java @@ -1078,6 +1078,7 @@ public class LevelChunk extends ChunkAccess implements ca.spottedleaf.moonrise.p gameprofilerfiller.pop(); } catch (Throwable throwable) { + if (throwable instanceof ThreadDeath) throw throwable; // Paper // Paper start - Prevent block entity and entity crashes final String msg = String.format("BlockEntity threw exception at %s:%s,%s,%s", LevelChunk.this.getLevel().getWorld().getName(), this.getPos().getX(), this.getPos().getY(), this.getPos().getZ()); net.minecraft.server.MinecraftServer.LOGGER.error(msg, throwable); diff --git a/src/main/java/org/bukkit/craftbukkit/util/ServerShutdownThread.java b/src/main/java/org/bukkit/craftbukkit/util/ServerShutdownThread.java index c6e8441e299f477ddb22c1ce2618710763978f1a..e8e93538dfd71de86515d9405f728db1631e949a 100644 --- a/src/main/java/org/bukkit/craftbukkit/util/ServerShutdownThread.java +++ b/src/main/java/org/bukkit/craftbukkit/util/ServerShutdownThread.java @@ -12,11 +12,27 @@ public class ServerShutdownThread extends Thread { @Override public void run() { try { + // Paper start - try to shutdown on main + server.safeShutdown(false, false); + for (int i = 1000; i > 0 && !server.hasStopped(); i -= 100) { + Thread.sleep(100); + } + if (server.hasStopped()) { + while (!server.hasFullyShutdown) Thread.sleep(1000); + return; + } + // Looks stalled, close async org.spigotmc.AsyncCatcher.enabled = false; // Spigot + server.forceTicks = true; this.server.close(); + while (!server.hasFullyShutdown) Thread.sleep(1000); + } catch (InterruptedException e) { + e.printStackTrace(); + // Paper end } finally { + org.apache.logging.log4j.LogManager.shutdown(); // Paper try { - net.minecrell.terminalconsole.TerminalConsoleAppender.close(); // Paper - Use TerminalConsoleAppender + //net.minecrell.terminalconsole.TerminalConsoleAppender.close(); // Paper - Move into stop } catch (Exception e) { } } diff --git a/src/main/java/org/spigotmc/RestartCommand.java b/src/main/java/org/spigotmc/RestartCommand.java index 39e56b95aaafbcd8ebe68fdefaace83702e9510d..3ba27955548a26367a87d6b87c3c61beb299dfb9 100644 --- a/src/main/java/org/spigotmc/RestartCommand.java +++ b/src/main/java/org/spigotmc/RestartCommand.java @@ -139,7 +139,7 @@ public class RestartCommand extends Command // Paper end // Paper start - copied from above and modified to return if the hook registered - private static boolean addShutdownHook(String restartScript) + public static boolean addShutdownHook(String restartScript) // Paper { String[] split = restartScript.split( " " ); if ( split.length > 0 && new File( split[0] ).isFile() ) diff --git a/src/main/java/org/spigotmc/WatchdogThread.java b/src/main/java/org/spigotmc/WatchdogThread.java index 529df2a41dd93d6e1505053bd04032dbf0cdaa31..c9e17225bc52fe5e7b2dc0908db225a86c6e94d1 100644 --- a/src/main/java/org/spigotmc/WatchdogThread.java +++ b/src/main/java/org/spigotmc/WatchdogThread.java @@ -11,6 +11,7 @@ import org.bukkit.Bukkit; public class WatchdogThread extends ca.spottedleaf.moonrise.common.util.TickThread // Paper - rewrite chunk system { + public static final boolean DISABLE_WATCHDOG = Boolean.getBoolean("disable.watchdog"); // Paper - Improved watchdog support private static WatchdogThread instance; private long timeoutTime; private boolean restart; @@ -39,6 +40,7 @@ public class WatchdogThread extends ca.spottedleaf.moonrise.common.util.TickThre { if ( WatchdogThread.instance == null ) { + if (timeoutTime <= 0) timeoutTime = 300; // Paper WatchdogThread.instance = new WatchdogThread( timeoutTime * 1000L, restart ); WatchdogThread.instance.start(); } else @@ -70,12 +72,13 @@ public class WatchdogThread extends ca.spottedleaf.moonrise.common.util.TickThre // Paper start Logger log = Bukkit.getServer().getLogger(); long currentTime = WatchdogThread.monotonicMillis(); - if ( this.lastTick != 0 && this.timeoutTime > 0 && currentTime > this.lastTick + this.earlyWarningEvery && !Boolean.getBoolean("disable.watchdog")) // Paper - Add property to disable + MinecraftServer server = MinecraftServer.getServer(); + if ( this.lastTick != 0 && this.timeoutTime > 0 && WatchdogThread.hasStarted && (!server.isRunning() || (currentTime > this.lastTick + this.earlyWarningEvery && !DISABLE_WATCHDOG) )) // Paper - add property to disable { - boolean isLongTimeout = currentTime > lastTick + timeoutTime; + boolean isLongTimeout = currentTime > lastTick + timeoutTime || (!server.isRunning() && !server.hasStopped() && currentTime > lastTick + 1000); // Don't spam early warning dumps if ( !isLongTimeout && (earlyWarningEvery <= 0 || !hasStarted || currentTime < lastEarlyWarning + earlyWarningEvery || currentTime < lastTick + earlyWarningDelay)) continue; - if ( !isLongTimeout && MinecraftServer.getServer().hasStopped()) continue; // Don't spam early watchdog warnings during shutdown, we'll come back to this... + if ( !isLongTimeout && server.hasStopped()) continue; // Don't spam early watchdog warnings during shutdown, we'll come back to this... lastEarlyWarning = currentTime; if (isLongTimeout) { // Paper end @@ -136,9 +139,24 @@ public class WatchdogThread extends ca.spottedleaf.moonrise.common.util.TickThre if ( isLongTimeout ) { - if ( this.restart && !MinecraftServer.getServer().hasStopped() ) + if ( !server.hasStopped() ) { - RestartCommand.restart(); + AsyncCatcher.enabled = false; // Disable async catcher incase it interferes with us + server.forceTicks = true; + if (restart) { + RestartCommand.addShutdownHook( SpigotConfig.restartScript ); + } + // try one last chance to safe shutdown on main incase it 'comes back' + server.abnormalExit = true; + server.safeShutdown(false, restart); + try { + Thread.sleep(1000); + } catch (InterruptedException e) { + e.printStackTrace(); + } + if (!server.hasStopped()) { + server.close(); + } } break; } // Paper end diff --git a/src/main/resources/log4j2.xml b/src/main/resources/log4j2.xml index 637d64da9938e51a97338b9253b43889585c67bb..d2a75850af9c6ad2aca66a5f994f1b587d73eac4 100644 --- a/src/main/resources/log4j2.xml +++ b/src/main/resources/log4j2.xml @@ -1,5 +1,5 @@ - +