Improve debug class and debugging startup

Author: syamn

FlagGame/src/syam/FlagGame/FlagGame.java

@@ -44,6 +44,7 @@
 import syam.FlagGame.Listeners.FGBlockListener;
 import syam.FlagGame.Listeners.FGEntityListener;
 import syam.FlagGame.Listeners.FGPlayerListener;
+import syam.FlagGame.Util.Debug;
 import syam.FlagGame.Util.DynmapHandler;
 
 public class FlagGame extends JavaPlugin{
@@ -96,7 +97,7 @@ public class FlagGame extends JavaPlugin{
 	 */
 
 	// ** Logger **
-	public final static Logger log = Logger.getLogger("Minecraft");
+	public final static Logger log = Logger.getLogger("FlagGame");
 	public final static String logPrefix = "[FlagGame] ";
 	public final static String msgPrefix = "&6[FlagGame] &f";
 
@@ -113,6 +114,7 @@ public class FlagGame extends JavaPlugin{
 	private ConfigurationManager config;
 	private GameManager gm;
 	private GameFileManager gfm;
+	private Debug debug;
 
 	// ** Variable **
 	// 存在するゲーム <String 一意のゲームID, Game>
@@ -133,6 +135,8 @@ public class FlagGame extends JavaPlugin{
 	 * プラグイン起動処理
 	 */
 	public void onEnable(){
+		Debug.setStartupBeginTime();
+
 		instance  = this;
 		PluginManager pm = getServer().getPluginManager();
 		config = new ConfigurationManager(this);
@@ -145,9 +149,15 @@ public void onEnable(){
 			ex.printStackTrace();
 		}
 
-		// プラグインフック
+		// setup Debugger
+		Debug.getInstance().init(log, logPrefix, "plugins/FlagGame/debug.log", getConfigs().isDebug);
+		debug = Debug.getInstance();
+
 		// Vault
+		debug.startTimer("vault");
 		setupVault();
+		debug.endTimer("vault");
+
 		// DeathNotifier
 		Plugin p = pm.getPlugin("DeathNotifier");
 		if (p != null){
@@ -170,27 +180,37 @@ public void onEnable(){
 		registerCommands();
 
 		// データベース連携
+		debug.startTimer("database");
 		database = new Database(this);
 		database.createStructure();
+		debug.endTimer("database");
 
 		// マネージャ
+		debug.startTimer("managers");
 		gm = new GameManager(this);
 		gfm = new GameFileManager(this); // 内部でDB使用
+		debug.endTimer("managers");
 
 		// ゲームデータ読み込み
+		debug.startTimer("load games");
 		gfm.loadGames();
+		debug.endTimer("load games");
 
 		// プレイヤー追加
 		for (Player player : getServer().getOnlinePlayers()){
 			PlayerManager.addPlayer(player);
 		}
 
 		// dynmapフック
+		debug.startTimer("dynmap");
 		setupDynmap();
+		debug.endTimer("dynmap");
 
 		// メッセージ表示
 		PluginDescriptionFile pdfFile=this.getDescription();
 		log.info("["+pdfFile.getName()+"] version "+pdfFile.getVersion()+" is enabled!");
+
+		debug.finishStartup();
 	}
 
 	/**
@@ -262,6 +282,9 @@ private void setupVault(){
 	    }
 	}
 
+	/**
+	 * Dynmapプラグインにフック
+	 */
 	private void setupDynmap(){
 		getServer().getScheduler().scheduleSyncDelayedTask(this, new Runnable(){
 			public void run(){

FlagGame/src/syam/FlagGame/Util/Debug.java

@@ -7,8 +7,10 @@
 import java.io.IOException;
 import java.text.DateFormat;
 import java.util.Date;
+import java.util.logging.ConsoleHandler;
 import java.util.logging.FileHandler;
 import java.util.logging.Formatter;
+import java.util.logging.Handler;
 import java.util.logging.Level;
 import java.util.logging.LogRecord;
 import java.util.logging.Logger;
@@ -22,13 +24,17 @@
  */
 public class Debug {
 	private static Debug instance = null;
-	private static long startup = 0L;
-	private long timeLog = 0L;
 
 	private Logger log;
 	private String logPrefix;
 	private TextFileHandler logFile = null;
 	private boolean debug = false;
+	private Level oldLogLevel = null;
+
+	// timer
+	private static boolean isStartup = true;
+	private static long startup = 0L;
+	private long timeLog = 0L;
 
 	/**
 	 * 初期化
@@ -90,6 +96,42 @@ public void debug(Object... args){
 		}
 	}
 
+	/**
+	 * コンソール出力するログレベルを変更
+	 * @param level
+	 */
+	private void setConsoleLevel(Level level){
+		if (level == null) return;
+
+		Handler handler = getConsoleHandler(log);
+		if (handler != null){
+			handler.setLevel(level);
+		}
+	}
+
+	/**
+	 * コンソールハンドラを返す
+	 * @param log
+	 * @return
+	 */
+	private Handler getConsoleHandler(Logger log){
+		// コンソールハンドラを返す
+		Handler[] handlers = log.getHandlers();
+		for (Handler h : handlers){
+			if (h instanceof ConsoleHandler){
+				return h;
+			}
+		}
+
+		// 親ロガーのコンソールハンドラを返す
+		Logger parent = log.getParent();
+		if (parent != null){
+			return getConsoleHandler(parent);
+		}else{
+			return null;
+		}
+	}
+
 	/* getter / setter */
 
 	/**
@@ -107,8 +149,16 @@ public void setDebug(boolean isDebug){
 		this.debug = isDebug;
 
 		if (isDebug){
+			oldLogLevel = log.getLevel();
+			log.setLevel(Level.FINE);
+			setConsoleLevel(Level.FINE);
+
 			log.info(logPrefix+ "DEBUG MODE ENABLED!");
 		}else{
+			if (oldLogLevel != null){
+				log.setLevel(oldLogLevel);
+				setConsoleLevel(oldLogLevel);
+			}
 			log.info(logPrefix+ "DEBUG MODE DISABLED!");
 		}
 	}
@@ -160,40 +210,35 @@ public static void setStartupBeginTime(){
 		if (startup <= 0L){
 			startup = System.currentTimeMillis();
 		}
+		isStartup = true;
+	}
+	/**
+	 * プラグイン起動完了時に経過時間を出力する
+	 */
+	public void finishStartup(){
+		isStartup = false;
+		debug("[Timer] Total initialization time: " + (System.currentTimeMillis()-startup) + "ms");
 	}
 
 	/**
 	 * デバッグ時刻計測開始
 	 * @param actionName
 	 * @param useStartup
 	 */
-	public void debugStartTimer(String actionName, boolean useStartup) {
+	public void startTimer(String actionName) {
     	timeLog = System.currentTimeMillis();
 
-    	if (debug){
-    		if (useStartup){
-    			debug("[Startup Timer] starting " + actionName + " (t+" + (System.currentTimeMillis()-startup) + ")");
-    		}else{
-    			debug("[Startup Timer] starting " + actionName);
-    		}
-    	}
+		if (isStartup){
+			debug("[Timer] starting " + actionName + " (t+" + (System.currentTimeMillis()-startup) + ")");
+		}else{
+			debug("[Timer] starting " + actionName);
+		}
     }
-
-	/**
-	 * デバッグ時刻計測開始
-	 * @param actionName
-	 */
-	public void debugStartTimer(String actionName){
-		this.debugStartTimer(actionName, false);
-	}
-
 	/**
 	 * デバッグ時刻計測終了
 	 * @param actionName
 	 */
-	public void debugEndTimer(String actionName){
-		if (debug){
-			debug("[Startup Timer] " + actionName + " finished in " + (System.currentTimeMillis()-timeLog) + "ms");
-		}
+	public void endTimer(String actionName){
+		debug("[Timer] " + actionName + " finished in " + (System.currentTimeMillis()-timeLog) + "ms");
 	}
 }