2020-05-06 11:48:49 +02:00
From 0000000000000000000000000000000000000000 Mon Sep 17 00:00:00 2001
2018-08-12 19:27:23 +02:00
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/com/destroystokyo/paper/PaperConfig.java b/src/main/java/com/destroystokyo/paper/PaperConfig.java
2021-02-26 18:54:48 +01:00
index bd508025b771424c942fd856c31d520b6f548082..62621562137cba4804f0465c58d25ca2786328e5 100644
2018-08-12 19:27:23 +02:00
--- a/src/main/java/com/destroystokyo/paper/PaperConfig.java
+++ b/src/main/java/com/destroystokyo/paper/PaperConfig.java
2020-06-26 08:29:44 +02:00
@@ -25,6 +25,7 @@ import org.bukkit.configuration.file.YamlConfiguration;
2018-08-12 19:27:23 +02:00
import co.aikar.timings.Timings;
import co.aikar.timings.TimingsManager;
2018-10-19 02:44:59 +02:00
import org.spigotmc.SpigotConfig;
2018-08-12 19:27:23 +02:00
+import org.spigotmc.WatchdogThread;
public class PaperConfig {
2021-02-26 18:54:48 +01:00
@@ -297,6 +298,14 @@ public class PaperConfig {
2018-08-12 19:27:23 +02:00
}
}
2018-08-12 19:27:23 +02:00
2018-08-12 19:27:23 +02:00
+ public static int watchdogPrintEarlyWarningEvery = 5000;
+ public static int watchdogPrintEarlyWarningDelay = 10000;
+ private static void watchdogEarlyWarning() {
+ watchdogPrintEarlyWarningEvery = getInt("settings.watchdog.early-warning-every", 5000);
+ watchdogPrintEarlyWarningDelay = getInt("settings.watchdog.early-warning-delay", 10000);
+ WatchdogThread.doStart(SpigotConfig.timeoutTime, SpigotConfig.restartOnCrash );
+ }
2018-08-12 19:27:23 +02:00
+
2018-08-29 18:26:24 +02:00
public static int tabSpamIncrement = 1;
2018-08-12 19:27:23 +02:00
public static int tabSpamLimit = 500;
private static void tabSpamLimiters() {
2018-08-12 19:27:23 +02:00
diff --git a/src/main/java/net/minecraft/server/MinecraftServer.java b/src/main/java/net/minecraft/server/MinecraftServer.java
2021-05-18 00:32:29 +02:00
index 5bbd3bb52b76b8b6cdf90c94bcb29f122f31c543..52c0dd4f2779125116d9dcccc2aef7a11af92945 100644
2018-08-12 19:27:23 +02:00
--- a/src/main/java/net/minecraft/server/MinecraftServer.java
+++ b/src/main/java/net/minecraft/server/MinecraftServer.java
2021-05-11 05:47:51 +02:00
@@ -1019,6 +1019,7 @@ public abstract class MinecraftServer extends IAsyncTaskHandlerReentrant<TickTas
2019-05-05 04:23:25 +02:00
this.a(this.serverPing);
2018-08-12 19:27:23 +02:00
// Spigot start
2018-08-17 00:11:35 +02:00
+ org.spigotmc.WatchdogThread.hasStarted = true; // Paper
2018-08-12 19:27:23 +02:00
Arrays.fill( recentTps, 20 );
2019-05-22 05:58:00 +02:00
long start = System.nanoTime(), curTime, tickSection = start; // Paper - Further improve server tick loop
2018-08-26 20:11:49 +02:00
lastTick = start - TICK_TIME; // Paper
2018-12-13 02:41:11 +01:00
diff --git a/src/main/java/org/bukkit/craftbukkit/CraftServer.java b/src/main/java/org/bukkit/craftbukkit/CraftServer.java
2021-05-18 00:32:29 +02:00
index ce08e0d14cc9ab1fd6d56900fd48268649e01f03..dad096e9bd7efeed59fd484ce6c93334f7adeaa9 100644
2018-12-13 02:41:11 +01:00
--- a/src/main/java/org/bukkit/craftbukkit/CraftServer.java
+++ b/src/main/java/org/bukkit/craftbukkit/CraftServer.java
2021-05-18 00:32:29 +02:00
@@ -812,6 +812,7 @@ public final class CraftServer implements Server {
2018-12-13 02:41:11 +01:00
@Override
public void reload() {
+ org.spigotmc.WatchdogThread.hasStarted = false; // Paper - Disable watchdog early timeout on reload
reloadCount++;
configuration = YamlConfiguration.loadConfiguration(getConfigFile());
commandsConfiguration = YamlConfiguration.loadConfiguration(getCommandsConfigFile());
2021-05-18 00:32:29 +02:00
@@ -930,6 +931,7 @@ public final class CraftServer implements Server {
2018-12-13 02:41:11 +01:00
enablePlugins(PluginLoadOrder.STARTUP);
enablePlugins(PluginLoadOrder.POSTWORLD);
getPluginManager().callEvent(new ServerLoadEvent(ServerLoadEvent.LoadType.RELOAD));
+ org.spigotmc.WatchdogThread.hasStarted = true; // Paper - Disable watchdog early timeout on reload
}
@Override
2018-08-12 19:27:23 +02:00
diff --git a/src/main/java/org/spigotmc/SpigotConfig.java b/src/main/java/org/spigotmc/SpigotConfig.java
2021-03-16 08:19:45 +01:00
index 11f8a2e5bf43013bce8675ea310ff42eacf14754..564285c1c96f3faf99022eec639dbefed54f2a7d 100644
2018-08-12 19:27:23 +02:00
--- a/src/main/java/org/spigotmc/SpigotConfig.java
+++ b/src/main/java/org/spigotmc/SpigotConfig.java
2020-11-09 02:05:27 +01:00
@@ -229,7 +229,7 @@ public class SpigotConfig
2018-08-12 19:27:23 +02:00
restartScript = getString( "settings.restart-script", restartScript );
restartMessage = transform( getString( "messages.restart", "Server is restarting" ) );
commands.put( "restart", new RestartCommand( "restart" ) );
- WatchdogThread.doStart( timeoutTime, restartOnCrash );
+ //WatchdogThread.doStart( timeoutTime, restartOnCrash ); // Paper - moved to PaperConfig
}
public static boolean bungee;
diff --git a/src/main/java/org/spigotmc/WatchdogThread.java b/src/main/java/org/spigotmc/WatchdogThread.java
2021-03-16 08:19:45 +01:00
index 4e0291be4bd5876bb5b5f62ebfa156635d4c758f..abaefa0b71104756e4b458abefe13d179e7a1724 100644
2018-08-12 19:27:23 +02:00
--- a/src/main/java/org/spigotmc/WatchdogThread.java
+++ b/src/main/java/org/spigotmc/WatchdogThread.java
@@ -5,6 +5,7 @@ import java.lang.management.MonitorInfo;
import java.lang.management.ThreadInfo;
import java.util.logging.Level;
import java.util.logging.Logger;
+import com.destroystokyo.paper.PaperConfig;
import net.minecraft.server.MinecraftServer;
import org.bukkit.Bukkit;
2021-01-12 21:06:27 +01:00
@@ -14,6 +15,10 @@ public class WatchdogThread extends Thread
2018-08-12 19:27:23 +02:00
private static WatchdogThread instance;
2021-01-12 21:06:27 +01:00
private long timeoutTime;
private boolean restart;
2018-08-12 19:27:23 +02:00
+ 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;
2021-01-12 21:06:27 +01:00
2018-08-12 19:27:23 +02:00
@@ -22,6 +27,8 @@ public class WatchdogThread extends Thread
super( "Paper Watchdog Thread" );
this.timeoutTime = timeoutTime;
this.restart = restart;
+ earlyWarningEvery = Math.min(PaperConfig.watchdogPrintEarlyWarningEvery, timeoutTime); // Paper
+ earlyWarningDelay = Math.min(PaperConfig.watchdogPrintEarlyWarningDelay, timeoutTime); // Paper
}
2018-11-24 06:28:04 +01:00
private static long monotonicMillis()
2021-01-12 21:06:27 +01:00
@@ -60,10 +67,18 @@ public class WatchdogThread extends Thread
2018-08-17 00:11:35 +02:00
{
2018-08-12 19:27:23 +02:00
while ( !stopping )
{
2018-08-17 00:11:35 +02:00
- //
2021-01-12 21:06:27 +01:00
- if ( lastTick != 0 && timeoutTime > 0 && monotonicMillis() > lastTick + timeoutTime && !Boolean.getBoolean("disable.watchdog")) // Paper - Add property to disable
2018-08-17 00:11:35 +02:00
+ // Paper start
2018-11-24 06:28:04 +01:00
+ Logger log = Bukkit.getServer().getLogger();
+ long currentTime = monotonicMillis();
2021-01-12 21:06:27 +01:00
+ if ( lastTick != 0 && timeoutTime > 0 && currentTime > lastTick + earlyWarningEvery && !Boolean.getBoolean("disable.watchdog") )
2018-08-12 19:27:23 +02:00
{
2018-11-24 06:28:04 +01:00
- Logger log = Bukkit.getServer().getLogger();
2018-08-12 19:27:23 +02:00
+ boolean isLongTimeout = currentTime > lastTick + timeoutTime;
2018-08-12 19:27:23 +02:00
+ // Don't spam early warning dumps
2018-08-12 19:27:23 +02:00
+ if ( !isLongTimeout && (earlyWarningEvery <= 0 || !hasStarted || currentTime < lastEarlyWarning + earlyWarningEvery || currentTime < lastTick + earlyWarningDelay)) continue;
2019-12-23 03:37:47 +01:00
+ if ( !isLongTimeout && MinecraftServer.getServer().hasStopped()) continue; // Don't spam early watchdog warnings during shutdown, we'll come back to this...
2018-08-12 19:27:23 +02:00
+ lastEarlyWarning = currentTime;
2018-11-24 06:28:04 +01:00
+ if (isLongTimeout) {
2018-08-12 19:27:23 +02:00
+ // Paper end
2018-11-24 06:28:04 +01:00
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" );
2021-01-12 21:06:27 +01:00
@@ -93,29 +108,46 @@ public class WatchdogThread extends Thread
2018-08-12 19:27:23 +02:00
}
}
// Paper end
+ } else
+ {
2018-10-24 21:05:39 +02:00
+ log.log(Level.SEVERE, "--- DO NOT REPORT THIS TO PAPER - THIS IS NOT A BUG OR A CRASH - " + Bukkit.getServer().getVersion() + " ---");
2018-08-12 19:27:23 +02:00
+ log.log(Level.SEVERE, "The server has not responded for " + (currentTime - lastTick) / 1000 + " seconds! Creating thread dump");
2018-08-12 19:27:23 +02:00
+ }
+ // Paper end - Different message for short timeout
log.log( Level.SEVERE, "------------------------------" );
2019-05-05 04:23:25 +02:00
log.log( Level.SEVERE, "Server thread dump (Look for plugins here before reporting to Paper!):" ); // Paper
dumpThread( ManagementFactory.getThreadMXBean().getThreadInfo( MinecraftServer.getServer().serverThread.getId(), Integer.MAX_VALUE ), log );
2018-08-12 19:27:23 +02:00
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 )
2018-08-12 19:27:23 +02:00
{
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, "------------------------------" );
2018-08-17 18:09:08 +02:00
+ if ( isLongTimeout )
+ {
2019-12-23 03:37:47 +01:00
if ( restart && !MinecraftServer.getServer().hasStopped() )
2018-08-12 19:27:23 +02:00
{
2018-08-12 19:27:23 +02:00
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 )
{
interrupt();