FileWatchDog for Configuration

在軟體開發與debug的時候,為了幫助了解程式做到什麼地方、發生問題在哪或狀態如何,會使用log去記錄重要的執行過程。但每次修改完log4j property file為了讓它生效,會重新啟動應用程式讓它reload,但這樣不是很煩嗎?為了解決這樣問題,我們可以透過Log4J提供的PropertyWatchdog去polling property file是否有做過修改。如以下程式碼,透過PropertyConfigurator的configureAndWatch就可以了,預設是60秒check一次。

org.apache.log4j.PropertyConfigurator.configureAndWatch(aLogPropertyFilePath);

但如果你是使用1.2版本或之前的,可能會遇到和我一樣的情況。在我將package名稱如以下更動後(增加.internal),就收到了log4j:ERROR Attempted to append to closed appender named的訊息,還狂跳不停。這是怎麼一回事?

log4j.additivity.org.tonylin.facebook=false
log4j.logger.org.tonylin.facebook=INFO, CONSOLE, LOGFILE
->
log4j.additivity.org.tonylin.facebook.internal=false
log4j.logger.org.tonylin.facebook.internal=INFO, CONSOLE, LOGFILE

我先告訴大家我最後的解法,細部內容待我最後說明,有興趣的再繼續看。一看訊息就可以猜應該是狀態不正常造成的,在trace code後發現原先在每次檔案有改變後,也僅做了下面的動作。

new PropertyConfigurator().doConfigure(filename, LogManager.getLoggerRepository())

於是我直接寫了一個class去繼承Log4j既有的FileWatchdog,並於發生改變時,重新reset configuration,這個問題就這樣解決了。

public class Log4jPropertyWatcher extends FileWatchdog {
 
	private static Logger mLogger = LoggerFactory.getLogger(Log4jPropertyWatcher.class);
	private static long mDefaultInterval = 1000l;
 
	Log4jPropertyWatcher(String filename){
		super(filename);
	}
 
	@Override
	protected void doOnChange() {
		mLogger.debug("Log4j config is changed.");
		LogManager.getLoggerRepository().resetConfiguration();
		new PropertyConfigurator().doConfigure(filename, LogManager.getLoggerRepository());
	}
 
	public static void configureAndWatch(String filename){
		Log4jPropertyWatcher fileWatcher = new Log4jPropertyWatcher(filename);
		fileWatcher.setDelay(mDefaultInterval);
		fileWatcher.start();
	}
 
	public static void setWatchInterval(long aInterval){
		mDefaultInterval = aInterval;
	}
}

h 那Root Cuase呢? 錯誤訊息是由AppenderSkeleton丟出的,原因是它發現Appender已經被close了。close也許是關閉檔案或串流等等動作,這由根據Append實做決定,但重點是的確被某人給關閉了。

public synchronized void doAppend(LoggingEvent event)
{
     if (this.closed) {
       LogLog.error("Attempted to append to closed appender named [" + this.name + "].");
       return;
     }

於是重頭開始trace PropertyConfigurator,在parseCategory中發現它會透過logger的removeAllAppenders,將可能原有的Appender都close掉,且它每一個Appender都是相同的instance。這會造成什麼問題? 因為Log4j在做config的時候,會根據你所設定的package去加入Appender。如果你移除了某些package,又或者像是Problem中增加package的child而不保留原本的。原先的package並沒有被Log4j回收或清除,它在執行log時,會使用原本設定在它身上的Appender,跟著就死翹翹啦!