mirror of
https://github.com/StarWishsama/Slimefun4.git
synced 2024-09-19 19:25:48 +00:00
Added a better profiler
This commit is contained in:
TheBusyBiscuit
parent
0aa99df8c2
commit
d82b66a842
@ -40,6 +40,7 @@
|
||||
* (1.16+) Added Warped and Crimson Fungus to the fuel list for the Bio Generator
|
||||
* Added an AoE damage effect to the Explosive Bow
|
||||
* Added runtime deprecation warnings for ItemHandlers and Attributes used by Addons
|
||||
* Added a proper lag profiler
|
||||
|
||||
#### Changes
|
||||
* Coolant Cells now last twice as long
|
||||
@ -54,6 +55,7 @@
|
||||
* Small performance improvements to the Cargo Net
|
||||
* Slimefun no longer supports CraftBukkit
|
||||
* Item Energy is now also stored persistently via NBT
|
||||
* General performance improvements for ticking blocks
|
||||
|
||||
#### Fixes
|
||||
* Fixed #2005
|
||||
@ -72,6 +74,9 @@
|
||||
* Fixed Grappling hooks making Bat sounds
|
||||
* Fixed #1959
|
||||
* Fixed Melon Juice requiring Melons instead of Melon Slices
|
||||
* Fixed Cargo networks not showing up in /sf timings
|
||||
* Fixed /sf timings reporting slightly inaccurate timings
|
||||
* Fixed concurrency-related issues with the profiling
|
||||
|
||||
## Release Candidate 13 (16 Jun 2020)
|
||||
https://thebusybiscuit.github.io/builds/TheBusyBiscuit/Slimefun4/stable/#13
|
||||
|
||||
@ -26,7 +26,8 @@ class TimingsCommand extends SubCommand {
|
||||
@Override
|
||||
public void onExecute(CommandSender sender, String[] args) {
|
||||
if (sender.hasPermission("slimefun.command.timings") || sender instanceof ConsoleCommandSender) {
|
||||
SlimefunPlugin.getTickerTask().info(sender);
|
||||
sender.sendMessage("Please wait a second... The results are coming in!");
|
||||
SlimefunPlugin.getProfiler().requestSummary(sender);
|
||||
}
|
||||
else {
|
||||
SlimefunPlugin.getLocalization().sendMessage(sender, "messages.no-permission", true);
|
||||
|
||||
@ -166,7 +166,7 @@ public class CargoNet extends ChestTerminalNetwork {
|
||||
destinations.addAll(output16);
|
||||
}
|
||||
|
||||
Slimefun.runSync(() -> run(b, destinations, output));
|
||||
run(b, destinations, output);
|
||||
}
|
||||
}
|
||||
|
||||
|
||||
@ -211,7 +211,7 @@ public class EnergyNet extends Network {
|
||||
Set<Location> exploded = new HashSet<>();
|
||||
|
||||
for (Location source : generators) {
|
||||
long timestamp = System.currentTimeMillis();
|
||||
long timestamp = SlimefunPlugin.getProfiler().newEntry();
|
||||
SlimefunItem item = BlockStorage.check(source);
|
||||
|
||||
if (item != null) {
|
||||
@ -247,7 +247,7 @@ public class EnergyNet extends Network {
|
||||
new ErrorReport(t, source, item);
|
||||
}
|
||||
|
||||
SlimefunPlugin.getTickerTask().addBlockTimings(source, System.currentTimeMillis() - timestamp);
|
||||
SlimefunPlugin.getProfiler().closeEntry(source, item, timestamp);
|
||||
}
|
||||
else {
|
||||
// This block seems to be gone now, better remove it to be extra safe
|
||||
|
||||
@ -56,7 +56,7 @@ class GitHubTask implements Runnable {
|
||||
}
|
||||
}
|
||||
|
||||
if (requests >= MAX_REQUESTS_PER_MINUTE) {
|
||||
if (requests >= MAX_REQUESTS_PER_MINUTE && SlimefunPlugin.instance != null && SlimefunPlugin.instance.isEnabled()) {
|
||||
// Slow down API requests and wait a minute after more than x requests were made
|
||||
Bukkit.getScheduler().runTaskLaterAsynchronously(SlimefunPlugin.instance, this::grabTextures, 2 * 60 * 20L);
|
||||
}
|
||||
|
||||
@ -85,7 +85,7 @@ class PlaceholderAPIHook extends PlaceholderExpansion {
|
||||
}
|
||||
|
||||
if (params.equals("timings_lag")) {
|
||||
return SlimefunPlugin.getTickerTask().getTime() + "ms";
|
||||
return SlimefunPlugin.getProfiler().getTime();
|
||||
}
|
||||
|
||||
if (params.equals("language")) {
|
||||
|
||||
@ -0,0 +1,49 @@
|
||||
package io.github.thebusybiscuit.slimefun4.core.services.profiler;
|
||||
|
||||
import org.bukkit.block.Block;
|
||||
|
||||
import io.github.thebusybiscuit.cscorelib2.blocks.BlockPosition;
|
||||
import io.github.thebusybiscuit.slimefun4.api.SlimefunAddon;
|
||||
import me.mrCookieSlime.Slimefun.Objects.SlimefunItem.SlimefunItem;
|
||||
|
||||
class ProfiledBlock {
|
||||
|
||||
private final BlockPosition position;
|
||||
private final SlimefunItem item;
|
||||
|
||||
ProfiledBlock(BlockPosition position, SlimefunItem item) {
|
||||
this.position = position;
|
||||
this.item = item;
|
||||
}
|
||||
|
||||
ProfiledBlock(Block b) {
|
||||
this(new BlockPosition(b), null);
|
||||
}
|
||||
|
||||
public BlockPosition getPosition() {
|
||||
return position;
|
||||
}
|
||||
|
||||
public String getId() {
|
||||
return item.getID();
|
||||
}
|
||||
|
||||
public SlimefunAddon getAddon() {
|
||||
return item.getAddon();
|
||||
}
|
||||
|
||||
@Override
|
||||
public boolean equals(Object obj) {
|
||||
if (obj instanceof ProfiledBlock) {
|
||||
return position.equals(((ProfiledBlock) obj).position);
|
||||
}
|
||||
|
||||
return false;
|
||||
}
|
||||
|
||||
@Override
|
||||
public int hashCode() {
|
||||
return position.hashCode();
|
||||
}
|
||||
|
||||
}
|
||||
@ -0,0 +1,317 @@
|
||||
package io.github.thebusybiscuit.slimefun4.core.services.profiler;
|
||||
|
||||
import java.util.Comparator;
|
||||
import java.util.HashMap;
|
||||
import java.util.Iterator;
|
||||
import java.util.List;
|
||||
import java.util.Locale;
|
||||
import java.util.Map;
|
||||
import java.util.Map.Entry;
|
||||
import java.util.Queue;
|
||||
import java.util.concurrent.ConcurrentHashMap;
|
||||
import java.util.concurrent.ConcurrentLinkedQueue;
|
||||
import java.util.concurrent.ExecutorService;
|
||||
import java.util.concurrent.Executors;
|
||||
import java.util.concurrent.atomic.AtomicBoolean;
|
||||
import java.util.concurrent.atomic.AtomicInteger;
|
||||
import java.util.function.Function;
|
||||
import java.util.logging.Level;
|
||||
import java.util.stream.Collectors;
|
||||
import java.util.stream.Stream;
|
||||
|
||||
import org.apache.commons.lang.Validate;
|
||||
import org.bukkit.ChatColor;
|
||||
import org.bukkit.Chunk;
|
||||
import org.bukkit.Location;
|
||||
import org.bukkit.Server;
|
||||
import org.bukkit.block.Block;
|
||||
import org.bukkit.command.CommandSender;
|
||||
import org.bukkit.entity.Player;
|
||||
|
||||
import io.github.thebusybiscuit.cscorelib2.blocks.BlockPosition;
|
||||
import io.github.thebusybiscuit.cscorelib2.chat.ChatColors;
|
||||
import io.github.thebusybiscuit.slimefun4.api.SlimefunAddon;
|
||||
import io.github.thebusybiscuit.slimefun4.implementation.SlimefunPlugin;
|
||||
import io.github.thebusybiscuit.slimefun4.implementation.tasks.TickerTask;
|
||||
import io.github.thebusybiscuit.slimefun4.utils.NumberUtils;
|
||||
import me.mrCookieSlime.Slimefun.Objects.SlimefunItem.SlimefunItem;
|
||||
import me.mrCookieSlime.Slimefun.api.Slimefun;
|
||||
import net.md_5.bungee.api.chat.HoverEvent;
|
||||
import net.md_5.bungee.api.chat.TextComponent;
|
||||
|
||||
/**
|
||||
* The {@link SlimefunProfiler} works closely to the {@link TickerTask} and is responsible for
|
||||
* monitoring that task.
|
||||
* It collects timings data for any ticked {@link Block} and the corresponding {@link SlimefunItem}.
|
||||
* This allows developers to identify laggy {@link SlimefunItem SlimefunItems} or {@link SlimefunAddon SlimefunAddons}.
|
||||
* But it also enabled Server Admins to locate lag-inducing areas on the {@link Server}.
|
||||
*
|
||||
* @author TheBusyBiscuit
|
||||
*
|
||||
* @see TickerTask
|
||||
*
|
||||
*/
|
||||
public class SlimefunProfiler {
|
||||
|
||||
// The threshold at which a Block or Chunk is significant enough to appear in /sf timings
|
||||
private static final int VISIBILITY_THRESHOLD = 275_000;
|
||||
|
||||
private final ExecutorService executor = Executors.newFixedThreadPool(3);
|
||||
private final AtomicBoolean running = new AtomicBoolean(false);
|
||||
private final AtomicInteger queued = new AtomicInteger(0);
|
||||
|
||||
private long totalElapsedTime;
|
||||
|
||||
private final Map<ProfiledBlock, Long> timings = new ConcurrentHashMap<>();
|
||||
private final Queue<CommandSender> requests = new ConcurrentLinkedQueue<>();
|
||||
|
||||
/**
|
||||
* This method starts the profiling, data from previous runs will be cleared.
|
||||
*/
|
||||
public void start() {
|
||||
running.set(true);
|
||||
queued.set(0);
|
||||
timings.clear();
|
||||
}
|
||||
|
||||
/**
|
||||
* This method starts a new profiler entry.
|
||||
*
|
||||
* @return A timestamp, best fed back into {@link #closeEntry(Location, SlimefunItem, long)}
|
||||
*/
|
||||
public long newEntry() {
|
||||
if (!running.get()) {
|
||||
return 0;
|
||||
}
|
||||
|
||||
queued.incrementAndGet();
|
||||
return System.nanoTime();
|
||||
}
|
||||
|
||||
/**
|
||||
* This method closes a previously started entry.
|
||||
* Make sure to call {@link #newEntry()} to get the timestamp in advance.
|
||||
*
|
||||
* @param l
|
||||
* The {@link Location} of our {@link Block}
|
||||
* @param item
|
||||
* The {@link SlimefunItem} at this {@link Location}
|
||||
* @param timestamp
|
||||
* The timestamp marking the start of this entry, you can retrieve it using {@link #newEntry()}
|
||||
*/
|
||||
public void closeEntry(Location l, SlimefunItem item, long timestamp) {
|
||||
if (timestamp == 0) {
|
||||
return;
|
||||
}
|
||||
|
||||
long elapsedTime = System.nanoTime() - timestamp;
|
||||
|
||||
executor.execute(() -> {
|
||||
ProfiledBlock block = new ProfiledBlock(new BlockPosition(l), item);
|
||||
timings.put(block, elapsedTime);
|
||||
queued.decrementAndGet();
|
||||
});
|
||||
}
|
||||
|
||||
/**
|
||||
* This stops the profiling.
|
||||
*/
|
||||
public void stop() {
|
||||
running.set(false);
|
||||
|
||||
if (SlimefunPlugin.instance == null || !SlimefunPlugin.instance.isEnabled()) {
|
||||
// Slimefun has been disabled
|
||||
return;
|
||||
}
|
||||
|
||||
// Since we got more than one Thread in our pool, blocking this one is completely fine
|
||||
executor.execute(() -> {
|
||||
|
||||
// Wait for all timing results to come in
|
||||
while (queued.get() > 0 && !running.get()) {
|
||||
try {
|
||||
Thread.sleep(1);
|
||||
}
|
||||
catch (InterruptedException e) {
|
||||
Slimefun.getLogger().log(Level.SEVERE, "A waiting Thread was interrupted", e);
|
||||
Thread.currentThread().interrupt();
|
||||
}
|
||||
}
|
||||
|
||||
if (running.get()) {
|
||||
// Looks like the next profiling has already started, abort!
|
||||
return;
|
||||
}
|
||||
|
||||
totalElapsedTime = timings.values().stream().mapToLong(Long::longValue).sum();
|
||||
|
||||
Iterator<CommandSender> iterator = requests.iterator();
|
||||
|
||||
while (iterator.hasNext()) {
|
||||
sendSummary(iterator.next());
|
||||
iterator.remove();
|
||||
}
|
||||
});
|
||||
|
||||
}
|
||||
|
||||
/**
|
||||
* This method requests a summary for the given {@link CommandSender}.
|
||||
* The summary will be sent upon the next available moment in time.
|
||||
*
|
||||
* @param sender
|
||||
* The {@link CommandSender} who shall receive this summary.
|
||||
*/
|
||||
public void requestSummary(CommandSender sender) {
|
||||
requests.add(sender);
|
||||
}
|
||||
|
||||
private Map<String, Long> getByItem() {
|
||||
Map<String, Long> map = new HashMap<>();
|
||||
|
||||
for (Map.Entry<ProfiledBlock, Long> entry : timings.entrySet()) {
|
||||
map.merge(entry.getKey().getId(), entry.getValue(), Long::sum);
|
||||
}
|
||||
|
||||
return map;
|
||||
}
|
||||
|
||||
private Map<String, Long> getByChunk() {
|
||||
Map<String, Long> map = new HashMap<>();
|
||||
|
||||
for (Map.Entry<ProfiledBlock, Long> entry : timings.entrySet()) {
|
||||
String world = entry.getKey().getPosition().getWorld().getName();
|
||||
int x = entry.getKey().getPosition().getChunkX();
|
||||
int z = entry.getKey().getPosition().getChunkZ();
|
||||
|
||||
map.merge(world + " (" + x + ',' + z + ')', entry.getValue(), Long::sum);
|
||||
}
|
||||
|
||||
return map;
|
||||
}
|
||||
|
||||
private int getBlocksInChunk(String chunk) {
|
||||
int blocks = 0;
|
||||
|
||||
for (ProfiledBlock block : timings.keySet()) {
|
||||
String world = block.getPosition().getWorld().getName();
|
||||
int x = block.getPosition().getChunkX();
|
||||
int z = block.getPosition().getChunkZ();
|
||||
|
||||
if (chunk.equals(world + " (" + x + ',' + z + ')')) {
|
||||
blocks++;
|
||||
}
|
||||
}
|
||||
|
||||
return blocks;
|
||||
}
|
||||
|
||||
private int getBlocks(String id) {
|
||||
int blocks = 0;
|
||||
|
||||
for (ProfiledBlock block : timings.keySet()) {
|
||||
if (block.getId().equals(id)) {
|
||||
blocks++;
|
||||
}
|
||||
}
|
||||
|
||||
return blocks;
|
||||
}
|
||||
|
||||
private void sendSummary(CommandSender sender) {
|
||||
Map<String, Long> chunks = getByChunk();
|
||||
Map<String, Long> machines = getByItem();
|
||||
|
||||
sender.sendMessage(ChatColors.color("&2== &aSlimefun Lag Profiler &2=="));
|
||||
sender.sendMessage(ChatColors.color("&6Running: &e&l" + String.valueOf(!SlimefunPlugin.getTickerTask().isHalted()).toUpperCase(Locale.ROOT)));
|
||||
sender.sendMessage("");
|
||||
sender.sendMessage(ChatColors.color("&6Impact: &e" + NumberUtils.getAsMillis(totalElapsedTime)));
|
||||
sender.sendMessage(ChatColors.color("&6Ticked Chunks: &e" + chunks.size()));
|
||||
sender.sendMessage(ChatColors.color("&6Ticked Blocks: &e" + timings.size()));
|
||||
sender.sendMessage("");
|
||||
sender.sendMessage(ChatColors.color("&6Ticking Machines:"));
|
||||
|
||||
summarizeTimings(sender, entry -> {
|
||||
int count = getBlocks(entry.getKey());
|
||||
String time = NumberUtils.getAsMillis(entry.getValue());
|
||||
String average = NumberUtils.getAsMillis(entry.getValue() / count);
|
||||
|
||||
return entry.getKey() + " - " + count + "x (" + time + ", " + average + " avg/block)";
|
||||
}, machines.entrySet().stream());
|
||||
|
||||
sender.sendMessage("");
|
||||
sender.sendMessage(ChatColors.color("&6Ticking Chunks:"));
|
||||
|
||||
summarizeTimings(sender, entry -> {
|
||||
int count = getBlocksInChunk(entry.getKey());
|
||||
String time = NumberUtils.getAsMillis(entry.getValue());
|
||||
|
||||
return entry.getKey() + " - " + count + "x (" + time + ")";
|
||||
}, chunks.entrySet().stream());
|
||||
}
|
||||
|
||||
private void summarizeTimings(CommandSender sender, Function<Map.Entry<String, Long>, String> formatter, Stream<Map.Entry<String, Long>> stream) {
|
||||
List<Entry<String, Long>> results = stream.sorted(Map.Entry.comparingByValue(Comparator.reverseOrder())).collect(Collectors.toList());
|
||||
|
||||
if (sender instanceof Player) {
|
||||
TextComponent component = new TextComponent(" Hover for more details...");
|
||||
component.setColor(net.md_5.bungee.api.ChatColor.GRAY);
|
||||
component.setItalic(true);
|
||||
StringBuilder builder = new StringBuilder();
|
||||
int hidden = 0;
|
||||
|
||||
for (Map.Entry<String, Long> entry : results) {
|
||||
if (entry.getValue() > VISIBILITY_THRESHOLD) {
|
||||
builder.append("\n&e").append(formatter.apply(entry));
|
||||
}
|
||||
else {
|
||||
hidden++;
|
||||
}
|
||||
}
|
||||
|
||||
builder.append("\n\n&c+ &6").append(hidden).append(" more");
|
||||
component.setHoverEvent(new HoverEvent(HoverEvent.Action.SHOW_TEXT, TextComponent.fromLegacyText(ChatColors.color(builder.toString()))));
|
||||
sender.spigot().sendMessage(component);
|
||||
}
|
||||
else {
|
||||
int hidden = 0;
|
||||
|
||||
for (Map.Entry<String, Long> entry : results) {
|
||||
if (entry.getValue() > VISIBILITY_THRESHOLD) {
|
||||
sender.sendMessage(" " + ChatColor.stripColor(formatter.apply(entry)));
|
||||
}
|
||||
else {
|
||||
hidden++;
|
||||
}
|
||||
}
|
||||
|
||||
sender.sendMessage("+ " + hidden + " more");
|
||||
}
|
||||
}
|
||||
|
||||
public String getTime() {
|
||||
return NumberUtils.getAsMillis(totalElapsedTime);
|
||||
}
|
||||
|
||||
public String getTime(Block b) {
|
||||
Validate.notNull("Cannot get timings for a null Block");
|
||||
|
||||
long time = timings.getOrDefault(new ProfiledBlock(b), 0L);
|
||||
return NumberUtils.getAsMillis(time);
|
||||
}
|
||||
|
||||
public String getTime(Chunk chunk) {
|
||||
Validate.notNull("Cannot get timings for a null Chunk");
|
||||
|
||||
long time = getByChunk().getOrDefault(chunk.getWorld().getName() + " (" + chunk.getX() + ',' + chunk.getZ() + ')', 0L);
|
||||
return NumberUtils.getAsMillis(time);
|
||||
}
|
||||
|
||||
public String getTime(SlimefunItem item) {
|
||||
Validate.notNull("Cannot get timings for a null SlimefunItem");
|
||||
|
||||
long time = getByItem().getOrDefault(item.getID(), 0L);
|
||||
return NumberUtils.getAsMillis(time);
|
||||
}
|
||||
|
||||
}
|
||||
@ -0,0 +1,9 @@
|
||||
/**
|
||||
* This package holds classes related to the
|
||||
* {@link io.github.thebusybiscuit.slimefun4.core.services.profiler.SlimefunProfiler}.
|
||||
* The {@link io.github.thebusybiscuit.slimefun4.core.services.profiler.SlimefunProfiler} is used to determine
|
||||
* {@link org.bukkit.block.Block Blocks}, {@link org.bukkit.Chunk Chunks} or
|
||||
* {@link me.mrCookieSlime.Slimefun.Objects.SlimefunItem.SlimefunItem SlimefunItems} that cause lag or performance
|
||||
* drops.
|
||||
*/
|
||||
package io.github.thebusybiscuit.slimefun4.core.services.profiler;
|
||||
@ -43,6 +43,7 @@ import io.github.thebusybiscuit.slimefun4.core.services.UpdaterService;
|
||||
import io.github.thebusybiscuit.slimefun4.core.services.github.GitHubService;
|
||||
import io.github.thebusybiscuit.slimefun4.core.services.metrics.MetricsService;
|
||||
import io.github.thebusybiscuit.slimefun4.core.services.plugins.ThirdPartyPluginService;
|
||||
import io.github.thebusybiscuit.slimefun4.core.services.profiler.SlimefunProfiler;
|
||||
import io.github.thebusybiscuit.slimefun4.implementation.items.altar.AncientAltar;
|
||||
import io.github.thebusybiscuit.slimefun4.implementation.items.backpacks.Cooler;
|
||||
import io.github.thebusybiscuit.slimefun4.implementation.items.electric.BasicCircuitBoard;
|
||||
@ -126,6 +127,7 @@ public final class SlimefunPlugin extends JavaPlugin implements SlimefunAddon {
|
||||
private final PerWorldSettingsService worldSettingsService = new PerWorldSettingsService(this);
|
||||
private final ThirdPartyPluginService thirdPartySupportService = new ThirdPartyPluginService(this);
|
||||
private final MinecraftRecipeService recipeService = new MinecraftRecipeService(this);
|
||||
private final SlimefunProfiler profiler = new SlimefunProfiler();
|
||||
private LocalizationService local;
|
||||
|
||||
private GPSNetwork gpsNetwork;
|
||||
@ -612,6 +614,10 @@ public final class SlimefunPlugin extends JavaPlugin implements SlimefunAddon {
|
||||
return instance.command;
|
||||
}
|
||||
|
||||
public static SlimefunProfiler getProfiler() {
|
||||
return instance.profiler;
|
||||
}
|
||||
|
||||
/**
|
||||
* This returns the currently installed version of Minecraft.
|
||||
*
|
||||
|
||||
@ -41,7 +41,7 @@ public class CargoManager extends SlimefunItem {
|
||||
|
||||
@Override
|
||||
public boolean isSynchronized() {
|
||||
return false;
|
||||
return true;
|
||||
}
|
||||
|
||||
}, new BlockUseHandler() {
|
||||
|
||||
@ -1,6 +1,5 @@
|
||||
package io.github.thebusybiscuit.slimefun4.implementation.listeners;
|
||||
|
||||
import org.bukkit.ChatColor;
|
||||
import org.bukkit.Material;
|
||||
import org.bukkit.block.Block;
|
||||
import org.bukkit.block.Skull;
|
||||
@ -15,12 +14,11 @@ import org.bukkit.inventory.EquipmentSlot;
|
||||
|
||||
import io.github.thebusybiscuit.cscorelib2.chat.ChatColors;
|
||||
import io.github.thebusybiscuit.cscorelib2.skull.SkullBlock;
|
||||
import io.github.thebusybiscuit.slimefun4.core.attributes.EnergyNetComponent;
|
||||
import io.github.thebusybiscuit.slimefun4.core.networks.energy.EnergyNet;
|
||||
import io.github.thebusybiscuit.slimefun4.implementation.SlimefunItems;
|
||||
import io.github.thebusybiscuit.slimefun4.implementation.SlimefunPlugin;
|
||||
import io.github.thebusybiscuit.slimefun4.implementation.tasks.TickerTask;
|
||||
import io.github.thebusybiscuit.slimefun4.utils.HeadTexture;
|
||||
import io.github.thebusybiscuit.slimefun4.utils.NumberUtils;
|
||||
import io.github.thebusybiscuit.slimefun4.utils.SlimefunUtils;
|
||||
import me.mrCookieSlime.Slimefun.Objects.SlimefunItem.SlimefunItem;
|
||||
import me.mrCookieSlime.Slimefun.api.BlockStorage;
|
||||
@ -28,14 +26,14 @@ import me.mrCookieSlime.Slimefun.api.energy.ChargableBlock;
|
||||
|
||||
public class DebugFishListener implements Listener {
|
||||
|
||||
private final String enabledTooltip;
|
||||
private final String disabledTooltip;
|
||||
private final String greenCheckmark;
|
||||
private final String redCross;
|
||||
|
||||
public DebugFishListener(SlimefunPlugin plugin) {
|
||||
plugin.getServer().getPluginManager().registerEvents(this, plugin);
|
||||
|
||||
enabledTooltip = "&2\u2714";
|
||||
disabledTooltip = "&4\u2718";
|
||||
greenCheckmark = "&2\u2714";
|
||||
redCross = "&4\u2718";
|
||||
}
|
||||
|
||||
@EventHandler
|
||||
@ -81,7 +79,7 @@ public class DebugFishListener implements Listener {
|
||||
p.sendMessage(ChatColors.color("&dPlugin: " + "&e" + item.getAddon().getName()));
|
||||
|
||||
if (b.getState() instanceof Skull) {
|
||||
p.sendMessage(ChatColors.color("&dSkull: " + enabledTooltip));
|
||||
p.sendMessage(ChatColors.color("&dSkull: " + greenCheckmark));
|
||||
|
||||
// Check if the skull is a wall skull, and if so use Directional instead of Rotatable.
|
||||
if (b.getType() == Material.PLAYER_WALL_HEAD) {
|
||||
@ -93,40 +91,40 @@ public class DebugFishListener implements Listener {
|
||||
}
|
||||
|
||||
if (BlockStorage.getStorage(b.getWorld()).hasInventory(b.getLocation())) {
|
||||
p.sendMessage(ChatColors.color("&dInventory: " + enabledTooltip));
|
||||
p.sendMessage(ChatColors.color("&dInventory: " + greenCheckmark));
|
||||
}
|
||||
else {
|
||||
p.sendMessage(ChatColors.color("&dInventory: " + disabledTooltip));
|
||||
p.sendMessage(ChatColors.color("&dInventory: " + redCross));
|
||||
}
|
||||
|
||||
TickerTask ticker = SlimefunPlugin.getTickerTask();
|
||||
|
||||
if (item.isTicking()) {
|
||||
p.sendMessage(ChatColors.color("&dTicker: " + enabledTooltip));
|
||||
p.sendMessage(ChatColors.color(" &dAsync: &e" + (BlockStorage.check(b).getBlockTicker().isSynchronized() ? disabledTooltip : enabledTooltip)));
|
||||
p.sendMessage(ChatColors.color(" &dTimings: &e" + NumberUtils.getAsMillis(ticker.getTimings(b))));
|
||||
p.sendMessage(ChatColors.color(" &dTotal Timings: &e" + NumberUtils.getAsMillis(ticker.getTimings(BlockStorage.checkID(b)))));
|
||||
p.sendMessage(ChatColors.color(" &dChunk Timings: &e" + NumberUtils.getAsMillis(ticker.getTimings(b.getChunk()))));
|
||||
p.sendMessage(ChatColors.color("&dTicker: " + greenCheckmark));
|
||||
p.sendMessage(ChatColors.color(" &dAsync: &e" + (item.getBlockTicker().isSynchronized() ? redCross : greenCheckmark)));
|
||||
p.sendMessage(ChatColors.color(" &dTimings: &e" + SlimefunPlugin.getProfiler().getTime(b)));
|
||||
p.sendMessage(ChatColors.color(" &dTotal Timings: &e" + SlimefunPlugin.getProfiler().getTime(item)));
|
||||
p.sendMessage(ChatColors.color(" &dChunk Timings: &e" + SlimefunPlugin.getProfiler().getTime(b.getChunk())));
|
||||
}
|
||||
else if (item.getEnergyTicker() != null) {
|
||||
p.sendMessage(ChatColors.color("&dTicking: " + "&3Indirect"));
|
||||
p.sendMessage(ChatColors.color(" &dTimings: &e" + NumberUtils.getAsMillis(ticker.getTimings(b))));
|
||||
p.sendMessage(ChatColors.color(" &dChunk Timings: &e" + NumberUtils.getAsMillis(ticker.getTimings(b.getChunk()))));
|
||||
p.sendMessage(ChatColors.color(" &dTimings: &e" + SlimefunPlugin.getProfiler().getTime(b)));
|
||||
p.sendMessage(ChatColors.color(" &dChunk Timings: &e" + SlimefunPlugin.getProfiler().getTime(b.getChunk())));
|
||||
}
|
||||
else {
|
||||
p.sendMessage(ChatColors.color("&dTicker: " + disabledTooltip));
|
||||
p.sendMessage(ChatColor.translateAlternateColorCodes('&', "&dTicking: " + disabledTooltip));
|
||||
p.sendMessage(ChatColors.color("&dTicker: " + redCross));
|
||||
p.sendMessage(ChatColors.color("&dTicking: " + redCross));
|
||||
}
|
||||
|
||||
if (ChargableBlock.isChargable(b)) {
|
||||
p.sendMessage(ChatColors.color("&dChargeable: " + enabledTooltip));
|
||||
p.sendMessage(ChatColors.color("&dChargeable: " + greenCheckmark));
|
||||
p.sendMessage(ChatColors.color(" &dEnergy: &e" + ChargableBlock.getCharge(b) + " / " + ChargableBlock.getMaxCharge(b)));
|
||||
}
|
||||
else {
|
||||
p.sendMessage(ChatColors.color("&dChargeable: " + disabledTooltip));
|
||||
p.sendMessage(ChatColors.color("&dChargeable: " + redCross));
|
||||
}
|
||||
|
||||
p.sendMessage(ChatColors.color(" &dEnergyNet Type: &e" + EnergyNet.getComponent(b.getLocation())));
|
||||
if (item instanceof EnergyNetComponent) {
|
||||
p.sendMessage(ChatColors.color(" &dEnergyNet Type: &e" + EnergyNet.getComponent(b.getLocation())));
|
||||
}
|
||||
|
||||
p.sendMessage(ChatColors.color("&6" + BlockStorage.getBlockInfoAsJson(b)));
|
||||
p.sendMessage(" ");
|
||||
|
||||
@ -1,70 +1,38 @@
|
||||
package io.github.thebusybiscuit.slimefun4.implementation.tasks;
|
||||
|
||||
import java.util.AbstractMap;
|
||||
import java.util.Comparator;
|
||||
import java.util.HashMap;
|
||||
import java.util.HashSet;
|
||||
import java.util.Iterator;
|
||||
import java.util.List;
|
||||
import java.util.Locale;
|
||||
import java.util.Map;
|
||||
import java.util.Map.Entry;
|
||||
import java.util.Set;
|
||||
import java.util.concurrent.ConcurrentHashMap;
|
||||
import java.util.concurrent.ConcurrentMap;
|
||||
import java.util.function.Function;
|
||||
import java.util.logging.Level;
|
||||
import java.util.stream.Collectors;
|
||||
import java.util.stream.Stream;
|
||||
|
||||
import org.bukkit.Bukkit;
|
||||
import org.bukkit.ChatColor;
|
||||
import org.bukkit.Chunk;
|
||||
import org.bukkit.Location;
|
||||
import org.bukkit.Material;
|
||||
import org.bukkit.World;
|
||||
import org.bukkit.block.Block;
|
||||
import org.bukkit.command.CommandSender;
|
||||
import org.bukkit.entity.Player;
|
||||
|
||||
import io.github.thebusybiscuit.cscorelib2.chat.ChatColors;
|
||||
import io.github.thebusybiscuit.slimefun4.api.ErrorReport;
|
||||
import io.github.thebusybiscuit.slimefun4.implementation.SlimefunPlugin;
|
||||
import io.github.thebusybiscuit.slimefun4.utils.NumberUtils;
|
||||
import io.github.thebusybiscuit.slimefun4.utils.PatternUtils;
|
||||
import me.mrCookieSlime.CSCoreLibPlugin.Configuration.Config;
|
||||
import me.mrCookieSlime.Slimefun.Objects.SlimefunItem.SlimefunItem;
|
||||
import me.mrCookieSlime.Slimefun.Objects.handlers.BlockTicker;
|
||||
import me.mrCookieSlime.Slimefun.api.BlockStorage;
|
||||
import me.mrCookieSlime.Slimefun.api.Slimefun;
|
||||
import net.md_5.bungee.api.chat.HoverEvent;
|
||||
import net.md_5.bungee.api.chat.TextComponent;
|
||||
|
||||
public class TickerTask implements Runnable {
|
||||
|
||||
private static final int VISIBILITY_THRESHOLD = 225_000;
|
||||
|
||||
private final Set<BlockTicker> tickers = new HashSet<>();
|
||||
|
||||
// These are "Queues" of blocks that need to be removed or moved
|
||||
private final ConcurrentMap<Location, Location> movingQueue = new ConcurrentHashMap<>();
|
||||
private final ConcurrentMap<Location, Boolean> deletionQueue = new ConcurrentHashMap<>();
|
||||
|
||||
private final ConcurrentMap<Location, Integer> buggedBlocks = new ConcurrentHashMap<>();
|
||||
|
||||
private final ConcurrentMap<Location, Long> blockTimings = new ConcurrentHashMap<>();
|
||||
private final ConcurrentMap<String, Integer> machineCount = new ConcurrentHashMap<>();
|
||||
private final ConcurrentMap<String, Long> machineTimings = new ConcurrentHashMap<>();
|
||||
|
||||
private final ConcurrentMap<String, Long> chunkTimings = new ConcurrentHashMap<>();
|
||||
private final ConcurrentMap<String, Integer> chunkItemCount = new ConcurrentHashMap<>();
|
||||
private final Set<String> skippedChunks = new HashSet<>();
|
||||
private final Map<Location, Location> movingQueue = new ConcurrentHashMap<>();
|
||||
private final Map<Location, Boolean> deletionQueue = new ConcurrentHashMap<>();
|
||||
private final Map<Location, Integer> buggedBlocks = new ConcurrentHashMap<>();
|
||||
|
||||
private boolean halted = false;
|
||||
|
||||
private int skippedBlocks = 0;
|
||||
private int chunks = 0;
|
||||
private int blocks = 0;
|
||||
private long time = 0;
|
||||
|
||||
private boolean running = false;
|
||||
|
||||
public void abortTick() {
|
||||
@ -78,18 +46,7 @@ public class TickerTask implements Runnable {
|
||||
}
|
||||
|
||||
running = true;
|
||||
long timestamp = System.nanoTime();
|
||||
|
||||
skippedBlocks = 0;
|
||||
chunks = 0;
|
||||
blocks = 0;
|
||||
chunkItemCount.clear();
|
||||
machineCount.clear();
|
||||
time = 0;
|
||||
chunkTimings.clear();
|
||||
skippedChunks.clear();
|
||||
machineTimings.clear();
|
||||
blockTimings.clear();
|
||||
SlimefunPlugin.getProfiler().start();
|
||||
|
||||
Map<Location, Integer> bugs = new HashMap<>(buggedBlocks);
|
||||
buggedBlocks.clear();
|
||||
@ -103,24 +60,23 @@ public class TickerTask implements Runnable {
|
||||
|
||||
if (!halted) {
|
||||
for (String chunk : BlockStorage.getTickingChunks()) {
|
||||
long chunkTimestamp = System.nanoTime();
|
||||
chunks++;
|
||||
try {
|
||||
Set<Location> locations = BlockStorage.getTickingLocations(chunk);
|
||||
String[] components = PatternUtils.SEMICOLON.split(chunk);
|
||||
|
||||
Set<Location> locations = BlockStorage.getTickingLocations(chunk);
|
||||
World world = Bukkit.getWorld(components[0]);
|
||||
int x = Integer.parseInt(components[components.length - 2]);
|
||||
int z = Integer.parseInt(components[components.length - 1]);
|
||||
|
||||
for (Location l : locations) {
|
||||
if (l.getWorld().isChunkLoaded(l.getBlockX() >> 4, l.getBlockZ() >> 4)) {
|
||||
tick(l, chunk, bugs);
|
||||
}
|
||||
else {
|
||||
skippedBlocks += locations.size();
|
||||
skippedChunks.add(chunk);
|
||||
chunks--;
|
||||
break;
|
||||
if (world != null && world.isChunkLoaded(x, z)) {
|
||||
for (Location l : locations) {
|
||||
tick(l, bugs);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
chunkTimings.put(chunk, System.nanoTime() - chunkTimestamp);
|
||||
catch (ArrayIndexOutOfBoundsException | NumberFormatException x) {
|
||||
Slimefun.getLogger().log(Level.SEVERE, x, () -> "An Exception has occured while trying to parse Chunk: " + chunk);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
@ -136,49 +92,27 @@ public class TickerTask implements Runnable {
|
||||
iterator.remove();
|
||||
}
|
||||
|
||||
time = System.nanoTime() - timestamp;
|
||||
running = false;
|
||||
SlimefunPlugin.getProfiler().stop();
|
||||
}
|
||||
|
||||
private void tick(Location l, String tickedChunk, Map<Location, Integer> bugs) {
|
||||
Block b = l.getBlock();
|
||||
SlimefunItem item = BlockStorage.check(l);
|
||||
private void tick(Location l, Map<Location, Integer> bugs) {
|
||||
Config data = BlockStorage.getLocationInfo(l);
|
||||
SlimefunItem item = SlimefunItem.getByID(data.getString("id"));
|
||||
|
||||
if (item != null && item.getBlockTicker() != null) {
|
||||
blocks++;
|
||||
|
||||
try {
|
||||
long timestamp = SlimefunPlugin.getProfiler().newEntry();
|
||||
Block b = l.getBlock();
|
||||
item.getBlockTicker().update();
|
||||
|
||||
if (item.getBlockTicker().isSynchronized()) {
|
||||
Slimefun.runSync(() -> {
|
||||
try {
|
||||
long timestamp = System.nanoTime();
|
||||
item.getBlockTicker().tick(b, item, BlockStorage.getLocationInfo(l));
|
||||
|
||||
long machinetime = NumberUtils.getLong(machineTimings.get(item.getID()), 0);
|
||||
int chunk = NumberUtils.getInt(chunkItemCount.get(tickedChunk), 0);
|
||||
int machine = NumberUtils.getInt(machineCount.get(item.getID()), 0);
|
||||
|
||||
machineTimings.put(item.getID(), machinetime + (System.nanoTime() - timestamp));
|
||||
chunkItemCount.put(tickedChunk, chunk + 1);
|
||||
machineCount.put(item.getID(), machine + 1);
|
||||
blockTimings.put(l, System.nanoTime() - timestamp);
|
||||
}
|
||||
catch (Exception | LinkageError x) {
|
||||
int errors = bugs.getOrDefault(l, 0);
|
||||
reportErrors(l, item, x, errors);
|
||||
}
|
||||
});
|
||||
// We are ignoring the timestamp from above because synchronized actions
|
||||
// are always ran with a 50ms delay (1 game tick)
|
||||
Slimefun.runSync(() -> tickBlock(bugs, l, b, item, data, System.nanoTime()));
|
||||
}
|
||||
else {
|
||||
long timestamp = System.nanoTime();
|
||||
item.getBlockTicker().tick(b, item, BlockStorage.getLocationInfo(l));
|
||||
|
||||
machineTimings.merge(item.getID(), (System.nanoTime() - timestamp), Long::sum);
|
||||
chunkItemCount.merge(tickedChunk, 1, Integer::sum);
|
||||
machineCount.merge(item.getID(), 1, Integer::sum);
|
||||
blockTimings.put(l, System.nanoTime() - timestamp);
|
||||
tickBlock(bugs, l, b, item, data, timestamp);
|
||||
}
|
||||
|
||||
tickers.add(item.getBlockTicker());
|
||||
@ -188,8 +122,18 @@ public class TickerTask implements Runnable {
|
||||
reportErrors(l, item, x, errors);
|
||||
}
|
||||
}
|
||||
else {
|
||||
skippedBlocks++;
|
||||
}
|
||||
|
||||
private void tickBlock(Map<Location, Integer> bugs, Location l, Block b, SlimefunItem item, Config data, long timestamp) {
|
||||
try {
|
||||
item.getBlockTicker().tick(b, item, data);
|
||||
}
|
||||
catch (Exception | LinkageError x) {
|
||||
int errors = bugs.getOrDefault(l, 0);
|
||||
reportErrors(l, item, x, errors);
|
||||
}
|
||||
finally {
|
||||
SlimefunPlugin.getProfiler().closeEntry(l, item, timestamp);
|
||||
}
|
||||
}
|
||||
|
||||
@ -215,101 +159,6 @@ public class TickerTask implements Runnable {
|
||||
}
|
||||
}
|
||||
|
||||
public String getTime() {
|
||||
return NumberUtils.getAsMillis(time);
|
||||
}
|
||||
|
||||
public void info(CommandSender sender) {
|
||||
sender.sendMessage(ChatColors.color("&2== &aSlimefun Diagnostic Tool &2=="));
|
||||
sender.sendMessage(ChatColors.color("&6Halted: &e&l" + String.valueOf(halted).toUpperCase(Locale.ROOT)));
|
||||
sender.sendMessage("");
|
||||
sender.sendMessage(ChatColors.color("&6Impact: &e" + NumberUtils.getAsMillis(time)));
|
||||
sender.sendMessage(ChatColors.color("&6Ticked Chunks: &e" + chunks));
|
||||
sender.sendMessage(ChatColors.color("&6Ticked Machines: &e" + blocks));
|
||||
sender.sendMessage(ChatColors.color("&6Skipped Machines: &e" + skippedBlocks));
|
||||
sender.sendMessage("");
|
||||
sender.sendMessage(ChatColors.color("&6Ticking Machines:"));
|
||||
|
||||
summarizeTimings(sender, entry -> {
|
||||
int count = machineCount.get(entry.getKey());
|
||||
String timings = NumberUtils.getAsMillis(entry.getValue());
|
||||
String average = NumberUtils.getAsMillis(entry.getValue() / count);
|
||||
|
||||
return entry.getKey() + " - " + count + "x (" + timings + ", " + average + " avg/machine)";
|
||||
}, machineCount.keySet().stream().map(key -> new AbstractMap.SimpleEntry<>(key, machineTimings.getOrDefault(key, 0L))));
|
||||
|
||||
sender.sendMessage("");
|
||||
sender.sendMessage(ChatColors.color("&6Ticking Chunks:"));
|
||||
|
||||
summarizeTimings(sender, entry -> {
|
||||
int count = chunkItemCount.getOrDefault(entry.getKey(), 0);
|
||||
String timings = NumberUtils.getAsMillis(entry.getValue());
|
||||
|
||||
return formatChunk(entry.getKey()) + " - " + count + "x (" + timings + ")";
|
||||
}, chunkTimings.entrySet().stream().filter(entry -> !skippedChunks.contains(entry.getKey())));
|
||||
}
|
||||
|
||||
private void summarizeTimings(CommandSender sender, Function<Map.Entry<String, Long>, String> formatter, Stream<Map.Entry<String, Long>> stream) {
|
||||
List<Entry<String, Long>> timings = stream.sorted(Map.Entry.comparingByValue(Comparator.reverseOrder())).collect(Collectors.toList());
|
||||
|
||||
if (sender instanceof Player) {
|
||||
TextComponent component = new TextComponent(" Hover for more Info");
|
||||
component.setColor(net.md_5.bungee.api.ChatColor.GRAY);
|
||||
component.setItalic(true);
|
||||
StringBuilder builder = new StringBuilder();
|
||||
int hidden = 0;
|
||||
|
||||
for (Map.Entry<String, Long> entry : timings) {
|
||||
if (entry.getValue() > VISIBILITY_THRESHOLD) {
|
||||
builder.append("\n&c").append(formatter.apply(entry));
|
||||
}
|
||||
else {
|
||||
hidden++;
|
||||
}
|
||||
}
|
||||
|
||||
builder.append("\n\n&c+ &4").append(hidden).append(" Hidden");
|
||||
component.setHoverEvent(new HoverEvent(HoverEvent.Action.SHOW_TEXT, TextComponent.fromLegacyText(ChatColors.color(builder.toString()))));
|
||||
sender.spigot().sendMessage(component);
|
||||
}
|
||||
else {
|
||||
int hidden = 0;
|
||||
|
||||
for (Map.Entry<String, Long> entry : timings) {
|
||||
if (entry.getValue() > VISIBILITY_THRESHOLD) {
|
||||
sender.sendMessage(" " + ChatColor.stripColor(formatter.apply(entry)));
|
||||
}
|
||||
else {
|
||||
hidden++;
|
||||
}
|
||||
}
|
||||
|
||||
sender.sendMessage("+ " + hidden + " Hidden");
|
||||
}
|
||||
}
|
||||
|
||||
private String formatChunk(String chunk) {
|
||||
String[] components = PatternUtils.SEMICOLON.split(chunk);
|
||||
return components[0] + " [" + components[2] + ',' + components[3] + ']';
|
||||
}
|
||||
|
||||
public long getTimings(Block b) {
|
||||
return blockTimings.getOrDefault(b.getLocation(), 0L);
|
||||
}
|
||||
|
||||
public long getTimings(String item) {
|
||||
return machineTimings.getOrDefault(item, 0L);
|
||||
}
|
||||
|
||||
public long getTimings(Chunk c) {
|
||||
String id = c.getWorld().getName() + ';' + c.getX() + ';' + c.getZ();
|
||||
return chunkTimings.getOrDefault(id, 0L);
|
||||
}
|
||||
|
||||
public void addBlockTimings(Location l, long time) {
|
||||
blockTimings.put(l, time);
|
||||
}
|
||||
|
||||
public boolean isHalted() {
|
||||
return halted;
|
||||
}
|
||||
@ -320,7 +169,7 @@ public class TickerTask implements Runnable {
|
||||
|
||||
@Override
|
||||
public String toString() {
|
||||
return "TickerTask {\n" + " HALTED = " + halted + "\n" + " tickers = " + tickers + "\n" + " move = " + movingQueue + "\n" + " delete = " + deletionQueue + "\n" + " chunks = " + chunkItemCount + "\n" + " machines = " + machineCount + "\n" + " machinetime = " + machineTimings + "\n" + " chunktime = " + chunkTimings + "\n" + " skipped = " + skippedChunks + "\n" + "}";
|
||||
return "TickerTask {\n" + " HALTED = " + halted + "\n" + " tickers = " + tickers + "\n" + " move = " + movingQueue + "\n" + " delete = " + deletionQueue + "}";
|
||||
}
|
||||
|
||||
public void queueMove(Location from, Location to) {
|
||||
|
||||
@ -69,6 +69,10 @@ public final class NumberUtils {
|
||||
}
|
||||
|
||||
public static String getAsMillis(long nanoseconds) {
|
||||
if (nanoseconds == 0) {
|
||||
return "0ms";
|
||||
}
|
||||
|
||||
String number = DECIMAL_FORMAT.format(nanoseconds / 1000000.0);
|
||||
String[] parts = PatternUtils.NUMBER_SEPERATOR.split(number);
|
||||
|
||||
@ -76,7 +80,7 @@ public final class NumberUtils {
|
||||
return parts[0];
|
||||
}
|
||||
else {
|
||||
return parts[0] + ',' + ChatColor.GRAY + parts[1] + "ms";
|
||||
return parts[0] + ',' + parts[1] + "ms";
|
||||
}
|
||||
}
|
||||
|
||||
|
||||
Loading…
Reference in New Issue
Block a user