在日誌中記錄Java異常信息的正確姿式

時間 2019-11-06

標籤日誌記錄 java 異常信息正確欄目 Java 简体版

原文原文鏈接

遇到的問題

今天遇到一個線上的BUG，在執行表單提交時失敗，可是從程序日誌中看不到任何異常信息。
在Review源代碼時發現，當catch到異常時只是輸出了e.getMessage()，以下所示：java

logger.error("error: {}, {}", params, e.getMessage());

在日誌中看不到任何信息，說明e.getMessage()返回值爲空字符串。web

緣由分析

先來看一下Java中的異常類圖：
spring

Throwable是Java中全部異常信息的頂級父類，其中的成員變量detailMessage就是在調用e.getMessage()返回的值。
那麼這個屬性會在何時賦值呢，追溯源碼發現，該屬性只會在Throwable構造函數中賦值。api

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()方法獲取異常信息（返回值爲空時，不利於問題排查）。tomcat

正確的作法

在Java開發中，經常使用的日誌框架及組件一般是：slf4j，log4j和logback，他們的關係能夠描述爲：slf4j提供了統一的日誌API，將具體的日誌實現交給log4j與logback。
也就是說，一般咱們只須要在項目中使用slf4j做爲日誌API，再集成log4j或者logback便可。
springboot

<!-- 使用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）：mvc

<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記錄日誌：app

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]

......