404 lines
17 KiB
Diff
404 lines
17 KiB
Diff
From 33ffd896356f9cff9cde44e093bade06e801e39c Mon Sep 17 00:00:00 2001
|
|
From: Aikar <aikar@aikar.co>
|
|
Date: Wed, 9 Jan 2013 22:18:26 -0500
|
|
Subject: [PATCH] Improved Timings System
|
|
|
|
Enables "Timings on Demand" so you can enable/disable timings without server restart.
|
|
Tracks timings on sync events a plugin registers (Single and Repeating)
|
|
Tracks how many ticks a timed area has caused the server to lose due to taking too long.
|
|
Enables automatically pasting to paste.ubuntu.com so you can quickly review the results on aikar.co/timings.php
|
|
|
|
diff --git a/src/main/java/org/bukkit/CustomTimingsHandler.java b/src/main/java/org/bukkit/CustomTimingsHandler.java
|
|
new file mode 100644
|
|
index 0000000..8c00824
|
|
--- /dev/null
|
|
+++ b/src/main/java/org/bukkit/CustomTimingsHandler.java
|
|
@@ -0,0 +1,134 @@
|
|
+package org.bukkit;
|
|
+
|
|
+import org.bukkit.event.HandlerList;
|
|
+import org.bukkit.plugin.Plugin;
|
|
+import org.bukkit.plugin.RegisteredListener;
|
|
+import org.bukkit.plugin.TimedRegisteredListener;
|
|
+
|
|
+import java.io.PrintStream;
|
|
+import java.util.concurrent.ConcurrentLinkedQueue;
|
|
+
|
|
+/**
|
|
+ * Provides custom timing sections for /timings merged
|
|
+ */
|
|
+public class CustomTimingsHandler {
|
|
+
|
|
+ final public String name;
|
|
+ public long count = 0;
|
|
+ public long start = 0;
|
|
+ public long timingDepth = 0;
|
|
+ public long totalTime = 0;
|
|
+ public long curTickTotal = 0;
|
|
+ public long violations = 0;
|
|
+ CustomTimingsHandler parent = null;
|
|
+
|
|
+ final public static ConcurrentLinkedQueue<CustomTimingsHandler> allList = new ConcurrentLinkedQueue<CustomTimingsHandler>();
|
|
+
|
|
+ public CustomTimingsHandler(String name) {
|
|
+ this.name = name;
|
|
+ allList.add(this);
|
|
+ }
|
|
+ public CustomTimingsHandler(String name, CustomTimingsHandler parent) {
|
|
+ this(name);
|
|
+ this.parent = parent;
|
|
+ }
|
|
+
|
|
+ /**
|
|
+ * Prints the timings and extra data to the printstream
|
|
+ * @param printStream
|
|
+ */
|
|
+ public static void printTimings(PrintStream printStream) {
|
|
+ printStream.println("Minecraft");
|
|
+ for (CustomTimingsHandler timings : allList) {
|
|
+ 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.getServer().getPluginManager().useTimings()) return;
|
|
+ for (CustomTimingsHandler timings : allList) {
|
|
+ timings.reset();
|
|
+ }
|
|
+ }
|
|
+
|
|
+ /**
|
|
+ * Ticked every tick by CraftBukkit to count the number of times a timer caused TPS loss.
|
|
+ */
|
|
+ public static void tick() {
|
|
+ if (!Bukkit.getServer().getPluginManager().useTimings()) return;
|
|
+ for (CustomTimingsHandler timings : allList) {
|
|
+ if (timings.curTickTotal > 50000000) {
|
|
+ timings.violations += Math.ceil(timings.curTickTotal / 50000000);
|
|
+ }
|
|
+ timings.curTickTotal = 0;
|
|
+ }
|
|
+
|
|
+ for (Plugin plugin : Bukkit.getPluginManager().getPlugins()) {
|
|
+ for (RegisteredListener listener : HandlerList.getRegisteredListeners(plugin)) {
|
|
+ if (listener instanceof TimedRegisteredListener) {
|
|
+ TimedRegisteredListener timings = (TimedRegisteredListener) listener;
|
|
+ if (timings.curTickTotal > 50000000) {
|
|
+ timings.violations += Math.ceil(timings.curTickTotal / 50000000);
|
|
+ }
|
|
+ timings.curTickTotal = 0;
|
|
+ }
|
|
+ }
|
|
+ }
|
|
+ }
|
|
+
|
|
+ /**
|
|
+ * Starts timing to track a section of code.
|
|
+ */
|
|
+ public void startTiming() {
|
|
+ if (!Bukkit.getServer().getPluginManager().useTimings()) return;
|
|
+
|
|
+ if (++timingDepth != 1) {
|
|
+ return; // Already timing.
|
|
+ }
|
|
+ start = System.nanoTime();
|
|
+
|
|
+ if (parent != null && ++parent.timingDepth == 1) {
|
|
+ parent.start = start;
|
|
+ }
|
|
+ }
|
|
+
|
|
+ public void stopTiming() {
|
|
+ if (!Bukkit.getServer().getPluginManager().useTimings()) return;
|
|
+ if (--timingDepth != 0 || start == 0) {
|
|
+ return;
|
|
+ }
|
|
+ long diff = System.nanoTime() - start;
|
|
+ totalTime += diff;
|
|
+ curTickTotal += diff;
|
|
+ count++;
|
|
+ start = 0;
|
|
+ if (parent != null) {
|
|
+ parent.stopTiming();
|
|
+ }
|
|
+ }
|
|
+
|
|
+ public void reset() {
|
|
+ count = 0;
|
|
+ violations = 0;
|
|
+ curTickTotal = 0;
|
|
+ totalTime = 0;
|
|
+ }
|
|
+}
|
|
+
|
|
diff --git a/src/main/java/org/bukkit/command/defaults/ReloadCommand.java b/src/main/java/org/bukkit/command/defaults/ReloadCommand.java
|
|
index fb3c90f..89c8414 100644
|
|
--- a/src/main/java/org/bukkit/command/defaults/ReloadCommand.java
|
|
+++ b/src/main/java/org/bukkit/command/defaults/ReloadCommand.java
|
|
@@ -6,6 +6,7 @@ import org.bukkit.Bukkit;
|
|
import org.bukkit.ChatColor;
|
|
import org.bukkit.command.Command;
|
|
import org.bukkit.command.CommandSender;
|
|
+import org.bukkit.CustomTimingsHandler;
|
|
|
|
public class ReloadCommand extends BukkitCommand {
|
|
public ReloadCommand(String name) {
|
|
@@ -20,6 +21,7 @@ public class ReloadCommand extends BukkitCommand {
|
|
public boolean execute(CommandSender sender, String currentAlias, String[] args) {
|
|
if (!testPermission(sender)) return true;
|
|
|
|
+ CustomTimingsHandler.reload(); // Spigot
|
|
Bukkit.reload();
|
|
Command.broadcastCommandMessage(sender, ChatColor.GREEN + "Reload complete.");
|
|
|
|
diff --git a/src/main/java/org/bukkit/command/defaults/TimingsCommand.java b/src/main/java/org/bukkit/command/defaults/TimingsCommand.java
|
|
index 94cd62c..426f9b4 100644
|
|
--- a/src/main/java/org/bukkit/command/defaults/TimingsCommand.java
|
|
+++ b/src/main/java/org/bukkit/command/defaults/TimingsCommand.java
|
|
@@ -10,40 +10,59 @@ import org.apache.commons.lang.Validate;
|
|
import org.bukkit.Bukkit;
|
|
import org.bukkit.ChatColor;
|
|
import org.bukkit.command.CommandSender;
|
|
+import org.bukkit.CustomTimingsHandler;
|
|
import org.bukkit.event.Event;
|
|
import org.bukkit.event.HandlerList;
|
|
import org.bukkit.plugin.Plugin;
|
|
import org.bukkit.plugin.RegisteredListener;
|
|
+import org.bukkit.plugin.SimplePluginManager; // Spigot
|
|
import org.bukkit.plugin.TimedRegisteredListener;
|
|
import org.bukkit.util.StringUtil;
|
|
|
|
import com.google.common.collect.ImmutableList;
|
|
+import java.io.ByteArrayOutputStream;
|
|
+import java.io.OutputStream;
|
|
+import java.net.HttpURLConnection;
|
|
+import java.net.URL;
|
|
+import java.net.URLEncoder;
|
|
+import java.util.logging.Level;
|
|
|
|
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("merged", "reset", "separate", "paste", "on", "off"); // Spigot
|
|
|
|
public static long timingStart = 0; // Spigot
|
|
public TimingsCommand(String name) {
|
|
super(name);
|
|
this.description = "Records timings for all plugin events";
|
|
- this.usageMessage = "/timings <reset|merged|separate>";
|
|
+ this.usageMessage = "/timings <reset|merged|separate|paste|on|off>"; // Spigot
|
|
this.setPermission("bukkit.command.timings");
|
|
}
|
|
|
|
@Override
|
|
public boolean execute(CommandSender sender, String currentAlias, String[] args) {
|
|
if (!testPermission(sender)) return true;
|
|
- if (args.length != 1) {
|
|
+ if (args.length < 1) { // Spigot
|
|
sender.sendMessage(ChatColor.RED + "Usage: " + usageMessage);
|
|
return false;
|
|
}
|
|
- if (!sender.getServer().getPluginManager().useTimings()) {
|
|
+ // Spigot start - this is dynamic now
|
|
+ /*if (!sender.getServer().getPluginManager().useTimings()) {
|
|
sender.sendMessage("Please enable timings by setting \"settings.plugin-profiling\" to true in bukkit.yml");
|
|
return true;
|
|
+ }*/
|
|
+ if ("on".equals(args[0])) {
|
|
+ ((SimplePluginManager)Bukkit.getServer().getPluginManager()).useTimings(true);
|
|
+ sender.sendMessage("Enabled Timings");
|
|
+ } else if ("off".equals(args[0])) {
|
|
+ ((SimplePluginManager)Bukkit.getServer().getPluginManager()).useTimings(false);
|
|
+ sender.sendMessage("Disabled Timings");
|
|
}
|
|
+ // Spigot end
|
|
|
|
boolean separate = "separate".equals(args[0]);
|
|
- if ("reset".equals(args[0])) {
|
|
+ boolean paste = "paste".equals(args[0]); // Spigot
|
|
+ if ("on".equals(args[0]) || "reset".equals(args[0])) { // Spigot
|
|
+ if (!"on".equals(args[0]) && !Bukkit.getServer().getPluginManager().useTimings()) {sender.sendMessage("Please enable timings by typing /timings on"); return true; } // Spigot
|
|
for (HandlerList handlerList : HandlerList.getHandlerLists()) {
|
|
for (RegisteredListener listener : handlerList.getRegisteredListeners()) {
|
|
if (listener instanceof TimedRegisteredListener) {
|
|
@@ -51,10 +70,11 @@ public class TimingsCommand extends BukkitCommand {
|
|
}
|
|
}
|
|
}
|
|
+ CustomTimingsHandler.reload(); // Spigot
|
|
timingStart = System.nanoTime(); // Spigot
|
|
sender.sendMessage("Timings reset");
|
|
- } else if ("merged".equals(args[0]) || separate) {
|
|
-
|
|
+ } else if ("merged".equals(args[0]) || separate || paste) { // Spigot
|
|
+ if (!Bukkit.getServer().getPluginManager().useTimings()) {sender.sendMessage("Please enable timings by typing /timings on"); return true; } // Spigot
|
|
long sampleTime = System.nanoTime() - timingStart; // Spigot
|
|
int index = 0;
|
|
int pluginIdx = 0;
|
|
@@ -62,11 +82,12 @@ public class TimingsCommand extends BukkitCommand {
|
|
timingFolder.mkdirs();
|
|
File timings = new File(timingFolder, "timings.txt");
|
|
File names = null;
|
|
+ ByteArrayOutputStream bout = (paste) ? new ByteArrayOutputStream() : null; // Spigot
|
|
while (timings.exists()) timings = new File(timingFolder, "timings" + (++index) + ".txt");
|
|
PrintStream fileTimings = null;
|
|
PrintStream fileNames = null;
|
|
try {
|
|
- fileTimings = new PrintStream(timings);
|
|
+ fileTimings = (paste) ? new PrintStream(bout) : new PrintStream(timings);
|
|
if (separate) {
|
|
names = new File(timingFolder, "names" + index + ".txt");
|
|
fileNames = new PrintStream(names);
|
|
@@ -89,14 +110,23 @@ public class TimingsCommand extends BukkitCommand {
|
|
totalTime += time;
|
|
Event event = trl.getEvent();
|
|
if (count > 0 && event != null) {
|
|
- fileTimings.println(" " + event.getClass().getSimpleName() + (trl.hasMultiple() ? " (and others)" : "") + " Time: " + time + " Count: " + count + " Avg: " + avg);
|
|
+ fileTimings.println(" " + event.getClass().getSimpleName() + (trl.hasMultiple() ? " (and others)" : "") + " Time: " + time + " Count: " + count + " Avg: " + avg + " Violations: " + trl.violations); // Spigot
|
|
}
|
|
}
|
|
}
|
|
fileTimings.println(" Total time " + totalTime + " (" + totalTime / 1000000000 + "s)");
|
|
}
|
|
- fileTimings.println("Sample time " + sampleTime + " (" + sampleTime / 1000000000 + "s)"); // Spigot
|
|
- sender.sendMessage("Timings written to " + timings.getPath());
|
|
+
|
|
+ // Spigot start
|
|
+ CustomTimingsHandler.printTimings(fileTimings);
|
|
+ fileTimings.println("Sample time " + sampleTime + " (" + sampleTime / 1000000000 + "s)");
|
|
+ if (paste) {
|
|
+ new PasteThread(sender, bout).start();
|
|
+ } else {
|
|
+ sender.sendMessage("Timings written to " + timings.getPath());
|
|
+ sender.sendMessage("Paste contents of file into form at http://aikar.co/timings.php to read results.");
|
|
+ }
|
|
+ // Spigot end
|
|
if (separate) sender.sendMessage("Names written to " + names.getPath());
|
|
} catch (IOException e) {
|
|
} finally {
|
|
@@ -122,4 +152,42 @@ 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(CommandSender sender, ByteArrayOutputStream bout) {
|
|
+ super("Timings paste thread");
|
|
+ this.sender = sender;
|
|
+ this.bout = bout;
|
|
+ }
|
|
+
|
|
+ @Override
|
|
+ public void run() {
|
|
+ try {
|
|
+ HttpURLConnection con = (HttpURLConnection) new URL("http://paste.ubuntu.com/").openConnection();
|
|
+ con.setDoOutput(true);
|
|
+ con.setRequestMethod("POST");
|
|
+ con.setInstanceFollowRedirects(false);
|
|
+
|
|
+ OutputStream out = con.getOutputStream();
|
|
+ out.write("poster=Spigot&syntax=text&content=".getBytes("UTF-8"));
|
|
+ out.write(URLEncoder.encode(bout.toString("UTF-8"), "UTF-8").getBytes("UTF-8"));
|
|
+ out.close();
|
|
+ con.getInputStream().close();
|
|
+
|
|
+ String location = con.getHeaderField("Location");
|
|
+ String pasteID = location.substring("http://paste.ubuntu.com/".length(), location.length() - 1);
|
|
+ sender.sendMessage(ChatColor.GREEN + "Your timings have been pasted to " + location);
|
|
+ sender.sendMessage(ChatColor.GREEN + "You can view the results at http://aikar.co/timings.php?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/TimedRegisteredListener.java b/src/main/java/org/bukkit/plugin/TimedRegisteredListener.java
|
|
index ed25e17..47dab3e 100644
|
|
--- a/src/main/java/org/bukkit/plugin/TimedRegisteredListener.java
|
|
+++ b/src/main/java/org/bukkit/plugin/TimedRegisteredListener.java
|
|
@@ -1,5 +1,6 @@
|
|
package org.bukkit.plugin;
|
|
|
|
+import org.bukkit.Bukkit; // Spigot
|
|
import org.bukkit.event.Event;
|
|
import org.bukkit.event.EventException;
|
|
import org.bukkit.event.EventPriority;
|
|
@@ -11,6 +12,8 @@ import org.bukkit.event.Listener;
|
|
public class TimedRegisteredListener extends RegisteredListener {
|
|
private int count;
|
|
private long totalTime;
|
|
+ public long curTickTotal = 0; // Spigot
|
|
+ public long violations = 0; // Spigot
|
|
private Event event;
|
|
private boolean multiple = false;
|
|
|
|
@@ -20,6 +23,7 @@ public class TimedRegisteredListener extends RegisteredListener {
|
|
|
|
@Override
|
|
public void callEvent(Event event) throws EventException {
|
|
+ if (!Bukkit.getServer().getPluginManager().useTimings()) { super.callEvent(event);return; } // Spigot
|
|
if (event.isAsynchronous()) {
|
|
super.callEvent(event);
|
|
return;
|
|
@@ -33,7 +37,11 @@ public class TimedRegisteredListener extends RegisteredListener {
|
|
}
|
|
long start = System.nanoTime();
|
|
super.callEvent(event);
|
|
- totalTime += System.nanoTime() - start;
|
|
+ // Spigot start
|
|
+ long diff = System.nanoTime() - start;
|
|
+ curTickTotal += diff;
|
|
+ totalTime += diff;
|
|
+ // Spigot end
|
|
}
|
|
|
|
/**
|
|
@@ -42,6 +50,8 @@ public class TimedRegisteredListener extends RegisteredListener {
|
|
public void reset() {
|
|
count = 0;
|
|
totalTime = 0;
|
|
+ curTickTotal = 0; // Spigot
|
|
+ violations = 0; // Spigot
|
|
}
|
|
|
|
/**
|
|
diff --git a/src/main/java/org/bukkit/plugin/java/JavaPluginLoader.java b/src/main/java/org/bukkit/plugin/java/JavaPluginLoader.java
|
|
index ea30d83..d905435 100644
|
|
--- a/src/main/java/org/bukkit/plugin/java/JavaPluginLoader.java
|
|
+++ b/src/main/java/org/bukkit/plugin/java/JavaPluginLoader.java
|
|
@@ -430,7 +430,7 @@ public class JavaPluginLoader implements PluginLoader {
|
|
}
|
|
}
|
|
};
|
|
- if (useTimings) {
|
|
+ if (true) { // Spigot - TRL 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()));
|
|
--
|
|
1.8.2.1
|
|
|