From 2001c15132c1ec27ef5041d1ceda9f128c4b6349 Mon Sep 17 00:00:00 2001 From: "Kristian S. Stangeland" Date: Fri, 20 Sep 2013 22:35:59 +0200 Subject: [PATCH] Add the ability to track the amount of time spent by each plugin. ProtocolLib can now keep track of the amount of time spent by each listener (for each packet), generated as a report file. This is done in the new "protocol timings" command. --- .../com/comphenix/protocol/CommandBase.java | 258 ++++++++++-------- .../com/comphenix/protocol/CommandPacket.java | 16 -- .../comphenix/protocol/CommandProtocol.java | 54 ++++ .../protocol/async/AsyncListenerHandler.java | 31 ++- .../injector/SortedPacketListenerList.java | 153 +++++++---- .../protocol/timing/StatisticsStream.java | 137 ++++++++++ .../protocol/timing/TimedListenerManager.java | 184 +++++++++++++ .../protocol/timing/TimedTracker.java | 63 +++++ .../timing/TimingReportGenerator.java | 119 ++++++++ .../wrappers/nbt/WrappedCompound.java | 1 - 10 files changed, 827 insertions(+), 189 deletions(-) create mode 100644 ProtocolLib/src/main/java/com/comphenix/protocol/timing/StatisticsStream.java create mode 100644 ProtocolLib/src/main/java/com/comphenix/protocol/timing/TimedListenerManager.java create mode 100644 ProtocolLib/src/main/java/com/comphenix/protocol/timing/TimedTracker.java create mode 100644 ProtocolLib/src/main/java/com/comphenix/protocol/timing/TimingReportGenerator.java diff --git a/ProtocolLib/src/main/java/com/comphenix/protocol/CommandBase.java b/ProtocolLib/src/main/java/com/comphenix/protocol/CommandBase.java index 7ca949bd..e7208c18 100644 --- a/ProtocolLib/src/main/java/com/comphenix/protocol/CommandBase.java +++ b/ProtocolLib/src/main/java/com/comphenix/protocol/CommandBase.java @@ -1,117 +1,141 @@ -/* - * ProtocolLib - Bukkit server library that allows access to the Minecraft protocol. - * Copyright (C) 2012 Kristian S. Stangeland - * - * This program is free software; you can redistribute it and/or modify it under the terms of the - * GNU General Public License as published by the Free Software Foundation; either version 2 of - * the License, or (at your option) any later version. - * - * This program is distributed in the hope that it will be useful, but WITHOUT ANY WARRANTY; - * without even the implied warranty of MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. - * See the GNU General Public License for more details. - * - * You should have received a copy of the GNU General Public License along with this program; - * if not, write to the Free Software Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA - * 02111-1307 USA - */ - -package com.comphenix.protocol; - -import org.bukkit.ChatColor; -import org.bukkit.command.Command; -import org.bukkit.command.CommandExecutor; -import org.bukkit.command.CommandSender; - -import com.comphenix.protocol.error.ErrorReporter; -import com.comphenix.protocol.error.Report; -import com.comphenix.protocol.error.ReportType; - -/** - * Base class for all our commands. - * - * @author Kristian - */ -abstract class CommandBase implements CommandExecutor { - public static final ReportType REPORT_COMMAND_ERROR = new ReportType("Cannot execute command %s."); - public static final ReportType REPORT_UNEXPECTED_COMMAND = new ReportType("Incorrect command assigned to %s."); - - public static final String PERMISSION_ADMIN = "protocol.admin"; - - private String permission; - private String name; - private int minimumArgumentCount; - - protected ErrorReporter reporter; - - public CommandBase(ErrorReporter reporter, String permission, String name) { - this(reporter, permission, name, 0); - } - - public CommandBase(ErrorReporter reporter, String permission, String name, int minimumArgumentCount) { - this.reporter = reporter; - this.name = name; - this.permission = permission; - this.minimumArgumentCount = minimumArgumentCount; - } - - @Override - public final boolean onCommand(CommandSender sender, Command command, String label, String[] args) { - try { - // Make sure we're dealing with the correct command - if (!command.getName().equalsIgnoreCase(name)) { - reporter.reportWarning(this, Report.newBuilder(REPORT_UNEXPECTED_COMMAND).messageParam(this)); - return false; - } - if (permission != null && !sender.hasPermission(permission)) { - sender.sendMessage(ChatColor.RED + "You haven't got permission to run this command."); - return true; - } - - // Check argument length - if (args != null && args.length >= minimumArgumentCount) { - return handleCommand(sender, args); - } else { - sender.sendMessage(ChatColor.RED + "Insufficient commands. You need at least " + minimumArgumentCount); - return false; - } - - } catch (Exception e) { - reporter.reportDetailed(this, - Report.newBuilder(REPORT_COMMAND_ERROR).error(e).messageParam(name).callerParam(sender, label, args) - ); - return true; - } - } - - /** - * Retrieve the permission necessary to execute this command. - * @return The permission, or NULL if not needed. - */ - public String getPermission() { - return permission; - } - - /** - * Retrieve the primary name of this command. - * @return Primary name. - */ - public String getName() { - return name; - } - - /** - * Retrieve the error reporter. - * @return Error reporter. - */ - protected ErrorReporter getReporter() { - return reporter; - } - - /** - * Main implementation of this command. - * @param sender - command sender. - * @param args - * @return - */ - protected abstract boolean handleCommand(CommandSender sender, String[] args); -} +/* + * ProtocolLib - Bukkit server library that allows access to the Minecraft protocol. + * Copyright (C) 2012 Kristian S. Stangeland + * + * This program is free software; you can redistribute it and/or modify it under the terms of the + * GNU General Public License as published by the Free Software Foundation; either version 2 of + * the License, or (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, but WITHOUT ANY WARRANTY; + * without even the implied warranty of MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. + * See the GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License along with this program; + * if not, write to the Free Software Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA + * 02111-1307 USA + */ + +package com.comphenix.protocol; + +import org.bukkit.ChatColor; +import org.bukkit.command.Command; +import org.bukkit.command.CommandExecutor; +import org.bukkit.command.CommandSender; + +import com.comphenix.protocol.error.ErrorReporter; +import com.comphenix.protocol.error.Report; +import com.comphenix.protocol.error.ReportType; + +/** + * Base class for all our commands. + * + * @author Kristian + */ +abstract class CommandBase implements CommandExecutor { + public static final ReportType REPORT_COMMAND_ERROR = new ReportType("Cannot execute command %s."); + public static final ReportType REPORT_UNEXPECTED_COMMAND = new ReportType("Incorrect command assigned to %s."); + + public static final String PERMISSION_ADMIN = "protocol.admin"; + + private String permission; + private String name; + private int minimumArgumentCount; + + protected ErrorReporter reporter; + + public CommandBase(ErrorReporter reporter, String permission, String name) { + this(reporter, permission, name, 0); + } + + public CommandBase(ErrorReporter reporter, String permission, String name, int minimumArgumentCount) { + this.reporter = reporter; + this.name = name; + this.permission = permission; + this.minimumArgumentCount = minimumArgumentCount; + } + + @Override + public final boolean onCommand(CommandSender sender, Command command, String label, String[] args) { + try { + // Make sure we're dealing with the correct command + if (!command.getName().equalsIgnoreCase(name)) { + reporter.reportWarning(this, Report.newBuilder(REPORT_UNEXPECTED_COMMAND).messageParam(this)); + return false; + } + if (permission != null && !sender.hasPermission(permission)) { + sender.sendMessage(ChatColor.RED + "You haven't got permission to run this command."); + return true; + } + + // Check argument length + if (args != null && args.length >= minimumArgumentCount) { + return handleCommand(sender, args); + } else { + sender.sendMessage(ChatColor.RED + "Insufficient commands. You need at least " + minimumArgumentCount); + return false; + } + + } catch (Exception e) { + reporter.reportDetailed(this, + Report.newBuilder(REPORT_COMMAND_ERROR).error(e).messageParam(name).callerParam(sender, label, args) + ); + return true; + } + } + + /** + * Parse a boolean value at a specific location. + * @param args - the argument array. + * @param parameterName - the parameter name. + * @param index - the argument index. + * @return The parsed boolean, or NULL if not valid. + */ + protected Boolean parseBoolean(String[] args, String parameterName, int index) { + if (index < args.length) { + String arg = args[index]; + + if (arg.equalsIgnoreCase("true") || arg.equalsIgnoreCase("on")) + return true; + else if (arg.equalsIgnoreCase(parameterName)) + return true; + else if (arg.equalsIgnoreCase("false") || arg.equalsIgnoreCase("off")) + return false; + else + return null; + } else { + return null; + } + } + + /** + * Retrieve the permission necessary to execute this command. + * @return The permission, or NULL if not needed. + */ + public String getPermission() { + return permission; + } + + /** + * Retrieve the primary name of this command. + * @return Primary name. + */ + public String getName() { + return name; + } + + /** + * Retrieve the error reporter. + * @return Error reporter. + */ + protected ErrorReporter getReporter() { + return reporter; + } + + /** + * Main implementation of this command. + * @param sender - command sender. + * @param args + * @return + */ + protected abstract boolean handleCommand(CommandSender sender, String[] args); +} diff --git a/ProtocolLib/src/main/java/com/comphenix/protocol/CommandPacket.java b/ProtocolLib/src/main/java/com/comphenix/protocol/CommandPacket.java index 5d866c5d..7f7d3b57 100644 --- a/ProtocolLib/src/main/java/com/comphenix/protocol/CommandPacket.java +++ b/ProtocolLib/src/main/java/com/comphenix/protocol/CommandPacket.java @@ -543,20 +543,4 @@ class CommandPacket extends CommandBase { return defaultValue; } } - - // Parse a boolean - private Boolean parseBoolean(String[] args, String parameterName, int index) { - if (index < args.length) { - if (args[index].equalsIgnoreCase("true")) - return true; - else if (args[index].equalsIgnoreCase(parameterName)) - return true; - else if (args[index].equalsIgnoreCase("false")) - return false; - else - return null; - } else { - return null; - } - } } diff --git a/ProtocolLib/src/main/java/com/comphenix/protocol/CommandProtocol.java b/ProtocolLib/src/main/java/com/comphenix/protocol/CommandProtocol.java index 620d224f..33328aeb 100644 --- a/ProtocolLib/src/main/java/com/comphenix/protocol/CommandProtocol.java +++ b/ProtocolLib/src/main/java/com/comphenix/protocol/CommandProtocol.java @@ -17,6 +17,7 @@ package com.comphenix.protocol; +import java.io.File; import java.io.IOException; import org.bukkit.ChatColor; @@ -29,6 +30,8 @@ import com.comphenix.protocol.error.ReportType; import com.comphenix.protocol.metrics.Updater; import com.comphenix.protocol.metrics.Updater.UpdateResult; import com.comphenix.protocol.metrics.Updater.UpdateType; +import com.comphenix.protocol.timing.TimedListenerManager; +import com.comphenix.protocol.timing.TimingReportGenerator; import com.comphenix.protocol.utility.WrappedScheduler; /** @@ -68,6 +71,8 @@ class CommandProtocol extends CommandBase { checkVersion(sender); else if (subCommand.equalsIgnoreCase("update")) updateVersion(sender); + else if (subCommand.equalsIgnoreCase("timings")) + toggleTimings(sender, args); else return false; return true; @@ -119,6 +124,55 @@ class CommandProtocol extends CommandBase { updateFinished(); } + private void toggleTimings(CommandSender sender, String[] args) { + TimedListenerManager manager = TimedListenerManager.getInstance(); + boolean state = !manager.isTiming(); // toggle + + // Parse the boolean parameter + if (args.length == 2) { + Boolean parsed = parseBoolean(args, "start", 2); + + if (parsed != null) { + state = parsed; + } else { + sender.sendMessage(ChatColor.RED + "Specify a state: ON or OFF."); + return; + } + } else if (args.length > 2) { + sender.sendMessage(ChatColor.RED + "Too many parameters."); + return; + } + + // Now change the state + if (state) { + if (manager.startTiming()) + sender.sendMessage(ChatColor.GOLD + "Started timing packet listeners."); + else + sender.sendMessage(ChatColor.RED + "Packet timing already started."); + } else { + if (manager.stopTiming()) { + saveTimings(manager); + sender.sendMessage(ChatColor.GOLD + "Stopped and saved result in plugin folder."); + } else { + sender.sendMessage(ChatColor.RED + "Packet timing already stopped."); + } + } + } + + private void saveTimings(TimedListenerManager manager) { + try { + File destination = new File(plugin.getDataFolder(), "Timings - " + System.currentTimeMillis() + ".txt"); + TimingReportGenerator generator = new TimingReportGenerator(); + + // Print to a text file + generator.saveTo(destination, manager); + manager.clear(); + + } catch (IOException e) { + reporter.reportMinimal(plugin, "saveTimings()", e); + } + } + private boolean isHttpError(Exception e) { Throwable cause = e.getCause(); diff --git a/ProtocolLib/src/main/java/com/comphenix/protocol/async/AsyncListenerHandler.java b/ProtocolLib/src/main/java/com/comphenix/protocol/async/AsyncListenerHandler.java index 47eb84a6..914ad105 100644 --- a/ProtocolLib/src/main/java/com/comphenix/protocol/async/AsyncListenerHandler.java +++ b/ProtocolLib/src/main/java/com/comphenix/protocol/async/AsyncListenerHandler.java @@ -30,6 +30,9 @@ import com.comphenix.protocol.events.ListeningWhitelist; import com.comphenix.protocol.events.PacketAdapter; import com.comphenix.protocol.events.PacketEvent; import com.comphenix.protocol.events.PacketListener; +import com.comphenix.protocol.timing.TimedListenerManager; +import com.comphenix.protocol.timing.TimedTracker; +import com.comphenix.protocol.timing.TimedListenerManager.ListenerType; import com.comphenix.protocol.utility.WrappedScheduler; import com.google.common.base.Function; import com.google.common.base.Joiner; @@ -84,6 +87,9 @@ public class AsyncListenerHandler { // Minecraft main thread private Thread mainThread; + // Timing manager + private TimedListenerManager timedManager = TimedListenerManager.getInstance(); + /** * Construct a manager for an asynchronous packet handler. * @param mainThread - the main game thread. @@ -575,10 +581,27 @@ public class AsyncListenerHandler { marker.setListenerHandler(this); marker.setWorkerID(workerID); - if (packet.isServerPacket()) - listener.onPacketSending(packet); - else - listener.onPacketReceiving(packet); + // We're not THAT worried about performance here + if (timedManager.isTiming()) { + // Retrieve the tracker to use + TimedTracker tracker = timedManager.getTracker(listener, + packet.isServerPacket() ? ListenerType.ASYNC_SERVER_SIDE : ListenerType.ASYNC_CLIENT_SIDE); + long token = tracker.beginTracking(); + + if (packet.isServerPacket()) + listener.onPacketSending(packet); + else + listener.onPacketReceiving(packet); + + // And we're done + tracker.endTracking(token, packet.getPacketID()); + + } else { + if (packet.isServerPacket()) + listener.onPacketSending(packet); + else + listener.onPacketReceiving(packet); + } } } catch (Throwable e) { diff --git a/ProtocolLib/src/main/java/com/comphenix/protocol/injector/SortedPacketListenerList.java b/ProtocolLib/src/main/java/com/comphenix/protocol/injector/SortedPacketListenerList.java index 5391a948..b6633ba2 100644 --- a/ProtocolLib/src/main/java/com/comphenix/protocol/injector/SortedPacketListenerList.java +++ b/ProtocolLib/src/main/java/com/comphenix/protocol/injector/SortedPacketListenerList.java @@ -25,6 +25,9 @@ import com.comphenix.protocol.error.ErrorReporter; import com.comphenix.protocol.events.ListenerPriority; import com.comphenix.protocol.events.PacketEvent; import com.comphenix.protocol.events.PacketListener; +import com.comphenix.protocol.timing.TimedListenerManager; +import com.comphenix.protocol.timing.TimedTracker; +import com.comphenix.protocol.timing.TimedListenerManager.ListenerType; /** * Registry of synchronous packet listeners. @@ -32,10 +35,13 @@ import com.comphenix.protocol.events.PacketListener; * @author Kristian */ public final class SortedPacketListenerList extends AbstractConcurrentListenerMultimap { + // The current listener manager + private TimedListenerManager timedManager = TimedListenerManager.getInstance(); + public SortedPacketListenerList() { super(Packets.MAXIMUM_PACKET_ID); } - + /** * Invokes the given packet event for every registered listener. * @param reporter - the error reporter that will be used to inform about listener exceptions. @@ -48,19 +54,18 @@ public final class SortedPacketListenerList extends AbstractConcurrentListenerMu return; // The returned list is thread-safe - for (PrioritizedListener element : list) { - try { - event.setReadOnly(element.getPriority() == ListenerPriority.MONITOR); - element.getListener().onPacketReceiving(event); + if (timedManager.isTiming()) { + for (PrioritizedListener element : list) { + TimedTracker tracker = timedManager.getTracker(element.getListener(), ListenerType.SYNC_CLIENT_SIDE); + long token = tracker.beginTracking(); - } catch (OutOfMemoryError e) { - throw e; - } catch (ThreadDeath e) { - throw e; - } catch (Throwable e) { - // Minecraft doesn't want your Exception. - reporter.reportMinimal(element.getListener().getPlugin(), "onPacketReceiving(PacketEvent)", e, - event.getPacket().getHandle()); + // Measure and record the execution time + invokeReceivingListener(reporter, event, element); + tracker.endTracking(token, event.getPacketID()); + } + } else { + for (PrioritizedListener element : list) { + invokeReceivingListener(reporter, event, element); } } } @@ -77,22 +82,46 @@ public final class SortedPacketListenerList extends AbstractConcurrentListenerMu if (list == null) return; - for (PrioritizedListener element : list) { - try { + // The returned list is thread-safe + if (timedManager.isTiming()) { + for (PrioritizedListener element : list) { if (element.getPriority() == priorityFilter) { - event.setReadOnly(element.getPriority() == ListenerPriority.MONITOR); - element.getListener().onPacketReceiving(event); + TimedTracker tracker = timedManager.getTracker(element.getListener(), ListenerType.SYNC_CLIENT_SIDE); + long token = tracker.beginTracking(); + + // Measure and record the execution time + invokeReceivingListener(reporter, event, element); + tracker.endTracking(token, event.getPacketID()); } - - } catch (OutOfMemoryError e) { - throw e; - } catch (ThreadDeath e) { - throw e; - } catch (Throwable e) { - // Minecraft doesn't want your Exception. - reporter.reportMinimal(element.getListener().getPlugin(), "onPacketReceiving(PacketEvent)", e, - event.getPacket().getHandle()); } + } else { + for (PrioritizedListener element : list) { + if (element.getPriority() == priorityFilter) { + invokeReceivingListener(reporter, event, element); + } + } + } + } + + /** + * Invoke a particular receiving listener. + * @param reporter - the error reporter. + * @param event - the related packet event. + * @param element - the listener to invoke. + */ + private final void invokeReceivingListener(ErrorReporter reporter, PacketEvent event, PrioritizedListener element) { + try { + event.setReadOnly(element.getPriority() == ListenerPriority.MONITOR); + element.getListener().onPacketReceiving(event); + + } catch (OutOfMemoryError e) { + throw e; + } catch (ThreadDeath e) { + throw e; + } catch (Throwable e) { + // Minecraft doesn't want your Exception. + reporter.reportMinimal(element.getListener().getPlugin(), "onPacketReceiving(PacketEvent)", e, + event.getPacket().getHandle()); } } @@ -107,19 +136,18 @@ public final class SortedPacketListenerList extends AbstractConcurrentListenerMu if (list == null) return; - for (PrioritizedListener element : list) { - try { - event.setReadOnly(element.getPriority() == ListenerPriority.MONITOR); - element.getListener().onPacketSending(event); + if (timedManager.isTiming()) { + for (PrioritizedListener element : list) { + TimedTracker tracker = timedManager.getTracker(element.getListener(), ListenerType.SYNC_SERVER_SIDE); + long token = tracker.beginTracking(); - } catch (OutOfMemoryError e) { - throw e; - } catch (ThreadDeath e) { - throw e; - } catch (Throwable e) { - // Minecraft doesn't want your Exception. - reporter.reportMinimal(element.getListener().getPlugin(), "onPacketSending(PacketEvent)", e, - event.getPacket().getHandle()); + // Measure and record the execution time + invokeSendingListener(reporter, event, element); + tracker.endTracking(token, event.getPacketID()); + } + } else { + for (PrioritizedListener element : list) { + invokeSendingListener(reporter, event, element); } } } @@ -136,22 +164,45 @@ public final class SortedPacketListenerList extends AbstractConcurrentListenerMu if (list == null) return; - for (PrioritizedListener element : list) { - try { + if (timedManager.isTiming()) { + for (PrioritizedListener element : list) { if (element.getPriority() == priorityFilter) { - event.setReadOnly(element.getPriority() == ListenerPriority.MONITOR); - element.getListener().onPacketSending(event); - } + TimedTracker tracker = timedManager.getTracker(element.getListener(), ListenerType.SYNC_SERVER_SIDE); + long token = tracker.beginTracking(); - } catch (OutOfMemoryError e) { - throw e; - } catch (ThreadDeath e) { - throw e; - } catch (Throwable e) { - // Minecraft doesn't want your Exception. - reporter.reportMinimal(element.getListener().getPlugin(), "onPacketSending(PacketEvent)", e, - event.getPacket().getHandle()); + // Measure and record the execution time + invokeSendingListener(reporter, event, element); + tracker.endTracking(token, event.getPacketID()); + } + } + } else { + for (PrioritizedListener element : list) { + if (element.getPriority() == priorityFilter) { + invokeSendingListener(reporter, event, element); + } } } } + + /** + * Invoke a particular sending listener. + * @param reporter - the error reporter. + * @param event - the related packet event. + * @param element - the listener to invoke. + */ + private final void invokeSendingListener(ErrorReporter reporter, PacketEvent event, PrioritizedListener element) { + try { + event.setReadOnly(element.getPriority() == ListenerPriority.MONITOR); + element.getListener().onPacketSending(event); + + } catch (OutOfMemoryError e) { + throw e; + } catch (ThreadDeath e) { + throw e; + } catch (Throwable e) { + // Minecraft doesn't want your Exception. + reporter.reportMinimal(element.getListener().getPlugin(), "onPacketSending(PacketEvent)", e, + event.getPacket().getHandle()); + } + } } diff --git a/ProtocolLib/src/main/java/com/comphenix/protocol/timing/StatisticsStream.java b/ProtocolLib/src/main/java/com/comphenix/protocol/timing/StatisticsStream.java new file mode 100644 index 00000000..97237348 --- /dev/null +++ b/ProtocolLib/src/main/java/com/comphenix/protocol/timing/StatisticsStream.java @@ -0,0 +1,137 @@ +package com.comphenix.protocol.timing; + +/** + * Represents an online algortihm for computing the mean and standard deviation without storing every value. + * @author Kristian + */ +public class StatisticsStream { + // This algorithm is due to Donald Knuth, as described in: + // Donald E. Knuth (1998). The Art of Computer Programming, volume 2: + // Seminumerical Algorithms, 3rd edn., p. 232. Boston: Addison-Wesley. + + private int count = 0; + private double mean = 0; + private double m2 = 0; + + // Also keep track of minimum and maximum observation + private double minimum = Double.MAX_VALUE; + private double maximum = 0; + + /** + * Construct a new stream with no observations. + */ + public StatisticsStream() { + } + + /** + * Construct a copy of the given stream. + * @param other - copy of the stream. + */ + public StatisticsStream(StatisticsStream other) { + this.count = other.count; + this.mean = other.mean; + this.m2 = other.m2; + this.minimum = other.minimum; + this.maximum = other.maximum; + } + + /** + * Observe a value. + * @param value - the observed value. + */ + public void observe(double value) { + double delta = value - mean; + + // As per Knuth + count++; + mean += delta / count; + m2 += delta * (value - mean); + + // Update extremes + if (value < minimum) + minimum = value; + if (value > maximum) + maximum = value; + } + + /** + * Retrieve the average of all the observations. + * @return The average. + */ + public double getMean() { + checkCount(); + return mean; + } + + /** + * Retrieve the variance of all the observations. + * @return The variance. + */ + public double getVariance() { + checkCount(); + return m2 / (count - 1); + } + + /** + * Retrieve the standard deviation of all the observations. + * @return The STDV. + */ + public double getStandardDeviation() { + return Math.sqrt(getVariance()); + } + + /** + * Retrieve the minimum observation yet observed. + * @return The minimum observation. + */ + public double getMinimum() { + checkCount(); + return minimum; + } + + /** + * Retrieve the maximum observation yet observed. + * @return The maximum observation. + */ + public double getMaximum() { + checkCount(); + return maximum; + } + + /** + * Combine the two statistics. + * @param other - the other statistics. + */ + public StatisticsStream add(StatisticsStream other) { + // Special cases + if (count == 0) + return other; + else if (other.count == 0) + return this; + + StatisticsStream stream = new StatisticsStream(); + double delta = other.mean - mean; + double n = count + other.count; + + stream.count = (int) n; + stream.mean = mean + delta * (other.count / n); + stream.m2 = m2 + other.m2 + ((delta * delta) * (count * other.count) / n); + stream.minimum = Math.min(minimum, other.minimum); + stream.maximum = Math.max(maximum, other.maximum); + return stream; + } + + /** + * Retrieve the number of observations. + * @return Number of observations. + */ + public int getCount() { + return count; + } + + private void checkCount() { + if (count == 0) { + throw new IllegalStateException("No observations in stream."); + } + } +} diff --git a/ProtocolLib/src/main/java/com/comphenix/protocol/timing/TimedListenerManager.java b/ProtocolLib/src/main/java/com/comphenix/protocol/timing/TimedListenerManager.java new file mode 100644 index 00000000..e6b516d4 --- /dev/null +++ b/ProtocolLib/src/main/java/com/comphenix/protocol/timing/TimedListenerManager.java @@ -0,0 +1,184 @@ +package com.comphenix.protocol.timing; + +import java.util.Calendar; +import java.util.Date; +import java.util.Set; +import java.util.concurrent.ConcurrentMap; +import java.util.concurrent.atomic.AtomicBoolean; + +import org.bukkit.plugin.Plugin; + +import com.comphenix.protocol.events.PacketListener; +import com.google.common.collect.ImmutableMap; +import com.google.common.collect.Maps; + +/** + * Represents a system for recording the time spent by each packet listener. + * @author Kristian + */ +public class TimedListenerManager { + public enum ListenerType { + ASYNC_SERVER_SIDE, + ASYNC_CLIENT_SIDE, + SYNC_SERVER_SIDE, + SYNC_CLIENT_SIDE; + } + + // The shared manager + private final static TimedListenerManager INSTANCE = new TimedListenerManager(); + // Running? + private final static AtomicBoolean timing = new AtomicBoolean(); + // When it was started + private volatile Date started; + private volatile Date stopped; + + // The map of time trackers + private ConcurrentMap> map = Maps.newConcurrentMap(); + + /** + * Retrieve the shared listener manager. + *

+ * This should never change. + * @return The shared listener manager. + */ + public static TimedListenerManager getInstance() { + return INSTANCE; + } + + /** + * Start timing listeners. + * @return TRUE if we started timing, FALSE if we are already timing listeners. + */ + public boolean startTiming() { + if (setTiming(true)) { + started = Calendar.getInstance().getTime(); + return true; + } + return false; + } + + /**s + * Stop timing listeners. + * @return TRUE if we stopped timing, FALSE otherwise. + */ + public boolean stopTiming() { + if (setTiming(false)) { + stopped = Calendar.getInstance().getTime(); + return true; + } + return false; + } + + /** + * Retrieve the time the listener was started. + * @return The time it was started, or NULL if they have never been started. + */ + public Date getStarted() { + return started; + } + + /** + * Retrieve the time the time listeners was stopped. + * @return The time they were stopped, or NULL if not found. + */ + public Date getStopped() { + return stopped; + } + + /** + * Set whether or not the timing manager is enabled. + * @param value - TRUE if it should be enabled, FALSE otherwise. + * @return TRUE if the value was changed, FALSE otherwise. + */ + private boolean setTiming(boolean value) { + return timing.compareAndSet(!value, value); + } + + /** + * Determine if we are currently timing listeners. + * @return TRUE if we are, FALSE otherwise. + */ + public boolean isTiming() { + return timing.get(); + } + + /** + * Reset all packet gathering data. + */ + public void clear() { + map.clear(); + } + + /** + * Retrieve every tracked plugin. + * @return Every tracked plugin. + */ + public Set getTrackedPlugins() { + return map.keySet(); + } + + /** + * Retrieve the timed tracker associated with the given plugin and listener type. + * @param plugin - the plugin. + * @param type - the listener type. + * @return The timed tracker. + */ + public TimedTracker getTracker(Plugin plugin, ListenerType type) { + return getTracker(plugin.getName(), type); + } + + /** + * Retrieve the timed tracker associated with the given listener and listener type. + * @param listener - the listener. + * @param type - the listener type. + * @return The timed tracker. + */ + public TimedTracker getTracker(PacketListener listener, ListenerType type) { + return getTracker(listener.getPlugin().getName(), type); + } + + /** + * Retrieve the timed tracker associated with the given listener and listener type. + * @param listener - the listener. + * @param type - the listener type. + * @return The timed tracker. + */ + public TimedTracker getTracker(String pluginName, ListenerType type) { + return getTrackers(pluginName).get(type); + } + + /** + * Retrieve the map of timed trackers for a specific plugin. + * @param pluginName - the plugin name. + * @return Map of timed trackers. + */ + private ImmutableMap getTrackers(String pluginName) { + ImmutableMap trackers = map.get(pluginName); + + // Atomic pattern + if (trackers == null) { + ImmutableMap created = newTrackerMap(); + trackers = map.putIfAbsent(pluginName, created); + + // Success! + if (trackers == null) { + trackers = created; + } + } + return trackers; + } + + /** + * Retrieve a new map of trackers for an unspecified plugin. + * @return + */ + private ImmutableMap newTrackerMap() { + ImmutableMap.Builder builder = ImmutableMap.builder(); + + // Construct a map with every listener type + for (ListenerType type : ListenerType.values()) { + builder.put(type, new TimedTracker()); + } + return builder.build(); + } +} diff --git a/ProtocolLib/src/main/java/com/comphenix/protocol/timing/TimedTracker.java b/ProtocolLib/src/main/java/com/comphenix/protocol/timing/TimedTracker.java new file mode 100644 index 00000000..ff6349af --- /dev/null +++ b/ProtocolLib/src/main/java/com/comphenix/protocol/timing/TimedTracker.java @@ -0,0 +1,63 @@ +package com.comphenix.protocol.timing; + +import com.comphenix.protocol.Packets; + +/** + * Tracks the invocation time for a particular plugin against a list of packets. + * @author Kristian + */ +public class TimedTracker { + // Table of packets and invocations + private StatisticsStream[] packets; + private int observations; + + /** + * Begin tracking an execution time. + * @return The current tracking token. + */ + public long beginTracking() { + return System.nanoTime(); + } + + /** + * Stop and record the execution time since the creation of the given tracking token. + * @param trackingToken - the tracking token. + * @param packetId - the packet ID. + */ + public synchronized void endTracking(long trackingToken, int packetId) { + // Lazy initialization + if (packets == null) + packets = new StatisticsStream[Packets.PACKET_COUNT]; + if (packets[packetId] == null) + packets[packetId] = new StatisticsStream(); + + // Store this observation + packets[packetId].observe(System.nanoTime() - trackingToken); + observations++; + } + + /** + * Retrieve the total number of observations. + * @return Total number of observations. + */ + public int getObservations() { + return observations; + } + + /** + * Retrieve an array (indexed by packet ID) of all relevant statistics. + * @return The array of statistics. + */ + public synchronized StatisticsStream[] getStatistics() { + StatisticsStream[] clone = new StatisticsStream[Packets.PACKET_COUNT]; + + if (packets != null) { + for (int i = 0; i < clone.length; i++) { + if (packets[i] != null) { + clone[i] = new StatisticsStream(packets[i]); + } + } + } + return clone; + } +} diff --git a/ProtocolLib/src/main/java/com/comphenix/protocol/timing/TimingReportGenerator.java b/ProtocolLib/src/main/java/com/comphenix/protocol/timing/TimingReportGenerator.java new file mode 100644 index 00000000..855bea9c --- /dev/null +++ b/ProtocolLib/src/main/java/com/comphenix/protocol/timing/TimingReportGenerator.java @@ -0,0 +1,119 @@ +package com.comphenix.protocol.timing; + +import java.io.BufferedWriter; +import java.io.File; +import java.io.IOException; +import java.io.Writer; +import java.util.Date; + +import com.comphenix.protocol.Packets; +import com.comphenix.protocol.timing.TimedListenerManager.ListenerType; +import com.google.common.base.Charsets; +import com.google.common.io.Closeables; +import com.google.common.io.Files; + +public class TimingReportGenerator { + private static final String NEWLINE = System.lineSeparator(); + private static final String META_STARTED = "Started: %s" + NEWLINE; + private static final String META_STOPPED = "Stopped: %s (after %s seconds)" + NEWLINE; + private static final String PLUGIN_HEADER = "=== PLUGIN %s ===" + NEWLINE; + private static final String LISTENER_HEADER = " TYPE: %s " + NEWLINE; + private static final String SEPERATION_LINE = " ------------------------------- " + NEWLINE; + private static final String STATISTICS_HEADER = " Packet: Count: Min (ms): Max (ms): Mean (ms): Std (ms): " + NEWLINE; + private static final String STATISTICS_ROW = " %-12s %-12d %-15.6f %-15.6f %-15.6f %.6f " + NEWLINE; + private static final String SUM_MAIN_THREAD = " => Time on main thread: %.6f ms" + NEWLINE; + + public void saveTo(File destination, TimedListenerManager manager) throws IOException { + BufferedWriter writer = null; + Date started = manager.getStarted(); + Date stopped = manager.getStopped(); + long seconds = Math.abs((stopped.getTime() - started.getTime()) / 1000); + + try { + writer = Files.newWriter(destination, Charsets.UTF_8); + + // Write some timing information + writer.write(String.format(META_STARTED, started)); + writer.write(String.format(META_STOPPED, stopped, seconds)); + writer.write(NEWLINE); + + for (String plugin : manager.getTrackedPlugins()) { + writer.write(String.format(PLUGIN_HEADER, plugin)); + + for (ListenerType type : ListenerType.values()) { + TimedTracker tracker = manager.getTracker(plugin, type); + + // We only care if it has any observations at all + if (tracker.getObservations() > 0) { + writer.write(String.format(LISTENER_HEADER, type)); + + writer.write(SEPERATION_LINE); + saveStatistics(writer, tracker, type); + writer.write(SEPERATION_LINE); + } + } + // Next plugin + writer.write(NEWLINE); + } + + } finally { + if (writer != null) { + // Don't suppress exceptions + writer.flush(); + Closeables.closeQuietly(writer); + } + } + } + + private void saveStatistics(Writer destination, TimedTracker tracker, ListenerType type) throws IOException { + StatisticsStream[] streams = tracker.getStatistics(); + StatisticsStream sum = new StatisticsStream(); + int count = 0; + + destination.write(STATISTICS_HEADER); + destination.write(SEPERATION_LINE); + + // Write every packet ID that we care about + for (int i = 0; i < Packets.PACKET_COUNT; i++) { + final StatisticsStream stream = streams[i]; + + if (stream != null && stream.getCount() > 0) { + printStatistic(destination, Integer.toString(i), stream); + + // Add it + count++; + sum = sum.add(stream); + } + } + + // Write the sum - if its useful + if (count > 1) { + printStatistic(destination, "SUM", sum); + } + // These are executed on the main thread + if (type == ListenerType.SYNC_SERVER_SIDE) { + destination.write(String.format(SUM_MAIN_THREAD, + toMilli(sum.getCount() * sum.getMean()) + )); + } + } + + private void printStatistic(Writer destination, String key, final StatisticsStream stream) throws IOException { + destination.write(String.format(STATISTICS_ROW, + key, stream.getCount(), + toMilli(stream.getMinimum()), + toMilli(stream.getMaximum()), + toMilli(stream.getMean()), + toMilli(stream.getStandardDeviation()) + )); + } + + /** + * Convert a value in nanoseconds to milliseconds. + * @param value - the value. + * @return The value in milliseconds. + */ + private double toMilli(double value) { + return value / 1000000.0; + } +} diff --git a/ProtocolLib/src/main/java/com/comphenix/protocol/wrappers/nbt/WrappedCompound.java b/ProtocolLib/src/main/java/com/comphenix/protocol/wrappers/nbt/WrappedCompound.java index fa1660aa..7ec1214e 100644 --- a/ProtocolLib/src/main/java/com/comphenix/protocol/wrappers/nbt/WrappedCompound.java +++ b/ProtocolLib/src/main/java/com/comphenix/protocol/wrappers/nbt/WrappedCompound.java @@ -106,7 +106,6 @@ class WrappedCompound implements NbtWrapper>>, Iterable