SpringBoot 2.5.5整合輕量級的分散式紀錄檔標記追蹤神器TLog

2022-10-19 06:01:02

TLog能解決什麼痛點

  隨著微服務盛行,很多公司都把系統按照業務邊界拆成了很多微服務,在排錯查紀錄檔的時候。因為業務鏈路貫穿著很多微服務節點,導致定位某個請求的紀錄檔以及上下游業務的紀錄檔會變得有些困難。

  這時候很多童鞋會開始考慮上SkyWalking,Pinpoint等分散式追蹤系統來解決,基於OpenTracing規範,而且通常都是無侵入性的,並且有相對友好的管理介面來進行鏈路Span的查詢。

但是搭建分散式追蹤系統,熟悉以及推廣到全公司的系統需要一定的時間週期,而且當中涉及到鏈路span節點的儲存成本問題,全量採集還是部分採集?如果全量採集,就以SkyWalking的儲存來舉例,ES叢集搭建至少需要5個節點。這就需要增加伺服器成本。況且如果微服務節點多的話,一天下來產生幾十G上百G的資料其實非常正常。如果想儲存時間長點的話,也需要增加伺服器磁碟的成本。

當然分散式追蹤系統是一個最終的解決方案,如果您的公司已經上了分散式追蹤系統,那TLog並不適用。

專案整合

專案結構

新增依賴

        <!-- 引入全量tlog依賴 -->
        <dependency>
            <groupId>com.yomahub</groupId>
            <artifactId>tlog-all-spring-boot-starter</artifactId>
            <version>1.5.0</version>
        </dependency>

logback-spring.xml

<?xml version="1.0" encoding="UTF-8"?>
<!-- 紀錄檔級別從低到高分為TRACE < DEBUG < INFO < WARN < ERROR < FATAL,如果設定為WARN,則低於WARN的資訊都不會輸出 -->
<!-- scan:當此屬性設定為true時,組態檔如果發生改變,將會被重新載入,預設值為true -->
<!-- scanPeriod:設定監測組態檔是否有修改的時間間隔,如果沒有給出時間單位,預設單位是毫秒。當scan為true時,此屬性生效。預設的時間間隔為1分鐘。 -->
<!-- debug:當此屬性設定為true時,將列印出logback內部紀錄檔資訊,實時檢視logback執行狀態。預設值為false。 -->
<configuration  scan="true" scanPeriod="10 seconds">

    <contextName>logback</contextName>
    <!-- name的值是變數的名稱,value的值時變數定義的值。通過定義的值會被插入到logger上下文中。定義變數後,可以使「${}」來使用變數。 -->
    <property name="log.path" value="applog/" />
    <property name="log.name" value="springboot-tlog"/>
    <property name="CONSOLE_LOG_PATTERN_FILE" value="%d{yyyy-MM-dd HH:mm:ss.SSS} %C:%M:%L [%thread] %-5level %msg%n"/>

    <!-- 彩色紀錄檔 -->
    <!-- 彩色紀錄檔依賴的渲染類 -->
    <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{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}}"/>

    <!--輸出到控制檯-->
    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <!--此紀錄檔appender是為開發使用,只設定最底級別,控制檯輸出的紀錄檔級別是大於或等於此級別的紀錄檔資訊-->
<!--        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">-->
<!--            <level>info</level>-->
<!--        </filter>-->
        <encoder class="com.yomahub.tlog.core.enhance.logback.AspectLogbackEncoder">
            <Pattern>${CONSOLE_LOG_PATTERN}</Pattern>
            <!-- 設定字元集 -->
            <charset>UTF-8</charset>
        </encoder>
    </appender>


    <!--輸出到檔案-->
    <!-- 時間捲動輸出 level為 INFO 紀錄檔 -->
    <appender name="INFO_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!-- 正在記錄的紀錄檔檔案的路徑及檔名 -->
        <file>${log.path}/${log.name}/${log.name}_info.log</file>
        <!--紀錄檔檔案輸出格式-->
        <encoder class="com.yomahub.tlog.core.enhance.logback.AspectLogbackEncoder">
            <pattern>${CONSOLE_LOG_PATTERN_FILE}</pattern>
            <charset>UTF-8</charset>
        </encoder>
        <!-- 紀錄檔記錄器的捲動策略,按日期,按大小記錄 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- 每天紀錄檔歸檔路徑以及格式 -->
            <fileNamePattern>${log.path}/${log.name}/info/${log.name}-info-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <!--紀錄檔檔案保留天數-->
            <maxHistory>180</maxHistory>
        </rollingPolicy>
        <!-- 此紀錄檔檔案只記錄info級別的 -->
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>info</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
    </appender>

    <!-- 時間捲動輸出 level為 ERROR 紀錄檔 -->
    <appender name="ERROR_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!-- 正在記錄的紀錄檔檔案的路徑及檔名 -->
        <file>${log.path}/${log.name}/${log.name}_error.log</file>
        <!--紀錄檔檔案輸出格式-->
        <encoder class="com.yomahub.tlog.core.enhance.logback.AspectLogbackEncoder">
            <pattern>${CONSOLE_LOG_PATTERN_FILE}</pattern>
            <charset>UTF-8</charset> <!-- 此處設定字元集 -->
        </encoder>
        <!-- 紀錄檔記錄器的捲動策略,按日期,按大小記錄 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${log.path}/${log.name}/error/${log.name}-error-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <!--紀錄檔檔案保留天數-->
            <maxHistory>180</maxHistory>
        </rollingPolicy>
        <!-- 此紀錄檔檔案只記錄ERROR級別的 -->
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>ERROR</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
    </appender>

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

    <!-- sql列印 -->
<!--    <logger name="com.ybchen.mapper" level="DEBUG"/>-->
</configuration>

請求類

package com.ybchen.request;

import lombok.Data;

/**
 * @author: chenyanbin 2022-10-18 23:03
 */
@Data
public class PersonRequest {
    private Long id;
    private Long age;
    private String name;
}

Controller

package com.ybchen.controller;

import com.ybchen.request.PersonRequest;
import com.yomahub.tlog.core.annotation.TLogAspect;
import lombok.extern.slf4j.Slf4j;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;

/**
 * @author: chenyanbin 2022-10-18 22:56
 */
@RestController
@Slf4j
public class DemoController {
    @TLogAspect({"id"})
    @GetMapping("demo1")
    public void demo1(String id, String name) {
        log.info("這是第一條紀錄檔---->簡單例子");
        log.info("這是第二條紀錄檔---->簡單例子");
        log.info("這是第三條紀錄檔---->簡單例子");
        new Thread(() -> log.info("這是非同步紀錄檔---->簡單例子")).start();
    }

    @TLogAspect({"id", "name"})
    @GetMapping("demo2")
    public void demo2(String id, String name) {
        log.info("這是第一條紀錄檔----->多個數值");
        log.info("這是第二條紀錄檔----->多個數值");
        log.info("這是第三條紀錄檔----->多個數值");
        new Thread(() -> log.info("這是非同步紀錄檔----->多個數值")).start();
    }

    @TLogAspect(value = {"id", "name"}, pattern = "<-{}->", joint = "_")
    @GetMapping("demo3")
    public void demo3(String id, String name) {
        log.info("多個數值-------->加了patter和joint的範例");
    }

    @TLogAspect(str = "陳彥斌部落格地址:https://www.cnblogs.com/chenyanbin/")
    @GetMapping("demo4")
    public void demo4(String name){
        log.info("這是第一條紀錄檔----->常數字串標籤");
        log.info("這是第二條紀錄檔----->常數字串標籤");
        log.info("這是第三條紀錄檔----->常數字串標籤");
        new Thread(() -> log.info("這是非同步紀錄檔----->常數字串標籤")).start();
    }

    @TLogAspect({"request.id","request.age"})
    @GetMapping("demo5")
    public void demo4(PersonRequest request){
        log.info("多引數加多層級範例");
    }
}

SpanId的生成規則

 

 TLog業務標籤

  很多公司的系統在打紀錄檔的時候,每打一個紀錄檔裡都會帶入一些業務資訊,比如記錄ID,會員CODE,方便業務紀錄檔的定位。現在有了TLog,不僅能做分散式鏈路標籤追加,還能自動幫你做業務標籤的新增。這樣在定位紀錄檔的時候可以更加方便的搜尋。

  Tlog支援方法級別的自定義業務標籤。你可以在方法上定義簡單的標註,來實現在某一個方法的紀錄檔裡,統一加入業務的指標標籤,用於更加細緻的定位。

演示

範例1

    @TLogAspect({"id"})
    @GetMapping("demo1")
    public void demo1(String id, String name) {
        log.info("這是第一條紀錄檔---->簡單例子");
        log.info("這是第二條紀錄檔---->簡單例子");
        log.info("這是第三條紀錄檔---->簡單例子");
        new Thread(() -> log.info("這是非同步紀錄檔---->簡單例子")).start();
    }

 

2022-10-18 23:14:37.450  INFO 88321 --- [nio-8080-exec-4] com.ybchen.controller.DemoController     : <0><11477324755760832> [id:"10086"] 這是第一條紀錄檔---->簡單例子
2022-10-18 23:14:37.451  INFO 88321 --- [nio-8080-exec-4] com.ybchen.controller.DemoController     : <0><11477324755760832> [id:"10086"] 這是第二條紀錄檔---->簡單例子
2022-10-18 23:14:37.451  INFO 88321 --- [nio-8080-exec-4] com.ybchen.controller.DemoController     : <0><11477324755760832> [id:"10086"] 這是第三條紀錄檔---->簡單例子
2022-10-18 23:14:37.452  INFO 88321 --- [      Thread-12] com.ybchen.controller.DemoController     : <0><11477324755760832> [id:"10086"] 這是非同步紀錄檔---->簡單例子
2022-10-18 23:14:41.160  INFO 88321 --- [nio-8080-exec-5] com.ybchen.controller.DemoController     : <0><11477324998899392> [id:"10087"] 這是第一條紀錄檔---->簡單例子
2022-10-18 23:14:41.160  INFO 88321 --- [nio-8080-exec-5] com.ybchen.controller.DemoController     : <0><11477324998899392> [id:"10087"] 這是第二條紀錄檔---->簡單例子
2022-10-18 23:14:41.160  INFO 88321 --- [nio-8080-exec-5] com.ybchen.controller.DemoController     : <0><11477324998899392> [id:"10087"] 這是第三條紀錄檔---->簡單例子
2022-10-18 23:14:41.161  INFO 88321 --- [      Thread-13] com.ybchen.controller.DemoController     : <0><11477324998899392> [id:"10087"] 這是非同步紀錄檔---->簡單例子
2022-10-18 23:14:43.938  INFO 88321 --- [nio-8080-exec-6] com.ybchen.controller.DemoController     : <0><11477325181023936> [id:"10085"] 這是第一條紀錄檔---->簡單例子
2022-10-18 23:14:43.939  INFO 88321 --- [nio-8080-exec-6] com.ybchen.controller.DemoController     : <0><11477325181023936> [id:"10085"] 這是第二條紀錄檔---->簡單例子
2022-10-18 23:14:43.939  INFO 88321 --- [nio-8080-exec-6] com.ybchen.controller.DemoController     : <0><11477325181023936> [id:"10085"] 這是第三條紀錄檔---->簡單例子
2022-10-18 23:14:43.940  INFO 88321 --- [      Thread-14] com.ybchen.controller.DemoController     : <0><11477325181023936> [id:"10085"] 這是非同步紀錄檔---->簡單例子

範例二

    @TLogAspect({"id", "name"})
    @GetMapping("demo2")
    public void demo2(String id, String name) {
        log.info("這是第一條紀錄檔----->多個數值");
        log.info("這是第二條紀錄檔----->多個數值");
        log.info("這是第三條紀錄檔----->多個數值");
        new Thread(() -> log.info("這是非同步紀錄檔----->多個數值")).start();
    }
2022-10-18 23:22:33.941  INFO 88321 --- [nio-8080-exec-8] com.ybchen.controller.DemoController     : <0><11477355982223040> [id:"10085",name:"alex"] 這是第一條紀錄檔----->多個數值
2022-10-18 23:22:33.946  INFO 88321 --- [nio-8080-exec-8] com.ybchen.controller.DemoController     : <0><11477355982223040> [id:"10085",name:"alex"] 這是第二條紀錄檔----->多個數值
2022-10-18 23:22:33.947  INFO 88321 --- [nio-8080-exec-8] com.ybchen.controller.DemoController     : <0><11477355982223040> [id:"10085",name:"alex"] 這是第三條紀錄檔----->多個數值
2022-10-18 23:22:33.950  INFO 88321 --- [      Thread-15] com.ybchen.controller.DemoController     : <0><11477355982223040> [id:"10085",name:"alex"] 這是非同步紀錄檔----->多個數值
2022-10-18 23:22:37.744  INFO 88321 --- [nio-8080-exec-9] com.ybchen.controller.DemoController     : <0><11477356232308416> [id:"10086",name:"alex"] 這是第一條紀錄檔----->多個數值
2022-10-18 23:22:37.744  INFO 88321 --- [nio-8080-exec-9] com.ybchen.controller.DemoController     : <0><11477356232308416> [id:"10086",name:"alex"] 這是第二條紀錄檔----->多個數值
2022-10-18 23:22:37.744  INFO 88321 --- [nio-8080-exec-9] com.ybchen.controller.DemoController     : <0><11477356232308416> [id:"10086",name:"alex"] 這是第三條紀錄檔----->多個數值
2022-10-18 23:22:37.745  INFO 88321 --- [      Thread-16] com.ybchen.controller.DemoController     : <0><11477356232308416> [id:"10086",name:"alex"] 這是非同步紀錄檔----->多個數值

範例三

    @TLogAspect(value = {"id", "name"}, pattern = "<-{}->", joint = "_")
    @GetMapping("demo3")
    public void demo3(String id, String name) {
        log.info("多個數值-------->加了patter和joint的範例");
    }
2022-10-18 23:24:52.137  INFO 88321 --- [nio-8080-exec-1] com.ybchen.controller.DemoController     : <0><11477365039888064> <-id:"10086"_name:"alex"-> 多個數值-------->加了patter和joint的範例
2022-10-18 23:24:56.329  INFO 88321 --- [nio-8080-exec-2] com.ybchen.controller.DemoController     : <0><11477365314614976> <-id:"10089"_name:"alex"-> 多個數值-------->加了patter和joint的範例

範例四

    @TLogAspect(str = "陳彥斌部落格地址:https://www.cnblogs.com/chenyanbin/")
    @GetMapping("demo4")
    public void demo4(String name){
        log.info("這是第一條紀錄檔----->常數字串標籤");
        log.info("這是第二條紀錄檔----->常數字串標籤");
        log.info("這是第三條紀錄檔----->常數字串標籤");
        new Thread(() -> log.info("這是非同步紀錄檔----->常數字串標籤")).start();
    }
2022-10-18 23:29:25.801  INFO 10245 --- [nio-8080-exec-4] com.ybchen.controller.DemoController     : <0><11477382974797504> [陳彥斌部落格地址:https://www.cnblogs.com/chenyanbin/] 這是第一條紀錄檔----->常數字串標籤
2022-10-18 23:29:25.802  INFO 10245 --- [nio-8080-exec-4] com.ybchen.controller.DemoController     : <0><11477382974797504> [陳彥斌部落格地址:https://www.cnblogs.com/chenyanbin/] 這是第二條紀錄檔----->常數字串標籤
2022-10-18 23:29:25.802  INFO 10245 --- [nio-8080-exec-4] com.ybchen.controller.DemoController     : <0><11477382974797504> [陳彥斌部落格地址:https://www.cnblogs.com/chenyanbin/] 這是第三條紀錄檔----->常數字串標籤
2022-10-18 23:29:25.803  INFO 10245 --- [       Thread-8] com.ybchen.controller.DemoController     : <0><11477382974797504> [陳彥斌部落格地址:https://www.cnblogs.com/chenyanbin/] 這是非同步紀錄檔----->常數字串標籤
2022-10-18 23:29:30.216  INFO 10245 --- [nio-8080-exec-5] com.ybchen.controller.DemoController     : <0><11477383264138944> [陳彥斌部落格地址:https://www.cnblogs.com/chenyanbin/] 這是第一條紀錄檔----->常數字串標籤
2022-10-18 23:29:30.217  INFO 10245 --- [nio-8080-exec-5] com.ybchen.controller.DemoController     : <0><11477383264138944> [陳彥斌部落格地址:https://www.cnblogs.com/chenyanbin/] 這是第二條紀錄檔----->常數字串標籤
2022-10-18 23:29:30.217  INFO 10245 --- [nio-8080-exec-5] com.ybchen.controller.DemoController     : <0><11477383264138944> [陳彥斌部落格地址:https://www.cnblogs.com/chenyanbin/] 這是第三條紀錄檔----->常數字串標籤
2022-10-18 23:29:30.218  INFO 10245 --- [       Thread-9] com.ybchen.controller.DemoController     : <0><11477383264138944> [陳彥斌部落格地址:https://www.cnblogs.com/chenyanbin/] 這是非同步紀錄檔----->常數字串標籤

範例五

@TLogAspect支援點操作符,適用於物件的取值,支援型別:

  • Bean物件
  • Map物件
  • Json格式的字串
  • Fastjson的JSONObject物件

    @TLogAspect({"request.id","request.age"})
    @GetMapping("demo5")
    public void demo4(PersonRequest request){

        log.info("多引數加多層級範例");
    }



================



@Data
public class PersonRequest {
    private Long id;
    private Long age;
    private String name;
}
2022-10-18 23:32:58.761  INFO 14747 --- [nio-8080-exec-2] com.ybchen.controller.DemoController     : <0><11477396931212992> [request.id:10089,request.age:27] 多引數加多層級範例
2022-10-18 23:33:03.289  INFO 14747 --- [nio-8080-exec-3] com.ybchen.controller.DemoController     : <0><11477397228025536> [request.id:10099,request.age:27] 多引數加多層級範例