基于SLF4J MDC机制实现日志的链路追踪

一、打印HTTP request body和response body实现日志跟踪

request 的inputStream和response 的outputStream默认情况下是只能读一次，不可重复读；这就导致要获取请求体或者响应体信息时必须要声明包裹类wrapper; spring为此提供了两个对应的包裹类ContentCachingRequestWrapper和ContentCachingResponseWrapper使得这两个流信息可重复读；

可以利用这两个类结合spring的WebUtil工具类来实现日志跟踪：

import lombok.extern.slf4j.Slf4j;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.stereotype.Component;
import org.springframework.web.filter.OncePerRequestFilter;
import org.springframework.web.util.ContentCachingRequestWrapper;
import org.springframework.web.util.ContentCachingResponseWrapper;
import org.springframework.web.util.WebUtils;import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.annotation.WebFilter;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;
import java.io.UnsupportedEncodingException;
import java.util.Enumeration;
import java.util.UUID;/*** @author: liumengbing* @date: 2019/03/12 10:10**/
@Component
@Slf4j
@WebFilter("/*")
public class WebLogFilter extends OncePerRequestFilter {private static Logger log = LoggerFactory.getLogger(WebLogFilter.class);public static final String SPLIT_STRING_M = "=";public static final String SPLIT_STRING_DOT = ", ";@Overrideprotected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException {//日志tradeMDC.clear();//使用唯一ID标识每次请求MDC.put("trade_id", UUID.randomUUID().toString().replaceAll("-",""));ContentCachingRequestWrapper wrapperRequest = new ContentCachingRequestWrapper(request);ContentCachingResponseWrapper wrapperResponse = new ContentCachingResponseWrapper(response);String urlParams = getRequestParams(request);log.info("request params[{}]", urlParams);filterChain.doFilter(wrapperRequest, wrapperResponse);String requestBodyStr = getRequestBody(wrapperRequest);log.info("request body:{}", requestBodyStr);String responseBodyStr = getResponseBody(wrapperResponse);log.info("response body:{}", responseBodyStr);wrapperResponse.copyBodyToResponse();}/*** 获取请求地址上的参数* @param request* @return*/public static String getRequestParams(HttpServletRequest request) {StringBuilder sb = new StringBuilder();Enumeration<String> enu = request.getParameterNames();//获取请求参数while (enu.hasMoreElements()) {String name = enu.nextElement();sb.append(name + SPLIT_STRING_M).append(request.getParameter(name));if(enu.hasMoreElements()) {sb.append(SPLIT_STRING_DOT);}}return sb.toString();}/*** 打印请求参数* @param request*/private String getRequestBody(ContentCachingRequestWrapper request) {ContentCachingRequestWrapper wrapper = WebUtils.getNativeRequest(request, ContentCachingRequestWrapper.class);if(wrapper != null) {byte[] buf = wrapper.getContentAsByteArray();if(buf.length > 0) {String payload;try {payload = new String(buf, 0, buf.length, wrapper.getCharacterEncoding());} catch (UnsupportedEncodingException e) {payload = "[unknown]";}return payload.replaceAll("\\n","");}}return "";}/*** 打印返回参数* @param response*/private String getResponseBody(ContentCachingResponseWrapper response) {ContentCachingResponseWrapper wrapper = WebUtils.getNativeResponse(response, ContentCachingResponseWrapper.class);if(wrapper != null) {byte[] buf = wrapper.getContentAsByteArray();if(buf.length > 0) {String payload;try {payload = new String(buf, 0, buf.length, wrapper.getCharacterEncoding());} catch (UnsupportedEncodingException e) {payload = "[unknown]";}return payload;}}return "";}}

在以上代码中还有一个技术点：使用了slf4j的MDC来跟踪请求信息，打印完整的请求处理日志；并在日志配置中加上了唯一ID，从而达到日志追踪的目的。

日志配置文件：

[%X{trade_id}]%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n

输出的日志信息：

[16fbd9304e23492cab3ccabb6a85d0c0]2019-03-12 10:40:49.127  INFO 13712 --- [nio-8188-exec-1] xxx.xx.xx.filter.WebLogFilter       : request params[{}]：account=xxxxx,  v_code=056036}
[16fbd9304e23492cab3ccabb6a85d0c0]2019-03-12 10:40:49.130  INFO 13712 --- [nio-8188-exec-1] xxx.xx.xx.filter.WebLogFilter       : request body:{}：{    "account":"xxxxx",  "v_code":"056036"}
[16fbd9304e23492cab3ccabb6a85d0c0]2019-03-12 10:40:49.131  INFO 13712 --- [nio-8188-exec-1] xxx.xx.xx.filter.WebLogFilter       : response body:{}：{"code":1,"msg":"请输入正确的验证码","data":"","success":false}

二、基于SLF4J MDC机制实现日志的链路追踪

问题引入：

系统上线之后，我们可能经常需要进行线上问题排查，排查问题必须用到的方式就是查看日志，但是在分布式系统中，各种无关日志穿行其中，导致我们没办法快速定位用户在某一次请求中的所有日志。因此，我们可能需要对一个用户的操作流程进行归类标记，比如使用线程+时间戳，或者用户身份标识等方式。这样的话，我们就可以从大量日志信息中grep出某个用户的操作流程，或者某个时间的流转记录，从而便于我们诊断线上问题。

解决方案：

1.在每次请求的时候，获取到请求的sessionId，或者自己生成一个伪sessionId，在每次输出日志的时候将这个sessionId连同日志信息一起输出。这个方式实现起来非常简单，但是代码侵入性强，每次输出的时候都需要额外多输出一个参数，重复且工作量大，但是可控粒度高；
2.使用LogBack的MDC机制，在日志模板中加入sessionId，如上面我们使用到的：

[%X{trade_id}]%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n

这种方式工作量小，代码侵入小，易扩展，但是可控粒度较低。

方案一：

logger.info("sessionId: {}, message: {}", sessionId, "日志信息");

方案二（以springmvc为例）：

1、新建一个日志拦截器，拦截所有的请求，在处理请求前将sessionId放到MDC中，处理完请求之后清除MDC中的内容。这就解决了80%的问题；
2、在旧版本中新启线程时MDC会自动将父线程的MDC内容复制给子线程，因为MDC内部使用的是InheritableThreadLocal，但是因为性能问题在最新的版本中被取消了，所以子线程不会自动获取父线程MDC的内容。官方建议我们在父线程新建子线程之前调用MDC.getCopyOfContextMap()方法将父线程的MDC内容取出传给子线程，子线程在执行操作之前先调用MDC.setContextMap()方法将父线程的MDC内容设置到子线程中去。
3、设置日志输出格式

[%X{trade_id}]%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n

MDC对外提供的方法：

package org.slf4j;
public class MDC {// 将一个K-V的键值对放到容器，其实是放到当前线程的ThreadLocalMap中public static void put(String key, String val);// 根据key在当前线程的MDC容器中获取对应的值public static String get(String key);// 根据key移除容器中的值public static void remove(String key);// 清空当前线程的MDC容器public static void clear();
}

MDC实现原理：

Slf4j 的实现原则就是调用底层具体实现类，比如logback,log4j等包；而不会去实现具体的输出打印等操作。这里使用了装饰者模式，看源码就能看出来，所有的方法都是在对mdcAdapter 这个属性进行操作。所以实现核心是MDCAdapter类。

public interface MDCAdapter {public void put(String key, String val);public String get(String key);public void remove(String key);public void clear();public Map<String, String> getCopyOfContextMap();public void setContextMap(Map<String, String> contextMap);
}

MDCAdapter有三个实现类：BasicMDCAdapter、LogbackMDCAdapter，NOPMDCAdapter。其中Logback使用的是LogbackMDCAdapter。通过查看源码发现它们的底层都是使用ThreadLocal实现的，这里不再具体分析源码，有兴趣的可以自己去看一下。

参考资料：
https://www.jianshu.com/p/afdd31bfbf94
https://www.jianshu.com/p/06b1d35526c2
https://blog.csdn.net/xiaolyuh123/article/details/80560662
https://www.jianshu.com/p/3dca4aeb6edd

基于SLF4J MDC机制实现日志的链路追踪相关推荐

MDC机制实现日志的链路追踪
一.问题描述排查问题用得最多的方式是查看日志,但是在现有系统中,各种无关日志穿行其中,导致没办法快速的找出用户在一次请求中所有的日志. 二.问题分析我们没办法快速定位用户在一次请求中对应的所有日志 ...
Slf4j MDC机制
MDC 简介 MDC ( Mapped Diagnostic Contexts ),它是一个线程安全的存放诊断日志的容器. Logback设计的一个目标之一是对分布式应用系统的审计和调试.在现在的分布 ...
logback利用mdc机制为日志增加traceId
1 . 增加LogMdcFilter package cn.xbz.common.filter;import org.slf4j.MDC;import javax.servlet.*; import ...
MDC实现日志链路追踪
开发过程中难免遇到需要查看日志来找出问题出在哪一环节的情况,而在实际情况中服务之间互相调用所产生的日志冗长且复杂,若是再加上同一时间别的请求所产生的日志,想要精准定位自己想要查看的日志就比较麻烦.为解 ...
SpringCloud 分布式链路追踪、分布式日志系统
目录概述 Zipkin的使用搭建zipkin server zipkin dependencies 在服务中添加zipkin的相关配置 SkyWalking的使用部署skywalking web ...
Spring Cloud Alibaba 高级特性应用性能监控：通过 SkyWalking 实施链路追踪
上一讲我们掌握了基于 Sleuth+Zipkin 对微服务架构实施基于日志的链路追踪,通过 Sleuth 在微服务应用中附加链路数据,再通过 Zipkin 实现链路数据收集与可视化,从而保证开发与运维 ...
springboot 之微服务调用之链路追踪
说明:本文来自本篇主要内容一.为什么要用链路追踪? 1.1 因:拆分服务单元微服务架构其实是一个分布式的架构,按照业务划分成了多个服务单元. 由于服务单元的数量是很多的,有可能几千个,而且业务也 ...
Slf4j之MDC机制
什么是MDC机制 MDC(Mapped Diagnostic Contexts)映射诊断上下文,主要用在做日志链路跟踪时,动态配置用户自定义的一些信息,比如requestId.sessionId等等. ...
java ndc_通过slf4j/log4j的MDC/NDC 实现日志追踪
在分布式系统或者较为复杂的系统中,我们希望可以看到一个客户请求的处理过程所涉及到的所有子系统\模块的处理日志. 由于slf4j/log4j基本是日志记录的标准组件,所以slf4j/log4j成为了我的 ...

基于SLF4J MDC机制实现日志的链路追踪

基于SLF4J MDC机制实现日志的链路追踪相关推荐

最新文章

热门文章