1. 程式人生 > >LOG使用規範(整理)

LOG使用規範(整理)

在開發B/S系統時,對於LOG,需要關注:

  1. 日誌資訊的集中採集、儲存、資訊檢索:在WEB叢集節點越來越多的情況下,讓開發及系統維護人員能很方便的檢視日誌資訊
  2. 日誌資訊的輸出策略:日誌資訊輸出全而不亂,便於跟蹤和分析問題
  3. 關鍵業務的日誌輸出:基於度量資料採集、資料核查、系統安全等方面的考慮,關鍵業務系統對輸出的日誌資訊有特殊的要求,需要做針對性的設計

本文主要從這3個方面進行說明,重點說明日誌輸出的使用

日誌的採集和儲存 對於目前儲存日誌,主要存在2種方式:

  1. 本地日誌:直接存放在本地磁碟上
  2. 遠端日誌:發往�日誌平臺,用作資料分析和日誌處理並展現。如使用者訪問行為的記錄,異常日誌,效能統計日誌等。

日誌工具的選擇 推薦使用SLF4J(Simple Logging Facade for Java)作為日誌的api,SLF4J是一個用於日誌系統的簡單Facade,允許終端使用者在部署其應用時使用其所希望的日誌系統。與使用apache commons-logging和直接使用log4j相比,SLF4J提供了一個名為引數化日誌的高階特性,可以顯著提高在配置為關閉日誌的情況下的日誌語句效能

//slf4j
log.debug("Found {} records matching filter: '{}'", records, filter);

//log4j
log.debug("Found " + records + " records matching filter: '" + filter + "'");

可以看出SLF4J的方式一方面更簡略易讀,另一方面少了字串拼接的開銷,並且在日誌級別達不到時(這裡例子即為設定級別為debug以上),不會呼叫物件的toString方法。

日誌輸出級別(由高到低)

  • ERROR:系統中發生了非常嚴重的問題,必須馬上有人進行處理。沒有系統可以忍受這個級別的問題的存在。比如:NPEs(空指標異常),資料庫不可用,關鍵業務流程中斷等等

  • WARN:發生這個級別問題時,處理過程可以繼續,但必須對這個問題給予額外關注。這個問題又可以細分成兩種情況:一種是存在嚴重的問題但有應急措施(比如資料庫不可用,使用Cache);第二種是潛在問題及建議(ATTENTION),比如生產環境的應用執行在Development模式下、管理控制檯沒有密碼保護等。系統可以允許這種錯誤的存在,但必須及時做跟蹤檢查

  • INFO:重要的業務處理已經結束。在實際環境中,系統管理員或者高階使用者要能理解INFO輸出的資訊並能很快的瞭解應用正在做什麼。比如,一個和處理機票預訂的系統,對每一張票要有且只有一條INFO資訊描述 "[Who] booked ticket from [Where] to [Where]"。另外一種對INFO資訊的定義是:記錄顯著改變應用狀態的每一個action,比如:資料庫更新、外部系統請求

  • DEBUG:用於開發人員使用。將在TRACE章節中一起說明這個級別該輸出什麼資訊

  • TRACE:非常具體的資訊,只能用於開發除錯使用。部署到生產環境後,這個級別的資訊只能保持很短的時間。這些資訊只能臨時存在,並將最終被關閉。要區分DEBUG和TRACE會比較困難,對一個在開發及測試完成後將被刪除的LOG輸出,可能會比較適合定義為TRACE級別

推薦使用debug,info,warn,error級別即可,對於不同的級別可以設定不同的輸出路徑,如debug,info輸出到一個檔案,warn,error輸出到一個帶error字尾的檔案

日誌API規範

  • Log物件的宣告和初始化,僅以下程式碼是符合規範的
// (推薦)
private static final Logger logger = LoggerFactory.getLogger(Xxx.class);

private final Logger logger = LoggerFactory.getLogger(getClass());

private  static  final Logger logger =  LoggerFactory.getLogger("loggerName");

private static Logger logger = LoggerFactory.getLogger(Xxx.class);

protected final Logger logger = LoggerFactory.getLogger(getClass());

private Logger logger = LoggerFactory.getLogger(getClass());

protected Logger logger = LoggerFactory.getLogger(getClass());
  • 不得使用System.out, System.err進行日誌記錄,請改使用logger.debug、logger.error

  • debug/info級別的資訊,資訊本身需要計算或合併的,必須加 isXxxEnabled() 判斷在前,這樣可以大大提高高併發下的效率。如:

if (logger.isDebugEnabled()) {
    logger.debug(test());
}

private String test(){
    int i = 0;
    while (i < 1000000) {
        i++;
    }

    return "";
}

如果不加 isXxxEnabled() 判斷,test()在info級別下也會執行。

  • 注意error和warn級別的區別,導致業務不正常服務的,用error級別;錯誤是預期會發生的,並且已經有了其他的處理流程,使用warn級別

  • 正確的記錄異常資訊 記錄異常資訊是“記錄所有資訊”中的一個重要組成,但很多開發人員只是把logging當做處理異常的一種方式。他們通常返回預設值,然後當做什麼都沒發生。 其他時候,他們先log異常資訊,然後再丟擲包裝過的異常。如:

log.error("IO exception", e);

throw new MyCustomException(e);

這種方法總是會列印兩次相同的 stack trace資訊,因為有些地方會捕捉MyCustomException異常,然後輸出導致問題的日誌資訊。 但有時基於某些原因我們真的想log異常資訊怎麼辦?很過見多的log語句有一半以上都是錯的, 如:

try {    
    Integer x = null;
    ++x;
} catch (Exception e) {

    //A
    log.error(e);        

    //B
    log.error(e, e);        

    //C
    log.error(""+ e);        

    //D
    log.error(e.toString());        

    //E
    log.error(e.getMessage());        

    //F
    log.error(null, e);        

    //G
    log.error("", e);        

    //H
    log.error("{}", e);        

    //I
    log.error("{}", e.getMessage());      
  
     //J
     log.error("Error reading configuration file: " + e);        

    //K
    log.error("Error reading configuration file: "+ e.getMessage());        

    //L
    log.error("Error reading configuration file", e);        


}

上面只有G、L是對的,L的處理方式更好一些

注意:捕獲異常後不處理也不輸出log是一種非常不負責任的行為,這會造成問題很難被定位,極大地提高debug成本!

  • 重要方法入口,業務流程前後及處理的結果等,推薦記錄log,並使用debug級別,如:
public String printDocument(Document doc, Mode mode) {

    log.debug("Entering printDocument(doc={}, mode={})", doc, mode);

    //Lengthy printing operation
    String id = "Id";
 
    log.debug("Leaving printDocument(): {}", id);
    
    return id;

}

因為對於非開發人員掌控的環境(無法做DEBUG),記錄方法呼叫、入參、返回值的方式對於排查問題會有很大幫助。

  • Log的內容一定要確保不會因為Log語句的問題而丟擲異常造成中斷,如:
log.debug("Processing request with id: {}", request.getId());

你能確保request物件不是NULL嗎?如果request為null,就會丟擲NullPointerException。

  • 避免拖慢應用系統 輸出太多日誌資訊:通常每小時輸出到disk的資料量達到幾百MiB就已經是上限了不正確使用toString() 或字串拼接方法。
try {
    log.trace("Id=" + request.getUser().getId() + " accesses" + manager.getPage().getUrl().toString())
} catch(NullPointerException e) {
}
  • 日誌資訊中儘量包含資料和描述:easy to read, easy to parse 一些反模式的例子
log.debug("Message processed");

log.debug(message.getJMSMessageID());

log.debug("Message with id '{}' processed", message.getJMSMessageID());

 
 
if (message instanceof TextMessage)

//...
else {
    log.warn("Unknown message type");
}

為什麼不包含 message type, message id, etc,包含個message content很難嗎?另一個anti-pattern是magic-log。 有些開發人員為了自己查詢資訊方便,輸出類似“&&&!#”的Log,而不是“Message with XYZ id received”。 最後,Log 不要涉及密碼及個人資訊(身份證、銀行卡號etc)

  • 關鍵業務系統日誌的要求
  • 使用者瀏覽日誌 使用WEB伺服器或應用伺服器實現日誌輸出,關鍵資訊包括:訪問時間使用者IP訪問的URL使用者瀏覽器資訊HTTP狀態碼請求處理時間

  • 使用者登入日誌 用於記錄使用者的Login、Logout、CheckLogin請求情況,關鍵資訊如下:Login請求時間使用者IP使用者名稱渠道資訊使用者瀏覽器資訊登入處理結果請求花費時間tokenIdsessionidLogout請求時間使用者IP使用者名稱渠道資訊使用者瀏覽器資訊登出結果請求花費時間tokenidsessionidCheckLogin請求時間使用者IP使用者名稱渠道資訊使用者瀏覽器資訊檢查結果檢查花費時間tokenidsessionId

  • 服務介面呼叫日誌 所有外部介面的呼叫需要記錄介面訪問資訊,關鍵資訊如下: 請求時間、介面URL、介面方法、呼叫結果、執行時間

配置規範

  • 統一使用log4j.xml、log4j2.xml、logback配置。

  • 所有的jar包中不推薦包含log4j.xml、log4j.properties、logback.xml檔案,避免干擾實際的業務系統。

  • 注意Logger間的繼承關係,如:

  • log4j的繼承是通過命名來實現的。
  • 子logger會預設繼承父logger的appender,將它們加入到自己的Appender中;除非加上了additivity="false",則不再繼承父logger的appender。
  • 子logger只在自己未定義輸出級別的情況下,才會繼承父logger的輸出級別。
  • Log檔案位置和命名,目前Log檔案的位置統一放在相同目錄下面,Log名字通常以業務名開頭,如xxx.log.2015-11-19等。

  • 日誌格式:必選列印資料項: 發生時間、日誌級別、日誌內容,可選檔案和行號。

  • 遠端日誌的輸出需要注意host和port,區分cagegory。