profiler rework

This commit is contained in:
gnembon committed 2021-04-06 00:41:12 -03:00
1 parent 063b4b84ec
commit 647a3a15b6
8 files changed
+76 -59

No files matched your search

@@ -397,7 +397,7 @@ public class ScriptCommand
{ {
try try
{ {
CarpetProfiler.ProfilerToken currentSection = CarpetProfiler.start_section(null, "Scarpet ace", CarpetProfiler.TYPE.GENERAL); CarpetProfiler.ProfilerToken currentSection = CarpetProfiler.start_section(null, "Scarpet run", CarpetProfiler.TYPE.GENERAL);
host.setChatErrorSnooper(source); host.setChatErrorSnooper(source);
long start = System.nanoTime(); long start = System.nanoTime();
Value result = call.get(); Value result = call.get();
@@ -2,6 +2,7 @@ package carpet.mixins;
import carpet.CarpetServer; import carpet.CarpetServer;
import carpet.CarpetSettings; import carpet.CarpetSettings;
import carpet.utils.CarpetProfiler;
import net.minecraft.server.MinecraftServer; import net.minecraft.server.MinecraftServer;
import net.minecraft.server.WorldGenerationProgressListener; import net.minecraft.server.WorldGenerationProgressListener;
import org.spongepowered.asm.mixin.Mixin; import org.spongepowered.asm.mixin.Mixin;
@@ -26,7 +27,9 @@ public abstract class MinecraftServer_coreMixin
) )
) )
private void onTick(BooleanSupplier booleanSupplier_1, CallbackInfo ci) { private void onTick(BooleanSupplier booleanSupplier_1, CallbackInfo ci) {
CarpetProfiler.ProfilerToken token = CarpetProfiler.start_section(null, "Carpet", CarpetProfiler.TYPE.GENERAL);
CarpetServer.tick((MinecraftServer) (Object) this); CarpetServer.tick((MinecraftServer) (Object) this);
CarpetProfiler.end_current_section(token);
} }
@Inject(method = "loadWorld", at = @At("HEAD")) @Inject(method = "loadWorld", at = @At("HEAD"))
@@ -208,7 +208,8 @@ public abstract class MinecraftServer_tickspeedMixin extends ReentrantThreadExec
{ {
if (CarpetProfiler.tick_health_requested != 0L) if (CarpetProfiler.tick_health_requested != 0L)
{ {
CarpetProfiler.end_tick_profiling((MinecraftServer) (Object)this, currentSection); CarpetProfiler.end_current_section(currentSection);
CarpetProfiler.end_tick_profiling((MinecraftServer) (Object)this);
} }
} }
@@ -74,7 +74,7 @@ public class ClientNetworkHandler
TickSpeed.is_superHot = ((ByteTag) t).equals(ByteTag.ONE); TickSpeed.is_superHot = ((ByteTag) t).equals(ByteTag.ONE);
}); });
dataHandlers.put("TickPlayerActiveTimeout", (p, t) -> TickSpeed.player_active_timeout = ((AbstractNumberTag)t).getInt()); dataHandlers.put("TickPlayerActiveTimeout", (p, t) -> TickSpeed.player_active_timeout = ((AbstractNumberTag)t).getInt());
dataHandlers.put("scShape", (p, t) -> { // deprecated dataHandlers.put("scShape", (p, t) -> { // deprecated // and unused // should remove for 1.17
if (CarpetClient.shapes != null) if (CarpetClient.shapes != null)
CarpetClient.shapes.addShape((CompoundTag)t); CarpetClient.shapes.addShape((CompoundTag)t);
}); });
@@ -553,7 +553,7 @@ public class CarpetScriptHost extends ScriptHost
{ {
try try
{ {
CarpetProfiler.ProfilerToken currentSection = CarpetProfiler.start_section(null, "Scarpet legacy", CarpetProfiler.TYPE.GENERAL); CarpetProfiler.ProfilerToken currentSection = CarpetProfiler.start_section(null, "Scarpet command", CarpetProfiler.TYPE.GENERAL);
Value res = callLegacy(source, call, coords, arg); Value res = callLegacy(source, call, coords, arg);
CarpetProfiler.end_current_section(currentSection); CarpetProfiler.end_current_section(currentSection);
return res; return res;
@@ -225,7 +225,7 @@ public class CarpetScriptServer
public boolean addScriptHost(ServerCommandSource source, String name, Function<ServerCommandSource, Boolean> commandValidator, public boolean addScriptHost(ServerCommandSource source, String name, Function<ServerCommandSource, Boolean> commandValidator,
boolean perPlayer, boolean autoload, boolean isRuleApp) boolean perPlayer, boolean autoload, boolean isRuleApp)
{ {
CarpetProfiler.ProfilerToken currentSection = CarpetProfiler.start_section(null, "Scarpet loading", CarpetProfiler.TYPE.GENERAL); CarpetProfiler.ProfilerToken currentSection = CarpetProfiler.start_section(null, "Scarpet load", CarpetProfiler.TYPE.GENERAL);
if (commandValidator == null) commandValidator = p -> true; if (commandValidator == null) commandValidator = p -> true;
long start = System.nanoTime(); long start = System.nanoTime();
name = name.toLowerCase(Locale.ROOT); name = name.toLowerCase(Locale.ROOT);
@@ -1,6 +1,7 @@
package carpet.script.utils; package carpet.script.utils;
import carpet.CarpetSettings; import carpet.CarpetSettings;
import carpet.utils.CarpetProfiler;
import com.mojang.blaze3d.systems.RenderSystem; import com.mojang.blaze3d.systems.RenderSystem;
import it.unimi.dsi.fastutil.longs.Long2ObjectOpenHashMap; import it.unimi.dsi.fastutil.longs.Long2ObjectOpenHashMap;
import net.minecraft.client.MinecraftClient; import net.minecraft.client.MinecraftClient;
@@ -49,6 +50,7 @@ public class ShapesRenderer
public void render(Camera camera, float partialTick) public void render(Camera camera, float partialTick)
{ {
CarpetProfiler.ProfilerToken token = CarpetProfiler.start_section(null, "Scarpet client", CarpetProfiler.TYPE.GENERAL);
//Camera camera = this.client.gameRenderer.getCamera(); //Camera camera = this.client.gameRenderer.getCamera();
ClientWorld iWorld = this.client.world; ClientWorld iWorld = this.client.world;
RegistryKey<World> dimensionType = iWorld.getRegistryKey(); RegistryKey<World> dimensionType = iWorld.getRegistryKey();
@@ -120,14 +122,17 @@ public class ShapesRenderer
RenderSystem.defaultBlendFunc(); RenderSystem.defaultBlendFunc();
RenderSystem.enableTexture(); RenderSystem.enableTexture();
RenderSystem.shadeModel(7424); RenderSystem.shadeModel(7424);
CarpetProfiler.end_current_section(token);
} }
public void addShapes(ListTag tag) public void addShapes(ListTag tag)
{ {
CarpetProfiler.ProfilerToken token = CarpetProfiler.start_section(null, "Scarpet client", CarpetProfiler.TYPE.GENERAL);
for (int i=0, count = tag.size(); i < count; i++) for (int i=0, count = tag.size(); i < count; i++)
{ {
addShape(tag.getCompound(i)); addShape(tag.getCompound(i));
} }
CarpetProfiler.end_current_section(token);
} }
public void addShape(CompoundTag tag) public void addShape(CompoundTag tag)
@@ -169,12 +174,14 @@ public class ShapesRenderer
public void renewShapes() public void renewShapes()
{ {
CarpetProfiler.ProfilerToken token = CarpetProfiler.start_section(null, "Scarpet client", CarpetProfiler.TYPE.GENERAL);
synchronized (shapes) synchronized (shapes)
{ {
shapes.values().forEach(el -> el.values().forEach(shape -> { shapes.values().forEach(el -> el.values().forEach(shape -> {
shape.expiryTick++; shape.expiryTick++;
})); }));
} }
CarpetProfiler.end_current_section(token);
} }
public abstract static class RenderedShape<T extends ShapeDispatcher.ExpiringShape> public abstract static class RenderedShape<T extends ShapeDispatcher.ExpiringShape>
+60 -54
View File
@@ -1,6 +1,5 @@
package carpet.utils; package carpet.utils;
import carpet.CarpetSettings;
import it.unimi.dsi.fastutil.objects.Object2LongMap; import it.unimi.dsi.fastutil.objects.Object2LongMap;
import it.unimi.dsi.fastutil.objects.Object2LongOpenHashMap; import it.unimi.dsi.fastutil.objects.Object2LongOpenHashMap;
import net.minecraft.block.entity.BlockEntityType; import net.minecraft.block.entity.BlockEntityType;
@@ -9,6 +8,7 @@ import net.minecraft.entity.EntityType;
import net.minecraft.server.MinecraftServer; import net.minecraft.server.MinecraftServer;
import net.minecraft.block.entity.BlockEntity; import net.minecraft.block.entity.BlockEntity;
import net.minecraft.server.command.ServerCommandSource; import net.minecraft.server.command.ServerCommandSource;
import net.minecraft.util.Identifier;
import net.minecraft.util.registry.Registry; import net.minecraft.util.registry.Registry;
import net.minecraft.util.registry.RegistryKey; import net.minecraft.util.registry.RegistryKey;
import net.minecraft.world.World; import net.minecraft.world.World;
@@ -29,11 +29,13 @@ public class CarpetProfiler
private static ServerCommandSource currentRequester = null; private static ServerCommandSource currentRequester = null;
public static int tick_health_requested = 0; public static int tick_health_requested = 0;
private static int tick_health_elapsed = 0; private static int tick_health_elapsed = 0;
private static TYPE test_type = TYPE.NONE; //1 for ticks, 2 for entities; private static TYPE test_type = TYPE.NONE; //1 for ticks, 2 for entities
private static long current_tick_start = 0; private static long current_tick_start = 0;
private static final String[] GENERAL_SECTIONS = {"Network", "Autosave", "Async Tasks", "Datapacks", private static final String[] GENERAL_SECTIONS = {"Network", "Autosave", "Async Tasks", "Datapacks", "Carpet"};
"Scarpet ace", "Scarpet legacy", "Scarpet events", "Scarpet schedule", private static final String[] SCARPET_SECTIONS = {
"Scarpet command", "Scarpet loading", "Scarpet app data"}; "Scarpet run", "Scarpet events", "Scarpet schedule",
"Scarpet command", "Scarpet load", "Scarpet app data", "Scarpet client"
};
private static final String[] SECTIONS = { private static final String[] SECTIONS = {
"Spawning and Random Ticks", "Ticket Manager","Unloading", "Spawning and Random Ticks", "Ticket Manager","Unloading",
"Blocks", "Entities", "Block Entities", "Blocks", "Entities", "Block Entities",
@@ -55,28 +57,15 @@ public class CarpetProfiler
public final long start; public final long start;
public final World world; public final World world;
public ProfilerToken(TYPE type, Object section, World world, long start) public ProfilerToken(TYPE type, Object section, World world)
{ {
this.type = type; this.type = type;
this.section = section; this.section = section;
this.start = start; this.start = System.nanoTime();
this.world = world; this.world = world;
} }
} }
private static String getSectionString(World world, String section)
{
return String.format("%s.%s%s",
world.getRegistryKey().getValue().getPath(),
section, // ^ getDImension getId
world.isClient ? " (Client)" : "");
}
private static String getDimName(RegistryKey<World> world)
{
return world.getValue().getPath();
}
public static void prepare_tick_report(ServerCommandSource source, int ticks) public static void prepare_tick_report(ServerCommandSource source, int ticks)
{ {
//maybe add so it only spams the sending player, but honestly - all may want to see it //maybe add so it only spams the sending player, but honestly - all may want to see it
@@ -85,17 +74,19 @@ public class CarpetProfiler
ENTITY_TIMES.clear(); ENTITY_TIMES.clear();
test_type = TYPE.GENERAL; test_type = TYPE.GENERAL;
SECTION_STATS.put("tick", 0L); SECTION_STATS.put("tick", 0L);
SECTION_STATS.put("Network", 0L);
SECTION_STATS.put("Autosave", 0L);
for (String section : GENERAL_SECTIONS) for (String section : GENERAL_SECTIONS)
{ {
SECTION_STATS.put(section, 0L); SECTION_STATS.put(section, 0L);
} }
for (String section : SCARPET_SECTIONS)
{
SECTION_STATS.put(section, 0L);
}
for (RegistryKey<World> level : source.getMinecraftServer().getWorldRegistryKeys()) for (RegistryKey<World> level : source.getMinecraftServer().getWorldRegistryKeys())
{ {
for (String section : SECTIONS) for (String section : SECTIONS)
{ {
SECTION_STATS.put(getDimName(level) + "." + section, 0L); SECTION_STATS.put(level.getValue() + "." + section, 0L);
} }
} }
@@ -123,21 +114,21 @@ public class CarpetProfiler
{ {
if (tick_health_requested == 0L || test_type != TYPE.GENERAL || current_tick_start == 0) if (tick_health_requested == 0L || test_type != TYPE.GENERAL || current_tick_start == 0)
return null; return null;
return new ProfilerToken(type, name, world, System.nanoTime()); return new ProfilerToken(type, name, world);
} }
public static ProfilerToken start_entity_section(World world, Entity e, TYPE type) public static ProfilerToken start_entity_section(World world, Entity e, TYPE type)
{ {
if (tick_health_requested == 0L || test_type != TYPE.ENTITY || current_tick_start == 0) if (tick_health_requested == 0L || test_type != TYPE.ENTITY || current_tick_start == 0)
return null; return null;
return new ProfilerToken(type, e.getType(), world, System.nanoTime()); return new ProfilerToken(type, e.getType(), world);
} }
public static ProfilerToken start_block_entity_section(World world, BlockEntity be, TYPE type) public static ProfilerToken start_block_entity_section(World world, BlockEntity be, TYPE type)
{ {
if (tick_health_requested == 0L || test_type != TYPE.ENTITY || current_tick_start == 0) if (tick_health_requested == 0L || test_type != TYPE.ENTITY || current_tick_start == 0)
return null; return null;
return new ProfilerToken(type, be.getType(), world, System.nanoTime()); return new ProfilerToken(type, be.getType(), world);
} }
public static void end_current_section(ProfilerToken tok) public static void end_current_section(ProfilerToken tok)
@@ -147,8 +138,10 @@ public class CarpetProfiler
long end_time = System.nanoTime(); long end_time = System.nanoTime();
if (tok.type == TYPE.GENERAL) if (tok.type == TYPE.GENERAL)
{ {
String current_section = (tok.world == null) ? (String) tok.section : World world = tok.world;
getSectionString(tok.world, (String)tok.section); String current_section = (world == null) ?
(String) tok.section :
String.format("%s.%s%s", world.getRegistryKey().getValue(), tok.section, world.isClient ? " (Client)" : "");
SECTION_STATS.put(current_section, SECTION_STATS.getOrDefault(current_section, 0L) + end_time - tok.start); SECTION_STATS.put(current_section, SECTION_STATS.getOrDefault(current_section, 0L) + end_time - tok.start);
} }
} }
@@ -168,12 +161,10 @@ public class CarpetProfiler
current_tick_start = System.nanoTime(); current_tick_start = System.nanoTime();
} }
public static void end_tick_profiling(MinecraftServer server, ProfilerToken postTasks) public static void end_tick_profiling(MinecraftServer server)
{ {
if (current_tick_start == 0L) if (current_tick_start == 0L)
return; return;
if (postTasks != null)
end_current_section(postTasks);
SECTION_STATS.put("tick", SECTION_STATS.get("tick") + System.nanoTime() - current_tick_start); SECTION_STATS.put("tick", SECTION_STATS.get("tick") + System.nanoTime() - current_tick_start);
tick_health_elapsed--; tick_health_elapsed--;
if (tick_health_elapsed <= 0) if (tick_health_elapsed <= 0)
@@ -212,7 +203,7 @@ public class CarpetProfiler
long total_tick_time = SECTION_STATS.get("tick"); long total_tick_time = SECTION_STATS.get("tick");
double divider = 1.0D / tick_health_requested / 1000000; double divider = 1.0D / tick_health_requested / 1000000;
Messenger.m(currentRequester, "w "); Messenger.m(currentRequester, "w ");
Messenger.m(currentRequester, String.format("gi Avg. server tick time: %.3fms", divider * total_tick_time)); Messenger.m(currentRequester, "wb Average tick time: ", String.format("yb %.3fms", divider * total_tick_time));
long accumulated = 0L; long accumulated = 0L;
for (String section : GENERAL_SECTIONS) for (String section : GENERAL_SECTIONS)
@@ -221,18 +212,26 @@ public class CarpetProfiler
if (amount > 0.01) if (amount > 0.01)
{ {
accumulated += SECTION_STATS.get(section); accumulated += SECTION_STATS.get(section);
Messenger.m(currentRequester, String.format("gi %s: %.3fms", section, amount)); Messenger.m(currentRequester, "w "+section+": ", String.format("y %.3fms", amount));
}
}
for (String section : SCARPET_SECTIONS)
{
double amount = divider * SECTION_STATS.get(section);
if (amount > 0.01)
{
Messenger.m(currentRequester, "gi "+section+": ", String.format("di %.3fms", amount));
} }
} }
for (RegistryKey<World> dim : server.getWorldRegistryKeys()) for (RegistryKey<World> dim : server.getWorldRegistryKeys())
{ {
String dimension = getDimName(dim); Identifier dimensionId = dim.getValue();
boolean hasSomethin = false; boolean hasSomethin = false;
for (String section : SECTIONS) for (String section : SECTIONS)
{ {
double amount = divider * SECTION_STATS.getOrDefault(dimension + "." + section, 0L); double amount = divider * SECTION_STATS.getOrDefault(dimensionId + "." + section, 0L);
if (amount > 0.01) if (amount > 0.01)
{ {
hasSomethin = true; hasSomethin = true;
@@ -243,15 +242,16 @@ public class CarpetProfiler
{ {
continue; continue;
} }
Messenger.m(currentRequester, "gi "+dimension + ":"); Messenger.m(currentRequester, "wb "+(dimensionId.getNamespace().equals("minecraft")?dimensionId.getPath():dimensionId.toString()) + ":");
for (String section : SECTIONS) for (String section : SECTIONS)
{ {
double amount = divider * SECTION_STATS.getOrDefault(dimension + "." + section, 0L); double amount = divider * SECTION_STATS.getOrDefault(dimensionId + "." + section, 0L);
if (amount > 0.01) if (amount > 0.01)
{ {
if (!(section.endsWith("(Client)"))) boolean cli = section.endsWith("(Client)");
accumulated += SECTION_STATS.get(dimension + "." + section); if (!cli)
Messenger.m(currentRequester, String.format("gi - %s: %.3fms", section, amount)); accumulated += SECTION_STATS.get(dimensionId + "." + section);
Messenger.m(currentRequester, String.format("%s - %s: ", cli?"gi":"w", section), String.format("%s %.3fms", cli?"di":"y", amount));
} }
} }
} }
@@ -263,20 +263,22 @@ public class CarpetProfiler
private static String sectionName(Pair<World,Object> section) private static String sectionName(Pair<World,Object> section)
{ {
String name; Identifier id;
if (section.getValue() instanceof EntityType) if (section.getValue() instanceof EntityType)
{ {
name = Registry.ENTITY_TYPE.getId((EntityType<?>) section.getValue()).getPath(); id = Registry.ENTITY_TYPE.getId((EntityType<?>) section.getValue());
} }
else else
{ {
name = Registry.BLOCK_ENTITY_TYPE.getId((BlockEntityType<?>) section.getValue()).getPath(); id = Registry.BLOCK_ENTITY_TYPE.getId((BlockEntityType<?>) section.getValue());
} }
String name = "minecraft".equals(id.getNamespace())?id.getPath():id.toString();
if (section.getKey().isClient) if (section.getKey().isClient)
{ {
name += " (client)"; name += " (client)";
} }
String dim = section.getKey().getRegistryKey().getValue().getPath(); Identifier dimkey = section.getKey().getRegistryKey().getValue();
String dim = "minecraft".equals(dimkey.getNamespace())?dimkey.getPath():dimkey.toString();
return name+" in "+dim; return name+" in "+dim;
} }
@@ -287,31 +289,35 @@ public class CarpetProfiler
long total_tick_time = SECTION_STATS.get("tick"); long total_tick_time = SECTION_STATS.get("tick");
double divider = 1.0D / tick_health_requested / 1000000; double divider = 1.0D / tick_health_requested / 1000000;
double divider_1 = 1.0D / (tick_health_requested - 1) / 1000000; double divider_1 = 1.0D / (tick_health_requested - 1) / 1000000;
Messenger.m(currentRequester, "gi "); Messenger.m(currentRequester, "w ");
Messenger.m(currentRequester, String.format("gi Average tick time: %.3fms", divider * total_tick_time)); Messenger.m(currentRequester, "wb Average tick time: ", String.format("yb %.3fms", divider * total_tick_time));
SECTION_STATS.remove("tick"); SECTION_STATS.remove("tick");
Messenger.m(currentRequester, "gi Top 10 counts:"); Messenger.m(currentRequester, "wb Top 10 counts:");
int total = 0; int total = 0;
for (Object2LongMap.Entry<Pair<World, Object>> sectionEntry : ENTITY_COUNT.object2LongEntrySet().stream().sorted(Map.Entry.comparingByValue(Comparator.reverseOrder())).collect(Collectors.toList())) for (Object2LongMap.Entry<Pair<World, Object>> sectionEntry : ENTITY_COUNT.object2LongEntrySet().stream().sorted(Map.Entry.comparingByValue(Comparator.reverseOrder())).collect(Collectors.toList()))
{ {
if (++total > 10) break; if (++total > 10) break;
Pair<World,Object> section = sectionEntry.getKey(); Pair<World,Object> section = sectionEntry.getKey();
boolean cli = section.getKey().isClient;
Messenger.m(currentRequester, String.format( Messenger.m(currentRequester, String.format(
"gi - %s: %.1f", "%s - %s: ", cli?"gi":"w",
sectionName(section), sectionName(section)),
1.0D * sectionEntry.getLongValue() / (tick_health_requested - (section.getKey().isClient? 1 : 0)) String.format("%s %.1f", cli?"di":"y",
1.0D * sectionEntry.getLongValue() / (tick_health_requested - (cli? 1 : 0))
)); ));
} }
Messenger.m(currentRequester, "gi Top 10 CPU hogs:"); Messenger.m(currentRequester, "wb Top 10 CPU hogs:");
total = 0; total = 0;
for (Object2LongMap.Entry<Pair<World,Object>> sectionEntry : ENTITY_TIMES.object2LongEntrySet().stream().sorted(Map.Entry.comparingByValue(Comparator.reverseOrder())).collect(Collectors.toList())) for (Object2LongMap.Entry<Pair<World,Object>> sectionEntry : ENTITY_TIMES.object2LongEntrySet().stream().sorted(Map.Entry.comparingByValue(Comparator.reverseOrder())).collect(Collectors.toList()))
{ {
if (++total > 10) break; if (++total > 10) break;
Pair<World,Object> section = sectionEntry.getKey(); Pair<World,Object> section = sectionEntry.getKey();
boolean cli = section.getKey().isClient;
Messenger.m(currentRequester, String.format( Messenger.m(currentRequester, String.format(
"gi - %s: %.2fms", "%s - %s: ", cli?"gi":"w",
sectionName(section), sectionName(section)),
(section.getKey().isClient ? divider : divider_1) * sectionEntry.getLongValue() String.format("%s %.2fms", cli?"di":"y",
(cli ? divider : divider_1) * sectionEntry.getLongValue()
)); ));
} }
} }