為什么要定制

Spring Boot 默認使用 Logback 作為日志實現(xiàn)，而我們一般使用 SLF4J 來輸出日志：

private static final Logger LOGGER = LoggerFactory.getLogger(<當前類>.class);

public void foo() {
    try {
        // ...
    } catch (Exception e) {
        LOGGER.error("foo: Oops, something is wrong!", e);
    }
}

上述代碼打印的日志看起來是這樣：

2019-05-16 11:26:13.194 ERROR 13789 --- [nio-8080-exec-1] com.hsinwong.demo.Service    : foo: Oops, something is wrong!

java.lang.NullPointerException: null
    at Main.main(Main.java:4)

當生產(chǎn)環(huán)境出現(xiàn)問題需要排查的時候诱咏，由于日志太多苔可，我們可能會使用 grep 命令過濾日志：

[root@hsinwong demo]# grep error demo.log
2019-05-16 11:26:13.194 ERROR 13789 --- [nio-8080-exec-1] com.hsinwong.demo.Service    : foo: Oops, something is wrong!
[root@hsinwong demo]# 

完全看不到有關(guān)異常的任何信息。所以有經(jīng)驗的程序員可能會這樣輸出日志：

LOGGER.error("foo: Oops, something is wrong! message={}", e.getMessage(), e);

一勞永逸

在 Spring Boot 的資源目錄下新增 logback-spring.xml 文件：

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <conversionRule conversionWord="clr" converterClass="org.springframework.boot.logging.logback.ColorConverter" />
    <conversionRule conversionWord="aEx" converterClass="com.hsinwong.demo.logging.ExtendedAdditionThrowableProxyConverter" />

    <logger name="org.apache.catalina.startup.DigesterFactory" level="ERROR"/>
    <logger name="org.apache.catalina.util.LifecycleBase" level="ERROR"/>
    <logger name="org.apache.coyote.http11.Http11NioProtocol" level="WARN"/>
    <logger name="org.apache.sshd.common.util.SecurityUtils" level="WARN"/>
    <logger name="org.apache.tomcat.util.net.NioSelectorPool" level="WARN"/>
    <logger name="org.eclipse.jetty.util.component.AbstractLifeCycle" level="ERROR"/>
    <logger name="org.hibernate.validator.internal.util.Version" level="WARN"/>

    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${CONSOLE_LOG_PATTERN:-%clr(%d{${LOG_DATEFORMAT_PATTERN:-yyyy-MM-dd HH:mm:ss.SSS}}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m${LOG_EXCEPTION_CONVERSION_WORD:-%aEx}}</pattern>
        </encoder>
    </appender>

    <root level="info">
        <appender-ref ref="CONSOLE" />
    </root>
</configuration>

該文件的原型是 Spring Boot 內(nèi)置的 Logback 默認配置文件 defaults.xml：

<?xml version="1.0" encoding="UTF-8"?>

<!--
Default logback configuration provided for import, equivalent to the programmatic
initialization performed by Boot
-->

<included>
    <conversionRule conversionWord="clr" converterClass="org.springframework.boot.logging.logback.ColorConverter" />
    <conversionRule conversionWord="wex" converterClass="org.springframework.boot.logging.logback.WhitespaceThrowableProxyConverter" />
    <conversionRule conversionWord="wEx" converterClass="org.springframework.boot.logging.logback.ExtendedWhitespaceThrowableProxyConverter" />
    <property name="CONSOLE_LOG_PATTERN" value="${CONSOLE_LOG_PATTERN:-%clr(%d{${LOG_DATEFORMAT_PATTERN:-yyyy-MM-dd HH:mm:ss.SSS}}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}"/>
    <property name="FILE_LOG_PATTERN" value="${FILE_LOG_PATTERN:-%d{${LOG_DATEFORMAT_PATTERN:-yyyy-MM-dd HH:mm:ss.SSS}} ${LOG_LEVEL_PATTERN:-%5p} ${PID:- } --- [%t] %-40.40logger{39} : %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}"/>

    <logger name="org.apache.catalina.startup.DigesterFactory" level="ERROR"/>
    <logger name="org.apache.catalina.util.LifecycleBase" level="ERROR"/>
    <logger name="org.apache.coyote.http11.Http11NioProtocol" level="WARN"/>
    <logger name="org.apache.sshd.common.util.SecurityUtils" level="WARN"/>
    <logger name="org.apache.tomcat.util.net.NioSelectorPool" level="WARN"/>
    <logger name="org.eclipse.jetty.util.component.AbstractLifeCycle" level="ERROR"/>
    <logger name="org.hibernate.validator.internal.util.Version" level="WARN"/>
</included>

新增 logback-spring.xml 文件后袋狞，還要新增一個自定義的類：

package com.hsinwong.demo.logging;

import ch.qos.logback.classic.pattern.ExtendedThrowableProxyConverter;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.classic.spi.IThrowableProxy;
import ch.qos.logback.core.CoreConstants;
import org.springframework.boot.logging.logback.ExtendedWhitespaceThrowableProxyConverter;

/**
 * 在 {@link ExtendedWhitespaceThrowableProxyConverter} 的基礎(chǔ)上附加異常摘要到日志第一行末尾<br>
 * 便于篩選日志時快速了解異常信息
 *
 * @author hsinwong
 */
public class ExtendedAdditionThrowableProxyConverter extends ExtendedThrowableProxyConverter {

    @Override
    public String convert(ILoggingEvent event) {
        IThrowableProxy tp = event.getThrowableProxy();
        if (tp == null) {
            return CoreConstants.LINE_SEPARATOR;
        }
        return super.convert(event);
    }

    @Override
    protected String throwableProxyToString(IThrowableProxy tp) {
        return " ==> " + tp.getClassName() + ": " + tp.getMessage() + CoreConstants.LINE_SEPARATOR +
                CoreConstants.LINE_SEPARATOR + super.throwableProxyToString(tp) + CoreConstants.LINE_SEPARATOR;
    }

}

日志現(xiàn)在看起來像這樣：

2019-05-16 11:26:13.194 ERROR 13789 --- [nio-8080-exec-1] com.hsinwong.demo.Service    : foo: Oops, something is wrong! ==> java.lang.NullPointerException: null

java.lang.NullPointerException: null
    at Main.main(Main.java:4)

大大提高了 grep error demo.log 命令的實用性焚辅。

又能擠出點寫代碼和排查問題的時間來劃水了……