赞
踩
排查问题是程序员的基本能力也是必须要会的,在开发环境,我们可以debug,但是一旦到了服务器上,就很难debug了,最有效的方式就是通过日志揪出bug,而一次请求的日志如果没有一个唯一的链路标识(我们下边称他为traceId),单靠程序员人工分析的话,费时费力,尤其是请求量高频的接口,更是雪上加霜,排查问题效率大打折扣,作为程序员,低效的方式是忍不了的!!! 本文我将用一次实战演练,来演示常用框架/中间件/多服务 之间如何传递traceId
本文大概有如下内容:
( 包含http(openFeign,httpClient restTemplate)、rpc(motan、 dubbo)、mq(RocketMq)
)所谓链路追踪,就是为了 把整个请求链路从头到尾串起来,不管调用链路有多深,多复杂,只要将一次链路完整无误的串联起来,就是合格的链路追踪功能。
业界不乏skywalking zipkin
等等链路追踪方面牛逼的框架,但是我们为了更轻量更灵活可控同时也是抱着学习心态,所以自己来实现链路追踪。
首先想实现链路追踪,有两点是核心,实现了这两点,问题也就不大了
本地
(或者说单服务内
) 传递
?分布式环境
中,traceId如何跨服务/中间件 传递
?首先我们先讲下单服务内的链路传递
作为java开发,最常用的就是slf4j来实现打印日志的功能(但是slf4j并不没有实现逻辑,因为 slf4j整个的定义是一个日志门面,该包中并无具体的实现,实现都是在 比如:logback log4j2
等等日志实现框架中)
slf4j的门面
不仅给我们提供了打印日志的功能,还提供了 org.slf4j.MDC
类, 该类的作用大概如下:
映射诊断上下文(Mapped Diagnostic Context,简称MDC)是一种工具,用于区分不同来源的交错日志输出。当服务器几乎同时处理多个客户机时,日志输出通常是交错的。 MDC是基于每个线程进行管理的 。
上边这个官方解释,最重要的一句话就是 MDC是基于每个线程进行管理的
上边这个太官方,说下我个人对MDC的理解:
他是一个日志的扩展,
扩展的目的就是给 每个线程 输出的日志打上一个标记
(一个线程只有一个标记且不能重复一般使用uuid即可),这样我们在查看日志时候,就可以根据这个标记来区分调用链路
了ps: 当然了, 光往MDC中设置当前线程的链路id也是不行的你还得在log4j2.xml文件中,设置占位符,这样最终输出的日志才会带链路信息。如何设置会在 2.1节 有讲。
从代码层面看下 MDC做了啥:
把代码流程梳理下大概如下:
- MDC(类)
- MDCAdapter(接口)
- Log4jMDCAdapter(实现类之一)
- ThreadContext(类)
- ThreadContextMap(接口)
- DefaultThreadContextMap
- //(MDC的几个操作都是往这个里边存取数据)
- ThreadLocal<Map<String, String>> localMap;
-
- 复制代码
上边我们说过 MDC最终设置的key,value 是放到 DefaultThreadContextMap
类中的 ThreadLocal<Map<String, String>> localMap
这个里边的,也就是说 里边的Map<String,String>是某个线程
的本地副本
(不懂线程本地副本的可以回顾下ThreadLocal的知识),有了这个知识基础,我们就不难理解为什么输出的日志是每个线程都有唯一的traceId
了。
举个例子来说就是:
线程t1
往MDC中设置的 key,value ,当log4j2打印t1的日志时,会找到当前(t1)线程设置的value,来把 log4j2.xml 中的占位符替换线程t2
往MDC中设置 key,value ,当log4j2打印t2的日志时,会找到当前(t2)线程设置的value,来把 log4j2.xml 中的占位符替换ok,从上边可以了解到,单服务内通过slf4j提供的MDC功能,可以实现 某服务内 的链路追踪。
我们都知道,所谓微服务,都是由各个小的单服务组合起来的,通过上边的描述,我们知道单服务内如何打印链路了,那么微服务间不管怎么调用,只要保证在请求最开始(一般是网关)生成一个链路id,在后续的调用中将这个链路id一层层传递下去,整个完整的调用链路追踪也就实现了。在下边小节,我们就看看traceId是怎么垮服务传递的。
垮服务间调用,本质上就是各个服务之间进行通信的过程, 一般情况下,微服务间常用通信方式有如下几种:(这里我们仅从应用层来看,如果从传输层看的话 1和2 都是tcp)
在日常开发中
我常用
的 :http 框架有
apache的 httpclient
,springcloud的 openfeign
,spring包中的 resttemplate
,okhttp
(okhttp一般安卓用的比较多)。rpc 框架的话一般是
dubbo
、motan
其他的本人没怎么用过。mq 的话我用过kafka rabbitmq rocketmq
下边,我搭建了四个微服务,分别是
网关服务 study-gateway,
微服务消费服务 study-consumer 后台管理服务 study-admin 订单服务 study-order
在这里我的 调用链路 大概如下图所示:
如上图所示的链路,该次请求会经过 网关
,openFeign
,异步调用
,httpClient
调用,mq
这几个组件,而如何在这几个组件 调用前传递traceId 和 调用后设置traceId
成为垮服务进行链路追踪的关键。 ps: dubbo和motan的我们就不演示了,会直接给出传递方案。
铺垫了那么多,我们下边直接了当点不再啰嗦!
在网关过滤器中生成并设置traceId到MDC(此刻网关服务的日志中将会打印traceId) ,同时通过header传递到下游服务。
简单看下网关配置:
注册拦截器到RestTemplate实例:
发送前
和消费前
添加钩子发送前添加钩子:
消费前添加钩子:
分别往生产和消费实例对象中设置钩子:
上边我们也说了,MDC底层 DefaultThreadContextMap
是用 ThreadLocal 来保存的链路信息,而ThreadLocal是同一个线程,才会有相同的副本数据,而当我们在项目中使用线程池时候,主线程和子线程肯定是不一样的,那么这种情况下就得考虑如何将主线程的值传递给子线程,让子线程也能记录traceId,从而保证 链路不会断!
值的一说的是jdk也想到了这个问题,提供了一个 InheritableThreadLocal
类,但是这个类并不适用于链路追踪场景,因为在异步调用
场景下,是要保证每一次请求,都要将主线程的traceId传递给子线程
,而 InheritableThreadLocal只能是第一次时候传递,或者说他不是每次都传递给子线程更贴切
,下边看下官方的描述:
InheritableThreadLocal存在的问题:官方原话: 使用InheritableThreadLocal时(ThreadContext 可能并不总是自动传递给工作线程)
由于线程池的复用机制,所以第n次请求时,线程池中线程所打印出的链路id,还是上次或者是上n次的链路id(我试验了确实如此),而我们真实希望是,线程池中线程打印的链路id保持和当前主线程中的链路id一致,换句话说: 我们需要的是 任务提交给线程池时的链路id传递到 任务执行时。
既然InheritableThreadLocal不满足需求,那么怎么办呢?看下边:
在log4j2中,他底层是通过spi机制提供了 对 ThreadContextMap
接口的扩展能力
,不了解的可以去看看官网,而正好阿里开源了一个这个小框架 ttl 和 ttl-thread-context-map ,ttl-thread-context-map 可以解决线程间的传递丢失问题(他内部也是使用的TransmittableThreadLocal也就是ttl
来存储MDC 的key和value)。ttl-thread-context-map 依赖java的spi机制,依靠spi机制,让log4j2 在启动加载时,用log4j2.component.properties中 log4j2.threadContextMap
这个key 对应的 value作为ThreadContextMap
接口的实现(也就是替换掉DefaultThreadContextMap这个默认实现
),从而实现了线程间传递的功能。对ttl和ttl-thread-context-map不熟悉的可以跳的github 讲的很详细很清楚。
TtlThreadContextMap内部使用TransmittableThreadLocal来存储MDC的key,value
spi配置:
而我们使用阿里这个工具也很简单首先maven引入(注意版本 不清楚的去maven库看看)
- <dependency>
- <groupId>com.alibaba</groupId>
- <artifactId>transmittable-thread-local</artifactId>
- <version>2.14.2</version>
- </dependency>
- <dependency>
- <groupId>com.alibaba</groupId>
- <artifactId>log4j2-ttl-thread-context-map</artifactId>
- <exclusions>
- <exclusion>
- <groupId>org.apache.logging.log4j</groupId>
- <artifactId>log4j-api</artifactId>
- </exclusion>
- </exclusions>
- <version>1.4.0</version>
- <scope>runtime</scope>
- </dependency>
- 复制代码
在引入这个后,我什么也没配,如果我使用jdk的 ThreadPoolExecutor
或者spring的 ThreadPoolTaskExecutor
,都是可以实现链路传递的,但是我使用 CompletableFuture
的话,第一次请求的链路是对的,当第二次请求时候,CompletableFuture线程池中的打印链路信息还是第一次的,这个问题github上有说明,作者让使用javaagent来解决,果然在我配置javaagent后,CompletableFuture 的链路信息每次都是正确的。
在idea 的 VM options 中配置:
-javaagent:/Users/hzz/.m2/repository/com/alibaba/transmittable-thread-local/2.14.2/transmittable-thread-local-2.14.2.jar
即可解决 CompletableFuture的链路id传递问题(这里我们最好是agent这样对代码无侵入,如果你使用TtlRunable修饰Runable的话 对代码侵入比较多,维护起来也比较麻烦)
最后我们将四个服务启动,看下整体效果:
postman调用:
study-gateway
study-consumer
study-admin
tcpdump抓包看看第三方的请求头中是否含有了链路id:
study-order
上边几张截图可以看到下边这个调用链 通过链路id 可以完美的串起来了!
最后我将TraceIdUtil代码粘出来。
- package com.xzll.common.util;
-
- import com.xzll.common.constant.StudyConstant;
- import jodd.util.StringUtil;
- import org.apache.commons.lang3.StringUtils;
- import org.slf4j.MDC;
-
- import javax.servlet.http.HttpServletRequest;
- import java.util.UUID;
-
- /**
- * @Author: hzz
- * @Date: 2023/2/26 15:19:36
- * @Description:
- */
- public class TraceIdUtil {
-
- public static final String REGEX = "-";
-
- /**
- * 从header和参数中获取traceId
- * 从网关传入数据
- *
- * @param request HttpServletRequest
- * @return traceId
- */
- public static String getTraceIdByRequest(HttpServletRequest request) {
- String traceId = request.getParameter(StudyConstant.TraceConstant.TRACE_ID);
- if (StringUtils.isBlank(traceId)) {
- traceId = request.getHeader(StudyConstant.TraceConstant.TRACE_ID);
- }
- return traceId;
- }
-
- public static String getTraceIdByLocal() {
- return MDC.get(StudyConstant.TraceConstant.TRACE_ID);
- }
-
- /**
- * 传递traceId至MDC
- *
- * @param traceId 链路id
- */
- public static void setTraceId(String traceId) {
- if (StringUtil.isNotBlank(traceId)) {
- MDC.put(StudyConstant.TraceConstant.TRACE_ID, traceId);
- }
- }
-
- /**
- * 构建traceId
- * @return
- */
- public static String buildTraceId() {
- return UUID.randomUUID().toString().replaceAll(REGEX, StringUtils.EMPTY);
- }
-
- /**
- * 清理traceId
- */
- public static void cleanTraceId() {
- MDC.clear();
- }
- }
-
- 复制代码
由于我的项目中没有使用motan和dubbo所以无法演示rpc调用,但是我接触的项目有,这里不粘完整代码了 ,直接给出答案,在motan中也是支持配置过滤器的 ,在调用前,通过过滤器往request的attachment中设置traceId来将traceId传递给服务提供者,在服务提供者中也可以添加过滤器,此时从attachment属性中取出traceId通过MDC.put(key,value)来将traceId设置进本服务。达到链路传递的效果。 同理dubbo框架也是类似做法。
ps:
log4j2-ttl-thread-context-map
,可以看看github的资料,已经讲的超级细了。另外如果像知道更多细节,需要从slf4j和log4j2的源码入手,相信会有更多的收获。你会发现每天使用的slf4j log4j2 里边居然这么多值的学习的地方!!!Copyright © 2003-2013 www.wpsshop.cn 版权所有,并保留所有权利。