PaperMC/feature-patches/1061-Improved-Watchdog-Support.patch

From 0000000000000000000000000000000000000000 Mon Sep 17 00:00:00 2001
From: Aikar <aikar@aikar.co>
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/io/papermc/paper/util/LogManagerShutdownThread.java b/io/papermc/paper/util/LogManagerShutdownThread.java
new file mode 100644
index 0000000000000000000000000000000000000000..3d7df554b89cff23f64da7ad48b5e4d26ac2baf7
--- /dev/null
+++ b/io/papermc/paper/util/LogManagerShutdownThread.java
@@ -0,0 +1,29 @@
+package io.papermc.paper.util;
+
+import org.apache.logging.log4j.LogManager;
+
+public final class LogManagerShutdownThread extends Thread {
+
+    static LogManagerShutdownThread INSTANCE = new LogManagerShutdownThread();
+
+    public static void hook() {
+        if (INSTANCE == null) {
+            throw new IllegalStateException("Cannot re-hook after being unhooked");
+        }
+        Runtime.getRuntime().addShutdownHook(INSTANCE);
+    }
+
+    public static void unhook() {
+        Runtime.getRuntime().removeShutdownHook(INSTANCE);
+        INSTANCE = null;
+    }
+
+    private LogManagerShutdownThread() {
+        super("Log4j2 Shutdown Thread");
+    }
+
+    @Override
+    public void run() {
+        LogManager.shutdown();
+    }
+}
diff --git a/net/minecraft/CrashReport.java b/net/minecraft/CrashReport.java
index 3e0e88afcf010d9a3d46e48bca5cbdf98fe97544..8bd7999c17c8772451f873966f8c90969aee1482 100644
--- a/net/minecraft/CrashReport.java
+++ b/net/minecraft/CrashReport.java
@@ -205,6 +205,7 @@ public class CrashReport {
     }
 
     public static CrashReport forThrowable(Throwable cause, String description) {
+        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/net/minecraft/server/Main.java b/net/minecraft/server/Main.java
index 4437283a5d157eede121b98be0112c1067eded5e..fc9ec242743f755a1f0c9ec6bccd11c82375d655 100644
--- a/net/minecraft/server/Main.java
+++ b/net/minecraft/server/Main.java
@@ -68,6 +68,7 @@ public class Main {
     )
     @DontObfuscate
     public static void main(final OptionSet optionSet) { // CraftBukkit - replaces main(String[] args)
+        io.papermc.paper.util.LogManagerShutdownThread.hook(); // Paper
         SharedConstants.tryDetectVersion();
         /* CraftBukkit start - Replace everything
         OptionParser optionParser = new OptionParser();
diff --git a/net/minecraft/server/MinecraftServer.java b/net/minecraft/server/MinecraftServer.java
index 22dc6bec58702762e4a31415f9aed2df2b3ad0d6..73704871594ed7372d2b9dc332051cae741beb75 100644
--- a/net/minecraft/server/MinecraftServer.java
+++ b/net/minecraft/server/MinecraftServer.java
@@ -302,6 +302,8 @@ public abstract class MinecraftServer extends ReentrantBlockableEventLoop<TickTa
     public boolean isIteratingOverLevels = false; // Paper - Throw exception on world create while being ticked
     private final Set<String> pluginsBlockingSleep = new java.util.HashSet<>(); // Paper - API to allow/disallow tick sleeping
     public static final long SERVER_INIT = System.nanoTime(); // Paper - Lag compensation
+    public volatile Thread shutdownThread; // Paper
+    public volatile boolean abnormalExit; // Paper
 
     public static <S extends MinecraftServer> S spin(Function<Thread, S> threadFunction) {
         ca.spottedleaf.dataconverter.minecraft.datatypes.MCTypeRegistry.init(); // Paper - rewrite data converter system
@@ -395,6 +397,7 @@ public abstract class MinecraftServer extends ReentrantBlockableEventLoop<TickTa
         }
         */
         // Paper end
+        io.papermc.paper.util.LogManagerShutdownThread.unhook(); // Paper
         Runtime.getRuntime().addShutdownHook(new org.bukkit.craftbukkit.util.ServerShutdownThread(this));
         // CraftBukkit end
         this.paperConfigurations = services.paperConfigurations(); // Paper - add paper configuration files
@@ -879,6 +882,7 @@ public abstract class MinecraftServer extends ReentrantBlockableEventLoop<TickTa
     // CraftBukkit start
     private boolean hasStopped = false;
     private boolean hasLoggedStop = false; // Paper - Debugging
+    public volatile boolean hasFullyShutdown = false; // Paper
     private final Object stopLock = new Object();
     public final boolean hasStopped() {
         synchronized (this.stopLock) {
@@ -894,6 +898,10 @@ public abstract class MinecraftServer extends ReentrantBlockableEventLoop<TickTa
             this.hasStopped = true;
         }
         if (!hasLoggedStop && isDebugging()) io.papermc.paper.util.TraceUtil.dumpTraceForThread("Server stopped"); // Paper - Debugging
+        // Paper start - kill main thread, and kill it hard
+        shutdownThread = Thread.currentThread();
+        org.spigotmc.WatchdogThread.doStop(); // Paper
+        // Paper end
         // CraftBukkit end
         if (this.metricsRecorder.isRecording()) {
             this.cancelRecordingMetrics();
@@ -966,6 +974,15 @@ public abstract class MinecraftServer extends ReentrantBlockableEventLoop<TickTa
             this.getProfileCache().save(false); // Paper - Perf: Async GameProfileCache saving
         }
         // Spigot end
+        // Paper start - Improved watchdog support - move final shutdown items here
+        Util.shutdownExecutors();
+        try {
+            net.minecrell.terminalconsole.TerminalConsoleAppender.close(); // Paper - Use TerminalConsoleAppender
+        } catch (final Exception ignored) {
+        }
+        io.papermc.paper.log.CustomLogManager.forceReset(); // Paper - Reset loggers after shutdown
+        this.onServerExit();
+        // Paper end - Improved watchdog support - move final shutdown items here
     }
 
     public String getLocalIp() {
@@ -1058,6 +1075,7 @@ public abstract class MinecraftServer extends ReentrantBlockableEventLoop<TickTa
 
     protected void runServer() {
         try {
+            long serverStartTime = Util.getNanos(); // Paper
             if (!this.initServer()) {
                 throw new IllegalStateException("Failed to initialize server");
             }
@@ -1068,6 +1086,17 @@ public abstract class MinecraftServer extends ReentrantBlockableEventLoop<TickTa
 
             this.server.spark.enableBeforePlugins(); // Paper - spark
             // Spigot start
+            // Paper start - Improved Watchdog Support
+            LOGGER.info("Running delayed init tasks");
+            this.server.getScheduler().mainThreadHeartbeat(); // run all 1 tick delay tasks during init,
+            // this is going to be the first thing the tick process does anyways, so move done and run it after
+            // everything is init before watchdog tick.
+            // anything at 3+ won't be caught here but also will trip watchdog....
+            // tasks are default scheduled at -1 + delay, and first tick will tick at 1
+            final long actualDoneTimeMs = System.currentTimeMillis() - org.bukkit.craftbukkit.Main.BOOT_TIME.toEpochMilli(); // Paper - Add total time
+            LOGGER.info("Done ({})! For help, type \"help\"", String.format(java.util.Locale.ROOT, "%.3fs", actualDoneTimeMs / 1000.00D)); // Paper - Add total time
+            org.spigotmc.WatchdogThread.tick();
+            // Paper end - Improved Watchdog Support
             org.spigotmc.WatchdogThread.hasStarted = true; // Paper
             Arrays.fill( this.recentTps, 20 );
             // Paper start - further improve server tick loop
@@ -1157,6 +1186,12 @@ public abstract class MinecraftServer extends ReentrantBlockableEventLoop<TickTa
                 JvmProfiler.INSTANCE.onServerTick(this.smoothedTickTimeMillis);
             }
         } catch (Throwable var69) {
+            // Paper start
+            if (var69 instanceof ThreadDeath) {
+                MinecraftServer.LOGGER.error("Main thread terminated by WatchDog due to hard crash", var69);
+                return;
+            }
+            // Paper end
             LOGGER.error("Encountered an unexpected exception", var69);
             CrashReport crashReport = constructOrExtractCrashReport(var69);
             this.fillSystemReport(crashReport.getSystemReport());
@@ -1179,15 +1214,15 @@ public abstract class MinecraftServer extends ReentrantBlockableEventLoop<TickTa
                     this.services.profileCache().clearExecutor();
                 }
 
-                org.spigotmc.WatchdogThread.doStop(); // Spigot
+                //org.spigotmc.WatchdogThread.doStop(); // Spigot // Paper - move into stop
                 // CraftBukkit start - Restore terminal to original settings
                 try {
-                    net.minecrell.terminalconsole.TerminalConsoleAppender.close(); // Paper - Use TerminalConsoleAppender
+                    //net.minecrell.terminalconsole.TerminalConsoleAppender.close(); // Paper - Move into stop
                 } catch (Exception ignored) {
                 }
                 // CraftBukkit end
-                io.papermc.paper.log.CustomLogManager.forceReset(); // Paper - Reset loggers after shutdown
-                this.onServerExit();
+                //io.papermc.paper.log.CustomLogManager.forceReset(); // Paper - Reset loggers after shutdown
+                //this.onServerExit(); // Paper - moved into stop
             }
         }
     }
@@ -1291,6 +1326,12 @@ public abstract class MinecraftServer extends ReentrantBlockableEventLoop<TickTa
 
     @Override
     public TickTask wrapRunnable(Runnable runnable) {
+        // Paper start - anything that does try to post to main during watchdog crash, run on watchdog
+        if (this.hasStopped && Thread.currentThread().equals(shutdownThread)) {
+            runnable.run();
+            runnable = () -> {};
+        }
+        // Paper end
         return new TickTask(this.tickCount, runnable);
     }
 
@@ -2087,7 +2128,15 @@ public abstract class MinecraftServer extends ReentrantBlockableEventLoop<TickTa
                     this.resources.managers.updateStaticRegistryTags();
                     this.resources.managers.getRecipeManager().finalizeRecipeLoading(this.worldData.enabledFeatures());
                     this.potionBrewing = this.potionBrewing.reload(this.worldData.enabledFeatures()); // Paper - Custom Potion Mixes
-                    this.getPlayerList().saveAll();
+                    // Paper start
+                    if (Thread.currentThread() != this.serverThread) {
+                        return;
+                    }
+                    // this.getPlayerList().saveAll(); // Paper - we don't need to save everything, just advancements // TODO Move this to a different patch
+                    for (ServerPlayer player : this.getPlayerList().getPlayers()) {
+                        player.getAdvancements().save();
+                    }
+                    // Paper end
                     this.getPlayerList().reloadResources();
                     this.functionManager.replaceLibrary(this.resources.managers.getFunctionLibrary());
                     this.structureTemplateManager.onResourceManagerReload(this.resources.resourceManager);
diff --git a/net/minecraft/server/dedicated/DedicatedServer.java b/net/minecraft/server/dedicated/DedicatedServer.java
index 118f4ebb617d304e9a1cac2f9a853dc219a42456..ef39268caa59836506928582e88bc81e9fb22e88 100644
--- a/net/minecraft/server/dedicated/DedicatedServer.java
+++ b/net/minecraft/server/dedicated/DedicatedServer.java
@@ -322,7 +322,7 @@ public class DedicatedServer extends MinecraftServer implements ServerInterface
             this.loadLevel(this.storageSource.getLevelId()); // CraftBukkit
             long l = Util.getNanos() - nanos;
             String string = String.format(Locale.ROOT, "%.3fs", l / 1.0E9);
-            LOGGER.info("Done ({})! For help, type \"help\"", string);
+            LOGGER.info("Done preparing level \"{}\" ({})", this.getLevelIdName(), string); // Paper - clarify startup log messages & add total time
             if (properties.announcePlayerAchievements != null) {
                 this.getGameRules().getRule(GameRules.RULE_ANNOUNCE_ADVANCEMENTS).set(properties.announcePlayerAchievements, this.overworld()); // CraftBukkit - per-world
             }
@@ -419,7 +419,7 @@ public class DedicatedServer extends MinecraftServer implements ServerInterface
         }
 
         this.hasFullyShutdown = true; // Paper - Improved watchdog support
-        System.exit(0); // CraftBukkit
+        System.exit(this.abnormalExit ? 70 : 0); // CraftBukkit // Paper
     }
 
     @Override
@@ -727,7 +727,7 @@ public class DedicatedServer extends MinecraftServer implements ServerInterface
     @Override
     public void stopServer() {
         super.stopServer();
-        Util.shutdownExecutors();
+        //Util.shutdownExecutors(); // Paper - moved into super
         SkullBlockEntity.clear();
     }
 
diff --git a/net/minecraft/server/players/PlayerList.java b/net/minecraft/server/players/PlayerList.java
index d227714de0fe13544779fae6cf0e9ff6af5469c7..393bd2ec0962d3870f5b4cb74200e5467b50cdb8 100644
--- a/net/minecraft/server/players/PlayerList.java
+++ b/net/minecraft/server/players/PlayerList.java
@@ -513,7 +513,7 @@ public abstract class PlayerList {
         this.cserver.getPluginManager().callEvent(playerQuitEvent);
         player.getBukkitEntity().disconnect(playerQuitEvent.getQuitMessage());
 
-        player.doTick(); // SPIGOT-924
+        if (this.server.isSameThread()) player.doTick(); // SPIGOT-924 // Paper - don't tick during emergency shutdowns (Watchdog)
         // CraftBukkit end
 
         // Paper start - Configurable player collision; Remove from collideRule team if needed
diff --git a/net/minecraft/util/thread/BlockableEventLoop.java b/net/minecraft/util/thread/BlockableEventLoop.java
index 186c1b2e3599770385150eb7acdcd890aa5835eb..bfea9a2ae5e0bd5dae2873f715d192dfcbe97ee5 100644
--- a/net/minecraft/util/thread/BlockableEventLoop.java
+++ b/net/minecraft/util/thread/BlockableEventLoop.java
@@ -169,6 +169,6 @@ public abstract class BlockableEventLoop<R extends Runnable> implements Profiler
     public static boolean isNonRecoverable(Throwable error) {
         return error instanceof ReportedException reportedException
             ? isNonRecoverable(reportedException.getCause())
-            : error instanceof OutOfMemoryError || error instanceof StackOverflowError;
+            : error instanceof OutOfMemoryError || error instanceof StackOverflowError || error instanceof ThreadDeath; // Paper
     }
 }
diff --git a/net/minecraft/world/level/Level.java b/net/minecraft/world/level/Level.java
index cb6ca60af3d3f90501e4693a78466b9f7462362d..127e25dab3a5e4df9cdf8eefd0485ea07b7696d9 100644
--- a/net/minecraft/world/level/Level.java
+++ b/net/minecraft/world/level/Level.java
@@ -863,6 +863,7 @@ public abstract class Level implements LevelAccessor, AutoCloseable {
         try {
             consumerEntity.accept(entity);
         } catch (Throwable var6) {
+            if (var6 instanceof ThreadDeath) throw var6; // 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, var6);
diff --git a/net/minecraft/world/level/chunk/LevelChunk.java b/net/minecraft/world/level/chunk/LevelChunk.java
index d1d0dc13eecb0e0eb3a7839b570a5fe7f62f3fba..205f5a687eb685284a2e403f3eb6bdc694fc5423 100644
--- a/net/minecraft/world/level/chunk/LevelChunk.java
+++ b/net/minecraft/world/level/chunk/LevelChunk.java
@@ -855,6 +855,7 @@ public class LevelChunk extends ChunkAccess {
 
                         profilerFiller.pop();
                     } catch (Throwable var5) {
+                        if (var5 instanceof ThreadDeath) throw var5; // 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, var5);