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 0b9e689d57705965721b5c55bc45d36657f360e4..dee00aac05f1acf050f05d4db557a08dd0f301c8 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/net/minecraft/CrashReport.java b/src/main/java/net/minecraft/CrashReport.java index d0fdb9ce57b22a1f582cddec9afcc35b75d58cc6..9b7a51890c667601b195ff15b2bf0d6c76c7f19f 100644 --- a/src/main/java/net/minecraft/CrashReport.java +++ b/src/main/java/net/minecraft/CrashReport.java @@ -257,6 +257,7 @@ public class CrashReport { } public static CrashReport a(Throwable throwable, String s) { + if (throwable instanceof ThreadDeath) com.destroystokyo.paper.util.SneakyThrow.sneaky(throwable); // Paper while (throwable instanceof CompletionException && throwable.getCause() != null) { throwable = throwable.getCause(); } diff --git a/src/main/java/net/minecraft/SystemUtils.java b/src/main/java/net/minecraft/SystemUtils.java index 397194b3e90c9df39cfae17b401c7ac891b0dbb7..61b4c42e95994343772a91640b243b8e8224e09b 100644 --- a/src/main/java/net/minecraft/SystemUtils.java +++ b/src/main/java/net/minecraft/SystemUtils.java @@ -130,6 +130,7 @@ public class SystemUtils { return SystemUtils.f; } + public static void shutdownServerThreadPool() { h(); } // Paper - OBFHELPER public static void h() { a(SystemUtils.e); a(SystemUtils.f); diff --git a/src/main/java/net/minecraft/server/MinecraftServer.java b/src/main/java/net/minecraft/server/MinecraftServer.java index 88679e7fa760e242c81466f90950d1f6f088e294..2ab3b3d42e08f7594361ab3a7354486aff0878ab 100644 --- a/src/main/java/net/minecraft/server/MinecraftServer.java +++ b/src/main/java/net/minecraft/server/MinecraftServer.java @@ -268,7 +268,7 @@ public abstract class MinecraftServer extends IAsyncTaskHandlerReentrant S a(Function function) { AtomicReference atomicreference = new AtomicReference(); Thread thread = new Thread(() -> { @@ -840,6 +842,7 @@ public abstract class MinecraftServer extends IAsyncTaskHandlerReentrant { + world.tickingEntities = false; + }); + } + // Paper end // CraftBukkit end MinecraftServer.LOGGER.info("Stopping server"); MinecraftTimings.stopServer(); // Paper @@ -919,7 +939,18 @@ public abstract class MinecraftServer extends IAsyncTaskHandlerReentrant {}; + } + // Paper end return new TickTask(this.ticks, runnable); } @@ -1410,6 +1466,7 @@ public abstract class MinecraftServer extends IAsyncTaskHandlerReentrant { CompletableFuture completablefuture; diff --git a/src/main/java/net/minecraft/server/level/WorldServer.java b/src/main/java/net/minecraft/server/level/WorldServer.java index c69eef0d523fc75dce2c2606f3e447591c7cf6dc..da3614a4a59884e7cbc8758cfdad9698eb15424f 100644 --- a/src/main/java/net/minecraft/server/level/WorldServer.java +++ b/src/main/java/net/minecraft/server/level/WorldServer.java @@ -177,7 +177,7 @@ public class WorldServer extends World implements GeneratorAccessSeed { private final Queue entitiesToAdd = Queues.newArrayDeque(); public final List players = Lists.newArrayList(); // Paper - private -> public public final ChunkProviderServer chunkProvider; // Paper - public - boolean tickingEntities; + public boolean tickingEntities; // Paper - expose for watchdog // Paper start List afterEntityTickingTasks = Lists.newArrayList(); public void doIfNotEntityTicking(java.lang.Runnable run) { diff --git a/src/main/java/net/minecraft/server/players/PlayerList.java b/src/main/java/net/minecraft/server/players/PlayerList.java index d6a6321e936ce803a3e52e7420ba2bcd096f4649..f58dd78e5984ace42ccd6121a5836fed29b82af0 100644 --- a/src/main/java/net/minecraft/server/players/PlayerList.java +++ b/src/main/java/net/minecraft/server/players/PlayerList.java @@ -507,7 +507,7 @@ public abstract class PlayerList { cserver.getPluginManager().callEvent(playerQuitEvent); entityplayer.getBukkitEntity().disconnect(playerQuitEvent.getQuitMessage()); - entityplayer.playerTick(); // SPIGOT-924 + if (server.isMainThread()) entityplayer.playerTick(); // SPIGOT-924 // Paper - don't tick during emergency shutdowns (Watchdog) // CraftBukkit end // Paper start - Remove from collideRule team if needed diff --git a/src/main/java/net/minecraft/util/thread/IAsyncTaskHandler.java b/src/main/java/net/minecraft/util/thread/IAsyncTaskHandler.java index ca23ca14d8011fc8daa7e20f2eaa550a8ff92c53..158ea6d77698d62ba795aff6c061a80652e42e03 100644 --- a/src/main/java/net/minecraft/util/thread/IAsyncTaskHandler.java +++ b/src/main/java/net/minecraft/util/thread/IAsyncTaskHandler.java @@ -135,6 +135,7 @@ public abstract class IAsyncTaskHandler implements Mailbox asList(String... params) { return Arrays.asList(params); diff --git a/src/main/java/org/bukkit/craftbukkit/util/ServerShutdownThread.java b/src/main/java/org/bukkit/craftbukkit/util/ServerShutdownThread.java index 449e99d1b673870ed6892f6ab2c715a2db35c35d..c7ed6e0f8a989cec97700df2b15198c9c481c549 100644 --- a/src/main/java/org/bukkit/craftbukkit/util/ServerShutdownThread.java +++ b/src/main/java/org/bukkit/craftbukkit/util/ServerShutdownThread.java @@ -12,12 +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 org.spigotmc.AsyncCatcher.shuttingDown = true; // Paper + server.forceTicks = true; server.close(); + while (!server.hasFullyShutdown) Thread.sleep(1000); + } catch (InterruptedException e) { + e.printStackTrace(); + // Paper end } finally { 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 b45d7e5c108c7a8541fcbc9ad92d1a79a94746a1..6a408dc9286a60c3ca7830f88171919fb0fe6363 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) { 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 58e50bf0fb0f309227e1f4c1f6bb11c01d8e08d3..30a665c090f419985e1d0f49df9e8d110c83943a 100644 --- a/src/main/java/org/spigotmc/WatchdogThread.java +++ b/src/main/java/org/spigotmc/WatchdogThread.java @@ -13,6 +13,7 @@ import org.bukkit.Bukkit; public class WatchdogThread extends Thread { + public static final boolean DISABLE_WATCHDOG = Boolean.getBoolean("disable.watchdog"); // Paper private static WatchdogThread instance; private long timeoutTime; private boolean restart; @@ -41,6 +42,7 @@ public class WatchdogThread extends Thread { if ( instance == null ) { + if (timeoutTime <= 0) timeoutTime = 300; // Paper instance = new WatchdogThread( timeoutTime * 1000L, restart ); instance.start(); } else @@ -71,12 +73,13 @@ public class WatchdogThread extends Thread // Paper start Logger log = Bukkit.getServer().getLogger(); long currentTime = monotonicMillis(); - if ( lastTick != 0 && timeoutTime > 0 && currentTime > lastTick + earlyWarningEvery && !Boolean.getBoolean("disable.watchdog") ) + MinecraftServer server = MinecraftServer.getServer(); + if (lastTick != 0 && timeoutTime > 0 && hasStarted && (!server.isRunning() || (currentTime > lastTick + earlyWarningEvery && !DISABLE_WATCHDOG) )) { - 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 @@ -118,7 +121,7 @@ public class WatchdogThread extends Thread log.log( Level.SEVERE, "------------------------------" ); log.log( Level.SEVERE, "Server thread dump (Look for plugins here before reporting to Paper!):" ); // Paper ChunkTaskManager.dumpAllChunkLoadInfo(); // Paper - dumpThread( ManagementFactory.getThreadMXBean().getThreadInfo( MinecraftServer.getServer().serverThread.getId(), Integer.MAX_VALUE ), log ); + dumpThread( ManagementFactory.getThreadMXBean().getThreadInfo( server.serverThread.getId(), Integer.MAX_VALUE ), log ); log.log( Level.SEVERE, "------------------------------" ); // // Paper start - Only print full dump on long timeouts @@ -139,9 +142,24 @@ public class WatchdogThread extends Thread if ( isLongTimeout ) { - if ( restart && !MinecraftServer.getServer().hasStopped() ) + if ( !server.hasStopped() ) { - RestartCommand.restart(); + AsyncCatcher.enabled = false; // Disable async catcher incase it interferes with us + AsyncCatcher.shuttingDown = true; + server.forceTicks = true; + if (restart) { + RestartCommand.addShutdownHook( SpigotConfig.restartScript ); + } + // try one last chance to safe shutdown on main incase it 'comes back' + 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 476f4a5cbe664ddd05474cb88553018bd334a5b8..8af159abd3d0cc94cf155fec5b384c42f69551bf 100644 --- a/src/main/resources/log4j2.xml +++ b/src/main/resources/log4j2.xml @@ -1,5 +1,5 @@ - +