logback全流程日志打印

前言

1. 打印内容：请求requestId、请求耗时、请求参数、执行方法、响应结果。
2. 复制黏贴就可以使用，经过生产考验的代码。

步骤

1. 业务流程图。
2. pom 依赖。 所有使用的依赖包
3. logback.xml 配置文件。指定打印的 日志信息模版。
4. filter 层。请求requestId、请求耗时、请求参数 等信息打印。
5. config 层。@Bean 实例化 filter 层。
6. util 层。用到的工具类。
7. aspect 层。响应结果打印。
8. wrapper 层。继承 HttpServletRequestWrapper 创建 request 作用
9. controller 层。测试日志打印。
10. service 层。测试异步打印 和 skywalking 的 tid 打印。
11. entity 层。 配合 Controller 层封装对象数据。
12. Main 主方法。
13. 学习方法。

1. 功能结构图、业务流程图。

https://www.processon.com/view/link/60a50bbb7d9c0830244d2df7

2. pom 依赖。 所有使用的依赖包

<?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 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>

    <groupId>org.example</groupId>
    <artifactId>Spring-logback</artifactId>
    <version>1.0-SNAPSHOT</version>

    <parent>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-parent</artifactId>
        <version>2.3.2.RELEASE</version>
        <relativePath/>
    </parent>

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

        <dependency>
            <groupId>org.apache.commons</groupId>
            <artifactId>commons-lang3</artifactId>
            <version>3.12.0</version>
        </dependency>

        <dependency>
            <groupId>commons-io</groupId>
            <artifactId>commons-io</artifactId>
            <version>2.8.0</version>
        </dependency>

        <dependency>
            <groupId>org.apache.skywalking</groupId>
            <artifactId>apm-toolkit-logback-1.x</artifactId>
            <version>6.2.0</version>
        </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.76</version>
        </dependency>

    </dependencies>

    <build>
        <plugins>
            <plugin>
                <groupId>org.springframework.boot</groupId>
                <artifactId>spring-boot-maven-plugin</artifactId>
            </plugin>
        </plugins>
    </build>
</project>

3. logback.xml 配置文件。指定打印的 日志信息模版。

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

<configuration>
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>

    <property name="LOG.HOME" value="${app.logs}"/>
    <property name="LOG.PATTERN" value="%d{yyyy-MM-dd HH:mm:ss.SSS} [%tid] [%X{requestId:-none}] %-5level %logger{36} - %msg%n"/>
    <property name="LOG.PATTERN.CALLER" value="%d{yyyy-MM-dd HH:mm:ss.SSS} [%tid:N/A] [%X{requestId:-none}] %-5level [%thread] %replace(%caller{1}){'\t|Caller.{1}0|\r\n', ''} - %msg%n"/>

    <!-- 日志输出的通道 -->
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <!-- requestId 或者其他，通过 MDC 可以打印-->
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS}[%tid:N/A]  [%X{requestId:-none}] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
        <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
            <layout class="org.apache.skywalking.apm.toolkit.log.logback.v1.x.TraceIdPatternLogbackLayout">
                <pattern>${LOG.PATTERN}</pattern>
            </layout>
        </encoder>
    </appender>

     <!--日志输出的通道，file -->
    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
    <file>user.log</file>
    <encoder>
    <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%X{requestId}] %-5level %logger{36} - %msg%n</pattern>
    </encoder>
    </appender>

    <logger name="com.jtfr" level="DEBUG"/>
    <logger name="org.springframework.web" level="INFO"/>

    <root>
        <level value="INFO"/>
        <!-- 指定输出类型。ref 引用-->
        <appender-ref ref="STDOUT"/>
        <appender-ref ref="FILE"/>
    </root>

</configuration>

4. filter 层。请求requestId、请求耗时、请求参数 等信息打印。

package com.jtfr.filter;

import com.jtfr.util.LogUtil;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.core.annotation.Order;
import org.springframework.http.HttpHeaders;
import org.springframework.web.filter.AbstractRequestLoggingFilter;

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

/**
 * 作用：打印请求耗时到日志
 * @Order 注解，指明 filter 处理优先级，数字小的优先处理。
 */
@Order(1)
public class LogbackRequestLoggingFilter extends AbstractRequestLoggingFilter {

    private final Logger logger = LoggerFactory.getLogger(LogbackRequestLoggingFilter.class);

    @Override
    protected void beforeRequest(HttpServletRequest request, String message) {

        MDC.put("requestId", UUID.randomUUID().toString());
        // message 是请求的 url 。案例：Before request [GET /test/get]
        logger.info(message);

        // 设置开始时间
        LogUtil.startTime();

        // 案例：Request Message RemoteIp: 127.0.0.1, AcceptGzip:  gzip, deflate, br
        logger.info("Request Message RemoteIp: {}, AcceptGzip: {}", LogUtil.getRemoteIp(request), request.getHeader(HttpHeaders.ACCEPT_ENCODING));

    }


    @Override
    protected void afterRequest(HttpServletRequest request, String message) {

        // 打印请求 url 和 请求耗时 案例： After request [POST /test/post], http request elapsed time: 134 ms
        logger.info("{}, http request elapsed time: {} ms.", message, LogUtil.elapsedTime());
        // 清理本线程缓存，防止干扰下次请求
        MDC.clear();
    }

}

package com.jtfr.filter;

import com.jtfr.wrapper.ParameterRequestWrapper;
import org.apache.commons.io.IOUtils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.core.annotation.Order;
import org.springframework.web.filter.OncePerRequestFilter;

import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;
import java.io.StringWriter;
import java.nio.charset.StandardCharsets;

/**
 * 作用：打印入参到日志
 * @Order 注解，指明 filter 处理优先级，数字小的优先处理。
 */
@Order(2)
public class ParameterWrapperFilter extends OncePerRequestFilter {

    private final Logger logger = LoggerFactory.getLogger(ParameterWrapperFilter.class);

    @Override
    protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException {

        // 打印请求参数
        StringWriter writer = new StringWriter();
        IOUtils.copy(request.getInputStream(), writer, StandardCharsets.UTF_8.name());
        String requestDataStr = writer.toString();
        logger.info("requestDataStr: {}", requestDataStr);

        /**
         * 1. HttpServletRequest 的  inputStream 读取是一次性的，最后还要我们自己写入进去。
         * 2. 打印响应结果，在 WebLogAspect
         */
        ParameterRequestWrapper requestWrapper = new ParameterRequestWrapper(request, requestDataStr);

        filterChain.doFilter(requestWrapper, response);
    }
}

5. config 层。@Bean 实例化 filter 层。

package com.jtfr.config;

import com.jtfr.filter.LogbackRequestLoggingFilter;
import com.jtfr.filter.ParameterWrapperFilter;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;

@Configuration
public class FilterConfig {

    @Bean
    public LogbackRequestLoggingFilter logbackRequestLoggingFilter() {
        LogbackRequestLoggingFilter logbackRequestLoggingFilter = new LogbackRequestLoggingFilter();
        return logbackRequestLoggingFilter;
    }

    @Bean
    public ParameterWrapperFilter parameterWrapperFilter() {
        ParameterWrapperFilter parameterWrapperFilter = new ParameterWrapperFilter();
        return parameterWrapperFilter;
    }

}

6. util 层。用到的工具类。

package com.jtfr.util;

import org.apache.commons.lang3.StringUtils;
import org.slf4j.MDC;

import javax.servlet.http.HttpServletRequest;

public class LogUtil {

    private static final String LOCALHOST_127 = System.getProperty("application.ip");

    public static void startTime() {
        MDC.put("startTime", String.valueOf(System.currentTimeMillis()));
    }

    public static long elapsedTime() {
        return System.currentTimeMillis() - Long.valueOf(MDC.get("startTime"));
    }

    public static Object getRemoteIp(HttpServletRequest request) {
        if (request == null) {
            return null;
        } else {
            String ip = request.getHeader("x-forwarded-for");
            if (ip == null || ip.length() == 0 || "unknown".equalsIgnoreCase(ip)) {
                ip = request.getHeader("Proxy-Client-IP");
            }

            if (ip == null || ip.length() == 0 || "unknown".equalsIgnoreCase(ip)) {
                ip = request.getHeader("WL-Proxy-Client-IP");
            }

            if (ip == null || ip.length() == 0 || "unknown".equalsIgnoreCase(ip)) {
                ip = request.getRemoteAddr();
            }

            if (StringUtils.isNotBlank(ip) && ip.contains(",")) {
                ip = ip.substring(0, ip.indexOf(44));
            }

            if ("0:0:0:0:0:0:0:1".equals(ip)) {
                ip = LOCALHOST_127;
            }

            return StringUtils.isNotBlank(ip) ? ip : LOCALHOST_127;
        }
    }
}

7. aspect 层。响应结果打印。

package com.jtfr.aspect;

import com.alibaba.fastjson.JSON;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.Signature;
import org.aspectj.lang.annotation.*;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.context.annotation.Configuration;

/**
 * Aop 配置参数
 * 1. spring.aop.auto=true # 默认true：开启@EnableAspectJAutoProxy.
 * 2. spring.aop.proxy-target-class=false # 默认false不使用CGLIB，true使用CGLIB
 */
@Aspect
@Configuration
public class WebLogAspect {

    private Logger logger = LoggerFactory.getLogger(WebLogAspect.class);

    @Pointcut("@within( org.springframework.stereotype.Controller)")
    private void controller() {
    }

    @Pointcut("@within(org.springframework.web.bind.annotation.RestController)")
    private void restController() {
    }


    @Pointcut("controller() || restController()")
    private void webLog() {
    }

    @Before("webLog()")
    public void doBefore(JoinPoint joinPoint) throws Throwable {

        final Signature signature = joinPoint.getSignature();
        // 打印执行的方法，类全路径名 + "." + 方法名。案例：Execute method: com.jtfr.controller.TestController.post
        logger.debug("Execute method: {}", (signature.getDeclaringTypeName() + "." + signature.getName()));

    }

    @AfterReturning(pointcut = "webLog()", returning = "obj")
    public void doAfterReturning(Object obj) {
        // 打印响应结果
        logger.info("Object Response: {}", JSON.toJSONString(obj));
    }

    @AfterThrowing(pointcut = "webLog()", throwing = "e")
    public void doRecoveryActions(Exception e) {
        // 异常返回
        String errorMsg = e.toString();
        // 此处用 warn 警示具体的error在 ControllerExceptionHandler 处理并记录
        logger.error("Exception Response: {}", e.toString());
    }
}

8. wrapper 层。继承 HttpServletRequestWrapper 创建 request 作用

package com.jtfr.wrapper;

import com.alibaba.fastjson.JSON;
import com.alibaba.fastjson.JSONObject;

import javax.servlet.ReadListener;
import javax.servlet.ServletInputStream;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletRequestWrapper;
import java.io.ByteArrayInputStream;
import java.nio.charset.StandardCharsets;
import java.util.Collections;
import java.util.Enumeration;
import java.util.HashMap;
import java.util.Map;


public class ParameterRequestWrapper extends HttpServletRequestWrapper {

    private Map<String, String[]> params = new HashMap<String, String[]>();

    private Object object;

    @SuppressWarnings("unchecked")
    public ParameterRequestWrapper(HttpServletRequest request) {

        super(request);

        this.params.putAll(request.getParameterMap());

    }

    public ParameterRequestWrapper(HttpServletRequest request, JSONObject object) {
        this(request);
        this.object = object;
        addAllParameters(object.getInnerMap());
    }

    public ParameterRequestWrapper(HttpServletRequest request, String jsonStr) {
        this(request);
        // Json 字符串 转换成 JSONObject 对象
        JSONObject object = JSON.parseObject(jsonStr);
        this.object = object;
        addAllParameters(object.getInnerMap());
    }

    @Override
    public Map<String, String[]> getParameterMap() {
        return Collections.unmodifiableMap(this.params);
    }

    @Override
    public String getParameter(String name) {
        String[] values = params.get(name);
        if (values == null || values.length == 0) {
            return null;
        }
        return values[0];
    }

    @Override
    public String[] getParameterValues(String name) {//同上
        return params.get(name);
    }


    @Override
    public Enumeration<String> getParameterNames() {
        return Collections.enumeration(this.params.keySet());
    }

    @Override
    public ServletInputStream getInputStream() {
        final ByteArrayInputStream in = new ByteArrayInputStream(object.toString().getBytes(StandardCharsets.UTF_8));
        return new ServletInputStream() {
            public int read() {
                return in.read();
            }

            public void setReadListener(ReadListener listener) {
            }

            public boolean isReady() {
                return true;
            }

            public boolean isFinished() {
                return false;
            }
        };
    }

    public final void addAllParameters(Map<String, Object> otherParams) {
        for (Map.Entry<String, Object> entry : otherParams.entrySet()) {
            addParameter(entry.getKey(), entry.getValue());
        }
    }

    public void addParameter(String name, Object value) {
        if (value != null) {
            if (value instanceof String[]) {
                params.put(name, (String[]) value);
            } else if (value instanceof String) {
                params.put(name, new String[]{(String) value});
            } else {
                params.put(name, new String[]{String.valueOf(value)});
            }
        }
    }

}

9. controller 层。测试日志打印。

package com.jtfr.controller;

import com.jtfr.entity.User;
import com.jtfr.service.TestService;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.web.bind.annotation.*;

@RestController
@RequestMapping("/test")
public class TestController {

    private static final Logger logger = LoggerFactory.getLogger(TestController.class);

    @PostMapping("/post")
    public String post(@RequestBody User user) {
        logger.info("info : {}", user.toString());
        return "TestController:post:"+user.toString();
    }

}

10. service 层。测试异步打印 和 skywalking 的 tid 打印。

package com.jtfr.service;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.scheduling.annotation.Async;
import org.springframework.stereotype.Service;

@Service
public class TestService {

    private static final Logger logger = LoggerFactory.getLogger(TestService.class);

    /**
     * 异步方法，用于测试 tid 日志打印
     */
    @Async
    public void testAnsync(){
        logger.info("Thread:{} 打印的 tid 相同，requestId:{}", Thread.currentThread().getName(), MDC.get("requestId"));
    }
}

11. entity 层。 配合 Controller 层封装对象数据。

package com.jtfr.entity;

public class User {

    private String id;
    private String username;

    public String getId() {
        return id;
    }

    public void setId(String id) {
        this.id = id;
    }

    public String getUsername() {
        return username;
    }

    public void setUsername(String username) {
        this.username = username;
    }

    @Override
    public String toString() {
        return "User{" +
                "id='" + id + '\'' +
                ", username='" + username + '\'' +
                '}';
    }
}

12. Main 主方法。

package com.jtfr;

import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;

@SpringBootApplication
public class SpringBootMain {
    public static void main(String[] args) {
        SpringApplication.run(SpringBootMain.class, args);
    }
}

13. 学习方法。

1. 日志打印的时候有一个 requestId不知道怎么获取。
2. 一、自己没有百度去找资料。二、没有把这个参数放到代码中搜索，搜索就知道又什么地方相关，一一排查一下就好了。