Paper/patches/server/0231-Add-Early-Warning-Feature-to-WatchDog.patch

From 0000000000000000000000000000000000000000 Mon Sep 17 00:00:00 2001
From: miclebrick <miclebrick@outlook.com>
Date: Wed, 8 Aug 2018 15:30:52 -0400
Subject: [PATCH] Add Early Warning Feature to WatchDog

Detect when the server has been hung for a long duration, and start printing
thread dumps at an interval until the point of crash.

This will help diagnose what was going on in that time before the crash.

diff --git a/src/main/java/net/minecraft/server/MinecraftServer.java b/src/main/java/net/minecraft/server/MinecraftServer.java
index 478445e7ed67b17d7aff0e10e9aae0788605a4b9..077b2e1d06a4bb0c2ce10274dc6144ee76608d90 100644
--- a/src/main/java/net/minecraft/server/MinecraftServer.java
+++ b/src/main/java/net/minecraft/server/MinecraftServer.java
@@ -1104,6 +1104,7 @@ public abstract class MinecraftServer extends ReentrantBlockableEventLoop<TickTa
             this.status = this.buildServerStatus();
 
             // Spigot start
+            org.spigotmc.WatchdogThread.hasStarted = true; // Paper
             Arrays.fill( this.recentTps, 20 );
             // Paper start - further improve server tick loop
             long tickSection = Util.getNanos();
diff --git a/src/main/java/net/minecraft/server/dedicated/DedicatedServer.java b/src/main/java/net/minecraft/server/dedicated/DedicatedServer.java
index 0ffa25a6e41cc56e78c79e0cee45e3b811794129..1b47e228ad7365b31d6ddd8c572d3bc5de90a591 100644
--- a/src/main/java/net/minecraft/server/dedicated/DedicatedServer.java
+++ b/src/main/java/net/minecraft/server/dedicated/DedicatedServer.java
@@ -212,6 +212,7 @@ public class DedicatedServer extends MinecraftServer implements ServerInterface
         this.paperConfigurations.initializeGlobalConfiguration(this.registryAccess());
         this.paperConfigurations.initializeWorldDefaultsConfiguration(this.registryAccess());
         // Paper end - initialize global and world-defaults configuration
+        org.spigotmc.WatchdogThread.doStart(org.spigotmc.SpigotConfig.timeoutTime, org.spigotmc.SpigotConfig.restartOnCrash); // Paper - start watchdog thread
         io.papermc.paper.command.PaperCommands.registerCommands(this); // Paper - setup /paper command
         com.destroystokyo.paper.Metrics.PaperMetrics.startMetrics(); // Paper - start metrics
         com.destroystokyo.paper.VersionHistoryManager.INSTANCE.getClass(); // Paper - load version history now
diff --git a/src/main/java/org/bukkit/craftbukkit/CraftServer.java b/src/main/java/org/bukkit/craftbukkit/CraftServer.java
index cbdfb4168f23bbbd37675da6dc88acb3191d88d6..9c673642b7c35bc3c443bd66fbcd278073eeccc2 100644
--- a/src/main/java/org/bukkit/craftbukkit/CraftServer.java
+++ b/src/main/java/org/bukkit/craftbukkit/CraftServer.java
@@ -926,6 +926,7 @@ public final class CraftServer implements Server {
 
     @Override
     public void reload() {
+        org.spigotmc.WatchdogThread.hasStarted = false; // Paper - Disable watchdog early timeout on reload
         this.reloadCount++;
         this.configuration = YamlConfiguration.loadConfiguration(this.getConfigFile());
         this.commandsConfiguration = YamlConfiguration.loadConfiguration(this.getCommandsConfigFile());
@@ -1016,6 +1017,7 @@ public final class CraftServer implements Server {
         this.enablePlugins(PluginLoadOrder.POSTWORLD);
         this.getPluginManager().callEvent(new ServerLoadEvent(ServerLoadEvent.LoadType.RELOAD));
         if (io.papermc.paper.plugin.PluginInitializerManager.instance().pluginRemapper != null) io.papermc.paper.plugin.PluginInitializerManager.instance().pluginRemapper.pluginsEnabled(); // Paper - Remap plugins
+        org.spigotmc.WatchdogThread.hasStarted = true; // Paper - Disable watchdog early timeout on reload
     }
 
     @Override
diff --git a/src/main/java/org/spigotmc/SpigotConfig.java b/src/main/java/org/spigotmc/SpigotConfig.java
index 7cd1f375b9ad9e6d6f2d26661519f12be064a9d2..9572177323f29ea8315a3dfb943dfe10463f32ae 100644
--- a/src/main/java/org/spigotmc/SpigotConfig.java
+++ b/src/main/java/org/spigotmc/SpigotConfig.java
@@ -229,7 +229,7 @@ public class SpigotConfig
         SpigotConfig.restartScript = SpigotConfig.getString( "settings.restart-script", SpigotConfig.restartScript );
         SpigotConfig.restartMessage = SpigotConfig.transform( SpigotConfig.getString( "messages.restart", "Server is restarting" ) );
         SpigotConfig.commands.put( "restart", new RestartCommand( "restart" ) );
-        WatchdogThread.doStart( SpigotConfig.timeoutTime, SpigotConfig.restartOnCrash );
+        // WatchdogThread.doStart( SpigotConfig.timeoutTime, SpigotConfig.restartOnCrash ); // Paper - moved to after paper config initialization
     }
 
     public static boolean bungee;
diff --git a/src/main/java/org/spigotmc/WatchdogThread.java b/src/main/java/org/spigotmc/WatchdogThread.java
index 81ccbe2533e6fc5899d6c068e421e0d7f1351d34..ad282d34919716b75acd10426cd071da9d064a51 100644
--- a/src/main/java/org/spigotmc/WatchdogThread.java
+++ b/src/main/java/org/spigotmc/WatchdogThread.java
@@ -14,6 +14,10 @@ public class WatchdogThread extends Thread
     private static WatchdogThread instance;
     private long timeoutTime;
     private boolean restart;
+    private final long earlyWarningEvery; // Paper - Timeout time for just printing a dump but not restarting
+    private final long earlyWarningDelay; // Paper
+    public static volatile boolean hasStarted; // Paper
+    private long lastEarlyWarning; // Paper - Keep track of short dump times to avoid spamming console with short dumps
     private volatile long lastTick;
     private volatile boolean stopping;
 
@@ -22,6 +26,8 @@ public class WatchdogThread extends Thread
         super( "Paper Watchdog Thread" );
         this.timeoutTime = timeoutTime;
         this.restart = restart;
+        earlyWarningEvery = Math.min(io.papermc.paper.configuration.GlobalConfiguration.get().watchdog.earlyWarningEvery, timeoutTime); // Paper
+        earlyWarningDelay = Math.min(io.papermc.paper.configuration.GlobalConfiguration.get().watchdog.earlyWarningDelay, timeoutTime); // Paper
     }
 
     private static long monotonicMillis()
@@ -61,9 +67,18 @@ public class WatchdogThread extends Thread
         while ( !this.stopping )
         {
             //
-            if ( this.lastTick != 0 && this.timeoutTime > 0 && WatchdogThread.monotonicMillis() > this.lastTick + this.timeoutTime && !Boolean.getBoolean("disable.watchdog")) // Paper - Add property to disable
+            // 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
             {
-                Logger log = Bukkit.getServer().getLogger();
+                boolean isLongTimeout = currentTime > lastTick + timeoutTime;
+                // 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...
+                lastEarlyWarning = currentTime;
+                if (isLongTimeout) {
+                // Paper end
                 log.log( Level.SEVERE, "------------------------------" );
                 log.log( Level.SEVERE, "The server has stopped responding! This is (probably) not a Paper bug." ); // Paper
                 log.log( Level.SEVERE, "If you see a plugin in the Server thread dump below, then please report it to that author" );
@@ -92,29 +107,45 @@ public class WatchdogThread extends Thread
                     }
                 }
                 // Paper end
+                } else
+                {
+                    log.log(Level.SEVERE, "--- DO NOT REPORT THIS TO PAPER - THIS IS NOT A BUG OR A CRASH  - " + Bukkit.getServer().getVersion() + " ---");
+                    log.log(Level.SEVERE, "The server has not responded for " + (currentTime - lastTick) / 1000 + " seconds! Creating thread dump");
+                }
+                // Paper end - Different message for short timeout
                 log.log( Level.SEVERE, "------------------------------" );
                 log.log( Level.SEVERE, "Server thread dump (Look for plugins here before reporting to Paper!):" ); // Paper
                 WatchdogThread.dumpThread( ManagementFactory.getThreadMXBean().getThreadInfo( MinecraftServer.getServer().serverThread.getId(), Integer.MAX_VALUE ), log );
                 log.log( Level.SEVERE, "------------------------------" );
                 //
+                // Paper start - Only print full dump on long timeouts
+                if ( isLongTimeout )
+                {
                 log.log( Level.SEVERE, "Entire Thread Dump:" );
                 ThreadInfo[] threads = ManagementFactory.getThreadMXBean().dumpAllThreads( true, true );
                 for ( ThreadInfo thread : threads )
                 {
                     WatchdogThread.dumpThread( thread, log );
                 }
+                } else {
+                    log.log(Level.SEVERE, "--- DO NOT REPORT THIS TO PAPER - THIS IS NOT A BUG OR A CRASH ---");
+                }
+
                 log.log( Level.SEVERE, "------------------------------" );
 
+                if ( isLongTimeout )
+                {
                 if ( this.restart && !MinecraftServer.getServer().hasStopped() )
                 {
                     RestartCommand.restart();
                 }
                 break;
+                } // Paper end
             }
 
             try
             {
-                sleep( 10000 );
+                sleep( 1000 ); // Paper - Reduce check time to every second instead of every ten seconds, more consistent and allows for short timeout
             } catch ( InterruptedException ex )
             {
                 this.interrupt();