467 lines
18 KiB
Diff
467 lines
18 KiB
Diff
From 8436d82f19ccc283c93fa2a2a2df7621437dd5ae 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 1eaf92d..7b25817 100644
|
|
--- a/src/main/java/org/bukkit/Bukkit.java
|
|
+++ b/src/main/java/org/bukkit/Bukkit.java
|
|
@@ -301,6 +301,7 @@ public final class Bukkit {
|
|
*/
|
|
public static void reload() {
|
|
server.reload();
|
|
+ org.spigotmc.CustomTimingsHandler.reload(); // Spigot
|
|
}
|
|
|
|
/**
|
|
diff --git a/src/main/java/org/bukkit/command/Command.java b/src/main/java/org/bukkit/command/Command.java
|
|
index 87c33d9..31e4f66 100644
|
|
--- a/src/main/java/org/bukkit/command/Command.java
|
|
+++ b/src/main/java/org/bukkit/command/Command.java
|
|
@@ -31,6 +31,7 @@ public abstract class Command {
|
|
protected String usageMessage;
|
|
private String permission;
|
|
private String permissionMessage;
|
|
+ public org.spigotmc.CustomTimingsHandler timings; // Spigot
|
|
|
|
protected Command(String name) {
|
|
this(name, "", "/" + name, new ArrayList<String>());
|
|
@@ -44,6 +45,7 @@ public abstract class Command {
|
|
this.usageMessage = usageMessage;
|
|
this.aliases = aliases;
|
|
this.activeAliases = new ArrayList<String>(aliases);
|
|
+ this.timings = new org.spigotmc.CustomTimingsHandler("** Command: " + name); // Spigot
|
|
}
|
|
|
|
/**
|
|
@@ -200,6 +202,7 @@ public abstract class Command {
|
|
public boolean setLabel(String name) {
|
|
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 d75380c..f15b95d 100644
|
|
--- a/src/main/java/org/bukkit/command/SimpleCommandMap.java
|
|
+++ b/src/main/java/org/bukkit/command/SimpleCommandMap.java
|
|
@@ -176,11 +176,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 05cfcb0..22926d6 100644
|
|
--- a/src/main/java/org/bukkit/command/defaults/TimingsCommand.java
|
|
+++ b/src/main/java/org/bukkit/command/defaults/TimingsCommand.java
|
|
@@ -19,23 +19,97 @@ import org.bukkit.util.StringUtil;
|
|
|
|
import com.google.common.collect.ImmutableList;
|
|
|
|
+// Spigot start
|
|
+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;
|
|
+
|
|
+import org.bukkit.command.RemoteConsoleCommandSender;
|
|
+import org.bukkit.plugin.SimplePluginManager;
|
|
+import org.spigotmc.CustomTimingsHandler;
|
|
+// 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(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(CommandSender sender, 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)" );
|
|
+
|
|
+ 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(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 (true) { executeSpigotTimings(sender, args); return true; } // Spigot
|
|
if (!sender.getServer().getPluginManager().useTimings()) {
|
|
sender.sendMessage("Please enable timings by setting \"settings.plugin-profiling\" to true in bukkit.yml");
|
|
return true;
|
|
@@ -118,4 +192,55 @@ 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 synchronized void start() {
|
|
+ if (sender instanceof RemoteConsoleCommandSender) {
|
|
+ run();
|
|
+ } else {
|
|
+ super.start();
|
|
+ }
|
|
+ }
|
|
+
|
|
+ @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 + "View timings results can be viewed at http://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 d2fe422..1d51908 100644
|
|
--- a/src/main/java/org/bukkit/plugin/SimplePluginManager.java
|
|
+++ b/src/main/java/org/bukkit/plugin/SimplePluginManager.java
|
|
@@ -295,6 +295,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 b178c0d..fe723c9 100644
|
|
--- a/src/main/java/org/bukkit/plugin/java/JavaPluginLoader.java
|
|
+++ b/src/main/java/org/bukkit/plugin/java/JavaPluginLoader.java
|
|
@@ -39,6 +39,7 @@ import org.bukkit.plugin.PluginLoader;
|
|
import org.bukkit.plugin.RegisteredListener;
|
|
import org.bukkit.plugin.TimedRegisteredListener;
|
|
import org.bukkit.plugin.UnknownDependencyException;
|
|
+import org.spigotmc.CustomTimingsHandler; // Spigot
|
|
import org.yaml.snakeyaml.error.YAMLException;
|
|
|
|
/**
|
|
@@ -49,6 +50,7 @@ public final class JavaPluginLoader implements PluginLoader {
|
|
private final Pattern[] fileFilters = new Pattern[] { Pattern.compile("\\.jar$"), };
|
|
private final Map<String, Class<?>> classes = new HashMap<String, Class<?>>();
|
|
private final Map<String, PluginClassLoader> loaders = new LinkedHashMap<String, PluginClassLoader>();
|
|
+ public static final CustomTimingsHandler pluginParentTimer = new CustomTimingsHandler("** Plugins"); // Spigot
|
|
|
|
/**
|
|
* This class was not meant to be constructed explicitly
|
|
@@ -283,13 +285,19 @@ 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() {
|
|
public void execute(Listener listener, Event event) throws EventException {
|
|
try {
|
|
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) {
|
|
@@ -297,7 +305,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 0000000..8d98297
|
|
--- /dev/null
|
|
+++ b/src/main/java/org/spigotmc/CustomTimingsHandler.java
|
|
@@ -0,0 +1,165 @@
|
|
+package org.spigotmc;
|
|
+
|
|
+import org.bukkit.command.defaults.TimingsCommand;
|
|
+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.Collection;
|
|
+import java.util.HashSet;
|
|
+import java.util.List;
|
|
+import java.util.Queue;
|
|
+import java.util.concurrent.ConcurrentLinkedQueue;
|
|
+
|
|
+import org.bukkit.Bukkit;
|
|
+import org.bukkit.World;
|
|
+
|
|
+/**
|
|
+ * 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(String name)
|
|
+ {
|
|
+ this( name, null );
|
|
+ }
|
|
+
|
|
+ public CustomTimingsHandler(String name, CustomTimingsHandler parent)
|
|
+ {
|
|
+ this.name = name;
|
|
+ this.parent = parent;
|
|
+ HANDLERS.add( this );
|
|
+ }
|
|
+
|
|
+ /**
|
|
+ * Prints the timings and extra data to the given stream.
|
|
+ *
|
|
+ * @param printStream
|
|
+ */
|
|
+ public static void printTimings(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;
|
|
+ }
|
|
+}
|
|
--
|
|
1.9.1
|
|
|