SpringCloud升级之路2020.0.x版-43.为何 SpringCloudGateway 中会有链路信息丢失
本系列代码地址:https://github.com/JoJoTec/spring-cloud-parent
在开始编写我们自己的日志 Filter 之前,还有一个问题我想在这里和大家分享,即在 Spring Cloud Gateway 中可能发生链路信息丢失的问题。
主要冲突 - Project Reactor 与 Java Logger MDC 之间的设计冲突
Poject Reactor 是基于异步响应式设计的编程模式的实现,它的主要实现思路是先编写执行链路,最后 sub 执行整个链路。但是链路的每一部分,究竟是哪个线程执行的,是不确定的。
Java 的日志框架设计,其上下文 MDC(Mapped Diagnostic Context)信息,是基于线程设计的,其实可以简单理解为一个 ThreadLocal 的 Map。日志的链路信息,是保存在这个 MDC 中的。
这样其实可以看出 Project Reactor 与日志框架的 MDC 默认是不兼容的,只要发生异步线程切换,这个 MDC 就变了。Spring Cloud Sleuth 为此加了很多粘合代码,但是智者千虑必有一失,Project Reactor 应用场景和库也在不断发展和壮大,Spring Cloud Sleuth 也可能会漏掉一些场景导致链路信息丢失。
一种 Spring Cloud Gateway 常见的链路信息丢失的场景
我们编写一个简单的测试项目(项目地址):
引入依赖:
<parent><groupId>org.springframework.boot</groupId><artifactId>spring-boot-starter-parent</artifactId><version>2.4.6</version>
</parent><dependencies><dependency><groupId>org.springframework.cloud</groupId><artifactId>spring-cloud-starter-gateway</artifactId></dependency><dependency><groupId>org.springframework.cloud</groupId><artifactId>spring-cloud-starter-sleuth</artifactId></dependency><dependency><groupId>org.springframework.boot</groupId><artifactId>spring-boot-starter-log4j2</artifactId></dependency><!--log4j2异步日志需要的依赖,所有项目都必须用log4j2和异步日志配置--><dependency><groupId>com.lmax</groupId><artifactId>disruptor</artifactId><version>${disruptor.version}</version></dependency>
</dependencies><dependencyManagement><dependencies><dependency><groupId>org.springframework.cloud</groupId><artifactId>spring-cloud-dependencies</artifactId><version>2020.0.3</version><type>pom</type><scope>import</scope></dependency></dependencies>
</dependencyManagement>
对所有路径开启 AdaptCachedBodyGlobalFilter
:
@Configuration(proxyBeanMethods = false)
public class ApiGatewayConfiguration {@Autowiredprivate AdaptCachedBodyGlobalFilter adaptCachedBodyGlobalFilter;@Autowiredprivate GatewayProperties gatewayProperties;@PostConstructpublic void init() {gatewayProperties.getRoutes().forEach(routeDefinition -> {//对 spring cloud gateway 路由配置中的每个路由都启用 AdaptCachedBodyGlobalFilter EnableBodyCachingEvent enableBodyCachingEvent = new EnableBodyCachingEvent(new Object(), routeDefinition.getId());adaptCachedBodyGlobalFilter.onApplicationEvent(enableBodyCachingEvent);});}
}
配置(我们只有一个路由,将请求转发到 httpbin.org 这个 http 请求测试网站):
server:port: 8181
spring:application:name: apiGatewaycloud:gateway:httpclient:connect-timeout: 500response-timeout: 60000routes:- id: first_routeuri: http://httpbin.orgpredicates:- Path=/httpbin/**filters:- StripPrefix=1
添加两个全局 Filter,一个在 AdaptCachedBodyGlobalFilter
之前,一个在 AdaptCachedBodyGlobalFilter
之后。这两个 Filter 非常简单,只是打一行日志。
@Log4j2
@Component
public class PreLogFilter implements GlobalFilter, Ordered {public static final int ORDER = new AdaptCachedBodyGlobalFilter().getOrder() - 1;@Overridepublic Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain) {log.info("before AdaptCachedBodyGlobalFilter");return chain.filter(exchange);}@Overridepublic int getOrder() {return ORDER;}
}@Log4j2
@Component
public class PostLogFilter implements GlobalFilter, Ordered {public static final int ORDER = new AdaptCachedBodyGlobalFilter().getOrder() + 1;@Overridepublic Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain) {log.info("after AdaptCachedBodyGlobalFilter");return chain.filter(exchange);}@Overridepublic int getOrder() {return ORDER;}
}
最后指定 Log4j2 的输出格式中包含链路信息,就像系列文章开头中指定的那样。
启动这个应用,之后访问 http://127.0.0.1:8181/httpbin/anything
,查看日志,发现 PostLogFilter 中的日志,没有链路信息了:
2021-09-08 06:32:35.457 INFO [service-apiGateway,51063d6f1fe264d0,51063d6f1fe264d0] [30600] [reactor-http-nio-2][?:]: before AdaptCachedBodyGlobalFilter
2021-09-08 06:32:35.474 INFO [service-apiGateway,,] [30600] [reactor-http-nio-2][?:]: after AdaptCachedBodyGlobalFilter
Spring Cloud Sleuth 是如何增加链路信息
通过系列之前的源码分析,我们知道,在最开始的 TraceWebFilter,我们将 Mono 封装成了一个 MonoWebFilterTrace,它的核心源码是:
@Override
public void subscribe(CoreSubscriber<? super Void> subscriber) {Context context = contextWithoutInitialSpan(subscriber.currentContext());Span span = findOrCreateSpan(context);//将 Span 放入执行上下文中,对于日志其实就是将链路信息放入 org.slf4j.MDC//日志的 MDC 一般都是 ThreadLocal 的 Map,对于 Log4j2 的实现类就是 org.apache.logging.log4j.ThreadContext,其核心 contextMap 就是一个基于 ThreadLocal 实现的 Map//简单理解就是将链路信息放入一个 ThreadLocal 的 Map 中,每个线程访问自己的 Map 获取链路信息try (CurrentTraceContext.Scope scope = this.currentTraceContext.maybeScope(span.context())) {//将实际的 subscribe 用 Span 所在的 Context 包裹住,结束时关闭 Spanthis.source.subscribe(new WebFilterTraceSubscriber(subscriber, context, span, this));}//在 scope.close() 之后,会将链路信息从 ThreadLocal 的 Map 中剔除
}@Override
public Object scanUnsafe(Attr key) {if (key == Attr.RUN_STYLE) {//执行的方式必须是不能切换线程,也就是同步的//因为,日志的链路信息是放在 ThreadLocal 对象中,切换线程,链路信息就没了return Attr.RunStyle.SYNC; }return super.scanUnsafe(key);
}
WebFilterTraceSubscriber 干了些什么呢?出现异常,以及 http 请求结束的时候,我们可能想将响应信息,异常信息记录进入 Span 中,就是通过这个类封装实现的。
经过 MonoWebFilterTrace 的封装,由于 Spring-WebFlux 处理请求,其实就是封装成我们上面得出的 Mono 之后进行 subscribe 处理的请求,所以这样,整个内部 Mono 的 publish 链路以及 subscribe 链路,就被 WebFilterTraceSubscriber 中的 scope 包裹起来了。只要我们自己不在 GatewayFilter 中转换成某些强制异步的 Mono 或者 Flux 导致切换线程,链路信息是不会丢失的。
为何上面的测试项目中链路信息会丢失
我们来看经过 AdaptCachedBodyGlobalFilter 之后,我们前面拼的 Mono 链路会变成什么样:
return Mono.defer(() ->new MonoWebFilterTrace(source, RoutePredicateHandlerMapping.this.lookupRoute(exchange) //根据请求寻找路由.flatMap((Function<Route, Mono<?>>) r -> {exchange.getAttributes().put(GATEWAY_ROUTE_ATTR, r); //将路由放入 Attributes 中,后面我们还会用到return Mono.just(RoutePredicateHandlerMapping.this.webHandler); //返回 RoutePredicateHandlerMapping 的 FilteringWebHandler}).switchIfEmpty( //如果为 Mono.empty(),也就是没找到路由Mono.empty() .then(Mono.fromRunnable(() -> { //返回 Mono.empty() 之后,记录日志if (logger.isTraceEnabled()) {logger.trace("No RouteDefinition found for [" + getExchangeDesc(exchange) + "]");}}))).switchIfEmpty(DispatcherHandler.this.createNotFoundError()) //如果没有返回不为 Mono.empty() 的 handlerMapping,则直接返回 404.then(Mono.defer(() -> {//省略在 AdaptCachedBodyGlobalFilter 前面的链路嵌套//读取 Body,由于 TCP 拆包,所以需要他们拼接到一起DataBufferUtils.join(exchange.getRequest().getBody())//如果没有 Body,则直接返回空 DataBuffer.defaultIfEmpty(factory.wrap(new EmptyByteBuf(factory.getByteBufAllocator())))//decorate方法中将 dataBuffer 放入 exchange 的 Attributes 列表,只是为了防止重复进入这个 `AdaptCachedBodyGlobalFilter` 的情况导致重复缓存请求 Body//之后,使用新的 body 以及原始请求封装成新的请求,继续 GatewayFilters 链路.map(dataBuffer -> decorate(exchange, dataBuffer, cacheDecoratedRequest)).switchIfEmpty(Mono.just(exchange.getRequest())).flatMap(function);}).then(Mono.empty()))), //调用对应的 HandlerTraceWebFilter.this.isTracePresent(), TraceWebFilter.this, TraceWebFilter.this.spanFromContextRetriever()).transformDeferred((call) -> {//MetricsWebFilter 相关的处理,在前面的代码中给出了,这里省略});
);
其中 DataBufferUtils.join(exchange.getRequest().getBody())
其实是一个 FluxReceive,这里我们可以理解为:提交一个尝试读取请求 Body 的任务,将之后的 GatewayFilter 的链路处理加到在读取完 Body 之后的回调当中,提交这个任务后,立刻返回。这么看可能比较复杂,我们用一个类似的例子类比下:
//首先我们创建一个新的 Span
Span span = tracer.newTrace();
//声明一个类似于 TraceWebFilter 中封装的 MonoWebFilterTrace 的 MonoOperator
class MonoWebFilterTrace<T> extends MonoOperator<T, T> {protected MonoWebFilterTrace(Mono<? extends T> source) {super(source);}@Overridepublic void subscribe(CoreSubscriber<? super T> actual) {//将 subscribe 用 span 包裹try (Tracer.SpanInScope spanInScope = tracer.withSpanInScope(span)) {source.subscribe(actual);//在将要关闭 spanInScope 的时候(即从 ThreadLocal 的 Map 中移除链路信息),打印日志log.info("stopped");}}
}Mono.defer(() -> new MonoWebFilterTrace(Mono.fromRunnable(() -> {log.info("first");})//模拟 FluxReceive.then(Mono.delay(Duration.ofSeconds(1)).doOnSuccess(longSignal -> log.info(longSignal))))
).subscribe(aLong -> log.info(aLong));
Mono.delay
和 FluxReceive 表现类似,都是异步切换线程池执行。执行上面的代码,我们可以从日志上面就能看出来:
2021-09-08 07:12:45.236 INFO [service-apiGateway,7b2f5c190e1406cb,7b2f5c190e1406cb] [31868] [reactor-http-nio-2][?:]: first
2021-09-08 07:12:45.240 INFO [service-apiGateway,7b2f5c190e1406cb,7b2f5c190e1406cb] [31868] [reactor-http-nio-2][?:]: stopped
2021-09-08 07:12:46.241 INFO [service-apiGateway,,] [31868] [parallel-1][?:]: doOnEach_onNext(0)
2021-09-08 07:12:46.242 INFO [service-apiGateway,,] [31868] [parallel-1][?:]: onComplete()
2021-09-08 07:12:46.242 INFO [service-apiGateway,,] [31868] [parallel-1][?:]: 0
在 Spring Cloud Gateway 中,Request Body 的 FluxReceive 使用的线程池和调用 GatewayFilter 的是同一个线程池,所以可能线程还是同一个,但是由于 Span 已经结束,从 ThreadLocal 的 Map 中已经移除了链路信息,所以日志中还是没有链路信息。
微信搜索“我的编程喵”关注公众号,每日一刷,轻松提升技术,斩获各种offer:
SpringCloud升级之路2020.0.x版-43.为何 SpringCloudGateway 中会有链路信息丢失相关推荐
- SpringCloud升级之路2020.0.x版-26.OpenFeign的组件
本系列代码地址:https://github.com/JoJoTec/spring-cloud-parent 首先,我们给出官方文档中的组件结构图: [外链图片转存失败,源站可能有防盗链机制,建议将图 ...
- SpringCloud升级之路2020.0.x版-13.UnderTow 核心配置
本系列代码地址:https://github.com/HashZhang/spring-cloud-scaffold/tree/master/spring-cloud-iiford Undertow ...
- SpringCloud升级之路2020.0.x版-12.UnderTow 简介与内部原理
本系列代码地址:https://github.com/HashZhang/spring-cloud-scaffold/tree/master/spring-cloud-iiford 在我们的项目中,我 ...
- SpringCloud升级之路2020.0.x版-41. SpringCloudGateway 基本流程讲解(3)
本系列代码地址:https://github.com/JoJoTec/spring-cloud-parent 我们继续分析上一节提到的 WebHandler.加入 Spring Cloud Sleut ...
- 2021-08-05SpringCloud升级之路2020.0.x版-5.所有项目的parent与spring-framework-common说明
本系列代码地址:https://github.com/HashZhang/spring-cloud-scaffold/tree/master/spring-cloud-iiford 源代码文件:htt ...
- Spring Cloud 升级之路 - 2020.0.x - 1. 背景知识、需求描述与公共依赖
1. 背景知识.需求描述与公共依赖 1.1. 背景知识 & 需求描述 Spring Cloud 官方文档说了,它是一个完整的微服务体系,用户可以通过使用 Spring Cloud 快速搭建一个 ...
- note8 升级android9,三星note8 N9500一键ADB升级One UI 9.0内测版
三星note8 N9500一键ADB升级One UI 9.0内测版是一款三星N9500 ADB一键升级9.0底包和刷机教程,三星 note8 安卓Pie,One UI .自己动手丰衣足食,抢不到官方资 ...
- 三星android安卓版本怎么升级,三星更改安卓9.0升级计划三款机型将可以升级到安卓9.0正式版...
描述 近日有网友发现三星中国更新了安卓9.0系统升级公告,和本月初那个公告相比,最明显的变化是国行Galaxy S9.S9+以及Galaxy Note9的升级时间提前到2019年1月,而原本计划是今年 ...
- 华为 android 5.0系统下载地址,华为emui5.0升级公告-emui 5.0官方版下载v5.0 官方最新版-西西软件下载...
emui5.0是关于华为最新的开发的一个手机的系统,对比其他的安卓系统来说,emui5.0的使用的界面可以说是十分的简洁,而且使用起来的体验也是十分的流畅,让用户能够享受到一个很不错的操作系统的体验, ...
最新文章
- 可突破任意ARP防火墙,以限制流量为目标的简单网络管理软件
- 1028 人口普查 (20 分)(c语言)
- Codeforces Round #192 (Div. 2)
- python语音信号时频分析_librosa-madmom:音频和音乐分析
- L - All in All(子序列)
- ACM-线段树区间更新+离散化
- 【LOJ#123】最小生成树,Kruskal模板
- Spoiler Alert – 实现内容模糊隐藏效果的 jQuery 插件
- HTML创建几个边框,使用HTML5创建多个边框
- 绕过“请在微信客户端打开链接”如微师下载视频等。
- 项目5—中断控制LED下降沿有效与低电平触发
- Linux笔记------关闭系统漏洞补丁(spectre meltdown补丁)
- android listview 图片闪烁,listView异步加载图片导致图片错位、闪烁、重复的问题的解决...
- p2197 nim游戏
- aspnet core 3.1 Kestrel Protocols Http1AndHttp2
- 总结40条常见的移动端Web页面问题及解决方案
- JavaScript - 停止计时器
- Pandas第三部分Day5练习题
- Windows Phone笔记(手机应用开发笔记)
- SegmentFault 巨献 1024 程序员护卫队#1红岸的呼唤