mirror of
https://github.com/PaperMC/Paper.git
synced 2024-08-26 22:50:23 +02:00
This greatly extends the timings improvements I've done in recent commits, and brings timings to fully cover the entire tick. The timings system also now tracks when specific timings causes the server to lose TPS. The timings are also able to be turned on "on demand", meaning you do not need to restart the server to enable them. This commit also overhauls the Entity Activation Range feature, fixing bugs, adding more immunities, and improving the performance of it. It also fixes a regression with a recent Spigot commit that broke the entire Entity Activation Range feature. This commit had to move the Tick Loop patch before timings because there was a change done there to time the entire tick, so lots of renames. These 2 commits had to be bundled together to simplify applying them and reduce redundant conflict resolution.
412 lines
18 KiB
Diff
412 lines
18 KiB
Diff
From 1d2352eb83a0e0cd6ff7cd592999430d37a8513a 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
|
|
---
|
|
src/main/java/org/bukkit/CustomTimingsHandler.java | 134 +++++++++++++++++++++
|
|
.../org/bukkit/command/defaults/ReloadCommand.java | 2 +
|
|
.../bukkit/command/defaults/TimingsCommand.java | 90 ++++++++++++--
|
|
.../org/bukkit/plugin/TimedRegisteredListener.java | 12 +-
|
|
.../org/bukkit/plugin/java/JavaPluginLoader.java | 2 +-
|
|
5 files changed, 227 insertions(+), 13 deletions(-)
|
|
create mode 100644 src/main/java/org/bukkit/CustomTimingsHandler.java
|
|
|
|
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 10fc26a..9c7288e 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.1.1
|
|
|