天天看點

Java 日志管理最佳實踐

日志記錄是應用程式運作中必不可少的一部分。具有良好格式和完備資訊的日志記錄可以在程式出現問題時幫助開發人員迅速地定位錯誤的根源。對于開 發人員來說,在程式中使用日志API記錄日志并不複雜,不過遵循一些最佳實踐可以更好的利用日志。本文介紹了在Java程式中記錄日志的最佳實踐,同時也 介紹了如何使用開源軟體對日志進行聚合和分析。

概述

對于現在的應用程式來說,日志的重要性是不言而喻的。很難想象沒有任何日志記錄功能的應用程式運作 在生産環境中。日志所能提供的功能是多種多樣的,包括記錄程式運作時産生的錯誤資訊、狀态資訊、調試資訊和執行時間資訊等。在生産環境中,日志是查找問題 來源的重要依據。應用程式運作時的産生的各種資訊,都應該通過日志 API 來進行記錄。很多開發人員習慣于使用 System.out.println、System.err.println 以及異常對象的 printStrackTrace 方法來輸出相關資訊。這些使用方式雖然簡便,但是所産生的資訊在出現問題時并不能提供有效的幫助。這些使用方式都應該改為使用日志 API。使用日志 API 并沒有增加很多複雜度,但是所提供的好處是顯著的。

盡管記錄日志是應用開發中并不可少的功能,在 JDK 的最初版本中并不包含日志記錄相關的 API 和實作。相關的 API(java.util.logging 包,JUL)和實作,直到 JDK 1.4 才被加入。是以在日志記錄這一個領域,社群貢獻了很多開源的實作。其中比較流行的包括 log4j 及其後繼者 logback。除了真正的日志記錄實作之外,還有一類與日志記錄相關的封裝 API,如 Apache Commons Logging 和 SLF4J。這類庫的作用是在日志記錄實作的基礎上提供一個封裝的 API 層次,對日志記錄 API 的使用者提供一個統一的接口,使得可以自由切換不同的日志記錄實作。比如從 JDK 的預設日志記錄實作 JUL 切換到 log4j。這類封裝 API 庫在架構的實作中比較常用,因為需要考慮到架構使用者的不同需求。在實際的項目開發中則使用得比較少,因為很少有項目會在開發中切換不同的日志記錄實作。 本文對于這兩類庫都會進行具體的介紹。

記錄日志隻是有效地利用日志的第一步,更重要的是如何對程式運作時産生的日志進行處理和分析。典型的 情景包括當日志中包含滿足特定條件的記錄時,觸發相應的通知機制,比如郵件或短信通知;還可以在程式運作出現錯誤時,快速地定位潛在的問題源。這樣的處理 和分析的能力對于實際系統的維護尤其重要。當運作系統中包含的元件過多時,日志對于錯誤的診斷就顯得格外重要。

本文首先介紹關于日志 API 的基本内容。

Java 日志 API

從功能上來說,日志 API 本身所需求的功能非常簡單,隻需要能夠記錄一段文本即可。API 的使用者在需要進行記錄時,根據目前的上下文資訊構造出相應的文本資訊,調用 API 完成記錄。一般來說,日志 API 由下面幾個部分組成:

記錄器(Logger):日志 API 的使用者通過記錄器來發出日志記錄請求,并提供日志的内容。在記錄日志時,需要指定日志的嚴重性級别。

格式化器(Formatter):對記錄器所記錄的文本進行格式化,并添加額外的中繼資料。

處理器(Handler):把經過格式化之後的日志記錄輸出到不同的地方。常見的日志輸出目标包括控制台、檔案和資料庫等。

記錄器

當 程式中需要記錄日志時,首先需要擷取一個日志記錄器對象。一般的日志記錄 API 都提供相應的工廠方法來建立記錄器對象。每個記錄器對象都是有名稱的。一般的做法是使用目前的 Java 類的名稱或所在包的名稱作為記錄器對象的名稱。記錄器的名稱通常是具有層次結構的,與 Java 包的層次結構相對應。比如 Java 類“com.myapp.web.IndexController”中使用的日志記錄器的名稱一般是 “com.myapp.web.IndexController”或“com.myapp.web”。除了使用類名或包名之外,還可以根據日志記錄所對應 的功能來進行劃分,進而選擇不同的名稱。比如用“security”作為所有與安全相關的日志記錄器的名稱。這樣的命名方式對于某些橫切的功能比較實用。 開發人員一般習慣于使用目前的類名作為日志記錄器的名稱,這樣可以快速在日志記錄中定位到産生日志的 Java 類。使用有意義的其他名稱在很多情況下也是一個不錯的選擇。

在通過日志記錄器對象記錄日志時,需要指定日志的嚴重性級别。根據每個記錄器對 象的不同配置,低于某個級别的日志消息可能不會被記錄下來。該級别是日志 API 的使用者根據日志記錄中所包含的資訊來自行決定的。不同的日志記錄 API 所定義的級别也不盡相同。日志記錄封裝 API 也會定義自己的級别并映射到底層實作中相對應的實際級别。比如 JDK 标準的日志 API 使用的級别包括 OFF、SEVERE、WARNING、INFO、CONFIG、FINE、FINER、FINEST 和 ALL 等,Log4j 使用的級别則包括 OFF、FATAL、ERROR、WARN、INFO、DEBUG、TRACE 和 ALL 等。一般情況下,使用得比較多的級别是 FATAL、ERROR、WARN、INFO、DEBUG 和 TRACE 等。這 6 個級别所對應的情況也有所不同:

FATAL:導緻程式提前結束的嚴重錯誤。

ERROR:運作時異常以及預期之外的錯誤。

WARN:預期之外的運作時狀況,不一定是錯誤的情況。

INFO:運作時産生的事件。

DEBUG:與程式運作時的流程相關的詳細資訊。

TRACE:更加具體的詳細資訊。

在這 6 個級别中,以 ERROR、WARN、INFO 和 DEBUG 作為常用。

日 志記錄 API 的使用者通過記錄器來記錄日志消息。日志消息在記錄下來之後隻能以文本的形式儲存。不過有的實作(如 Log4j)允許在記錄日志時使用任何 Java 對象。非 String 類型的對象會被轉換成 String 類型。由于日志記錄通常在出現異常時使用,記錄器在記錄消息時可以把産生的異常(Throwable 類的對象)也記錄下來。

每個記錄器對 象都有一個運作時對應的嚴重性級别。該級别可以通過配置檔案或代碼的方式來進行設定。如果沒有顯式指定嚴重性級别,則會根據記錄器名稱的層次結構關系往上 進行查找,直到找到一個設定了嚴重性級别的名稱為止。比如名稱為“com.myapp.web.IndexController”的記錄器對象,如果沒有 顯式指定其嚴重性級别,則會依次查找是否有為名稱“com.myapp.web”、“com.myapp”和“com”指定的嚴重性級别。如果仍然沒有找 到,則使用根記錄器配置的值。

通過記錄器對象來記錄日志時,隻是發出一個日志記錄請求。該請求是否會完成取決于請求和記錄器對象的嚴重性級 别。記錄器使用者産生的低于記錄器對象嚴重性級别的日志消息不會被記錄下來。這樣的記錄請求會被忽略。除了基于嚴重性級别的過濾方式之外,日志記錄架構還 支援其他自定義的過濾方式。比如 JUL 可以通過實作 java.util.logging.Filter 接口的方式來進行過濾。Log4j 可以通過繼承 org.apache.log4j.spi.Filter 類的方式來過濾。

格式化器

實際記錄的日志中除了使用記錄器對象時提供的消息之外,還包括一些中繼資料。這些中繼資料由日志記錄架構來提供。常用的資訊包括記錄器的名稱、時間戳、線程名等。格式化器用來确定所有這些資訊在日志記錄中的展示方式。不同的日志記錄實作提供各自預設的格式化方式和自定義支援。

JUL 中通過繼承 java.util.logging.Formatter 類來自定義格式化的方式,并提供了兩個标準實作 SimpleFormatter 類和 XMLFormatter 類。清單 1 中給出了 JUL 中自定義格式化器的實作方式,隻需要繼承自 Formatter 類并實作 format 方法即可。參數 LogRecord 類的對象中包含了日志記錄中的全部資訊。

清單 1. JUL 中自定義格式化器的實作

public class CustomFormatter extends Formatter { 
    public String format(LogRecord record) { 
        return String.format("<%s> [%s] : %s", new Date(record.getMillis()), record.getLoggerName(), record.getMessage()); 
    } 
 }      

對于自定義的格式化器類,需要在 JUL 的配置檔案中進行指定,如清單 2 所示。

清單 2. 在 JUL 配置檔案中指定自定義的格式化器類

1

java.util.logging.ConsoleHandler.formatter = logging.jul.CustomFormatter

Log4j 在格式化器的實作上要簡單一些,由 org.apache.log4j.PatternLayout 類來負責完成日志記錄的格式化。在自定義時不需要建立新的 Java 類,而是通過配置檔案指定所需的格式化模式。在格式化模式中,不同的占位符表示不同類型的資訊。比如“%c”表示記錄器的名稱,“%d”表示日 期,“%m”表示日志的消息文本,“%p”表示嚴重性級别,“%t”表示線程的名稱。清單 3 給出了 Log4j 配置檔案中日志記錄的自定義方式。

清單 3. Log4j 中日志記錄的自定義方式

log4j.appender.stdout.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} [%p] %c - %m%n      

日志處理器

日志記錄經過格式化之後,由不同的處理器來進行處理。不同的處理器有各自不同的處理方式。比如控制台處理器會把日志輸出到控制台中,檔案處理器把日志寫入到檔案中。除了這些之外,還有寫入到資料庫、通過郵件發送、寫入到 JMS 隊列等各種不同的處理方式。

日志處理器也可以配置所處理日志資訊的最低嚴重性級别。低于該級别的日志不會被處理。這樣可以控制所處理的日志記錄數量。比如控制台處理器的級别一般設定為 INFO,而檔案處理器則一般設定為 DEBUG。

日志記錄架構一般提供了比較多的日志處理器實作。開發人員也可以建立自定義的實作。

Java 日志封裝 API

除 了 JUL 和 log4j 這樣的日志記錄庫之外,還有一類庫用來封裝不同的日志記錄庫。這樣的封裝庫中一開始以 Apache Commons Logging 架構最為流行,現在比較流行的是 SLF4J。這樣封裝庫的 API 都比較簡單,隻是在日志記錄庫的 API 基礎上做了一層簡單的封裝,屏蔽不同實作之間的差別。由于日志記錄實作所提供的 API 大緻上比較相似,封裝庫的作用更多的是達到文法上的一緻性。

在 Apache Commons Logging 庫中,核心的 API 是 org.apache.commons.logging.LogFactory 類和 org.apache.commons.logging.Log 接口。LogFactory 類提供了工廠方法用來建立 Log 接口的實作對象。比如 LogFactory.getLog 可以根據 Java 類或名稱來建立 Log 接口的實作對象。Log 接口中為 6 個不同的嚴重性級别分别定義了一組方法。比如對 DEBUG 級别,定義了 isDebugEnabled()、debug(Object message) 和 debug(Object message, Throwable t) 三個方法。從這個層次來說,Log 接口簡化了對于日志記錄器的使用。

SLF4J 庫的使用方式與 Apache Commons Logging 庫比較類似。SLF4J 庫中核心的 API 是提供工廠方法的 org.slf4j.LoggerFactory 類和記錄日志的 org.slf4j.Logger 接口。通過 LoggerFactory 類的 getLogger 方法來擷取日志記錄器對象。與 Apache Commons Logging 庫中的 Log 接口類似,Logger 接口中的方法也是按照不同的嚴重性級别來進行分組的。Logger 接口中有同樣 isDebugEnabled 方法。不過 Logger 接口中發出日志記錄請求的 debug 等方法使用 String 類型來表示消息,同時可以使用包含參數的消息,如清單 4 所示。

清單 4. SLF4J 的使用方式

public class Slf4jBasic { 
   private static final Logger LOGGER = LoggerFactory.getLogger(Slf4jBasic.class); 
   public void logBasic() { 
       if (LOGGER.isInfoEnabled()) { 
           LOGGER.info("My log message for %s", "Alex"); 
       } 
   } 
}      

MDC

MDC(Mapped Diagnostic Context,映射調試上下文)是 log4j 和 logback 提供的一種友善在多線程條件下記錄日志的功能。某些應用程式采用多線程的方式來處理多個使用者的請求。在一個使用者的使用過程中,可能有多個不同的線程來進行 處理。典型的例子是 Web 應用伺服器。當使用者通路某個頁面時,應用伺服器可能會建立一個新的線程來處理該請求,也可能從線程池中複用已有的線程。在一個使用者的會話存續期間,可能有 多個線程處理過該使用者的請求。這使得比較難以區分不同使用者所對應的日志。當需要追蹤某個使用者在系統中的相關日志記錄時,就會變得很麻煩。

一種解決的辦法是采用自定義的日志格式,把使用者的資訊采用某種方式編碼在日志記錄中。這種方式的問題在于要求在每個使用日志記錄器的類中,都可以通路到使用者相關的資訊。這樣才可能在記錄日志時使用。這樣的條件通常是比較難以滿足的。MDC 的作用是解決這個問題。

MDC 可以看成是一個與目前線程綁定的哈希表,可以往其中添加鍵值對。MDC 中包含的内容可以被同一線程中執行的代碼所通路。目前線程的子線程會繼承其父線程中的 MDC 的内容。當需要記錄日志時,隻需要從 MDC 中擷取所需的資訊即可。MDC 的内容則由程式在适當的時候儲存進去。對于一個 Web 應用來說,通常是在請求被處理的最開始儲存這些資料。清單 5 中給出了 MDC 的使用示例。

清單 5. MDC 使用示例

public class MdcSample { 
   private static final Logger LOGGER = Logger.getLogger("mdc"); 
   public void log() { 
       MDC.put("username", "Alex"); 
       if (LOGGER.isInfoEnabled()) { 
           LOGGER.info("This is a message."); 
       } 
   } 
}      

清單 5 中,在記錄日志前,首先在 MDC 中儲存了名稱為“username”的資料。其中包含的資料可以在格式化日志記錄時直接引用,如清單 6 所示,“%X{username}”表示引用 MDC 中“username”的值。

清單 6. 使用 MDC 中記錄的資料

log4j.appender.stdout.layout.ConversionPattern=%X{username} %d{yyyy-MM-dd HH:mm:ss} [%p] %c - %m%n      

日志記錄最佳實踐

下面主要介紹一些在記錄日志時的比較好的實踐。

檢查日志是否可以被記錄

當 日志記錄器收到一個日志記錄請求時,如果請求的嚴重性級别低于記錄器對象的實際有效級别,則該請求會被忽略。在日志記錄方法的實作中會首先進行這樣的檢 查。不過推薦的做法是在調用 API 進行記錄之前,首先進行相應的檢查,這樣可以避免不必要的性能問題,如清單 7 所示。

清單 7. 檢查日志是否可以被記錄

if (LOGGER.isDebugEnabled()) { 
   LOGGER.debug("This is a message."); 
}      

清單 7 中的做法的作用在于避免了構造日志記錄消息所帶來的開銷。日志消息中通常包含與目前上下文相關的資訊。為了擷取這些資訊并構造相應的消息文本,不可避免會 産生額外的開銷。尤其對于 DEBUG 和 TRACE 級别的日志消息來說,它們所出現的頻率很高,累加起來的開銷比較大。是以在記錄 INFO、DEBUG 和 TRACE 級别的日志時,首先進行相應的檢查是一個好的實踐。而 WARN 及其以上級别的日志則一般不需要進行檢查。

日志中包含充分的資訊

日 志中所包含的資訊應該是充分的。在記錄日志消息時應該盡可能多的包含目前上下文中的各種資訊,以友善在遇到問題時可以快速的擷取到所需的資訊。比如在網上 支付功能中,與支付相關的日志應該完整的包含目前使用者、訂單以及支付方式等全部資訊。一種比較常見的做法是把相關的日志記錄分散在由不同日志記錄器所記錄 的日志中。當出現問題之後,需要手工查找并比對相關的日志來定位問題,所花費的時間和精力會更多。是以,應該盡可能在一條日志記錄中包含足夠多的資訊。

使用合适的日志記錄器名稱

一 般的日志記錄實踐是使用目前 Java 類的全名作為其使用的日志記錄器的名稱。這樣做可以得到一個與 Java 類和包的層次結構相對應的日志記錄器的層次結構。可以很友善的按照不同的子產品來設定相應的日志記錄級别。不過對于某些全局的或是橫切的功能,如安全和性能 等,則推薦使用功能相關的名稱。比如程式中可能包含用來提供性能剖析資訊的日志記錄。對于這樣的日志記錄,應該使用同一名稱的日志記錄器,如類似 “performance”或“performance.web”。這樣當需要啟用和禁用性能剖析時,隻需要配置這些名稱的記錄器即可。

使用半結構化的日志消息

在 介紹日志記錄 API 中的格式化器時提到過,日志記錄中除了基本的日志消息之外,還包括由日志架構提供的其他中繼資料。這些資料按照給定的格式出現在日志記錄中。這些半結構化的 格式使得可以通過工具提取日志記錄中的相關資訊進行分析。在使用日志 API 進行記錄時,對于日志消息本身,也推薦使用半結構化的方式來組織。

比如一個電子商務的網站,當使用者登入之後,該使用者所産生的不同操作所對應的日志記錄中都可以包含該使用者的使用者名,并以固定的格式出現在日志記錄中,如清單 8 所示。

清單 8. 使用半結構化的日志消息

[user1] 使用者登入成功。
[user1] 使用者成功購買産品 A。
[user2] 訂單 003 付款失敗。      

當需要通過日志記錄來排查某個使用者所遇到的問題時,隻需要通過正則表達就可以很快地查詢到使用者相關的日志記錄。

日志聚合與分析

在 程式中正确的地方輸出合适的日志消息,隻是合理使用日志的第一步。日志記錄的真正作用在于當有問題發生時,能夠幫助開發人員很快的定位問題所在。不過一個 實用的系統通常由很多個不同的部分組成。這其中包括所開發的程式本身,也包括所依賴的第三方應用程式。以一個典型的電子商務網站為例,除了程式本身,還包 括所依賴的底層作業系統、應用伺服器、資料庫、HTTP 伺服器和代理伺服器和緩存等。當一個問題發生時,真正的原因可能來自程式本身,也可能來自所依賴的第三方程式。這就意味着開發人員可能需要檢查不同伺服器 上不同應用程式的日志來确定真正的原因。

日志聚合的作用就在于可以把來自不同伺服器上不同應用程式産生的日志聚合起來,存放在單一的伺服器 上,友善進行搜尋和分析。在日志聚合方面,已經有不少成熟的開源軟體可以很好的滿足需求。本文中要介紹的是 logstash,一個流行的事件和日志管理開源軟體。logstash 采用了一種簡單的處理模式:輸入 -> 過濾器 -> 輸出。logstash 可以作為代理程式安裝到每台需要收集日志的機器上。logstash 提供了非常多的插件來處理不同類型的資料輸入。典型的包括控制台、檔案和 syslog 等;對于輸入的資料,可以使用過濾器來進行處理。典型的處理方式是把日志消息轉換成結構化的字段;過濾之後的結果可以被輸出到不同的目的地,比如 ElasticSearch、檔案、電子郵件和資料庫等。

Logstash 在使用起來很簡單。從官方網站下載下傳 jar 包并運作即可。在運作時需要指定一個配置檔案。配置檔案中定義了輸入、過濾器和輸出的相關配置。清單 9 給出了一個簡單的 logstash 配置檔案的示例。

清單 9. logstash 配置檔案示例

input { 
 file { 
   path => [ "/var/log/*.log", "/var/log/messages", "/var/log/syslog" ] 
   type => 'syslog'
 } 
} 
 
output { 
 stdout { 
debug => true
debug_format => "json"
 } 
}      

清單 9 中定義了 logstash 收集日志時的輸入(input)和輸出(output)的相關配置。輸入類型是檔案(file)。每種類型輸入都有相應的配置。對于檔案來說,需要配置的 是檔案的路徑。對每種類型的輸入,都需要指定一個類型(type)。該類型用來區分來自不同輸入的記錄。代碼中使用的輸出是控制台。配置檔案完成之後,通 過“java -jar logstash-1.1.13-flatjar.jar agent -f logstash-simple.conf”就可以啟動 logstash。

在日志分析中,比較重要的是結構化的資訊。而日志資訊通常隻是 一段文本,其中的不同字段表示不同的含義。不同的應用程式産生的日志的格式并不相同。在分析時需要關注的是其中包含的不同字段。比如 Apache 伺服器會産生與使用者通路請求相關的日志。在日志中包含了通路者的各種資訊,包括 IP 位址、時間、HTTP 狀态碼、響應内容的長度和 User Agent 字元串等資訊。在 logstash 收集到日志資訊之後,可以根據一定的規則把日志資訊中包含的資料提取出來并命名。logstash 提供了 grok 插件可以完成這樣的功能。grok 基于正規表達式來工作,同時提供了非常多的常用類型資料的提取模式,如清單 10 所示。

清單 10. 使用 grok 提取日志記錄中的内容

//Apache 通路日志
49.50.214.136 GET /index.html 200 1150 "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.17 (KHTML, like Gecko) Chrome/24.0.1312.57 Safari/537.17"
 
//grok 提取模式
%{IP:client} %{WORD:method} %{URIPATHPARAM:request} %{NUMBER:status} %{NUMBER:bytes} %{QS:useragent}      

在經過上面 grok 插件的提取之後,Apache 通路日志被轉換成包含字段 client、method、request、status、bytes 和 useragent 的格式化資料。可以根據這些字段來進行搜尋。這對于分析問題和進行統計都是很有幫助的。

當 日志記錄通過 logstash 進行收集和處理之後,通常會把這些日志記錄儲存到資料庫中進行分析和處理。目前比較流行的方式是儲存到 ElasticSearch 中,進而可以利用 ElasticSearch 提供的索引和搜尋能力來分析日志。已經有不少的開源軟體在 ElasticSearch 基礎之上開發出相應的日志管理功能,可以很友善的進行搜尋和分析。本文中介紹的是 Graylog2。

Graylog2 由伺服器和 Web 界面兩部分組成。伺服器負責接收日志記錄并儲存到 ElasticSearch 之中。Web 界面則可以檢視和搜尋日志,并提供其他的輔助功能。logstash 提供了插件 gelf,可以把 logstash 收集和處理過的日志記錄發送到 Graylog2 的伺服器。這樣就可以利用 Graylog2 的 Web 界面來進行查詢和分析。隻需要把清單 9 中的 logstash 的配置檔案中的 output 部分改成清單 11 中所示即可。

清單 11. 配置 logstash 輸出到 Graylog2

output { 
 gelf { 
   host => '127.0.0.1'
 } 
}      

在安裝 Graylog2 時需要注意,一定要安裝與 Graylog2 的版本相對應的版本的 ElasticSearch,否則會出現日志記錄無法儲存到 ElasticSearch 的問題。本文中使用的是 Graylog2 伺服器 0.11.0 版本和 ElasticSearch 0.20.4 版本。

小結