跳到主要內容

Log4j - FileWatchDog for Configuration

Problem

在軟體開發與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

How to resolve?

我先告訴大家我最後的解法,細部內容待我最後說明,有興趣的再繼續看。一看訊息就可以猜應該是狀態不正常造成的,在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;
	}
}

那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,跟著就死翹翹啦!

Reference

留言

這個網誌中的熱門文章

解決RobotFramework從3.1.2升級到3.2.2之後,Choose File突然會整個Hand住的問題

考慮到自動測試環境的維護,我們很久以前就使用java去執行robot framework。前陣子開始處理從3.1.2升級到3.2.2的事情,主要先把明確的runtime語法錯誤與deprecate item處理好,這部分內容可以參考: link 。 直到最近才發現,透過SeleniumLibrary執行Choose File去上傳檔案的動作,會導致測試案例timeout。本篇文章主要分享心路歷程與解決方法,我也送了一條issue給robot framework: link 。 我的環境如下: RobotFramework: 3.2.2 Selenium: 3.141.0 SeleniumLibrary: 3.3.1 Remote Selenium Version: selenium-server-standalone-3.141.59 首先並非所有Choose File的動作都會hang住,有些測試案例是可以執行的,但是上傳一個作業系統ISO檔案一定會發生問題。後來我透過wireshark去比對新舊版本的上傳動作,因為我使用 Remote Selenium ,所以Selenium會先把檔案透過REST API發送到Remote Selenium Server上。從下圖我們可以發現,在3.2.2的最後一個TCP封包,比3.1.2大概少了500個bytes。 於是就開始了我trace code之路。包含SeleniumLibrary產生要送給Remote Selenium Server的request內容,還有HTTP Content-Length的計算,我都確認過沒有問題。 最後發現問題是出在socket API的使用上,就是下圖的這支code: 最後發現可能因為開始使用nio的方式送資料,但沒處理到尚未送完的資料內容,而導致發生問題。加一個loop去做計算就可以解決了。 最後我有把解法提供給robot framework官方,在他們出新的版本之前,我是將改完的_socket.py放在我們自己的Lib底下,好讓我們測試可以正常進行。(shutil.py應該也是為了解某個bug而產生的樣子..)

第一次寫MIB就上手

SNMP(Simple Network Management Protocol)是用來管理網路設備的一種Protocol,我對它的認識也是從工作接觸開始。雖說是管理網路設備,但是主機、電源供應器、RAID等也都可以透過它來做管理。如果你做了一個應用程式,當然所有的操作也都可以透過SNMP來完成,不過可能會很痛苦。前陣子遇到一個學弟,它告訴我說:「我可能不會想寫程式。」為什麼? 因為這是他痛苦的根源。 在這篇文章中,不是要告訴你SNMP是什麼,會看這篇文章的大哥們,應該已經對SNMP有些認識了。 是的!主題是MIB(Management information base)! 對於一個3th-party的SNMP oid,有MIB可以幫助你去了解它所提供的資訊是什麼,且可以對它做什麼操作。最近我運氣很好剛好做到關於修改MIB的工作,也讓我順便了解一下它的語法,接下來我要交給大家MIB的基礎認識。 smidump 我並非使用什麼高強的Editor去編寫MIB,我僅透過Nodepad++編輯和smidump編譯而已。smidump是Kay教我使用的一個將MIB module轉成樹狀結構或oid列表的工具,唯一的缺點是不會告訴你哪一行打錯。當然有錢直接買編輯樹狀結構的工具就可以不需要了解語法了! 安裝 在Ubuntu上可先輸入smidump確認是否安裝,如果沒安裝可透過apt-get install libsmi2ldbl安裝。(CentOS可以透過yum install libsmi) root@tonylin:~/multi-boot-server# smidump The program 'smidump' is currently not installed. You can install it by typing: apt-get install libsmi2ldbl 使用 透過下面兩行指令,就可以將mib file產生出對應的tree與oid列表的檔案。也可以透過這個結果確認MIB是不是你想要的。 smidump -f tree example1.mib > xtree.txt smidump -f identifiers example1.mib > xiden.txt 如果有參考其它檔案要加上p的參數: smidum...

升級SeleniumLibrary到4.5.0與Selenium到3.141.0

最近我們將RobotFramework升級至4.1.2,因為Jython的關係這個是目前可以使用Java執行的最後版本。 我們目前Selenium相關的Libraries版本如下: Selenium2Library - 3.0.0 (Latest, https://github.com/robotframework/Selenium2Library ) SeleniumLibrary - 3.0.0 ( https://github.com/robotframework/SeleniumLibrary/releases ) Selenium - 3.8.0 其中Selenium2Library已經沒在維護,也是最後一個版本,它所做的事情僅僅是把keyword forward給SeleniumLibrary。所以升級重點在SeleniumLibrary與Selenium。 而要升級這些Libraries,最重要的就是要知道它們彼此之間的相依,還有python版本的支援度。在我查詢套件的release note之後,因為4.1.2版本的jython只能支援到python 2.7.x,所以能升級的版本就有限制。其中SeleniumLibrary的情況如下: SeleniumLibrary 5.0.0 - 不支援Python 2 and Jython  SeleniumLibrary 4.5.0 - Python 2.7 and Selenium 3.141.0+  SeleniumLibrary 3.3.1 - Python 2.7 and Selenium 3.4+ 所以搭配了Selenium後,以下為我的第一個升級計畫: Selenium - 3.141.0 SeleniumLibrary - 3.3.。主要想確定是否會有deprecated items產生。 升級方式就是把以上原始碼丟到Lib底下,執行robot測試的時候會透過jython重新編譯。在我執行後,出現了urllib3找不到的問題: 我想可能是原本的套件中有包含urllib3,因此我到urllib3的package網站查了release note,找了可以匹配python 2.7的版本: urllib3 - 1.26.20 (https://pypi.org/project/...