Spring Boot 中使用 LogBack 配置

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

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

LogBack、Slf4j和Log4j之間的關係

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

LogBackLog4j都是開源日記工具庫,LogBackLog4j的改良版本,比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、Lilithlog事件的觀察者,和log4jchainsaw類似。而lilith還能處理大數量的log資料 。
7、謹慎的模式和非常友好的恢復,在謹慎模式下,多個FileAppender例項跑在多個JVM下,能 夠安全地寫道同一個日誌檔案。RollingFileAppender會有些限制。LogbackFileAppender和它的子類包括 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-classiclogback-access

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

logback-classic則實現了Slf4jAPI,所以當想配合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:關注公眾號,搜雲庫,專注於開發技術的研究與知識分享

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

相關文章