0
0
mirror of https://hub.spigotmc.org/stash/scm/spigot/spigot.git synced 2024-11-24 10:36:25 +00:00
spigot/Bukkit-Patches/0003-Spigot-Timings.patch
2024-10-23 02:15:00 +11:00

465 lines
18 KiB
Diff

From 4cd1115e6462137456755e35b6641a16d56cc3b5 Mon Sep 17 00:00:00 2001
From: Aikar <aikar@aikar.co>
Date: Sun, 2 Jun 2013 10:42:57 +1000
Subject: [PATCH] Spigot Timings
Adds performance tracking timings all around the Minecraft Server, and improves the usability of the /timings command
Plugins can track their own timings with CustomTimingsHandler
diff --git a/src/main/java/org/bukkit/Bukkit.java b/src/main/java/org/bukkit/Bukkit.java
index eeb34a674..67b6e7e67 100644
--- a/src/main/java/org/bukkit/Bukkit.java
+++ b/src/main/java/org/bukkit/Bukkit.java
@@ -868,6 +868,7 @@ public final class Bukkit {
*/
public static void reload() {
server.reload();
+ org.spigotmc.CustomTimingsHandler.reload(); // Spigot
}
/**
diff --git a/src/main/java/org/bukkit/Server.java b/src/main/java/org/bukkit/Server.java
index 36fbd94a9..4a965bbbd 100644
--- a/src/main/java/org/bukkit/Server.java
+++ b/src/main/java/org/bukkit/Server.java
@@ -1838,6 +1838,10 @@ public interface Server extends PluginMessageRecipient {
// Spigot start
public class Spigot {
+ @NotNull
+ public org.bukkit.configuration.file.YamlConfiguration getConfig() {
+ throw new UnsupportedOperationException("Not supported yet.");
+ }
}
@NotNull
diff --git a/src/main/java/org/bukkit/command/Command.java b/src/main/java/org/bukkit/command/Command.java
index d498b16bb..ac89f041d 100644
--- a/src/main/java/org/bukkit/command/Command.java
+++ b/src/main/java/org/bukkit/command/Command.java
@@ -33,6 +33,7 @@ public abstract class Command {
protected String usageMessage;
private String permission;
private String permissionMessage;
+ public org.spigotmc.CustomTimingsHandler timings; // Spigot
protected Command(@NotNull String name) {
this(name, "", "/" + name, new ArrayList<String>());
@@ -46,6 +47,7 @@ public abstract class Command {
this.usageMessage = (usageMessage == null) ? "/" + name : usageMessage;
this.aliases = aliases;
this.activeAliases = new ArrayList<String>(aliases);
+ this.timings = new org.spigotmc.CustomTimingsHandler("** Command: " + name); // Spigot
}
/**
@@ -243,6 +245,7 @@ public abstract class Command {
}
this.nextLabel = name;
if (!isRegistered()) {
+ this.timings = new org.spigotmc.CustomTimingsHandler("** Command: " + name); // Spigot
this.label = name;
return true;
}
diff --git a/src/main/java/org/bukkit/command/SimpleCommandMap.java b/src/main/java/org/bukkit/command/SimpleCommandMap.java
index c399c1497..fd5a7a554 100644
--- a/src/main/java/org/bukkit/command/SimpleCommandMap.java
+++ b/src/main/java/org/bukkit/command/SimpleCommandMap.java
@@ -145,11 +145,15 @@ public class SimpleCommandMap implements CommandMap {
}
try {
+ target.timings.startTiming(); // Spigot
// Note: we don't return the result of target.execute as thats success / failure, we return handled (true) or not handled (false)
target.execute(sender, sentCommandLabel, Arrays.copyOfRange(args, 1, args.length));
+ target.timings.stopTiming(); // Spigot
} catch (CommandException ex) {
+ target.timings.stopTiming(); // Spigot
throw ex;
} catch (Throwable ex) {
+ target.timings.stopTiming(); // Spigot
throw new CommandException("Unhandled exception executing '" + commandLine + "' in " + target, ex);
}
diff --git a/src/main/java/org/bukkit/command/defaults/TimingsCommand.java b/src/main/java/org/bukkit/command/defaults/TimingsCommand.java
index ed4cbce77..516d7fc78 100644
--- a/src/main/java/org/bukkit/command/defaults/TimingsCommand.java
+++ b/src/main/java/org/bukkit/command/defaults/TimingsCommand.java
@@ -18,23 +18,102 @@ import org.bukkit.plugin.TimedRegisteredListener;
import org.bukkit.util.StringUtil;
import org.jetbrains.annotations.NotNull;
+// Spigot start
+// CHECKSTYLE:OFF
+import java.io.ByteArrayOutputStream;
+import java.io.OutputStream;
+import java.net.HttpURLConnection;
+import java.net.URL;
+import java.util.logging.Level;
+import org.bukkit.command.RemoteConsoleCommandSender;
+import org.bukkit.plugin.SimplePluginManager;
+import org.spigotmc.CustomTimingsHandler;
+// CHECKSTYLE:ON
+// Spigot end
+
public class TimingsCommand extends BukkitCommand {
- private static final List<String> TIMINGS_SUBCOMMANDS = ImmutableList.of("merged", "reset", "separate");
+ private static final List<String> TIMINGS_SUBCOMMANDS = ImmutableList.of("report", "reset", "on", "off", "paste"); // Spigot
+ public static long timingStart = 0; // Spigot
public TimingsCommand(@NotNull String name) {
super(name);
- this.description = "Records timings for all plugin events";
- this.usageMessage = "/timings <reset|merged|separate>";
+ this.description = "Manages Spigot Timings data to see performance of the server."; // Spigot
+ this.usageMessage = "/timings <reset|report|on|off|paste>"; // Spigot
this.setPermission("bukkit.command.timings");
}
+ // Spigot start - redesigned Timings Command
+ public void executeSpigotTimings(@NotNull CommandSender sender, @NotNull String[] args) {
+ if ("on".equals(args[0])) {
+ ((SimplePluginManager) Bukkit.getPluginManager()).useTimings(true);
+ CustomTimingsHandler.reload();
+ sender.sendMessage("Enabled Timings & Reset");
+ return;
+ } else if ("off".equals(args[0])) {
+ ((SimplePluginManager) Bukkit.getPluginManager()).useTimings(false);
+ sender.sendMessage("Disabled Timings");
+ return;
+ }
+
+ if (!Bukkit.getPluginManager().useTimings()) {
+ sender.sendMessage("Please enable timings by typing /timings on");
+ return;
+ }
+
+ boolean paste = "paste".equals(args[0]);
+ if ("reset".equals(args[0])) {
+ CustomTimingsHandler.reload();
+ sender.sendMessage("Timings reset");
+ } else if ("merged".equals(args[0]) || "report".equals(args[0]) || paste) {
+ long sampleTime = System.nanoTime() - timingStart;
+ int index = 0;
+ File timingFolder = new File("timings");
+ timingFolder.mkdirs();
+ File timings = new File(timingFolder, "timings.txt");
+ ByteArrayOutputStream bout = (paste) ? new ByteArrayOutputStream() : null;
+ while (timings.exists()) timings = new File(timingFolder, "timings" + (++index) + ".txt");
+ PrintStream fileTimings = null;
+ try {
+ fileTimings = (paste) ? new PrintStream(bout) : new PrintStream(timings);
+
+ CustomTimingsHandler.printTimings(fileTimings);
+ fileTimings.println("Sample time " + sampleTime + " (" + sampleTime / 1E9 + "s)");
+
+ fileTimings.println("<spigotConfig>");
+ fileTimings.println(Bukkit.spigot().getConfig().saveToString());
+ fileTimings.println("</spigotConfig>");
+
+ if (paste) {
+ new PasteThread(sender, bout).start();
+ return;
+ }
+
+ sender.sendMessage("Timings written to " + timings.getPath());
+ sender.sendMessage("Paste contents of file into form at http://www.spigotmc.org/go/timings to read results.");
+
+ } catch (IOException e) {
+ } finally {
+ if (fileTimings != null) {
+ fileTimings.close();
+ }
+ }
+ }
+ }
+ // Spigot end
+
@Override
public boolean execute(@NotNull CommandSender sender, @NotNull String currentAlias, @NotNull String[] args) {
if (!testPermission(sender)) return true;
- if (args.length != 1) {
+ if (args.length < 1) { // Spigot
sender.sendMessage(ChatColor.RED + "Usage: " + usageMessage);
return false;
}
+ // Spigot start
+ if (true) {
+ executeSpigotTimings(sender, args);
+ return true;
+ }
+ // Spigot end
if (!sender.getServer().getPluginManager().useTimings()) {
sender.sendMessage("Please enable timings by setting \"settings.plugin-profiling\" to true in bukkit.yml");
return true;
@@ -122,4 +201,50 @@ public class TimingsCommand extends BukkitCommand {
}
return ImmutableList.of();
}
+
+ // Spigot start
+ private static class PasteThread extends Thread {
+
+ private final CommandSender sender;
+ private final ByteArrayOutputStream bout;
+
+ public PasteThread(@NotNull CommandSender sender, @NotNull ByteArrayOutputStream bout) {
+ super("Timings paste thread");
+ this.sender = sender;
+ this.bout = bout;
+ }
+
+ @Override
+ public synchronized void start() {
+ if (sender instanceof RemoteConsoleCommandSender) {
+ run();
+ } else {
+ super.start();
+ }
+ }
+
+ @Override
+ public void run() {
+ try {
+ HttpURLConnection con = (HttpURLConnection) new URL("https://timings.spigotmc.org/paste").openConnection();
+ con.setDoOutput(true);
+ con.setRequestMethod("POST");
+ con.setInstanceFollowRedirects(false);
+
+ OutputStream out = con.getOutputStream();
+ out.write(bout.toByteArray());
+ out.close();
+
+ com.google.gson.JsonObject location = new com.google.gson.Gson().fromJson(new java.io.InputStreamReader(con.getInputStream()), com.google.gson.JsonObject.class);
+ con.getInputStream().close();
+
+ String pasteID = location.get("key").getAsString();
+ sender.sendMessage(ChatColor.GREEN + "Timings results can be viewed at https://www.spigotmc.org/go/timings?url=" + pasteID);
+ } catch (IOException ex) {
+ sender.sendMessage(ChatColor.RED + "Error pasting timings, check your console for more information");
+ Bukkit.getServer().getLogger().log(Level.WARNING, "Could not paste timings", ex);
+ }
+ }
+ }
+ // Spigot end
}
diff --git a/src/main/java/org/bukkit/plugin/SimplePluginManager.java b/src/main/java/org/bukkit/plugin/SimplePluginManager.java
index 04dda4d22..839130f71 100644
--- a/src/main/java/org/bukkit/plugin/SimplePluginManager.java
+++ b/src/main/java/org/bukkit/plugin/SimplePluginManager.java
@@ -370,6 +370,7 @@ public final class SimplePluginManager implements PluginManager {
}
}
+ org.bukkit.command.defaults.TimingsCommand.timingStart = System.nanoTime(); // Spigot
return result.toArray(new Plugin[result.size()]);
}
diff --git a/src/main/java/org/bukkit/plugin/java/JavaPluginLoader.java b/src/main/java/org/bukkit/plugin/java/JavaPluginLoader.java
index 39b991ff7..047c0304f 100644
--- a/src/main/java/org/bukkit/plugin/java/JavaPluginLoader.java
+++ b/src/main/java/org/bukkit/plugin/java/JavaPluginLoader.java
@@ -43,6 +43,7 @@ import org.bukkit.plugin.TimedRegisteredListener;
import org.bukkit.plugin.UnknownDependencyException;
import org.jetbrains.annotations.NotNull;
import org.jetbrains.annotations.Nullable;
+import org.spigotmc.CustomTimingsHandler; // Spigot
import org.yaml.snakeyaml.error.YAMLException;
/**
@@ -53,6 +54,7 @@ public final class JavaPluginLoader implements PluginLoader {
private final Pattern[] fileFilters = new Pattern[]{Pattern.compile("\\.jar$")};
private final List<PluginClassLoader> loaders = new CopyOnWriteArrayList<PluginClassLoader>();
private final LibraryLoader libraryLoader;
+ public static final CustomTimingsHandler pluginParentTimer = new CustomTimingsHandler("** Plugins"); // Spigot
/**
* This class was not meant to be constructed explicitly
@@ -290,6 +292,7 @@ public final class JavaPluginLoader implements PluginLoader {
}
}
+ final CustomTimingsHandler timings = new CustomTimingsHandler("Plugin: " + plugin.getDescription().getFullName() + " Event: " + listener.getClass().getName() + "::" + method.getName() + "(" + eventClass.getSimpleName() + ")", pluginParentTimer); // Spigot
EventExecutor executor = new EventExecutor() {
@Override
public void execute(@NotNull Listener listener, @NotNull Event event) throws EventException {
@@ -297,7 +300,12 @@ public final class JavaPluginLoader implements PluginLoader {
if (!eventClass.isAssignableFrom(event.getClass())) {
return;
}
+ // Spigot start
+ boolean isAsync = event.isAsynchronous();
+ if (!isAsync) timings.startTiming();
method.invoke(listener, event);
+ if (!isAsync) timings.stopTiming();
+ // Spigot end
} catch (InvocationTargetException ex) {
throw new EventException(ex.getCause());
} catch (Throwable t) {
@@ -305,7 +313,7 @@ public final class JavaPluginLoader implements PluginLoader {
}
}
};
- if (useTimings) {
+ if (false) { // Spigot - RL handles useTimings check now
eventSet.add(new TimedRegisteredListener(listener, executor, eh.priority(), plugin, eh.ignoreCancelled()));
} else {
eventSet.add(new RegisteredListener(listener, executor, eh.priority(), plugin, eh.ignoreCancelled()));
diff --git a/src/main/java/org/spigotmc/CustomTimingsHandler.java b/src/main/java/org/spigotmc/CustomTimingsHandler.java
new file mode 100644
index 000000000..44badfedc
--- /dev/null
+++ b/src/main/java/org/spigotmc/CustomTimingsHandler.java
@@ -0,0 +1,137 @@
+package org.spigotmc;
+
+import java.io.PrintStream;
+import java.util.Queue;
+import java.util.concurrent.ConcurrentLinkedQueue;
+import org.bukkit.Bukkit;
+import org.bukkit.World;
+import org.bukkit.command.defaults.TimingsCommand;
+import org.jetbrains.annotations.NotNull;
+import org.jetbrains.annotations.Nullable;
+
+/**
+ * Provides custom timing sections for /timings merged.
+ */
+public class CustomTimingsHandler {
+
+ private static Queue<CustomTimingsHandler> HANDLERS = new ConcurrentLinkedQueue<CustomTimingsHandler>();
+ /*========================================================================*/
+ private final String name;
+ private final CustomTimingsHandler parent;
+ private long count = 0;
+ private long start = 0;
+ private long timingDepth = 0;
+ private long totalTime = 0;
+ private long curTickTotal = 0;
+ private long violations = 0;
+
+ public CustomTimingsHandler(@NotNull String name) {
+ this(name, null);
+ }
+
+ public CustomTimingsHandler(@NotNull String name, @Nullable CustomTimingsHandler parent) {
+ this.name = name;
+ this.parent = parent;
+ HANDLERS.add(this);
+ }
+
+ /**
+ * Prints the timings and extra data to the given stream.
+ *
+ * @param printStream output stream
+ */
+ public static void printTimings(@NotNull PrintStream printStream) {
+ printStream.println("Minecraft");
+ for (CustomTimingsHandler timings : HANDLERS) {
+ long time = timings.totalTime;
+ long count = timings.count;
+ if (count == 0) {
+ continue;
+ }
+ long avg = time / count;
+
+ printStream.println(" " + timings.name + " Time: " + time + " Count: " + count + " Avg: " + avg + " Violations: " + timings.violations);
+ }
+ printStream.println("# Version " + Bukkit.getVersion());
+ int entities = 0;
+ int livingEntities = 0;
+ for (World world : Bukkit.getWorlds()) {
+ entities += world.getEntities().size();
+ livingEntities += world.getLivingEntities().size();
+ }
+ printStream.println("# Entities " + entities);
+ printStream.println("# LivingEntities " + livingEntities);
+ }
+
+ /**
+ * Resets all timings.
+ */
+ public static void reload() {
+ if (Bukkit.getPluginManager().useTimings()) {
+ for (CustomTimingsHandler timings : HANDLERS) {
+ timings.reset();
+ }
+ }
+ TimingsCommand.timingStart = System.nanoTime();
+ }
+
+ /**
+ * Ticked every tick by CraftBukkit to count the number of times a timer
+ * caused TPS loss.
+ */
+ public static void tick() {
+ if (Bukkit.getPluginManager().useTimings()) {
+ for (CustomTimingsHandler timings : HANDLERS) {
+ if (timings.curTickTotal > 50000000) {
+ timings.violations += Math.ceil(timings.curTickTotal / 50000000);
+ }
+ timings.curTickTotal = 0;
+ timings.timingDepth = 0; // incase reset messes this up
+ }
+ }
+ }
+
+ /**
+ * Starts timing to track a section of code.
+ */
+ public void startTiming() {
+ // If second condtion fails we are already timing
+ if (Bukkit.getPluginManager().useTimings() && ++timingDepth == 1) {
+ start = System.nanoTime();
+ if (parent != null && ++parent.timingDepth == 1) {
+ parent.start = start;
+ }
+ }
+ }
+
+ /**
+ * Stops timing a section of code.
+ */
+ public void stopTiming() {
+ if (Bukkit.getPluginManager().useTimings()) {
+ if (--timingDepth != 0 || start == 0) {
+ return;
+ }
+ long diff = System.nanoTime() - start;
+ totalTime += diff;
+ curTickTotal += diff;
+ count++;
+ start = 0;
+ if (parent != null) {
+ parent.stopTiming();
+ }
+ }
+ }
+
+ /**
+ * Reset this timer, setting all values to zero.
+ */
+ public void reset() {
+ count = 0;
+ violations = 0;
+ curTickTotal = 0;
+ totalTime = 0;
+ start = 0;
+ timingDepth = 0;
+ }
+}
diff --git a/src/main/java/org/spigotmc/package-info.java b/src/main/java/org/spigotmc/package-info.java
new file mode 100644
index 000000000..a287faff5
--- /dev/null
+++ b/src/main/java/org/spigotmc/package-info.java
@@ -0,0 +1,4 @@
+/**
+ * Spigot-specific classes.
+ */
+package org.spigotmc;
--
2.47.0