Spring Boot 中使用 LogBack 配置

搜雲庫技術團隊發表於2017-11-30
Spring Boot

LogBack是一個日誌框架，它與Log4j可以說是同出一源，都出自Ceki Gülcü之手。（log4j的原型是早前由Ceki Gülcü貢獻給Apache基金會的）下載地址 logback.qos.ch/download.ht…

LogBack、Slf4j和Log4j之間的關係

Slf4j是The Simple Logging Facade for Java的簡稱，是一個簡單日誌門面抽象框架，它本身只提供了日誌Facade API和一個簡單的日誌類實現，一般常配合Log4j，LogBack，java.util.logging使用。Slf4j作為應用層的Log接入時，程式可以根據實際應用場景動態調整底層的日誌實現框架(Log4j/LogBack/JdkLog…)。

LogBack和Log4j都是開源日記工具庫，LogBack是Log4j的改良版本，比Log4j擁有更多的特性，同時也帶來很大效能提升。詳細資料可參照下面地址：Reasons to prefer logback over log4j。

LogBack官方建議配合Slf4j使用，這樣可以靈活地替換底層日誌框架。

TIPS：為了優化log4j，以及更大效能的提升，Apache基金會已經著手開發了log4j 2.0, 其中也借鑑和吸收了logback的一些先進特性，目前log4j2還處於beta階段

logback取代log4j的理由

1、更快的實現：Logback的核心重寫了，在一些關鍵執行路徑上效能提升10倍以上。而且logback不僅效能提升了，初始化記憶體載入也更小了。
2、非常充分的測試：Logback經過了幾年，數不清小時的測試。Logback的測試完全不同級別的。
3、Logback-classic非常自然實現了SLF4j：Logback-classic實現了SLF4j。在使用SLF4j中，你都感覺不到logback-classic。而且因為logback-classic非常自然地實現了slf4j ， 所 以切換到log4j或者其他，非常容易，只需要提供成另一個jar包就OK，根本不需要去動那些通過SLF4JAPI實現的程式碼。
4、非常充分的文件 官方網站有兩百多頁的文件。
5、自動重新載入配置檔案，當配置檔案修改了，Logback-classic能自動重新載入配置檔案。掃描過程快且安全，它並不需要另外建立一個掃描執行緒。這個技術充分保證了應用程式能跑得很歡在JEE環境裡面。
6、Lilith是log事件的觀察者，和log4j的chainsaw類似。而lilith還能處理大數量的log資料 。
7、謹慎的模式和非常友好的恢復，在謹慎模式下，多個FileAppender例項跑在多個JVM下，能 夠安全地寫道同一個日誌檔案。RollingFileAppender會有些限制。Logback的FileAppender和它的子類包括 RollingFileAppender能夠非常友好地從I/O異常中恢復。
8、配置檔案可以處理不同的情況，開發人員經常需要判斷不同的Logback配置檔案在不同的環境下（開發，測試，生產）。而這些配置檔案僅僅只有一些很小的不同，可以通過,和來實現，這樣一個配置檔案就可以適應多個環境。
9、Filters（過濾器）有些時候，需要診斷一個問題，需要打出日誌。在log4j，只有降低日誌級別，不過這樣會打出大量的日誌，會影響應用效能。在Logback，你可以繼續 保持那個日誌級別而除掉某種特殊情況，如alice這個使用者登入，她的日誌將打在DEBUG級別而其他使用者可以繼續打在WARN級別。要實現這個功能只需加4行XML配置。可以參考MDCFIlter。
10、SiftingAppender（一個非常多功能的Appender）：它可以用來分割日誌檔案根據任何一個給定的執行引數。如，SiftingAppender能夠區別日誌事件跟進使用者的Session，然後每個使用者會有一個日誌檔案。
11、自動壓縮已經打出來的log：RollingFileAppender在產生新檔案的時候，會自動壓縮已經打出來的日誌檔案。壓縮是個非同步過程，所以甚至對於大的日誌檔案，在壓縮過程中應用不會受任何影響。
12、堆疊樹帶有包版本：Logback在打出堆疊樹日誌時，會帶上包的資料。
13、自動去除舊的日誌檔案：通過設定TimeBasedRollingPolicy或者SizeAndTimeBasedFNATP的maxHistory屬性，你可以控制已經產生日誌檔案的最大數量。如果設定maxHistory 12，那那些log檔案超過12個月的都會被自動移除。

LogBack的結構

LogBack被分為3個元件，logback-core, logback-classic 和 logback-access。

logback-core提供了LogBack的核心功能，是另外兩個元件的基礎。

logback-classic則實現了Slf4j的API，所以當想配合Slf4j使用時，需要將logback-classic加入classpath。

logback-access是為了整合Servlet環境而準備的，可提供HTTP-access的日誌介面。

配置詳解

Github 程式碼

程式碼我已放到 Github ，匯入spring-boot-logback 專案

github spring-boot-logback

Maven依賴

假如maven依賴中新增了spring-boot-starter-logging：

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-logging</artifactId>
</dependency>
複製程式碼

那麼，我們的Spring Boot應用將自動使用logback作為應用日誌框架，Spring Boot啟動的時候，由org.springframework.boot.logging.Logging-Application-Listener根據情況初始化並使用。

但是呢，實際開發中我們不需要直接新增該依賴，你會發現spring-boot-starter其中包含了 spring-boot-starter-logging，該依賴內容就是 Spring Boot 預設的日誌框架 logback

依賴關係

配置檔案

配置檔案 logback-spring.xml

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

    <!-- 日誌根目錄-->
    <springProperty scope="context" name="LOG_HOME" source="logging.path" defaultValue="/data/logs/spring-boot-logback"/>

    <!-- 日誌級別 -->
    <springProperty scope="context" name="LOG_ROOT_LEVEL" source="logging.level.root" defaultValue="DEBUG"/>

    <!--  標識這個"STDOUT" 將會新增到這個logger -->
    <springProperty scope="context" name="STDOUT" source="log.stdout" defaultValue="STDOUT"/>

    <!-- 日誌檔名稱-->
    <property name="LOG_PREFIX" value="spring-boot-logback" />

    <!-- 日誌檔案編碼-->
    <property name="LOG_CHARSET" value="UTF-8" />

    <!-- 日誌檔案路徑+日期-->
    <property name="LOG_DIR" value="${LOG_HOME}/%d{yyyyMMdd}" />

    <!--對日誌進行格式化-->
    <property name="LOG_MSG" value="- | [%X{requestUUID}] | [%d{yyyyMMdd HH:mm:ss.SSS}] | [%level] | [${HOSTNAME}] | [%thread] | [%logger{36}] | --> %msg|%n "/>

    <!--檔案大小，預設10MB-->
    <property name="MAX_FILE_SIZE" value="50MB" />

    <!-- 配置日誌的滾動時間 ，表示只保留最近 10 天的日誌-->
    <property name="MAX_HISTORY" value="10"/>

    <!--輸出到控制檯-->
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <!-- 輸出的日誌內容格式化-->
        <layout class="ch.qos.logback.classic.PatternLayout">
            <pattern>${LOG_MSG}</pattern>
        </layout>
    </appender>

    <!--輸出到檔案-->
    <appender name="0" class="ch.qos.logback.core.rolling.RollingFileAppender">
    </appender>

    <!-- 定義 ALL 日誌的輸出方式:-->
    <appender name="FILE_ALL" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!--日誌檔案路徑，日誌檔名稱-->
        <File>${LOG_HOME}/all_${LOG_PREFIX}.log</File>

        <!-- 設定滾動策略，當天的日誌大小超過 ${MAX_FILE_SIZE} 檔案大小時候，新的內容寫入新的檔案， 預設10MB -->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">

            <!--日誌檔案路徑，新的 ALL 日誌檔名稱，“ i ” 是個變數 -->
            <FileNamePattern>${LOG_DIR}/all_${LOG_PREFIX}%i.log</FileNamePattern>

            <!-- 配置日誌的滾動時間 ，表示只保留最近 10 天的日誌-->
            <MaxHistory>${MAX_HISTORY}</MaxHistory>

            <!--當天的日誌大小超過 ${MAX_FILE_SIZE} 檔案大小時候，新的內容寫入新的檔案， 預設10MB-->
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>${MAX_FILE_SIZE}</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>

        </rollingPolicy>

        <!-- 輸出的日誌內容格式化-->
        <layout class="ch.qos.logback.classic.PatternLayout">
            <pattern>${LOG_MSG}</pattern>
        </layout>
    </appender>

    <!-- 定義 ERROR 日誌的輸出方式:-->
    <appender name="FILE_ERROR" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!-- 下面為配置只輸出error級別的日誌 -->
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>ERROR</level>
            <OnMismatch>DENY</OnMismatch>
            <OnMatch>ACCEPT</OnMatch>
        </filter>
        <!--日誌檔案路徑，日誌檔名稱-->
        <File>${LOG_HOME}/err_${LOG_PREFIX}.log</File>

        <!-- 設定滾動策略，當天的日誌大小超過 ${MAX_FILE_SIZE} 檔案大小時候，新的內容寫入新的檔案， 預設10MB -->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">

            <!--日誌檔案路徑，新的 ERR 日誌檔名稱，“ i ” 是個變數 -->
            <FileNamePattern>${LOG_DIR}/err_${LOG_PREFIX}%i.log</FileNamePattern>

            <!-- 配置日誌的滾動時間 ，表示只保留最近 10 天的日誌-->
            <MaxHistory>${MAX_HISTORY}</MaxHistory>

            <!--當天的日誌大小超過 ${MAX_FILE_SIZE} 檔案大小時候，新的內容寫入新的檔案， 預設10MB-->
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>${MAX_FILE_SIZE}</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
        </rollingPolicy>

        <!-- 輸出的日誌內容格式化-->
        <layout class="ch.qos.logback.classic.PatternLayout">
            <Pattern>${LOG_MSG}</Pattern>
        </layout>
    </appender>

    <!-- additivity 設為false,則logger內容不附加至root ，配置以配置包下的所有類的日誌的列印，級別是 ERROR-->

    <logger name="org.springframework"     level="ERROR" />
    <logger name="org.apache.commons"      level="ERROR" />
    <logger name="org.apache.zookeeper"    level="ERROR"  />
    <logger name="com.alibaba.dubbo.monitor" level="ERROR"/>
    <logger name="com.alibaba.dubbo.remoting" level="ERROR" />

    <!-- ${LOG_ROOT_LEVEL} 日誌級別 -->
    <root level="${LOG_ROOT_LEVEL}">

        <!-- 標識這個"${STDOUT}"將會新增到這個logger -->
        <appender-ref ref="${STDOUT}"/>

        <!-- FILE_ALL 日誌輸出新增到 logger -->
        <appender-ref ref="FILE_ALL"/>

        <!-- FILE_ERROR 日誌輸出新增到 logger -->
        <appender-ref ref="FILE_ERROR"/>
    </root>

</configuration>
複製程式碼

配置檔案 application.properties

#日誌級別從低到高分為TRACE < DEBUG < INFO < WARN < ERROR < FATAL，如果設定為WARN，則低於WARN的資訊都不會輸出
logging.level.root=trace

logging.path=/data/logs/spring-boot-logback
複製程式碼

節點介紹

這裡參考，嘟嘟獨立部落格，和 Albin 的文章

Spring Boot乾貨系列：（七）預設日誌logback配置解析

logback節點配置詳解

日誌會每天新建一個資料夾，日文檔案配置的每50兆，一個文字檔案，超過新寫入一個

資料夾：20171031
資料夾內容：all_spring-boot-logback0.log 
資料夾內容：all_spring-boot-logback1.log
資料夾內容：all_spring-boot-logback2.log

資料夾內容：err_spring-boot-logback0.log
複製程式碼

MDC requestUUID

一種多執行緒下日誌管理實踐方式

logback MDC(Mapped Diagnostic Context)與分散式系統的跟蹤系統

Slf4j MDC 使用和 基於 Logback 的實現分析

MDC介紹 -- 一種多執行緒下日誌管理實踐方式

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

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

MDC 可以看成是一個與當前執行緒繫結的雜湊表，可以往其中新增鍵值對。MDC 中包含的內容可以被同一執行緒中執行的程式碼所訪問。當前執行緒的子執行緒會繼承其父執行緒中的 MDC 的內容。當需要記錄日誌時，只需要從 MDC 中獲取所需的資訊即可。MDC 的內容則由程式在適當的時候儲存進去。對於一個 Web 應用來說，通常是在請求被處理的最開始儲存這些資料。

自定義攔截器 logback requestUUID

/**
 * 描述: 自定義攔截器 logback requestUUID
 *
 * @author yanpenglei
 * @create 2017-10-30 16:15
 **/

public class ControllerInterceptor extends HandlerInterceptorAdapter {

    private Logger LOGGER = LoggerFactory.getLogger(ControllerInterceptor.class);

    //在請求處理之前回撥方法
    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {

        String requestUUID = MDC.get("requestUUID");
        if (requestUUID == null || "".equals(requestUUID)) {
            String uuid = UUID.randomUUID().toString();
            uuid = uuid.replaceAll("-", "").toUpperCase();
            MDC.put("requestUUID", uuid);
            LOGGER.info("ControllerInterceptor preHandle 在請求處理之前生成 logback requestUUID:{}", uuid);
        }

        return true;// 只有返回true才會繼續向下執行，返回false取消當前請求
    }

    //請求處理之後回撥方法
    @Override
    public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) throws Exception {
        /* 執行緒結束後需要清除,否則當前執行緒會一直佔用這個requestId值 */
        MDC.remove("requestUUID");
        LOGGER.info("ControllerInterceptor postHandle 請求處理之後清除 logback MDC requestUUID");
    }

    //整個請求處理完畢回撥方法
    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {
        /*整個請求執行緒結束後需要清除,否則當前執行緒會一直佔用這個requestId值 */
        MDC.clear();
        LOGGER.info("ControllerInterceptor afterCompletion 整個請求處理完畢清除 logback MDC requestUUID");
    }
}
複製程式碼

對日誌進行格式化,時候用到

<property name="LOG_MSG" value="- | [%X{requestUUID}] | [%d{yyyyMMdd HH:mm:ss.SSS}] | [%level] | [${HOSTNAME}] | [%thread] | [%logger{36}] | --> %msg|%n "/>
複製程式碼
/**
 * 描述:攔截器配置
 *
 * @author yanpenglei
 * @create 2017-10-30 16:54
 **/
@Configuration
public class MyWebMvcConfigurer extends WebMvcConfigurerAdapter {

    @Override
    public void addInterceptors(InterceptorRegistry registry) {

        /**
         * 多個攔截器組成一個攔截器鏈
         * addPathPatterns 用於新增攔截規則
         * excludePathPatterns 用於排除攔截
         */
        registry.addInterceptor(new ControllerInterceptor()).addPathPatterns("/**");
        super.addInterceptors(registry);
    }
}
複製程式碼

日誌切面

@Aspect
@Component
public class LogAspect {

    private static final Logger log = LoggerFactory.getLogger(LogAspect.class);
    private static final String dateFormat = "yyyy-MM-dd HH:mm:ss";
    private static final String STRING_START = "\n>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>\n";
    private static final String STRING_END   = "\n<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<\n";

    @Pointcut("execution(* io.ymq.logback.controller..*(..))")
    public void serviceLog() {
    }

    @Around("serviceLog()")
    public Object around(ProceedingJoinPoint joinPoint) {
        try {
            MethodSignature signature = (MethodSignature) joinPoint.getSignature();
            Method method = signature.getMethod();
            Class<?> targetClass = method.getDeclaringClass();

            StringBuffer classAndMethod = new StringBuffer();

            Log classAnnotation = targetClass.getAnnotation(Log.class);
            Log methodAnnotation = method.getAnnotation(Log.class);

            if (classAnnotation != null) {
                if (classAnnotation.ignore()) {
                    return joinPoint.proceed();
                }
                classAndMethod.append(classAnnotation.value()).append("-");
            }

            if (methodAnnotation != null) {
                if (methodAnnotation.ignore()) {
                    return joinPoint.proceed();
                }
                classAndMethod.append(methodAnnotation.value());
            }

            String target = targetClass.getName() + "#" + method.getName();
            String params = JSONObject.toJSONStringWithDateFormat(joinPoint.getArgs(), dateFormat, SerializerFeature.WriteMapNullValue);

            log.info(STRING_START + "{} 開始呼叫--> {} 引數:{}", classAndMethod.toString(), target, params);

            long start = System.currentTimeMillis();
            Object result = joinPoint.proceed();
            long timeConsuming = System.currentTimeMillis() - start;

            log.info("\n{} 呼叫結束<-- {} 返回值:{} 耗時:{}ms" + STRING_END, classAndMethod.toString(), target, JSONObject.toJSONStringWithDateFormat(result, dateFormat, SerializerFeature.WriteMapNullValue), timeConsuming);
            return result;
        } catch (Throwable throwable) {
            log.error(throwable.getMessage(), throwable);
        }
        return null;
    }

}
複製程式碼

測試 logback

瀏覽器訪問：http://127.0.0.1:8080/index/?content="我是測試內容"

@RestController
@RequestMapping(value = "/index")
public class IndexController {

    private final Logger LOGGER = LoggerFactory.getLogger(this.getClass());

    /**
     * http://127.0.0.1:8080/index/?content="我是測試內容"
     *
     * @param content
     * @return
     */
    @Log("首頁IndexController")
    @RequestMapping(value="", method= RequestMethod.GET)
    public String index(@RequestParam String content) {
        LocalDateTime localDateTime = LocalDateTime.now();

        LOGGER.trace("請求引數：content:{}", content);
        LOGGER.debug("請求引數：content:{}", content);
        LOGGER.info("請求引數：content:{}", content);
        LOGGER.warn("請求引數：content:{}", content);
        LOGGER.error("請求引數：content:{}", content);

        return localDateTime + ",content:" + content;
    }
}
複製程式碼

前面的07E94BA525CF4C97851E4B9E4ABB4890 就是通過logback 的 MDC 做到的

首頁IndexController 開始呼叫--> io.ymq.logback.controller.IndexController#index 引數:["\"我是測試內容\""]|
- | [07E94BA525CF4C97851E4B9E4ABB4890] | [20171101 10:02:35.589] | [DEBUG] | [DESKTOP-VG43S0C] | [http-nio-8080-exec-1] | [i.y.l.controller.IndexController] | --> 請求引數：content:"我是測試內容"|
- | [07E94BA525CF4C97851E4B9E4ABB4890] | [20171101 10:02:35.589] | [INFO] | [DESKTOP-VG43S0C] | [http-nio-8080-exec-1] | [i.y.l.controller.IndexController] | --> 請求引數：content:"我是測試內容"|
- | [07E94BA525CF4C97851E4B9E4ABB4890] | [20171101 10:02:35.589] | [WARN] | [DESKTOP-VG43S0C] | [http-nio-8080-exec-1] | [i.y.l.controller.IndexController] | --> 請求引數：content:"我是測試內容"|
- | [07E94BA525CF4C97851E4B9E4ABB4890] | [20171101 10:02:35.590] | [ERROR] | [DESKTOP-VG43S0C] | [http-nio-8080-exec-1] | [i.y.l.controller.IndexController] | --> 請求引數：content:"我是測試內容"|
- | [07E94BA525CF4C97851E4B9E4ABB4890] | [20171101 10:02:35.606] | [INFO] | [DESKTOP-VG43S0C] | [http-nio-8080-exec-1] | [i.y.logback.config.commons.LogAspect] | --> 
首頁IndexController 呼叫結束<-- io.ymq.logback.controller.IndexController#index 返回值:"2017-11-01T10:02:35.589,content:\"我是測試內容\"" 耗時:23ms
複製程式碼

從上圖可以看到，日誌輸出內容元素具體如下：

requestUUID：一次請求是唯一的
時間日期：精確到毫秒
日誌級別：ERROR, WARN, INFO, DEBUG or TRACE
主機名：
程式ID：
類路徑：
分隔符： --> 標識實際日誌的開始
日誌內容：

日誌切面的響應：

首頁IndexController 開始呼叫--> io.ymq.logback.controller.IndexController#index 引數:["\"我是測試內容\""]|
首頁IndexController 呼叫結束<-- io.ymq.logback.controller.IndexController#index 返回值:"2017-11-01T10:02:35.589,content:\"我是測試內容\"" 耗時:23ms
複製程式碼

程式碼我已放到 Github ，匯入spring-boot-logback 專案

github spring-boot-logback

slf4j-logback 日誌以json格式匯入ELK

Contact

  • 作者：鵬磊
  • 出處：www.ymq.io
  • Email：admin@souyunku.com
  • 版權歸作者所有，轉載請註明出處
  • Wechat：關注公眾號，搜雲庫，專注於開發技術的研究與知識分享

關注公眾號-搜雲庫
搜雲庫

相關文章