SpringBoot+log4j2+MDC+AOP记录requestId

前言

在AOP切面注入RequestId，拦截Controller、Service方法，打印入参出参耗时等，方便排查问题。

可以在服务上通过RequestId查询一次调用链日志：

 可以使用 Linux grep 命令查询日志：

grep 命令用于查找文件里符合条件的字符串。

日志文件太大无法直接 cat 查看，可以用grep

常用参数：

• -A<显示行数> : 除了显示符合范本样式的那一列之外，并显示该行之后的内容。
• -C<显示行数> : 除了显示符合样式的那一行之外，并显示该行之前后的内容。
• -E  : 将样式为延伸的正则表达式来使用。

eg:

查询 包含 trainSegment/detail 的字符串的前后10行

　　grep -C 10 trainSegment/detail webapi-info-VM-130-116-centos.log

正则

grep -E -C 30 "keyword1.* keyword2.* " webapi-info-VM-130-116-centos.log

 

代码

Controller

/**
 * @author lihaoyang
 * @date 2021/3/17
 */
@RestController
public class HiController {

    @Autowired
    HiServiceImpl hiService;

    @GetMapping("get")
    public String get(String msg) {
        String rs = hiService.getHi(msg);
        return rs;
    }


}

Service

@Service
public class HiServiceImpl {

    public String getHi(String msg) {
        return "service:  >>>>> " + msg;
    }

}

切面类

RequestId切面

@Aspect
@Component
@Slf4j
@Order(-10)
public class ControllerRequestIdAspect {

    @Pointcut("execution(public * com.nb.log.controller..*.*(..))")
    public void controllerPoint() {
    }

    @Around("controllerPoint()")
    public Object doControllerPointAround(ProceedingJoinPoint joinPoint) throws Throwable {
        String requestId = UUID.randomUUID().toString();
        MDC.put("requestId", requestId);
        Object result = null;
        try {
            result = joinPoint.proceed();
        } finally {
            MDC.remove("requestId");
        }
        return result;
    }
}

Controller切面

package com.nb.log.aop;

import com.alibaba.fastjson.JSONObject;
import lombok.extern.slf4j.Slf4j;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;

import javax.servlet.http.HttpServletRequest;
import java.util.Arrays;

/**
 * controller切面
 */
@Aspect
@Slf4j
@Component
@Order(0)
public class ControllerLogAspect {

    @Pointcut("execution(public * com.nb.log.controller..*.*(..))")
    public void controllerPoint() {}

    @Around("controllerPoint()")
    public Object doControllerAround(ProceedingJoinPoint joinPoint) throws Throwable {
        long startTime = System.currentTimeMillis();

        Object result = null;
        try {
            HttpServletRequest request =
                ((ServletRequestAttributes) RequestContextHolder.getRequestAttributes()).getRequest();
            Object[] params = joinPoint.getArgs();
            log.info("Controller层 className={}, methodName={}, params={},url={},ip={}",
                joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName(),
                Arrays.toString(params), request.getRequestURL(), IpUtil.getIpAddr(request));
            result = joinPoint.proceed();
        } finally {
            log.info("Controller层 耗时={}(ms), className={}, methodName={}, result={}",
                System.currentTimeMillis() - startTime, joinPoint.getSignature().getDeclaringTypeName(),
                joinPoint.getSignature().getName(), JSONObject.toJSONString(result));
        }
        return result;
    }
}

Service切面

package com.nb.log.aop;

import lombok.extern.slf4j.Slf4j;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;

import java.util.Arrays;

/**
 * service层切面日志
 */
@Aspect
@Slf4j
@Order(0)
@Component
public class ServiceLogAspect {


    @Pointcut("execution(public * com.nb.log.service..*ServiceImpl.*(..))")
    public void servicePoint() {
    }

    @Around("servicePoint()")
    public Object doServiceAround(ProceedingJoinPoint joinPoint) throws Throwable {
        long startTime = System.currentTimeMillis();
        Object result = null;
        try {
            Object[] params = joinPoint.getArgs();
            log.info("Service层 className={}, methodName={}, params={}", joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName(), Arrays.toString(params));
            result = joinPoint.proceed();
        }
        finally {
            log.info("Service层 耗时={}(ms), className={}, methodName={}", System.currentTimeMillis() - startTime, joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName());
        }
        return result;
    }
}

log4j2.xml

<?xml version="1.0" encoding="UTF-8"?>
<!--设置log4j2的自身log级别为warn-->
<!--日志级别以及优先级排序: OFF > FATAL > ERROR > WARN > INFO > DEBUG > TRACE > ALL -->
<!--Configuration后面的status，这个用于设置log4j2自身内部的信息输出，可以不设置，
    当设置成trace时，你会看到log4j2内部各种详细输出-->
<!--monitorInterval：Log4j能够自动检测修改配置 文件和重新配置本身，设置间隔秒数-->
<configuration status="warn" monitorInterval="30">
    <Properties>
        <property name="log_pattern">%d{yyyy-MM-dd HH:mm:ss.SSS} [%level] -%X{filter} &lt;%t|%C{1.}.%M(%L)&gt; -%X{requestId} %m%n%ex</property>
        <property name="project">remix-collector</property>
        <property name="basePath">D:/log/${project}/</property>
        <!--<property name="basePath">F:\neworiental\www\logs</property>-->
        <property name="rolling_file_name">${basePath}/%d{yyyy-MM-dd}-%i</property>
        <!-- 日志切割的最小单位 -->
        <property name="every_file_size">500 MB</property>
    </Properties>
    <!--先定义所有的appender-->
    <appenders>
        <!--这个输出控制台的配置-->
        <console name="Console" target="SYSTEM_OUT">
            <!--输出日志的格式-->
            <PatternLayout pattern="${log_pattern}"/>
        </console>
        <!--文件会打印出所有信息，这个log每次运行程序会自动清空，由append属性决定，这个也挺有用的，适合临时测试用-->
        <!--      <File name="log" fileName="${sys:user.home}/old_log/test.log" append="false">
                  <PatternLayout pattern="${log_pattern}"/>
              </File>-->
        <!-- 这个会打印出所有的info及以下级别的信息，每次大小超过size，
        则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩，作为存档-->
        <RollingFile name="RollingFile" fileName="${basePath}/${project}-info-${hostName}.log" filePattern="${basePath}/${project}-info-${hostName}-%d{yyyy-MM-dd}-%i.log">
            <Filters>
                <!--控制台只输出level及以上级别的信息（onMatch），其他的直接拒绝（onMismatch）-->
                <ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY"/>
                <ThresholdFilter level="WARN" onMatch="ACCEPT" onMismatch="NEUTRAL"/>
                <ThresholdFilter level="ERROR" onMatch="DENY" onMismatch="NEUTRAL"/>
            </Filters>
            <PatternLayout pattern="${log_pattern}"/>
            <Policies>
                <TimeBasedTriggeringPolicy/>
                <SizeBasedTriggeringPolicy size="${every_file_size}"/>
            </Policies>

            <!-- 最多备份7天以内-->
            <DefaultRolloverStrategy>
                <Delete basePath="${basePath}" maxDepth="1">
                    <IfFileName glob="*.log" />
                    <IfLastModified age="3d">
                        <!-- <IfAny>
                             <IfAccumulatedFileSize exceeds="10 GB" />
                             <IfAccumulatedFileCount exceeds="10" />
                         </IfAny>-->
                    </IfLastModified>
                </Delete>
            </DefaultRolloverStrategy>
        </RollingFile>

        <!--warn-->
        <RollingFile name="RollingFileWarn"
                     fileName="${basePath}/${project}-warn-${hostName}.log"
                     filePattern="${rolling_file_name}-warn-${hostName}-%d{yyyy-MM-dd}-%i.log">
            <Filters>
                <ThresholdFilter level="WARN" onMatch="ACCEPT" onMismatch="DENY"/>
                <ThresholdFilter level="ERROR" onMatch="DENY" onMismatch="NEUTRAL"/>
            </Filters>
            <PatternLayout pattern="${log_pattern}"/>
            <Policies>
                <TimeBasedTriggeringPolicy modulate="true" interval="24"/>
                <SizeBasedTriggeringPolicy/>
            </Policies>
            <!-- DefaultRolloverStrategy属性如不设置，则默认为最多同一文件夹下7个文件，这里设置了20 -->
            <DefaultRolloverStrategy max="20"/>
        </RollingFile>

        <!--Error级别日志输出-->
        <RollingFile name="RollingFileError"
                     fileName="${basePath}/${project}-error-${hostName}.log"
                     filePattern="${rolling_file_name}-error-${hostName}-%d{yyyy-MM-dd}-%i.log">
            <Filters>
                <ThresholdFilter level="ERROR" onMatch="ACCEPT" onMismatch="DENY" />
            </Filters>
            <PatternLayout pattern="${log_pattern}"/>
            <SizeBasedTriggeringPolicy size="${every_file_size}"/>
        </RollingFile>


    </appenders>
    <!--然后定义logger，只有定义了logger并引入的appender，appender才会生效-->
    <loggers>
        <!-- druid日志 -->
        <logger name="druid.sql.Statement" level="debug" additivity="false">
            <AppenderRef ref="Console"/>
            <AppenderRef ref="druidSqlAppender"/>
            <AppenderRef ref="invokeAppender"/>
        </logger>
        <logger name="druid.sql.ResultSet" level="debug" additivity="false">
            <AppenderRef ref="Console"/>
            <AppenderRef ref="druidSqlAppender"/>
            <AppenderRef ref="invokeAppender"/>
        </logger>
        <logger name="com.nb.log.controller" level="INFO">
        </logger>

        <root level="info">
            <appender-ref ref="Console"/>
            <appender-ref ref="RollingFile"/>
            <appender-ref ref="RollingFileWarn"/>
            <appender-ref ref="RollingFileError"/>
        </root>
    </loggers>

</configuration>

maven pom.xml

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 https://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>
    <groupId>com.nb</groupId>
    <artifactId>nb-log</artifactId>
    <version>0.0.1-SNAPSHOT</version>
    <name>nb-log</name>
    <description>Demo project for Spring Boot</description>

    <properties>
        <java.version>1.8</java.version>
        <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
        <project.reporting.outputEncoding>UTF-8</project.reporting.outputEncoding>
        <spring-boot.version>2.3.7.RELEASE</spring-boot.version>
    </properties>

    <dependencies>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-web</artifactId>
        </dependency>

        <!--集成springmvc框架并实现自动配置 -->
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-web</artifactId>
            <exclusions><!-- 去掉springboot默认配置 -->
                <exclusion>
                    <groupId>org.springframework.boot</groupId>
                    <artifactId>spring-boot-starter-logging</artifactId>
                </exclusion>
            </exclusions>
        </dependency>
        <!-- 引入log4j2依赖 -->
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-log4j2</artifactId>
        </dependency>

        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-aop</artifactId>
        </dependency>

        <dependency>
            <groupId>com.alibaba</groupId>
            <artifactId>fastjson</artifactId>
            <version>1.2.75</version>
        </dependency>

        <dependency>
            <groupId>org.projectlombok</groupId>
            <artifactId>lombok</artifactId>
            <version>1.18.18</version>
            <scope>provided</scope>
        </dependency>


        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-test</artifactId>
            <scope>test</scope>
            <exclusions>
                <exclusion>
                    <groupId>org.junit.vintage</groupId>
                    <artifactId>junit-vintage-engine</artifactId>
                </exclusion>
            </exclusions>
        </dependency>
    </dependencies>

    <dependencyManagement>
        <dependencies>
            <dependency>
                <groupId>org.springframework.boot</groupId>
                <artifactId>spring-boot-dependencies</artifactId>
                <version>${spring-boot.version}</version>
                <type>pom</type>
                <scope>import</scope>
            </dependency>
        </dependencies>
    </dependencyManagement>

    <build>
        <plugins>
            <plugin>
                <groupId>org.apache.maven.plugins</groupId>
                <artifactId>maven-compiler-plugin</artifactId>
                <version>3.8.1</version>
                <configuration>
                    <source>1.8</source>
                    <target>1.8</target>
                    <encoding>UTF-8</encoding>
                </configuration>
            </plugin>
            <plugin>
                <groupId>org.springframework.boot</groupId>
                <artifactId>spring-boot-maven-plugin</artifactId>
                <version>2.3.7.RELEASE</version>
                <configuration>
                    <mainClass>com.nb.log.NbLogApplication</mainClass>
                </configuration>
                <executions>
                    <execution>
                        <id>repackage</id>
                        <goals>
                            <goal>repackage</goal>
                        </goals>
                    </execution>
                </executions>
            </plugin>
        </plugins>
    </build>

</project>

完整代码

https://gitee.com/haoyangli/mdc-log.git