Debug messages: Execution time on reload/enable.

~ Probably needs removed later?

2 files changed, 105 insertions, 2 deletions

diff --git a/Essentials/src/com/earth2me/essentials/Essentials.java b/Essentials/src/com/earth2me/essentials/Essentials.java
index 1ad9a6893..a571483f6 100644
--- a/Essentials/src/com/earth2me/essentials/Essentials.java
+++ b/Essentials/src/com/earth2me/essentials/Essentials.java
@@ -60,6 +60,7 @@ public class Essentials extends JavaPlugin implements IEssentials
 	private transient final Methods paymentMethod = new Methods();
 	private transient PermissionsHandler permissionsHandler;
 	private transient UserMap userMap;
+	private transient ExecuteTimer execTimer;
 
 	@Override
 	public ISettings getSettings()
@@ -90,6 +91,8 @@ public class Essentials extends JavaPlugin implements IEssentials
 	@Override
 	public void onEnable()
 	{
+		execTimer = new ExecuteTimer();
+		execTimer.start();
 		final String[] javaversion = System.getProperty("java.version").split("\\.", 3);
 		if (javaversion == null || javaversion.length < 2 || Integer.parseInt(javaversion[1]) < 6)
 		{
@@ -97,21 +100,27 @@ public class Essentials extends JavaPlugin implements IEssentials
 		}
 		final EssentialsUpgrade upgrade = new EssentialsUpgrade(this);
 		upgrade.beforeSettings();
+		execTimer.mark("Upgrade");
 		confList = new ArrayList<IConf>();
 		settings = new Settings(this);
 		confList.add(settings);
+		execTimer.mark("Settings");
 		upgrade.afterSettings();
+		execTimer.mark("Upgrade2");
 		Util.updateLocale(settings.getLocale(), this);
 		userMap = new UserMap(this);
 		confList.add(userMap);
+		execTimer.mark("Init(Usermap)");
 		spawn = new Spawn(getServer(), this.getDataFolder());
 		confList.add(spawn);
 		warps = new Warps(getServer(), this.getDataFolder());
 		confList.add(warps);
+		execTimer.mark("Init(Spawn/Warp)");
 		worth = new Worth(this.getDataFolder());
 		confList.add(worth);
 		itemDb = new ItemDb(this);
 		confList.add(itemDb);
+		execTimer.mark("Init(Worth/ItemDB)");
 		reload();
 		backup = new Backup(this);
 
@@ -183,6 +192,7 @@ public class Essentials extends JavaPlugin implements IEssentials
 		pm.registerEvent(Type.ENTITY_REGAIN_HEALTH, entityListener, Priority.Lowest, this);
 		pm.registerEvent(Type.FOOD_LEVEL_CHANGE, entityListener, Priority.Lowest, this);
 
+		//TODO: Check if this should be here, and not above before reload()
 		jail = new Jail(this);
 		final JailPlayerListener jailPlayerListener = new JailPlayerListener(this);
 		confList.add(jail);
@@ -199,7 +209,13 @@ public class Essentials extends JavaPlugin implements IEssentials
 		final EssentialsTimer timer = new EssentialsTimer(this);
 		getScheduler().scheduleSyncRepeatingTask(this, timer, 1, 100);
 		Economy.setEss(this);
+		execTimer.mark("RegListeners");
 		LOGGER.info(Util.format("loadinfo", this.getDescription().getName(), this.getDescription().getVersion(), Util.joinList(this.getDescription().getAuthors())));
+		final String timeroutput = execTimer.end();
+		if (getSettings().isDebug())
+		{
+			LOGGER.log(Level.INFO, "Essentials load " + timeroutput);
+		}
 	}
 
 	@Override
@@ -216,6 +232,7 @@ public class Essentials extends JavaPlugin implements IEssentials
 		for (IConf iConf : confList)
 		{
 			iConf.reloadConfig();
+			execTimer.mark("Reload(" + iConf.getClass().getSimpleName() + ")");
 		}
 
 		Util.updateLocale(settings.getLocale(), this);
@@ -587,10 +604,12 @@ public class Essentials extends JavaPlugin implements IEssentials
 	@Override
 	public int broadcastMessage(final IUser sender, final String message)
 	{
-		if (sender == null) {
+		if (sender == null)
+		{
 			return getServer().broadcastMessage(message);
 		}
-		if (sender.isHidden()) {
+		if (sender.isHidden())
+		{
 			return 0;
 		}
 		final Player[] players = getServer().getOnlinePlayers();
diff --git a/Essentials/src/com/earth2me/essentials/ExecuteTimer.java b/Essentials/src/com/earth2me/essentials/ExecuteTimer.java
new file mode 100644
index 000000000..7a88018c2
--- /dev/null
+++ b/Essentials/src/com/earth2me/essentials/ExecuteTimer.java
@@ -0,0 +1,84 @@
+package com.earth2me.essentials;
+
+import java.util.ArrayList;
+import java.util.List;
+
+
+public class ExecuteTimer
+{
+	private final List<ExecuteRecord> times;
+
+	public ExecuteTimer()
+	{
+		times = new ArrayList<ExecuteRecord>();
+	}
+
+	public void start()
+	{
+		times.clear();
+		mark("start");
+
+	}
+
+	public void mark(final String label)
+	{
+		if (!times.isEmpty() || "start".equals(label))
+		{
+			times.add(new ExecuteRecord(label, System.currentTimeMillis()));
+		}
+	}
+
+	public String end()
+	{
+		final StringBuilder output = new StringBuilder();
+		output.append("execution time: ");
+		String mark;
+		long time0 = 0;
+		long time1 = 0;
+		long time2 = 0;
+		long duration;
+
+		for (ExecuteRecord pair : times)
+		{
+			mark = (String)pair.getMark();
+			time2 = (Long)pair.getTime();
+			if (time1 > 0)
+			{
+				duration = time2 - time1;
+				output.append(mark).append(": ").append(duration).append("ms - ");
+			}
+			else
+			{
+				time0 = time2;
+			}
+			time1 = time2;
+		}
+		duration = time1 - time0;
+		output.append("Total: ").append(duration).append("ms");
+		times.clear();
+		return output.toString();
+	}
+
+
+	static private class ExecuteRecord
+	{
+		private final String mark;
+		private final long time;
+
+		public ExecuteRecord(final String mark, final long time)
+		{
+			this.mark = mark;
+			this.time = time;
+		}
+
+		public String getMark()
+		{
+			return mark;
+		}
+
+		public long getTime()
+		{
+			return time;
+		}
+	}
+}
\ No newline at end of file