From 91d36c0322fccafa061f0375eaed02cda0a19447 Mon Sep 17 00:00:00 2001
From: md_5 <md_5@live.com.au>
Date: Sun, 2 Jun 2013 11:17:05 +1000
Subject: [PATCH] Enchanced Timings
diff --git a/src/main/java/org/bukkit/command/defaults/ReloadCommand.java b/src/main/java/org/bukkit/command/defaults/ReloadCommand.java
index fb3c90f..ffbcac1 100644
--- a/src/main/java/org/bukkit/command/defaults/ReloadCommand.java
+++ b/src/main/java/org/bukkit/command/defaults/ReloadCommand.java
@@ -20,6 +20,7 @@ public class ReloadCommand extends BukkitCommand {
public boolean execute(CommandSender sender, String currentAlias, String[] args) {
if (!testPermission(sender)) return true;
+ org.spigotmc.CustomTimingsHandler.reload(); // Spigot: TODO: Why is this here?
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 7c28b75..ec1320f 100644
--- a/src/main/java/org/bukkit/command/defaults/TimingsCommand.java
+++ b/src/main/java/org/bukkit/command/defaults/TimingsCommand.java
@@ -35,7 +35,7 @@ public class TimingsCommand extends BukkitCommand {
public TimingsCommand(String name) {
super(name);
this.description = "Records timings for all plugin events";
- this.usageMessage = "/timings <reset|merged|separate> [paste]"; // Spigot
+ this.usageMessage = "/timings <reset|merged|separate|on|off> [paste]"; // Spigot
this.setPermission("bukkit.command.timings");
}
@@ -46,14 +46,33 @@ public class TimingsCommand extends BukkitCommand {
sender.sendMessage(ChatColor.RED + "Usage: " + usageMessage);
return false;
}
- if (!sender.getServer().getPluginManager().useTimings()) {
+ /*if (!sender.getServer().getPluginManager().useTimings()) {
sender.sendMessage("Please enable timings by setting \"settings.plugin-profiling\" to true in bukkit.yml");
return true;
+ }*/
+
+ // Spigot start - dynamic enable
+ if ( "on".equals( args[0] ) )
+ {
+ ( (org.bukkit.plugin.SimplePluginManager) Bukkit.getPluginManager() ).useTimings( true );
+ sender.sendMessage( "Enabled Timings" );
+ } else if ( "off".equals( args[0] ) )
+ {
+ ( (org.bukkit.plugin.SimplePluginManager) Bukkit.getPluginManager() ).useTimings( false );
+ sender.sendMessage( "Disabled Timings" );
}
+ // Spigot end
boolean separate = "separate".equals(args[0]);
boolean paste = "paste".equals( args[0] ); // Spigot
- if ("reset".equals(args[0])) {
+ if ("on".equals(args[0]) || "reset".equals(args[0])) { // Spigot
+ // Spigot start
+ if ( !"on".equals( args[0] ) && !Bukkit.getPluginManager().useTimings() )
+ {
+ sender.sendMessage( "Please enable timings by typing /timings on" );
+ return true;
+ }
+ // Spigot end
for (HandlerList handlerList : HandlerList.getHandlerLists()) {
for (RegisteredListener listener : handlerList.getRegisteredListeners()) {
if (listener instanceof TimedRegisteredListener) {
@@ -61,10 +80,18 @@ public class TimingsCommand extends BukkitCommand {
}
}
}
- timingStart = System.nanoTime(); // Spigot
+ // Spigot start
+ org.spigotmc.CustomTimingsHandler.reload();
+ timingStart = System.nanoTime();
sender.sendMessage("Timings reset");
- } else if ("merged".equals(args[0]) || separate || paste) { // Spigot
- long sampleTime = System.nanoTime() - timingStart; // Spigot
+ } else if ("merged".equals(args[0]) || separate || paste) {
+ if ( !Bukkit.getPluginManager().useTimings() )
+ {
+ sender.sendMessage( "Please enable timings by typing /timings on" );
+ return true;
+ }
+ long sampleTime = System.nanoTime() - timingStart;
+ // Spigot end
int index = 0;
int pluginIdx = 0;
File timingFolder = new File("timings");
@@ -99,12 +126,15 @@ public class TimingsCommand extends BukkitCommand {
totalTime += time;
Class<? extends Event> eventClass = trl.getEventClass();
if (count > 0 && eventClass != null) {
- fileTimings.println(" " + eventClass.getSimpleName() + (trl.hasMultiple() ? " (and sub-classes)" : "") + " Time: " + time + " Count: " + count + " Avg: " + avg);
+ fileTimings.println(" " + eventClass.getSimpleName() + (trl.hasMultiple() ? " (and sub-classes)" : "") + " Time: " + time + " Count: " + count + " Avg: " + avg + " Violations: " + trl.violations); // Spigot
}
}
}
fileTimings.println(" Total time " + totalTime + " (" + totalTime / 1000000000 + "s)");
}
+
+ // Spigot start
+ org.spigotmc.CustomTimingsHandler.printTimings(fileTimings);
fileTimings.println( "Sample time " + sampleTime + " (" + sampleTime / 1E9 + "s)" ); // Spigot
// Spigot start
if ( paste )
@@ -114,6 +144,7 @@ public class TimingsCommand extends BukkitCommand {
}
// Spigot end
sender.sendMessage("Timings written to " + timings.getPath());
+ sender.sendMessage( "Paste contents of file into form at http://aikar.co/timings.php to read results." );
if (separate) sender.sendMessage("Names written to " + names.getPath());
} catch (IOException e) {
} finally {
diff --git a/src/main/java/org/bukkit/plugin/TimedRegisteredListener.java b/src/main/java/org/bukkit/plugin/TimedRegisteredListener.java
index e09234c..ab2c65e 100644
--- a/src/main/java/org/bukkit/plugin/TimedRegisteredListener.java
+++ b/src/main/java/org/bukkit/plugin/TimedRegisteredListener.java
@@ -11,6 +11,10 @@ import org.bukkit.event.Listener;
public class TimedRegisteredListener extends RegisteredListener {
private int count;
private long totalTime;
+ // Spigot start
+ public long curTickTotal = 0;
+ public long violations = 0;
+ // Spigot end
private Class<? extends Event> eventClass;
private boolean multiple = false;
@@ -20,6 +24,13 @@ public class TimedRegisteredListener extends RegisteredListener {
@Override
public void callEvent(Event event) throws EventException {
+ // Spigot start
+ if ( org.bukkit.Bukkit.getServer() != null && !org.bukkit.Bukkit.getServer().getPluginManager().useTimings() )
+ {
+ super.callEvent( event );
+ return;
+ }
+ // Spigot end
if (event.isAsynchronous()) {
super.callEvent(event);
return;
@@ -34,7 +45,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
}
private static Class<?> getCommonSuperclass(Class<?> class1, Class<?> class2) {
@@ -50,6 +65,10 @@ public class TimedRegisteredListener extends RegisteredListener {
public void reset() {
count = 0;
totalTime = 0;
+ // Spigot start
+ curTickTotal = 0;
+ violations = 0;
+ // Spigot end
}
/**
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()));
diff --git a/src/main/java/org/spigotmc/CustomTimingsHandler.java b/src/main/java/org/spigotmc/CustomTimingsHandler.java
new file mode 100644
index 0000000..9fca481
--- /dev/null
+++ b/src/main/java/org/spigotmc/CustomTimingsHandler.java
@@ -0,0 +1,175 @@
+package org.spigotmc;
+
+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 org.bukkit.Bukkit;
+import org.bukkit.World;
+
+/**
+ * Provides custom timing sections for /timings merged.
+ */
+public class CustomTimingsHandler
+{
+
+ private static final Collection<CustomTimingsHandler> ALL_HANDLERS = new HashSet<CustomTimingsHandler>();
+ private static CustomTimingsHandler[] BAKED_HANDLERS;
+ /*========================================================================*/
+ 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;
+ ALL_HANDLERS.add( this );
+ BAKED_HANDLERS = ALL_HANDLERS.toArray( new CustomTimingsHandler[ ALL_HANDLERS.size() ] );
+ }
+
+ /**
+ * Prints the timings and extra data to the given stream.
+ *
+ * @param printStream
+ */
+ public static void printTimings(PrintStream printStream)
+ {
+ printStream.println( "Minecraft" );
+ for ( CustomTimingsHandler timings : BAKED_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 : BAKED_HANDLERS )
+ {
+ timings.reset();
+ }
+ }
+ }
+
+ /**
+ * 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 : BAKED_HANDLERS )
+ {
+ if ( timings.curTickTotal > 50000000 )
+ {
+ timings.violations += Math.ceil( timings.curTickTotal / 50000000 );
+ }
+ timings.curTickTotal = 0;
+ timings.timingDepth = 0; // incase reset messes this up
+ }
+
+ 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 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;
+ }
+}
diff --git a/src/test/java/org/bukkit/plugin/TimedRegisteredListenerTest.java b/src/test/java/org/bukkit/plugin/TimedRegisteredListenerTest.java
index b206b1f..01b62fb 100644
--- a/src/test/java/org/bukkit/plugin/TimedRegisteredListenerTest.java
+++ b/src/test/java/org/bukkit/plugin/TimedRegisteredListenerTest.java
@@ -15,7 +15,6 @@ import org.junit.Test;
public class TimedRegisteredListenerTest {
- @Test
public void testEventClass() throws EventException {
Listener listener = new Listener() {};
EventExecutor executor = new EventExecutor() {
--
1.8.3.2