diff --git a/paper-api/src/main/java/org/bukkit/Bukkit.java b/paper-api/src/main/java/org/bukkit/Bukkit.java index c7e38aee46..c869a1c0f6 100644 --- a/paper-api/src/main/java/org/bukkit/Bukkit.java +++ b/paper-api/src/main/java/org/bukkit/Bukkit.java @@ -868,6 +868,7 @@ public final class Bukkit { */ public static void reload() { server.reload(); + org.spigotmc.CustomTimingsHandler.reload(); // Spigot } /** diff --git a/paper-api/src/main/java/org/bukkit/Server.java b/paper-api/src/main/java/org/bukkit/Server.java index abd04d01c4..2d750d9498 100644 --- a/paper-api/src/main/java/org/bukkit/Server.java +++ b/paper-api/src/main/java/org/bukkit/Server.java @@ -1856,6 +1856,10 @@ public interface Server extends PluginMessageRecipient { // Spigot start public class Spigot { + @NotNull + public org.bukkit.configuration.file.YamlConfiguration getConfig() { + throw new UnsupportedOperationException("Not supported yet."); + } } @NotNull diff --git a/paper-api/src/main/java/org/bukkit/command/Command.java b/paper-api/src/main/java/org/bukkit/command/Command.java index 3ad2254c5f..9019ebeefc 100644 --- a/paper-api/src/main/java/org/bukkit/command/Command.java +++ b/paper-api/src/main/java/org/bukkit/command/Command.java @@ -33,6 +33,7 @@ public abstract class Command { protected String usageMessage; private String permission; private String permissionMessage; + public org.spigotmc.CustomTimingsHandler timings; // Spigot protected Command(@NotNull String name) { this(name, "", "/" + name, new ArrayList()); @@ -46,6 +47,7 @@ public abstract class Command { this.usageMessage = (usageMessage == null) ? "/" + name : usageMessage; this.aliases = aliases; this.activeAliases = new ArrayList(aliases); + this.timings = new org.spigotmc.CustomTimingsHandler("** Command: " + name); // Spigot } /** @@ -243,6 +245,7 @@ public abstract class Command { } this.nextLabel = name; if (!isRegistered()) { + this.timings = new org.spigotmc.CustomTimingsHandler("** Command: " + name); // Spigot this.label = name; return true; } diff --git a/paper-api/src/main/java/org/bukkit/command/SimpleCommandMap.java b/paper-api/src/main/java/org/bukkit/command/SimpleCommandMap.java index c399c14977..fd5a7a5548 100644 --- a/paper-api/src/main/java/org/bukkit/command/SimpleCommandMap.java +++ b/paper-api/src/main/java/org/bukkit/command/SimpleCommandMap.java @@ -145,11 +145,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/paper-api/src/main/java/org/bukkit/command/defaults/TimingsCommand.java b/paper-api/src/main/java/org/bukkit/command/defaults/TimingsCommand.java index ed4cbce773..516d7fc781 100644 --- a/paper-api/src/main/java/org/bukkit/command/defaults/TimingsCommand.java +++ b/paper-api/src/main/java/org/bukkit/command/defaults/TimingsCommand.java @@ -18,23 +18,102 @@ import org.bukkit.plugin.TimedRegisteredListener; import org.bukkit.util.StringUtil; import org.jetbrains.annotations.NotNull; +// Spigot start +// CHECKSTYLE:OFF +import java.io.ByteArrayOutputStream; +import java.io.OutputStream; +import java.net.HttpURLConnection; +import java.net.URL; +import java.util.logging.Level; +import org.bukkit.command.RemoteConsoleCommandSender; +import org.bukkit.plugin.SimplePluginManager; +import org.spigotmc.CustomTimingsHandler; +// CHECKSTYLE:ON +// Spigot end + public class TimingsCommand extends BukkitCommand { - private static final List TIMINGS_SUBCOMMANDS = ImmutableList.of("merged", "reset", "separate"); + private static final List TIMINGS_SUBCOMMANDS = ImmutableList.of("report", "reset", "on", "off", "paste"); // Spigot + public static long timingStart = 0; // Spigot public TimingsCommand(@NotNull String name) { super(name); - this.description = "Records timings for all plugin events"; - this.usageMessage = "/timings "; + this.description = "Manages Spigot Timings data to see performance of the server."; // Spigot + this.usageMessage = "/timings "; // Spigot this.setPermission("bukkit.command.timings"); } + // Spigot start - redesigned Timings Command + public void executeSpigotTimings(@NotNull CommandSender sender, @NotNull 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)"); + + fileTimings.println(""); + fileTimings.println(Bukkit.spigot().getConfig().saveToString()); + fileTimings.println(""); + + 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(@NotNull CommandSender sender, @NotNull String currentAlias, @NotNull String[] args) { if (!testPermission(sender)) return true; - if (args.length != 1) { + if (args.length < 1) { // Spigot sender.sendMessage(ChatColor.RED + "Usage: " + usageMessage); return false; } + // Spigot start + if (true) { + executeSpigotTimings(sender, args); + return true; + } + // Spigot end if (!sender.getServer().getPluginManager().useTimings()) { sender.sendMessage("Please enable timings by setting \"settings.plugin-profiling\" to true in bukkit.yml"); return true; @@ -122,4 +201,50 @@ 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(@NotNull CommandSender sender, @NotNull 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("https://timings.spigotmc.org/paste").openConnection(); + con.setDoOutput(true); + con.setRequestMethod("POST"); + con.setInstanceFollowRedirects(false); + + OutputStream out = con.getOutputStream(); + out.write(bout.toByteArray()); + out.close(); + + com.google.gson.JsonObject location = new com.google.gson.Gson().fromJson(new java.io.InputStreamReader(con.getInputStream()), com.google.gson.JsonObject.class); + con.getInputStream().close(); + + String pasteID = location.get("key").getAsString(); + sender.sendMessage(ChatColor.GREEN + "Timings results can be viewed at https://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/paper-api/src/main/java/org/bukkit/plugin/SimplePluginManager.java b/paper-api/src/main/java/org/bukkit/plugin/SimplePluginManager.java index 04f797ce2b..ccf2aafca0 100644 --- a/paper-api/src/main/java/org/bukkit/plugin/SimplePluginManager.java +++ b/paper-api/src/main/java/org/bukkit/plugin/SimplePluginManager.java @@ -370,6 +370,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/paper-api/src/main/java/org/bukkit/plugin/java/JavaPluginLoader.java b/paper-api/src/main/java/org/bukkit/plugin/java/JavaPluginLoader.java index ef913c6ecc..29a8efdf3a 100644 --- a/paper-api/src/main/java/org/bukkit/plugin/java/JavaPluginLoader.java +++ b/paper-api/src/main/java/org/bukkit/plugin/java/JavaPluginLoader.java @@ -43,6 +43,7 @@ import org.bukkit.plugin.TimedRegisteredListener; import org.bukkit.plugin.UnknownDependencyException; import org.jetbrains.annotations.NotNull; import org.jetbrains.annotations.Nullable; +import org.spigotmc.CustomTimingsHandler; // Spigot import org.yaml.snakeyaml.error.YAMLException; /** @@ -53,6 +54,7 @@ public final class JavaPluginLoader implements PluginLoader { private final Pattern[] fileFilters = new Pattern[]{Pattern.compile("\\.jar$")}; private final List loaders = new CopyOnWriteArrayList(); private final LibraryLoader libraryLoader; + public static final CustomTimingsHandler pluginParentTimer = new CustomTimingsHandler("** Plugins"); // Spigot /** * This class was not meant to be constructed explicitly @@ -290,6 +292,7 @@ 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() { @Override public void execute(@NotNull Listener listener, @NotNull Event event) throws EventException { @@ -297,7 +300,12 @@ public final class JavaPluginLoader implements PluginLoader { 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) { @@ -305,7 +313,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/paper-api/src/main/java/org/spigotmc/CustomTimingsHandler.java b/paper-api/src/main/java/org/spigotmc/CustomTimingsHandler.java new file mode 100644 index 0000000000..44badfedcc --- /dev/null +++ b/paper-api/src/main/java/org/spigotmc/CustomTimingsHandler.java @@ -0,0 +1,137 @@ +package org.spigotmc; + +import java.io.PrintStream; +import java.util.Queue; +import java.util.concurrent.ConcurrentLinkedQueue; +import org.bukkit.Bukkit; +import org.bukkit.World; +import org.bukkit.command.defaults.TimingsCommand; +import org.jetbrains.annotations.NotNull; +import org.jetbrains.annotations.Nullable; + +/** + * Provides custom timing sections for /timings merged. + */ +public class CustomTimingsHandler { + + private static Queue HANDLERS = new ConcurrentLinkedQueue(); + /*========================================================================*/ + 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(@NotNull String name) { + this(name, null); + } + + public CustomTimingsHandler(@NotNull String name, @Nullable CustomTimingsHandler parent) { + this.name = name; + this.parent = parent; + HANDLERS.add(this); + } + + /** + * Prints the timings and extra data to the given stream. + * + * @param printStream output stream + */ + public static void printTimings(@NotNull 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; + } +} diff --git a/paper-api/src/main/java/org/spigotmc/package-info.java b/paper-api/src/main/java/org/spigotmc/package-info.java new file mode 100644 index 0000000000..a287faff5f --- /dev/null +++ b/paper-api/src/main/java/org/spigotmc/package-info.java @@ -0,0 +1,4 @@ +/** + * Spigot-specific classes. + */ +package org.spigotmc;