方法 |
%M |
</tr>
</tbody>
</table>
例如,下面的PatternLayout會在中括號內x顯示日志級別,后面是線程名字和日志事件的消息:
[%p] %t: %m
下面是使用了上述轉換模式后的日志輸出示例:
[INFO] main: initializing worker threads
[DEBUG] worker: listening on port 12222[INFO] worker: received request from 192.168.1.200[ERROR] worker: unknown request ID from 192.168.1.200
記錄棧跟蹤信息
如果你在Java程序中使用過異常,那么很有可能已經看到過棧跟蹤信息。它提供了一個程序中方法調用的快照,讓你準確定位程序執行的位置。例如,下面的棧跟蹤信息是程序試圖打開一個不存在的文件后生成的:
[ERROR] main: Unable to open file! java.io.FileNotFoundException: foo.file (No such file or directory)
at java.io.FileInputStream.open(Native Method) ~[?:1.7.0_79]
at java.io.FileInputStream.<init>(FileInputStream.java:146) ~[?:1.7.0_79]
at java.io.FileInputStream.<init>(FileInputStream.java:101) ~[?:1.7.0_79]
at java.io.FileReader.<init>(FileReader.java:58) ~[?:1.7.0_79]
at FooClass.main(FooClass.java:47)
這個示例使用了一個名為FooClass的類,它包含一個main方法。在程序第47行,FileReader獨享試圖打開一個名為foo.file的文件,由于在程序目錄下沒有名字是foo.file的文件,因此Java虛擬機拋出了一個FileNotFoundException。因為這個方法調用被放到了try-catch語塊中,所以我們能夠捕獲這個異常并記錄它,或者至少可以阻止程序崩潰。
使用PatternLayout記錄棧跟蹤信息
在寫本篇文章時最新版本的Log4j和Logback中,如果在Layout中沒有和可拋異常相關的信息,那么都會自動將%xEx(這種棧跟蹤信息包含了每次方法調用的包信息)添加到PatternLayout中。如果對于普通的日志信息的模式如下:
[%p] %t: %m
它會變為:
[%p] %t: %m%xEx
這樣不僅僅錯誤信息會被記錄下來,完整的棧跟蹤信息也會被記錄:
[ERROR] main: Unable to open file! java.io.FileNotFoundException: foo.file (No such file or directory)
at java.io.FileInputStream.open(Native Method) ~[?:1.7.0_79]
at java.io.FileInputStream.<init>(FileInputStream.java:146) ~[?:1.7.0_79]
at java.io.FileInputStream.<init>(FileInputStream.java:101) ~[?:1.7.0_79]
at java.io.FileReader.<init>(FileReader.java:58) ~[?:1.7.0_79]
at FooClass.main(FooClass.java:47)
%xEx中的包查詢是一個代價昂貴的操作,如果你頻繁的記錄異常信息,那么可能會碰到性能問題,例如:
// ...
} catch (FileNotFoundException ex) {
logger.error(“Unable to open file!”, ex);
}
一種解決方法是在模式中顯式的包含%ex,這樣就只會請求異常的棧跟蹤信息:
[%p] %t: %m%ex
另外一種方法是通過追加%xEx(none)的方法排除(在Log4j)中所有的異常信息:
[%p] %t: %m%xEx{none}
或者在Logback中使用%nopex:
[%p] %t: %m%nopex
使用結構化布局輸出棧跟蹤信息
如你在“解析多行棧跟蹤信息”一節中所見,對于站跟蹤信息來說,使用結構化布局來記錄是最合適的方式,例如JSON和XML。 這些布局會自動將棧跟蹤信息按照核心組件進行分解,這樣我們可以很容易將其導出到其他程序或者日志服務中。對于上述站跟蹤信息,如果使用JSON格式,部分信息顯示如下:
...
"loggerName" : "FooClass",
"message" : "Foo, oh no! ",
"thrown" : {
"commonElementCount" : 0,
"localizedMessage" : "foo.file (No such file or directory)",
"message" : "foo.file (No such file or directory)",
"name" : "java.io.FileNotFoundException",
"extendedStackTrace" : [ {
"class" : "java.io.FileInputStream",
"method" : "open",
"file" : "FileInputStream.java",
...
記錄未捕獲異常
通常情況下,我們通過捕獲的方式來處理異常。如果一個異常沒有被捕獲,那么它可能會導致程序終止。如果能夠留存任何日志,那么這是一個可以幫助我們調試為什么會發生異常的好辦法,這樣你就可以找到發生異常的根本原因并解決它。下面來說明我們如何建立一個默認的異常處理器來記錄這些錯誤。
Thread類中有兩個方法,我們可以用它來為未捕獲的異常指定一個ExceptionHandler:
setDefaultUncaughtExceptionHandler 可以讓你在任何線程上處理任何異常。setUncaughtExceptionHandler可以讓你針對一個指定的線程設定一個不同的處理方法。而ThreadGroup則允許你設定一個處理方法。大部分人會使用默認的異常處理方法。
下面是一個示例,它設定了一個默認的異常處理方法,來創建一個日志事件。它要求你傳入一個UncaughtExceptionHandler:
import java.util.logging.*;
public class ExceptionDemo {
private static final Logger logger = Logger.getLogger(ExceptionDemo.class);
public static void main(String[] args) {
Thread.setDefaultUncaughtExceptionHandler(new Thread.UncaughtExceptionHandler() {
public void uncaughtException(Thread t, Throwable e) {
logger.log(Level.SEVERE, t + " ExceptionDemo threw an exception: ", e);
};
});
class adminThread implements Runnable {
public void run() {
throw new RuntimeException();
}
}
Thread t = new Thread(new adminThread());
t.start();
}
}
下面是一個未處理異常的輸出示例:
May 29, 2015 2:21:15 PM ExceptionDemo$1 uncaughtException
SEVERE: Thread[Thread-1,5,main] ExceptionDemo threw an exception:
java.lang.RuntimeException
at ExceptionDemo$1adminThread.run(ExceptionDemo.java:15)
at java.lang.Thread.run(Thread.java:745)
JSON
JSON(JavaScript Object Notation)是一種用來存儲結構化數據的格式,它將數據存儲成鍵值對的集合,類似于HashMap或者Hashtable。JSON具有的可移植性和通用性,大部分現代語言都內置支持它或者通過已經準備好的第三方類庫來支持它。
JSON支持許多基本數據類型,包括字符串、數字、布爾、數組和null。例如,你可以使用下面的JSON格式來表示一個電腦:
{
"manufacturer": "Dell",
"model": "Inspiron",
"hardware": {
"cpu": "Intel Core i7",
"ram": 16384,
“cdrom”: null
},
"peripherals": [
{
"type": "monitor",
"manufacturer": "Acer",
"model": "S231HL"
}
]
}
JSON的可移植性使得它非常適合存儲日志記錄,使用JSON后,Java日志可以被任何數目的JSON解釋器所讀取。因為數據已經是結構化的,所以解析JSON日志要遠比解析純文本日志容易。
Java中的JSON
對于Java來說,有大量的JSON實現,其中一個是JSON.simple。JSON.simple是輕量級的、易于使用,并且全部符合JSON標準。
如果想將上面的computer對象轉換成可用的Java對象,我們可以從文件中讀取JSON內容,將其傳遞給JSON.simple,然后返回一個Object,接著我們可以將Object轉換成JSONObject:
Object computer = JSONValue.parse(new FileReader("computer.json"));
JSONObject computerJSON = (JSONObject)computer;
另外,為了取得鍵值對的信息,你可以使用任何日志框架來記錄一個JSONObject,JSONObject對象包含一個toString()方法, 它可以將JSON轉換成文本:
2015-05-06 14:54:32,878 INFO JSONTest main {"peripherals":[{"model":"S231HL","manufacturer":"Acer","type":"monitor"}],"model":"Inspiron","hardware":{"cdrom":null,"ram":16384,"cpu":"Intel Core i7"},"manufacturer":"Dell"}
雖然這樣做可以很容易的打印JSONObject,但如果你使用結構化的Layouts,例如JSONLayout或者XMLLayout,可能會導致意想不到的結果:
...
"message" : "{"peripherals":[{"model":"S231HL","manufacturer":"Acer","type":"monitor"}],"model":"Inspiron","hardware":{"cdrom":null,"ram":16384,"cpu":"Intel Core i7"},"manufacturer":"Dell"}",
...
Log4j中的JSONLayout并沒有內置支持內嵌JSON對象,但你可以通過創建自定義Layout的方式來添加一個JSONObject字段,這個Layout會繼承或者替換JSONLayout。然 而,如果你使用一個日志管理系統,需要記住許多日志管理系統會針對某些字段使用預定義的數據類型。如果你創建一個Layout并將JSONObject存 儲到message字段中,那么它可能會和日志系統中使用的String數據類型相沖突。一種解決辦法是將JSON數據存儲到一個字段中,然后將字符串類 型的日志消息存儲到另外一個字段中。
其它JSON庫
除了JSON.simple,Java中還有很多其它JSON庫。JSON-java是由JSON創建者開發的一個參考實現,它包含了額外的一些功能,可以轉換其它數據類型,包括web元素。但是目前JSON-java已經沒有人來維護和提供支持了。
如果想將JSON對象轉換成Java對象或者逆向轉換,Google提供了一個Gson庫。使 用Gson時,可以很簡單使用 toJson() 和 fromJson() 方法來解析JSON,這兩個方法分別用來將Java對象轉換成JSON字符串以及將JSON字符串轉換成Java對象。Gson甚至可以應用在內存對象 中,允許你映射到那些沒有源代碼的對象上。
Jackson是一個強大的、流行的、功能豐富的庫,它可以在Java中管理JSON對象。有一些框架甚至使用Jackson作為它們的JSONLayouts。盡管它很大并且復雜,但Jackson對于初學者和高級用戶來說,是很容易使用的。
Logback通過logback-jackson和logback-json-classic庫繼承了Jackson,這兩個庫也是logback-contrib項目的一部分。在集成了Jackson后,你可以將日志以JSON的格式導出到任何Appender中。
Logback Wiki詳細解釋了如何將JSON添加到logback中,在Wiki頁面中的示例使用了LogglyAppender,這里的配置也可以應用到其他Appender上。下面的示例說明了如何將JSON格式化的日志記錄寫入到名為myLog.json的文件中:
...
<appender name="file" class="ch.qos.Logback.core.FileAppender">
<file>myLog.json</file>
<encoder class="ch.qos.Logback.core.encoder.LayoutWrappingEncoder">
<layout class="ch.qos.Logback.contrib.json.classic.JsonLayout">
<jsonFormatter class="ch.qos.Logback.contrib.jackson.JacksonJsonFormatter"/>
</layout>
</encoder>
</appender>
...
你也可以通過FasterXML Wiki找到更多關于Jackson的深度介紹。
了解更多JSON相關信息
你可以通過JSON主頁學習更多JSON相關信息,或者通過CodeAcademy來通過學習一個交互式的快速上手教程(請注意這個課程是基于JavaScript的,而不是Java)。有一些在線工具例如JSONLint和JSON在線編輯器可以幫助你解析、驗證以及格式化JSON代碼。
NDC、MDC以及ThreadContext
當處理多線程應用程序,特別是web服務時,跟蹤事件可能會變得困難。當針對多個同時存在的多個用戶生成日志記錄時,你如何區分哪個行為和哪個日志 事件有關呢?如何兩個用戶沒有成功打開一個相同的文件,或者在同一時間沒有成功登陸,那么怎么處理日志記錄?你可能需要一種方式來將日志記錄和程序中的唯 一標示符關聯起來,這些標識符可能是用戶ID,會話ID或者設備ID。而這就是NDC、MDC以及ThreadContext的用武之地。
NDC、MDC和ThreadContext通過向單獨的日志記錄中添加獨一無二的數據戳,來創建日志足跡(log trails)。這些數據戳也被稱為魚標記(fish tagging),我們可以通過一個或者多個獨一無二的值來區分日志。這些數據戳在每個線程級別上進行管理,并且一直持續到線程結束,或者直到數據戳被刪 掉。例如,如果你的Web應用程序為每個用戶生成一個新的線程,那么你可以使用這個用戶的ID來標記日志記錄。當你想在一個復雜的系統中跟蹤特定的請求、 事務或者用戶,這是一種非常有用的方法。
嵌套診斷上下文(NDC)
NDC或者嵌套診斷上下文(Nested Diagnostic Context)是基于棧的思想,信息可以被放到棧上或者從棧中移除。而棧中的值可以被Logger訪問,并且Logger無需顯示想日志方法中傳入任何值。
下面的代碼示例使用NDC和Log4j來將用戶姓名和一條日志記錄關聯起來。NDC是一個靜態類,因此我們可以直接訪問它的方法,而無需實例化一個 NDC對象。在這個示例中, NDC.oush(username) 和 NDC.push(sessionID) 方法在棧中存儲了當前的用戶名(admin)和會話ID(1234),而NDC.pop()方法將一些項從棧中移除,NDC.remove()方法讓 Java回收內存,以免造成內存溢出。
import java.io.FileReader;
import org.apache.Log4j.Logger;
import org.apache.Log4j.NDC;
...
String username = "admin";
String sessionID = "1234";
NDC.push(username);
NDC.push(sessionID);
try {
// tmpFile doesn't exist, causing an exception.
FileReader fr = new FileReader("tmpFile");
}
catch (Exception ex) {
logger.error("Unable to open file.");
}
finally {
NDC.pop();
NDC.pop();
NDC.remove();
}
Log4j的PatternLayout類通過%x轉換字符從NDC中提取值。如果一個日志事件被觸發,那么完整的NDC棧就被傳到Log4j:
<PatternLayout pattern="%x %-5p - %m%n" />
運行程序后,我們可以得出下面的輸出:
"admin 1234 ERROR – Unable to open file."
映射診斷上下文(MDC)
MDC或者映射診斷上下文和NDC很相似,不同之處在于MDC將值存儲在鍵值對中,而不是棧中。這樣你可以很容易的在Layout中引用一個單獨的 鍵。MDC.put(key,value) 方法將一個新的鍵值對添加到上下文中,而 MDC.remove(key) 方法會移除指定的鍵值對。
如果想在日志中同樣顯示用戶名和會話ID,我們需要使用 MDC.put() 方法將這兩個變量存儲成鍵值對:
import java.io.FileReader;
import org.apache.Log4j.Logger;
import org.apache.Log4j.MDC;
...
MDC.put("username", "admin");
MDC.put("sessionID", "1234");
try {
// tmpFile doesn't exist, causing an exception.
FileReader fr = new FileReader("tmpFile");
}
catch (Exception ex) {
logger.error("Unable to open file!");
}
finally {
MDC.clear();
}
這里再一次強調,在不需要使用Context后,我們需要使用 MDC.clear() 方法將所有的鍵值對從MDC中移除,這樣會降低內存的使用量,并阻止MDC在后面試圖調用那些已經過期的數據。
在日志框架中訪問MDC的值時,也稍微有些區別。對于存儲在上下文中的任何鍵,我們可以使用%X(鍵)的方式來訪問對應的值。這樣,我們可以使用 %X(username) 和 %X(sessionID) 來獲取對應的用戶名和會話ID:
<PatternLayout pattern="%X{username} %X{sessionID} %-5p - %m%n" />
"admin 1234 ERROR – Unable to open file!"
如果我們沒有指定任何鍵,那么MDC上下文就會被以 {(key, value),(key, value)} 的方式傳遞給Appender。
Logback中的NDC和MDC
和Log4j不同,Logback內置沒有實現NDC。但是slf4j-ext包提供了一個NDC實現,它使用MDC作為基礎。在Logback內部,你可以使用 MDC.put()、MDC.remove() 和 MDC.clear() 方法來訪問和管理MDC:
import org.slf4j.MDC;
...
Logger logger = LoggerFactory.getLogger(MDCLogback.class);
...
MDC.put("username", "admin");
MDC.put("sessionID", "1234");
try {
FileReader fr = new FileReader("tmpFile");
}
catch (Exception ex) {
logger.error("Unable to open file.");
}
finally {
MDC.clear();
}
在Logback中,你可以在Logback.xml中將如下模式應用到Appender上,它可以輸出和上面Log4j相同的結果:
<Pattern>[%X{username}] %X{sessionID} %-5p - %m%n</Pattern>
"[admin] 1234 ERROR - Unable to open file."
針對MDC的訪問并不僅僅限制在PatternLayout上,例如,當使用JSONFormatter時,MDC中的所有值都會被導出:
{
"timestamp":"1431970324945",
"level":"ERROR",
"thread":"main",
"mdc":{
"username":"admin",
"sessionID":"1234"
},
"logger":"MyClass",
"message":"Unable to open file.",
"context":"default"
}
ThreadContext
Version 2 of Log4j merged MDC and NDC into a single concept known as the Thread Context. The Thread Context is an evolution of MDC and NDC, presenting them respectively as the Thread Context Map and Thread Context Stack. The Thread Context is managed through the static ThreadContext class, which is implemented similar to Log4j 1’s MDC and NDC classes.
Log4j版本2中將MDC和NDC合并到一個單獨的組件中,這個組件被稱為線程上下文。線程上下文是針對MDC和NDC的進化,它分別用線程上下文Map映射線程上下文棧來表示MDC和NDC。我們可以通過ThreadContext靜態類來管理線程上下文,這個類在實現上類似于Log4j版本1中的MDC和NDC。
When using the Thread Context Stack, data is pushed to and popped from a stack just like with NDC:
當使用線程上下文棧時,我們可以向NDC那樣向棧中添加或者刪除數據:
import org.apache.logging.Log4j.ThreadContext;
...
ThreadContext.push(username);
ThreadContext.push(sessionID);
// Logging methods go here
ThreadContext.pop();
...
當使用線程上下文映射時,我們可以像MDC那樣將值和鍵結合在一起:
import org.apache.logging.Log4j.ThreadContext;
...
ThreadContext.put(“username”,"admin");
ThreadContext.put("sessionID", "1234");
// Logging methods go here
ThreadContext.clearMap();
...
ThreadContext類提供了一些方法,用于清除棧、清除MDC、清除存儲在上下文中的所有值,對應的方法是ThreadContext.clearAll()、ThreadContext.clearMap()和ThreadContext.clearStack()。
和在MDC以及NDC中一樣,我們可以使用Layouts在線程上下文中訪問這些值。使用PatternLayout時,%x轉換模式會從棧中獲取值,%X和%X(鍵)會從圖中獲取值。
ThreadContext過濾
一些框架允許你基于某些屬性對日志進行過濾。例如,Log4j的DynamicThresholdFilter 會在鍵滿足特定條件的情況下,自動調整日志級別。再比如,如果我們想要觸發TRACE級別的日志消息,我們可以創建一個名為trace-logging-enabled的鍵,并向log4j配置文件中添加一個過濾器:
<Configuration name="MyApp">
<DynamicThresholdFilter key="trace-logging-enabled" onMatch="ACCEPT" onMismatch="NEUTRAL">
<KeyValuePair key="true" value="TRACE" />
</DynamicThresholdFilter>
...
如果ThreadContext包含一個名為trace-logging-enabled的鍵,onMatch 和 onMismatch 會決定如何處理它。關于 onMatch 和 onMismatch,我們有三個可選項:ACCEPT,它會處理過濾器的規則;DENY,它會忽略過濾器的規則;NEUTRAL,它會推遲到下一個過濾 器。除了這些,我們還定義一個鍵值對,當值為true時,我們啟用TRACE級別的日志。
現在,當trace-logging-enabled被設置成true時,即使根Logger設置的日志級別高于TRACE,Appender也會記錄TRACE級別的消息。
你可能還想過濾一些特定的日志到特定的Appender中,Log4j中提供了ThreadContextMapFilter來實現這一點。如果我們想要限制某個特定的Appender,只記錄針對某個用戶的TRACE級別的消息,我們可以基于username鍵添加一個ThreadContextMapFilter:
<Console name="ConsoleAppender" target="SYSTEM_OUT">
<ThreadContextMapFilter onMatch="ACCEPT" onMismatch="DENY">
<KeyValuePair key="username" value="admin" />
</ThreadContextMapFilter>
...
如果想了解更多信息,你可以查看Log4j和Logback文檔中關于DynamicThresholdFilter部分。
Markers
Markers允許你對單獨的日志記錄添加一些獨一無二的數據。它可以用來對日志記錄進行分組,觸發一些行為,或者對日志記錄進行過濾,并將過濾結果輸出到指定的Appender中。你甚至可以將Markers和ThreadContext結合在一起使用,以提高搜索和過濾日志數據的能力。
例如,假設我們有一個可以連接到數據庫的類,如果在打開數據庫的時候發生了異常,我們需要把異常記錄成fatal錯誤。我們可以創建一個名為DB_ERROR的Marker,然后將其應用到日志事件中:
import org.apache.logging.Log4j.Marker;
import org.apache.logging.Log4j.MarkerManager;
...
final static Marker DB_ERROR = MarkerManager.getMarker("DATABASE_ERROR");
...
logger.fatal(DB_ERROR, "An exception occurred.");
為了在日志輸出中顯示Marker信息,我們需要在PatternLayout中添加%marker轉換模式:
<PatternLayout pattern="%p %marker: %m%n" />
[FATAL] DATABASE_ERROR: An exception occurred.
或者對于JSON和XML格式的Layouts,會自動在輸出中包含Marker信息:
...
"thread" : "main",
"level" : "FATAL",
"loggerName" : "DBClass",
"marker" : {
"name" : "DATABASE_ERROR"
},
"message" : "An exception occurred.",
...
通過對Marker數據進行自動解析和排序,集中式的日志服務可以很容易對日志進行搜索處理。
Markers過濾
Marker過濾器可以讓你決定哪些Marker由哪些Logger來處理。marker字段會比較在日志事件里面的Marker名字,如果名字匹配,那么Logger會執行后續的行為。例如,在Log4j中,我們可以配置一個Appender來只顯示哪些使用了DB_ERROR Marker的消息,這可以通過log4j2.xml中的Appender添加如下信息來實現:
<MarkerFilter marker="DATABASE_ERROR" onMatch="ACCEPT" onMismatch="DENY" />
如果日志記錄中某一條的Marker可以匹配這里的marker字段,那么onMatch會決定如何處理這條記錄。如果不能夠匹配,或者日志記錄中 沒有Marker信息,那么onMismatch就會決定如何處理這條記錄。對于onMatch和onMismatch來說,有3個可選 項:ACCEPT,它允許記錄事件;DENY,它會阻塞事件;NEUTRAL,它不會對事件進行任何處理。
在Logback中,我們需要更多一些設置。首先,想Appender中添加一個新的EvaluatorFilter,并如上所述指定onMatch和onMismatch行為。然后,添加一個OnMarkerEvaluator并將Marker的名字傳遞給它:
<filter class="ch.qos.Logback.core.filter.EvaluatorFilter">
<evaluator class="ch.qos.Logback.classic.boolex.OnMarkerEvaluator">
<marker>DATABASE_ERROR</marker>
</evaluator>
<onMatch>ACCEPT</onMatch>
<onMismatch>DENY</onMismatch>
</filter>
將Markers和NDC、MDC以及ThreadContext結合使用
Marker的功能和ThreadContext類似,它們都是向日志記錄中添加獨一無二的數據,這些數據可以被Appender訪問。如果把這兩者結合使用,可以讓你更容易的對日志數據進行索引和搜索。如果能夠知道何時使用哪一種技術,會對我們有所幫助。
NDC、MDC和ThreadContext被用于將相關日志記錄結 合在一起。如果你的應用程序會處理多個同時存在的用戶,ThreadContext可以讓你將針對某個特定用戶的一組日志記錄組合在一起。因為 ThreadContext針對每個線程都是不一樣的,所以你可以使用同樣的方法來對相關的日志記錄進行自動分組。
另一方面,Marker通常用于標記或者高亮顯示某些特殊事件。在上述示例中,我們使用DB_ERROR Marker來標明在方法中發生的SQL相關異常。我們可以使用DB_ERROR Marker來將這些事件的處理過程和其他事件區分開來,例如我們可以使用SMTP Appender來將這些事件通過郵件發送給數據庫管理員。
額外資源
指南和教程