UP | HOME

Log4j自定义Converter
发布于 Jun 12, 2020 by ThinkCat.

Table of Contents

缘由

新公司的基础框架不是太好用,和前公司比,还是差了不少。由于接手的都是老系统,所有东西,都是用的很久之前的,好多很原生的东西,包括JDBC、reids操作,都是裸操作连接。

前两天还出了一个任务中,使用了JDBC连接,没有归还连接池,导致的bug… ORZ…

其中基础的日志链路追踪,和前公司比,真是差了不少。加上老系统代码比较杂,追踪问题特别麻烦,日志中也很难看到连续的东西。于是打算把TraceId这种东西,加到每个日志里面,方便按每个请求查链路日志。

实现

拿SpringBoot做了一个小demo来验证了一下,代码很简单。

依赖项

首先引入日志依赖:

<dependency>
  <groupId>org.springframework.boot</groupId>
  <artifactId>spring-boot-starter</artifactId>
  <exclusions>
    <!--排除logback-->
    <exclusion>
      <groupId>org.springframework.boot</groupId>
      <artifactId>spring-boot-starter-logging</artifactId>
    </exclusion>
  </exclusions>
</dependency>
<dependency>
  <groupId>org.springframework.boot</groupId>
  <artifactId>spring-boot-starter-log4j2</artifactId>
</dependency>
<dependency>
  <groupId>org.projectlombok</groupId>
  <artifactId>lombok</artifactId>
  <version>1.18.8</version>
  <scope>provided</scope>
</dependency>

由于公司现有用的都是 log4j2 的组件,所以依赖中要排除掉 spring boot 默认用的logback组件,然后引入 log4j2 依赖。另外平时使用 lombok 习惯了,也引入一下。

自定义Converter

代码如下:

package org.example;

import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.config.plugins.Plugin;
import org.apache.logging.log4j.core.pattern.ConverterKeys;
import org.apache.logging.log4j.core.pattern.LogEventPatternConverter;

@Plugin(name = "TradeConverter",category = "Converter")
@ConverterKeys({"traceId"})
public class TraceConverter extends LogEventPatternConverter {
    protected TraceConverter(String name, String style) {
        super(name, style);
    }

    public static TraceConverter newInstance(final String[] options) {
        return new TraceConverter("traceId", "traceId");
    }


    @Override
    public void format(LogEvent logEvent, StringBuilder stringBuilder) {
        stringBuilder.append(getTraceId());
    }

    private String getTraceId(){
        //这里实际从基础框架获取请求的TraceId
        return "TestTraceId";
    }
}

实际还是很简单的,继承 LogEventPatternConverter 就可以了。

配置log4j2.xml

找了一份比较齐全的配置文件:

<?xml version="1.0" encoding="UTF-8"?>
<!--日志级别以及优先级排序: OFF > FATAL > ERROR > WARN > INFO > DEBUG > TRACE > ALL -->
<!--Configuration后面的status,这个用于设置log4j2自身内部的信息输出,可以不设置,当设置成trace时,你会看到log4j2内部各种详细输出-->
<!--monitorInterval:Log4j能够自动检测修改配置 文件和重新配置本身,设置间隔秒数-->
<configuration status="WARN" monitorInterval="30">
    <!--先定义所有的appender-->
    <appenders>
        <!--这个输出控制台的配置-->
        <console name="Console" target="SYSTEM_OUT">
            <!--输出日志的格式-->
            <PatternLayout pattern="[%d{HH:mm:ss:SSS}] [%p] ----[%traceId]  ------ %l - %m%n"/>
        </console>
        <!--文件会打印出所有信息,这个log每次运行程序会自动清空,由append属性决定,这个也挺有用的,适合临时测试用-->
        <File name="log" fileName="log/test.log" append="false">
            <PatternLayout pattern="%d{HH:mm:ss.SSS} %-5level %class{36} %L %M - %msg%xEx%n"/>
        </File>
        <!-- 这个会打印出所有的info及以下级别的信息,每次大小超过size,则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩,作为存档-->
        <RollingFile name="RollingFileInfo" fileName="${sys:user.home}/logs/info.log"
                     filePattern="${sys:user.home}/logs/$${date:yyyy-MM}/info-%d{yyyy-MM-dd}-%i.log">
            <!--控制台只输出level及以上级别的信息(onMatch),其他的直接拒绝(onMismatch)-->
            <ThresholdFilter level="info" onMatch="ACCEPT" onMismatch="DENY"/>
            <PatternLayout pattern="[%d{HH:mm:ss:SSS}] [%p] - %l - %m%n"/>
            <Policies>
                <TimeBasedTriggeringPolicy/>
                <SizeBasedTriggeringPolicy size="100 MB"/>
            </Policies>
        </RollingFile>
        <RollingFile name="RollingFileWarn" fileName="${sys:user.home}/logs/warn.log"
                     filePattern="${sys:user.home}/logs/$${date:yyyy-MM}/warn-%d{yyyy-MM-dd}-%i.log">
            <ThresholdFilter level="warn" onMatch="ACCEPT" onMismatch="DENY"/>
            <PatternLayout pattern="[%d{HH:mm:ss:SSS}] [%p] - %l - %m%n"/>
            <Policies>
                <TimeBasedTriggeringPolicy/>
                <SizeBasedTriggeringPolicy size="100 MB"/>
            </Policies>
            <!-- DefaultRolloverStrategy属性如不设置,则默认为最多同一文件夹下7个文件,这里设置了20 -->
            <DefaultRolloverStrategy max="20"/>
        </RollingFile>
        <RollingFile name="RollingFileError" fileName="${sys:user.home}/logs/error.log"
                     filePattern="${sys:user.home}/logs/$${date:yyyy-MM}/error-%d{yyyy-MM-dd}-%i.log">
            <ThresholdFilter level="error" onMatch="ACCEPT" onMismatch="DENY"/>
            <PatternLayout pattern="[%d{HH:mm:ss:SSS}] [%p] - %l - %m%n"/>
            <Policies>
                <TimeBasedTriggeringPolicy/>
                <SizeBasedTriggeringPolicy size="100 MB"/>
            </Policies>
        </RollingFile>
    </appenders>
    <!--然后定义logger,只有定义了logger并引入的appender,appender才会生效-->
    <loggers>
        <!--过滤掉spring和mybatis的一些无用的DEBUG信息-->
        <logger name="org.springframework" level="INFO"/>
        <logger name="org.mybatis" level="INFO"/>
        <root level="all">
            <appender-ref ref="Console"/>
            <appender-ref ref="RollingFileInfo"/>
            <appender-ref ref="RollingFileWarn"/>
            <appender-ref ref="RollingFileError"/>
        </root>
    </loggers>
</configuration>

重点在于配置的 PatternLayout :

<PatternLayout pattern="[%d{HH:mm:ss:SSS}] [%p] ----[%traceId]  ------ %l - %m%n"/>

测试验证

启动一下,打个日志看看。

package org.example;

import lombok.extern.log4j.Log4j2;
import lombok.extern.slf4j.Slf4j;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;

/**
 * Hello world!
 */
@Log4j2
@SpringBootApplication
public class App {

    public static void main(String[] args) {

        SpringApplication.run(App.class, args);
        log.error("Hello World");
        log.info("Hello World");
    }
}

Console 的输出格式如下:

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.2.7.RELEASE)

[22:04:19:068] [INFO] ----[TestTraceId]  ------ org.springframework.boot.StartupInfoLogger.logStarting(StartupInfoLogger.java:55) - Starting App on HeHe-2.local with PID 25792 ..
[22:04:19:071] [DEBUG] ----[TestTraceId]  ------ org.springframework.boot.StartupInfoLogger.logStarting(StartupInfoLogger.java:56) - Running with Spring Boot v2.2.7.RELEASE, Spring v5.2.6.RELEASE
[22:04:19:072] [INFO] ----[TestTraceId]  ------ org.springframework.boot.SpringApplication.logStartupProfileInfo(SpringApplication.java:651) - No active profile set, falling back to default profiles: default
[22:04:19:423] [INFO] ----[TestTraceId]  ------ org.springframework.boot.StartupInfoLogger.logStarted(StartupInfoLogger.java:61) - Started App in 0.557 seconds (JVM running for 1.165)
[22:04:19:424] [ERROR] ----[TestTraceId]  ------ org.example.App.main(App.java:18) - Hello World
[22:04:19:424] [INFO] ----[TestTraceId]  ------ org.example.App.main(App.java:19) - Hello World

Process finished with exit code 0

已经可以正常输出拿到的 TestTraceId 信息了。至此,完成。