|
級別: 中級
Charles Chan , 首席顧問, Ambrose Software Inc.
2005 年 9 月 05 日
在企業級的開發過程中，我們不可避免地會碰到很多問題；如果您希望在開發過程的后期能夠有效地捕捉 bug，那就需要一種有效的日志策略。但是在一個企業的應用程序中要想實現有效地記錄日志，需要進行一番規劃，并設計一些準則。在本文中，顧問 Charles Chan 將向您介紹一些最好的實踐，從而幫助您從項目一開始就編寫有用的日志代碼。
如果您是一名開發人員，那您很可能就已經具有這種經驗：您已經開發了一些代碼以及一些測試用例。應用程序經過了嚴格的 QA 測試，您確信代碼可以完全適合業務的需求。然而，在將應用程序最終交付終端用戶的手里時，卻會出現一些預想不到的問題。如果沒有適當的日志消息，可能需要花費幾天的時間來診斷這些問題。不幸的是，大部分項目對于日志都沒有一個清晰的策略。如果沒有這種策略，系統產生的日志消息就有可能無益于問題的分析和解決。在本文中，我們將討論企業應用程序日志的各個方面的問題。您將看到一個 Java? 平臺上日志 API 的概述，學習一些最好的編寫日志代碼的實踐，并了解如果需要在產品環境中對詳細日志重新進行排序，應該如何處理。
選擇日志 API
在使用 Java 平臺進行開發時，可以使用兩個主要的日志 API：Apache Log4J 和 Java Logging API，在 1.4 及更高版本的 Java 平臺中都提供了這兩個 API。與 Java Logging API 相比，Log4J 更加成熟，特性也更加豐富。這兩個日志的實現都采用了一個類似的設計模式（如圖 1 所示）。除非您的公司限制要使用第三方的庫，否則我強烈建議使用 Log4J。如果您不能決定使用哪個 API，就可以使用 Apache Commons Logging API，它對底層的日志實現進行了封裝。從理論上來說，這樣不用修改代碼就可以進行日志實現的切換。然而，實際上您很少會切換日志的實現；因此，我不建議使用 Apache Commons Logging API，因為它的復雜性并不沒有給您帶來其他特性。
日志概述
Log4J 和 Java Logging API 都采用了類似的設計和使用模式（如圖 1 和清單 1 所示）。消息首先被創建，然后傳遞給一個具有特定優先權的日志對象。這些消息的目的和格式是由輸出處理程序及其布局所決定。
圖 1. 日志實現的主要組件
清單 1. 日志對象的實例化和使用
import org.apache.log4j.Logger;
public class MyClass {
/*
* Obtain a logger for a message category. In this case, the message category is
* the fully qualified class name of MyClass.
*/
private static final Logger logger = Logger.getLogger(MyClass.class.getName());
...
public void myMethod() {
...
if (logger.isDebugEnabled()) {
logger.debug("Executing with parameters: " + param1 + ":" + param2);
}
}
}
|
一個好的日志實現中提供了很多不同的輸出處理程序，最常見的文件輸出處理程序和終端輸出處理程序。Log4J 還提供了一些處理程序將消息發布到一個 JMS 主題中，或者將消息插入一個數據庫表中。盡管這編寫一個定制的附加器并不困難，但是編寫和維護這種代碼的總體成本不應低估。消息的格式可以通過 Layout 對象進行配置。最常見的 layout 對象是 PatternLayout，它根據所提供的模式對消息進行格式化。
清單 2 給出了一個 Log4J 的樣例配置文件，它負責配置 FileAppender。在這種配置中，com.ambrosesoft.log.MyClass 類中的錯誤消息被發送給 FileAppender，后者將其寫入一個名為 log.txt 的文件中。這些消息是根據與這個添加器相關的 layout（在這種情況中是 PatternLayout）進行格式化的。
清單 2. Log4J XML 配置樣例文件
日志最佳實踐
關于日志，您要做的一個最重要的選擇可能是確定一種模式，將每個日志消息分配給一個特定的 類別。常見的一種實踐是使用每個類的全名，這些類的操作會被作為一個消息類別在日志中記錄（正如我們在清單 1 中看到的一樣），這是因為這可以讓開發人員更細粒度地記錄每個類的設置。然而，這只有在使用日志消息來跟蹤執行過程時才能良好地工作。在企業級的應用程序中，有很多其他類型的日志消息。舉例來說，一條日志消息可能是為安全顧問產生的，而另外一條日志消息則可能是會為了幫助進行性能調優而產生的。如果這兩條消息所關注的是同一個類，這樣就會被分配給相同的類別，這將很難在日志輸出結果中對其進行區分。
為了避免這個問題，應用程序應該具有一組專用的日志記錄程序，它們都進行了獨特的分類，如清單 3 所示。每個日志記錄程序都可以配置自己的優先級和輸出處理程序。例如，安全性日志記錄程序可以在將日志寫入目的地之前對消息進行加密。有時應用程序的設計者應該與使用日志的用戶（例如安全顧問）一起來商討日志的輸出格式，從而對這些消息進行更好的控制。
清單 3. 專用的日志記錄程序
import org.apache.log4j.Logger;
public interface Loggers {
Logger performance = Logger.getLogger("performance");
Logger security = Logger.getLogger("security");
Logger business = Logger.getLogger("business");
}
...
public class MyClass {
....
if (Loggers.security.isWarnEnabled()) {
Loggers.security.warn("Access denied: Username [" + userName + "] ...");
}
...
}
|
選擇日志的級別
一個 類別 （例如 security）中的消息可以具有不同的 優先級。有些消息是為了調試而產生的，有些是為了警告而產生的，有些則是出現錯誤而產生的。消息的不同優先級可以通過記錄 級別 來產生。最常用的日志級別有：
- Debug: 這個級別的消息中包含了非常廣泛的上下文信息。通常用于問題診斷。
- Info: 這些消息包含了一些有助于在產品環境中（粒度較粗）幫助跟蹤執行過程的上下文消息。
- Warning: 警告消息，說明系統中可能存在問題。例如，如果這個消息類別是有關安全性方面的，那么如果檢測到字典攻擊，就應該產生一條警告消息。
- Error: 錯誤消息說明系統中出現了嚴重的問題。這種問題通常都是不可恢復的，需要人工進行干預。
標準的 Java Logging API 和 Apache Log4J 在此之外又提供了一些日志級別。日志級別的主要目標是幫助您過濾有用信息中的噪聲。為了防止出現使用錯誤的級別以及降低日志消息的效用的情況，在開始編碼之前，必須為開發人員提供一個清晰的指導方針。
日志消息的格式
一旦選定日志記錄程序并建立起日志級別之后，就可以開始構建日志消息了。在這樣做時，重要的是要包含盡可能多的上下文信息，例如用戶提供的參數，其他應用程序的狀態信息。記錄日志對象的一種方法是將它們轉換成 XML。第三方庫，例如 XStream（請參閱 參考資料）可以自動將 Java 對象轉換成 XML 。盡管這是一種非常強大的機制，但是我們必須要考慮在速度與詳細程度之間達到一種平衡。除了典型的應用程序狀態信息之外，還應該記錄以下信息：
- 線程 ID: 企業級的應用程序通常都是在多線程的環境中運行的。使用線程 ID 信息，您就可以將多個請求區分開來。
- 調用程序的標識: 調用程序的標識也是非常重要的信息。由于不同的用戶具有不同的特權，它們的執行路徑也可能會有很大的不同。將用戶的標識放到日志消息中，這對于對安全性敏感的應用程序是非常大的一個幫助。
- 時間戳: 通常來說，用戶只能近似地知道問題發生的時間。如果沒有時間戳，就很難讓別人來判斷問題的原因所在。
- 源代碼信息: 這包括類名、方法名和行號。除非您非常關注安全性，否則我建議您保留調試標記（
-g），即使在編譯產品時也是如此。如果沒有調試標記，Java 編譯器就會刪除所有的行號信息，從而極大地減少日志消息的可用性。
上面這些信息（除了調用程序標識）都是由日志實現自動獲取的。為了將這些信息包含到消息中，您只需要為輸出處理程序配置一個適當的 layout 模式即可。要捕獲調用者的標識，您可以利用 Log4J 中的診斷上下文特性（更多信息請參閱 參考資料）。診斷上下文讓您可以將上下文信息與當前正在運行的線程關聯在一起。這些信息可以在為輸出進行格式化的同時而包含到每條消息中。
在 J2EE Web 應用程序中，應用邏輯將用戶標識保存到診斷上下文中最好的地方是在一個 servlet 過濾器中。清單 4 中顯示了要實現這種功能的必要代碼。它使用了 Log4J 1.3 alpha 中提供的映射診斷上下文類（MDC）。您可以使用 Log4J 1.2 中提供的嵌套診斷上下文（NDC）實現相同的功能。有關 servlet 過濾器的更多通用信息，請參閱 參考資料 中的信息。
清單 4. 在 servlet 過濾器中使用診斷上下文
import javax.servlet.Filter;
...
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpSession;
import org.apache.log4j.MDC;
public class LoggerFilter implements Filter {
public void doFilter(ServletRequest request, ServletResponse response,
FilterChain chain) throws IOException, ServletException {
// Retrieves the session object from the current request.
HttpSession session = ((HttpServletRequest)request).getSession();
// Put the username into the diagnostic context.
// Use %X{username} in the layout pattern to include this information.
MDC.put("username", session.getAttribute("username"));
// Continue processing the rest of the filter chain.
chain.doFilter(request, response);
// Remove the username from the diagnostic context.
MDC.remove("username");
}
...
}
|
使用 AspectJ 跟蹤執行情況
在對問題進行診斷時，通常跟蹤程序的執行情況會很有幫助。您可以在程序執行的不同地方持續發送日志消息嗎？例如方法的入口函數和出口函數。這是一個老問題，在出現 AspectJ 之前一直都沒有什么好的解決方案。使用 AspectJ，可以在應用程序的不同地方執行代碼段。在 AspectJ 中，這些地方都稱為 point cut，在 point cut 處所執行的代碼稱為 advice。point cut 和advice 合稱 aspect。
關于 AspectJ，有一件事情非常神奇，aspect 不用很多努力就可以應用到整個應用程序中。有關 AspectJ 的更多信息，請參閱 參考資料。清單 5 給出了一個 AspectJ 源文件的例子，它用來對方法的入口和出口函數記錄日志。在這個例子中，跟蹤日志程序將在每次進入或退出 com.ambrosesoft 包的一個共有方法時都會記錄一條日志。
清單 5. 使用 AspectJ 記錄方法的入口和出口
import org.apache.log4j.Logger;
import java.lang.reflect.Field;
public aspect AutoTrace {
private static final Logger logger = Logger.getLogger(AutoTrace.class);
pointcut publicMethods() : execution(public * com.ambrosesoft..*(..));
pointcut loggableCalls() : publicMethods();
/**
* Inspect the class and find its logger object. If none is found, use
* the one defined here.
*/
private Logger getLogger(org.aspectj.lang.JoinPoint joinPoint) {
try {
/*
* Try to discover the logger object.
* The logger object must be a static field called logger.
*/
Class declaringType = joinPoint.getSignature().getDeclaringType();
Field loggerField = declaringType.getField("logger");
loggerField.setAccessible(true);
return (Logger)loggerField.get(null);
} catch(NoSuchFieldException e) {
/*
* Cannot find a logger object, use the internal one.
*/
return logger;
} catch(Exception e) {
throw new RuntimeException(e);
}
}
/**
* An aspect to log method entry.
*/
before() : loggableCalls(){
getLogger(thisJoinPoint).debug("Entering.." + thisJoinPoint.getSignature().toString());
}
/**
* An aspect to log method exit.
*/
after() : loggableCalls(){
getLogger(thisJoinPoint).debug("Exiting.." + thisJoinPoint.getSignature().toString());
}
}
|
 |
產品環境中的日志
一旦應用程序處于產品環境中之后，您通常都需要關閉調試或信息日志消息，從而對運行時的性能進行優化。然而，當有些不好的事情發生時，您又不能在開發環境中重現這個問題，那就可能需要在產品環境中激活調試消息了。重要的是能夠修改日志的設置，而不用關閉服務器。診斷產品的問題即使不用花費數天來進行詳細的調研，通常也需要幾個小時的時間。在這段時間之內，開發人員需要激活或關閉應用程序不同范圍的日志。如果每次修改日志的設置之后都需要重新啟動產品應用程序，那么情況就會變得非常不可靠了。
幸運的是，Log4J 提供了一種簡單的機制來解決這個問題。在 Log4J 1.2 中，DOMConfigurator 中的 configureAndWatch() 方法會對 Log4J 進行配置，并自動監視日志配置文件中的變化。這在清單 6 中進行了闡述。（注意，在 Log4J 1.3（目前仍是 alpha 版本） 中并不推薦使用 DOMConfigurator，它使用了一個更加靈活的實現 JoranConfigurator。）
為了確保 configureAndWatch() 是在 Log4J 初始化之前調用的，您應該在啟動類中調用它。不同的應用程序服務器采用了不同的機制來執行啟動代碼（更多信息請參閱 參考資料）。詳細信息請查看應用服務器的實現。有些應用服務器可能需要您將 Log4J 的庫放到服務器的 classpath 中。日志配置文件應該保存到一個需要日志的人可以訪問的位置。
清單 6. 使用 DOMConfigurator 配置 Log4J
/*
* Configure Log4J library and periodically monitor log4j.xml for any update.
*/
DOMConfigurator.configureAndWatch("/apps/config/log4j.xml");
|
如果您的日志配置文件不能方便地進行訪問（例如您的產品環境是由一個不同的組織進行維護的），那么您就必須使用一種不同的策略。標準的方法是使用 JMX，它提供了一個標準的 API 來管理自己的應用程序設置。在現代 JMX 兼容的服務器中，您可以使用管理 bean （或 MBeans ）來擴展應用服務器的管理終端的功能（更多有關使用 JMX 以及在 WebSphere Application Server 6.0 中使用 JMX 的內容，請參閱 參考資料 一節。）由于 JMX 方法非常復雜，如果您的情況需要使用 JMX，那就應該只用作這個用途。
記錄敏感的數據
在記錄產品環境中的日志時，除了技術方面的挑戰之外，還存在一些業務問題需要克服。例如，記錄敏感的信息可能會引起安全性的問題。并沒有任何限制可以防止您將某個用戶的用戶名和密碼保存到正文文件中。您還必須要保護其他敏感信息，例如 e-mail 地址、電話號碼以及帳號信息。安全顧問和設計師有責任要確保這些信息不會未加任何處理就保存到日志中。對敏感信息使用安全性專用的日志程序可以幫助降低風險。您可以給這個日志程序配置一個專用的附加器，從而使用一種加密的格式來保存消息，或者將其保存到一個安全的地方。然而，防止出現安全風險的最佳方法是在項目開始之前就設置適當的編碼規范，并在檢查代碼時強制施行這些規范。
從異常中提取有用信息
當發生一個非預期的異常時 —— 例如，如果數據庫連接突然失效了，或者系統資源變得很低了 —— 就必須對其適當地進行處理，否則就會丟失有用的信息，這些信息在診斷問題時是非常有幫助的。首先，必須記錄異常及其堆棧跟蹤狀況。其次，應該使用一種用戶界面友好的方式來標識錯誤頁面，這對于終端用戶和技術支持小組來說都是非常有幫助的。
技術支持小組在接到一個技術支持電話時所面臨的一個挑戰是在用戶所報告的問題與特定的日志異常之間建立某種關聯。非常有用的一種簡單技術是為每個異常都記錄一個唯一的 ID。這個 ID 可以告訴用戶，也可以包含在終端用戶所填寫的問題報告表單中。這樣可以減少技術支持團隊成員猜測的時間，讓他們可以快速對問題作出響應。考慮到可讀性的問題，可以定期對 ID 進行回收。
日志文件的管理
一個非常繁忙的應用程序的日志文件可能會迅速變得非常大。較大的日志文件很難使用，這是因為它們需要過濾大量的噪聲才能找到有用的信號。Log 循環 是常見的一個可以幫助解決這個問題的實踐。日志循環會周期性地對舊日志進行歸檔，這樣新消息就可以總能寫到一個相對較小的文件中。日志消息降低了一些效用來提高速度；您可能很少需要參考一周之前的日志消息。在 Log4J 1.2 中， DailyRollingFileAppender 附加器可以根據所提供的日期模式來循環使用日志文件。（在 Log4J 1.3 中，已經對這個循環日志文件附加器重新進行了設計。現在您可以提供一種策略來控制如何進行循環了。例如， TimeBasedRollingPolicy 定義了一種基于時間和日期的循環模式。）清單 7 顯示了讓 Log4J 在每天午夜對自己的日志文件進行循環所采用的配置片斷。
清單 7. 使用 DailyRollingFileAppender 循環使用日志文件
集群環境中的日志
現在有越來越多的企業級應用程序是在集群環境或分布式環境中進行部署的。然而，集群環境中的日志需要更多規劃，因為消息都是從不同的源頭生成的（通常是不同的機器）。如果要對不同的機器記錄日志，那就必須對這些機器的時間戳進行同步，否則日志消息的次序就混亂了。對機器間時鐘進行同步的一種簡單方法是使用一個時間服務器。有兩種方法可以設置時間服務器。您可以指定一臺內部的機器作為時間服務器。然后其他機器就可以使用網絡時間協議（NTP）來與時間服務器的時間戳進行同步。另外，您可以使用 Internet 上提供的時間服務器（請參閱 參考資料）。在 AIX 上，xntpd 守護進程用來對不同機器的系統時間進行同步。當機器具有相同的時間之后，就可以對日志一起進行分析了。
在集群環境中搜集日志消息還面臨著一些挑戰。在這種環境中保存日志消息的一種簡單方法是將它們保存到主機特定的日志文件中。當集群是使用 session affinity 配置時，這可以很好地工作 —— 如果對某個特定用戶會話的請求都要到同一個服務器上，并且 EJB 也都是部署在本地的。在這種配置中，集群中的機器所產生的日志文件都可以獨立進行分析。如果不是這種情況 —— 換而言之，如果任何給定的請求都可以由多臺機器進行處理 —— 那么對不同日志文件中的日志消息進行分析就會變得更加困難。在這種情況中，一種好的辦法是使用系統管理軟件來管理日志消息，例如 IBM Tivoli? 軟件（請參閱 參考資料 中的鏈接）。這種軟件對所有的日志消息（在系統管理軟件的術語中稱之為 事件）提供了一個綜合的視圖，從而便于管理員使用。系統管理軟件也可以根據所接收到的事件的類型觸發一些操作（例如發送 e-mail 消息或傳呼消息）。
結束語
在本文中，我們介紹了在規劃日志策略時需要考慮哪些問題。正如在編程時所碰到的問題一樣，從一開始就采用一個經過詳細考慮的規劃要比在進行的同時規劃更能節省工作量。良好的日志策略可以極大地幫助對問題進行診斷。最終，終端用戶可以獲得更好的應用程序，并能從技術支持團隊獲得迅速的響應。
參考資料
|
關于作者
 |
|
|
Charles Chan 是一名獨立軟件顧問，在加拿大的 Toronto 工作。他的興趣包括分布式系統、高性能計算、國際化以及軟件設計模式。在空閑時間，他為開源社區貢獻自己的成果。 | |