Skip to content

Commit

Permalink
Clean up profiler implementation and separate it from command handlin…
Browse files Browse the repository at this point in the history
…g, add periodic saving of profiling information to disk.

Signed-off-by: Ross Allan <rallanpcl@gmail.com>
  • Loading branch information
LunNova committed May 29, 2013
1 parent 31493a5 commit 6f97fe8
Show file tree
Hide file tree
Showing 4 changed files with 132 additions and 43 deletions.
73 changes: 71 additions & 2 deletions src/common/me/nallar/tickprofiler/minecraft/TickProfiler.java
@@ -1,20 +1,31 @@
package me.nallar.tickprofiler.minecraft;

import java.io.File;
import java.lang.reflect.Field;
import java.util.Arrays;
import java.util.EnumSet;
import java.util.List;

import com.google.common.base.Charsets;
import com.google.common.io.Files;

import cpw.mods.fml.common.IScheduledTickHandler;
import cpw.mods.fml.common.Mod;
import cpw.mods.fml.common.TickType;
import cpw.mods.fml.common.event.FMLInitializationEvent;
import cpw.mods.fml.common.event.FMLPreInitializationEvent;
import cpw.mods.fml.common.event.FMLServerStartingEvent;
import cpw.mods.fml.common.network.NetworkMod;
import cpw.mods.fml.common.registry.TickRegistry;
import cpw.mods.fml.relauncher.Side;
import me.nallar.tickprofiler.Log;
import me.nallar.tickprofiler.minecraft.commands.Command;
import me.nallar.tickprofiler.minecraft.commands.DumpCommand;
import me.nallar.tickprofiler.minecraft.commands.ProfileCommand;
import me.nallar.tickprofiler.minecraft.entitylist.EntityList;
import me.nallar.tickprofiler.minecraft.entitylist.LoadedEntityList;
import me.nallar.tickprofiler.minecraft.entitylist.LoadedTileEntityList;
import me.nallar.tickprofiler.minecraft.profiling.EntityTickProfiler;
import me.nallar.tickprofiler.reporting.Metrics;
import me.nallar.tickprofiler.util.ReflectUtil;
import me.nallar.tickprofiler.util.TableFormatter;
Expand All @@ -24,8 +35,10 @@
import net.minecraft.item.Item;
import net.minecraft.item.ItemStack;
import net.minecraft.network.packet.PacketCount;
import net.minecraft.server.MinecraftServer;
import net.minecraft.world.World;
import net.minecraftforge.common.Configuration;
import net.minecraftforge.common.DimensionManager;
import net.minecraftforge.common.MinecraftForge;
import net.minecraftforge.event.ForgeSubscribe;
import net.minecraftforge.event.entity.player.PlayerInteractEvent;
Expand All @@ -40,6 +53,8 @@ public class TickProfiler {
private static final int loadedTileEntityFieldIndex = 2;
public boolean requireOpForProfileCommand = true;
public boolean requireOpForDumpCommand = true;
private int profilingInterval = 0;
private String profilingFileName = "profile.txt";

static {
new Metrics("TickProfiler", VersionUtil.versionNumber());
Expand All @@ -52,6 +67,15 @@ public TickProfiler() {
@Mod.Init
public void init(FMLInitializationEvent event) {
MinecraftForge.EVENT_BUS.register(this);
initPeriodicProfiling();
}

private void initPeriodicProfiling() {
final int profilingInterval = this.profilingInterval;
if (profilingInterval == 0) {
return;
}
TickRegistry.registerScheduledTickHandler(new ProfilingScheduledTickHandler(profilingInterval, MinecraftServer.getServer().getFile(profilingFileName)), Side.SERVER);
}

@SuppressWarnings ("FieldRepeatedlyAccessedInMethod")
Expand All @@ -65,6 +89,8 @@ public void preInit(FMLPreInitializationEvent event) {
DumpCommand.name = config.get(GENERAL, "dumpCommandName", DumpCommand.name, "Name of the command to be used for profiling reports.").value;
requireOpForProfileCommand = config.get(GENERAL, "requireOpForProfileCommand", requireOpForProfileCommand, "If a player must be opped to use /profile").getBoolean(requireOpForProfileCommand);
requireOpForDumpCommand = config.get(GENERAL, "requireOpForProfileCommand", requireOpForDumpCommand, "If a player must be opped to use /dump").getBoolean(requireOpForDumpCommand);
profilingInterval = config.get(GENERAL, "profilingInterval", profilingInterval, "Interval, in minutes, to record profiling information to disk. 0 = never. Recommended >= 5.").getInt();
profilingFileName = config.get(GENERAL, "profilingFileName", profilingFileName, "Location to store profiling information to. For example, why not store it in a computercraft computer's folder?").value;
config.save();
PacketCount.allowCounting = false;
}
Expand All @@ -80,7 +106,6 @@ public void serverStarting(FMLServerStartingEvent event) {
public synchronized void hookProfiler(World world) {
if (world.isRemote) {
Log.severe("World " + Log.name(world) + " seems to be a client world", new Throwable());
return;
}
try {
Field loadedTileEntityField = ReflectUtil.getFields(World.class, List.class)[loadedTileEntityFieldIndex];
Expand All @@ -96,7 +121,6 @@ public synchronized void hookProfiler(World world) {
public synchronized void unhookProfiler(World world) {
if (world.isRemote) {
Log.severe("World " + Log.name(world) + " seems to be a client world", new Throwable());
return;
}
try {
Field loadedTileEntityField = ReflectUtil.getFields(World.class, List.class)[loadedTileEntityFieldIndex];
Expand Down Expand Up @@ -133,4 +157,49 @@ public void onPlayerInteract(PlayerInteractEvent event) {
}
}
}

private static class ProfilingScheduledTickHandler implements IScheduledTickHandler {
private static final EnumSet<TickType> TICKS = EnumSet.of(TickType.SERVER);
private final int profilingInterval;
private final File profilingFile;

public ProfilingScheduledTickHandler(final int profilingInterval, final File profilingFile) {
this.profilingInterval = profilingInterval;
this.profilingFile = profilingFile;
}

@Override
public int nextTickSpacing() {
return profilingInterval * 60 * 20;
}

@Override
public void tickStart(final EnumSet<TickType> type, final Object... tickData) {
final EntityTickProfiler entityTickProfiler = EntityList.ENTITY_TICK_PROFILER;
entityTickProfiler.startProfiling(new Runnable() {
@Override
public void run() {
try {
Files.write(entityTickProfiler.writeData(new TableFormatter(MinecraftServer.getServer())).toString(), profilingFile, Charsets.UTF_8);
} catch (Throwable t) {
Log.severe("Failed to save periodic profiling data to " + profilingFile, t);
}
}
}, ProfileCommand.ProfilingState.GLOBAL, 20, Arrays.<World>asList(DimensionManager.getWorlds()));
}

@Override
public void tickEnd(final EnumSet<TickType> type, final Object... tickData) {
}

@Override
public EnumSet<TickType> ticks() {
return TICKS;
}

@Override
public String getLabel() {
return "TickProfiler scheduled profiling handler";
}
}
}
Expand Up @@ -30,14 +30,11 @@ public boolean requireOp() {
@Override
public void processCommand(final ICommandSender commandSender, List<String> arguments) {
World world = null;
long time_ = 30;
int time_ = 30;
boolean location = false;
Integer x = null;
Integer z = null;
try {
if (arguments.isEmpty()) {
throw new Exception();
}
if ("c".equals(arguments.get(0))) {
location = true;
if (arguments.size() > 2) {
Expand All @@ -53,8 +50,13 @@ public void processCommand(final ICommandSender commandSender, List<String> argu
} else if (commandSender instanceof Entity) {
world = ((Entity) commandSender).worldObj;
}
if (location && x == null) {
Entity entity = (Entity) commandSender;
x = entity.chunkCoordX;
z = entity.chunkCoordZ;
}
} catch (Exception e) {
sendChat(commandSender, "Usage: /profile e/(c [chunk x] [chunk z])] [time=30] [dimensionid=all]");
sendChat(commandSender, "Usage: /profile [e/(c [chunk x] [chunk z])] [time=30] [dimensionid=all]");
return;
}
final List<World> worlds = new ArrayList<World>();
Expand All @@ -63,42 +65,20 @@ public void processCommand(final ICommandSender commandSender, List<String> argu
} else {
worlds.add(world);
}
final long time = time_;
synchronized (EntityList.class) {
if (!EntityList.startProfiling(location ? ProfilingState.CHUNK : ProfilingState.GLOBAL)) {
sendChat(commandSender, "Someone else is currently profiling.");
return;
}
for (World world_ : worlds) {
TickProfiler.instance.hookProfiler(world_);
}
EntityTickProfiler entityTickProfiler = EntityList.ENTITY_TICK_PROFILER;
if (location) {
entityTickProfiler.setLocation(x, z);
}
}
Runnable profilingRunnable = new Runnable() {
final int time = time_;
final EntityTickProfiler entityTickProfiler = EntityList.ENTITY_TICK_PROFILER;
if (!entityTickProfiler.startProfiling(new Runnable() {
@Override
public void run() {
try {
Thread.sleep(1000 * time);
} catch (InterruptedException ignored) {
}

synchronized (EntityList.class) {
EntityList.endProfiling();
sendChat(commandSender, EntityList.ENTITY_TICK_PROFILER.writeData(new TableFormatter(commandSender)).toString());
EntityList.ENTITY_TICK_PROFILER.clear();
for (World world_ : worlds) {
TickProfiler.instance.unhookProfiler(world_);
}
}
sendChat(commandSender, entityTickProfiler.writeData(new TableFormatter(commandSender)).toString());
}
};
Thread profilingThread = new Thread(profilingRunnable);
profilingThread.setName("TickProfiler");
}, location ? ProfilingState.CHUNK : ProfilingState.GLOBAL, time, worlds)) {
sendChat(commandSender, "Someone else is currently profiling.");
}
if (location) {
entityTickProfiler.setLocation(x, z);
}
sendChat(commandSender, "Profiling for " + time + " seconds in " + (world == null ? "all worlds " : Log.name(world)) + (location ? " at " + x + ',' + z : ""));
profilingThread.start();
}

public static enum ProfilingState {
Expand Down
Expand Up @@ -77,7 +77,7 @@ public void ensureCapacity(final int minCapacity) {

@Override
public int size() {
if (profilingState == ProfileCommand.ProfilingState.NONE || !World.class.isAssignableFrom(contextAccess.getContext(1)) || !MinecraftServer.class.isAssignableFrom(contextAccess.getContext(2))) {
if (profilingState == ProfileCommand.ProfilingState.NONE || !World.class.isAssignableFrom(contextAccess.getContext(1)) || !World.class.isAssignableFrom(contextAccess.getContext(2))) {
return innerList.size();
}
tick();
Expand Down Expand Up @@ -186,7 +186,7 @@ public ListIterator<T> listIterator() {

@Override
public Iterator<T> iterator() {
if (profilingState == ProfileCommand.ProfilingState.NONE || !World.class.isAssignableFrom(contextAccess.getContext(1)) || !MinecraftServer.class.isAssignableFrom(contextAccess.getContext(2))) {
if (profilingState == ProfileCommand.ProfilingState.NONE || !World.class.isAssignableFrom(contextAccess.getContext(1)) || !World.class.isAssignableFrom(contextAccess.getContext(2))) {
return innerList.iterator();
}
tick();
Expand Down
@@ -1,6 +1,7 @@
package me.nallar.tickprofiler.minecraft.profiling;

import java.util.ArrayList;
import java.util.Collection;
import java.util.HashMap;
import java.util.Iterator;
import java.util.List;
Expand All @@ -11,6 +12,7 @@
import com.google.common.base.Functions;
import com.google.common.collect.Ordering;

import me.nallar.tickprofiler.minecraft.TickProfiler;
import me.nallar.tickprofiler.minecraft.commands.ProfileCommand;
import me.nallar.tickprofiler.minecraft.entitylist.EntityList;
import me.nallar.tickprofiler.util.MappingUtil;
Expand All @@ -28,14 +30,52 @@
public class EntityTickProfiler {
private int ticks;
private final AtomicLong totalTime = new AtomicLong();
private int chunkX;
private int chunkZ;
private volatile int chunkX;
private volatile int chunkZ;

public void setLocation(final int x, final int z) {
chunkX = x;
chunkZ = z;
}

public boolean startProfiling(final Runnable runnable, ProfileCommand.ProfilingState state, final int time, final Collection<World> worlds_) {
if (time <= 0) {
throw new IllegalArgumentException("time must be > 0");
}
final Collection<World> worlds = new ArrayList<World>(worlds_);
synchronized (EntityList.class) {
if (!EntityList.startProfiling(state)) {
return false;
}
for (World world_ : worlds) {
TickProfiler.instance.hookProfiler(world_);
}
}

Runnable profilingRunnable = new Runnable() {
@Override
public void run() {
try {
Thread.sleep(1000 * time);
} catch (InterruptedException ignored) {
}

synchronized (EntityList.class) {
EntityList.endProfiling();
runnable.run();
clear();
for (World world_ : worlds) {
TickProfiler.instance.unhookProfiler(world_);
}
}
}
};
Thread profilingThread = new Thread(profilingRunnable);
profilingThread.setName("TickProfiler");
profilingThread.start();
return true;
}

public void runEntities(World world, ArrayList<Entity> toTick) {
long end = System.nanoTime();
long start;
Expand Down

0 comments on commit 6f97fe8

Please sign in to comment.