在日誌中記錄Java異常資訊的正確姿勢
阿新 • • 發佈：2019-06-21
遇到的問題
今天遇到一個線上的BUG，在執行表單提交時失敗，但是從程式日誌中看不到任何異常資訊。
在Review原始碼時發現，當catch到異常時只是輸出了e.getMessage()，如下所示：
logger.error("error: {}, {}", params, e.getMessage());在日誌中看不到任何資訊，說明e.getMessage()返回值為空字串。
原因分析
先來看一下Java中的異常類圖：
Throwable是Java中所有異常資訊的頂級父類，其中的成員變數detailMessage就是在呼叫e.getMessage()返回的值。
那麼這個屬性會在什麼時候賦值呢，追溯原始碼發現，該屬性只會在Throwable建構函式中賦值。
public Throwable() { // 在預設建構函式中不會給detailMessage屬性賦值 fillInStackTrace(); } public Throwable(String message) { fillInStackTrace(); // 直接將引數賦值給detailMessage detailMessage = message; } public Throwable(String message, Throwable cause) { fillInStackTrace(); // 直接將引數賦值給detailMessage detailMessage = message; this.cause = cause; } public Throwable(Throwable cause) { fillInStackTrace(); // 當傳入的Throwable物件不為空時，為detailMessage賦值 detailMessage = (cause==null ? null : cause.toString()); this.cause = cause; } protected Throwable(String message, Throwable cause, boolean enableSuppression, boolean writableStackTrace) { if (writableStackTrace) { fillInStackTrace(); } else { stackTrace = null; } // 直接將引數賦值給detailMessage detailMessage = message; this.cause = cause; if (!enableSuppression) suppressedExceptions = null; }
顯然，從原始碼中可以看到在Throwable的預設建構函式中是不會給detailMessage屬性賦值的。
也就是說，當異常物件是通過預設建構函式例項化的，或者例項化時傳入的message為空字串，那麼呼叫getMessage()方法時返回值就為空，也就是我遇到的情形。
所以，在程式日誌中不要單純使用getMessage()方法獲取異常資訊（返回值為空時，不利於問題排查）。
正確的做法
在Java開發中，常用的日誌框架及元件通常是：slf4j，log4j和logback，他們的關係可以描述為：slf4j提供了統一的日誌API，將具體的日誌實現交給log4j與logback。
也就是說，通常我們只需要在專案中使用slf4j作為日誌API，再整合log4j或者logback即可。
<!-- 使用slf4j作為日誌API -->
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
<version>1.7.25</version>
</dependency>
<!-- 整合logback作為具體的日誌實現 -->
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-core</artifactId>
<version>1.2.3</version>
</dependency>
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-classic</artifactId>
<version>1.2.3</version>
</dependency>上述配置以整合slf4j和logback為例，新增對應的logback配置檔案（logback.xml）：
<configuration scan="false" scanPeriod="30 seconds" debug="false" packagingData="true">
<statusListener class="ch.qos.logback.core.status.OnConsoleStatusListener"/>
<!-- 輸出到控制檯 -->
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%date %level [%thread] %logger{10} [%file:%line] %msg%n</pattern>
</encoder>
</appender>
<!-- 輸出到檔案 -->
<appender name="FILE" class="ch.qos.logback.core.FileAppender">
<file>test.log</file>
<encoder>
<pattern>%date %level [%thread] %logger{10} [%file:%line] %msg%n</pattern>
</encoder>
</appender>
<root level="info">
<appender-ref ref="STDOUT"/>
<appender-ref ref="FILE" />
</root>
</configuration>在Java中通過slf4j提供的日誌API記錄日誌：
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class Test {
private static final Logger logger = LoggerFactory.getLogger(Test.class);
}當我們需要在程式日誌中輸出異常資訊時，應該直接傳入異常物件即可，而不要單純通過異常物件的getMessage()方法獲取輸出異常資訊。
public void test() {
try {
// 使用預設建構函式實例項化異常物件
throw new NullPointerException();
} catch (Exception e) {
// 直接將異常物件傳入日誌介面，儲存異常資訊到日誌檔案中
logger.error("error: {}", e.getMessage(), e);
e.printStackTrace();
}
}如下是儲存到日誌檔案中的異常資訊片段：
2019-06-20 20:04:25,290 ERROR [http-nio-8090-exec-1] o.c.s.f.c.TestExceptionController [TestExceptionController.java:26] error: null # 使用預設構造引數例項化異常物件時，getMessage()方法返回值為空物件
# 如下是具體的異常堆疊資訊
java.lang.NullPointerException: null
at org.chench.springboot.falsework.controller.TestExceptionController.test(TestExceptionController.java:24) ~[classes/:na]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_181]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_181]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_181]
at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_181]
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:209) [spring-web-5.0.6.RELEASE.jar:5.0.6.RELEASE]
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:136) [spring-web-5.0.6.RELEASE.jar:5.0.6.RELEASE]
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:102) [spring-webmvc-5.0.6.RELEASE.jar:5.0.6.RELEASE]
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:877) [spring-webmvc-5.0.6.RELEASE.jar:5.0.6.RELEASE]
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:783) [spring-webmvc-5.0.6.RELEASE.jar:5.0.6.RELEASE]
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) [spring-webmvc-5.0.6.RELEASE.jar:5.0.6.RELEASE]
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:991) [spring-webmvc-5.0.6.RELEASE.jar:5.0.6.RELEASE]
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:925) [spring-webmvc-5.0.6.RELEASE.jar:5.0.6.RELEASE]
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:974) [spring-webmvc-5.0.6.RELEASE.jar:5.0.6.RELEASE]
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:866) [spring-webmvc-5.0.6.RELEASE.jar:5.0.6.RELEASE]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:635) [tomcat-embed-core-8.5.31.jar:8.5.31]
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:851) [spring-webmvc-5.0.6.RELEASE.jar:5.0.6.RELEASE]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:742) [tomcat-embed-core-8.5.31.jar:8.5.31]
......