skywalking 引起 spring-cloud-gateway 的内存溢出 skywalking的bug

大家好，我是烤鸭：

   又是个线上问题记录，这次坑惨了，开源软件也不是万能的，还是要做好压测和灰度。

问题

上游反馈大量超时，不止某一个服务，查看服务没有问题，猜测是网络或者环境问题。

想到网关接入了skywaling（已接入24小时），回滚后问题消失。

堆内存在某个时间点后上升且无法回收。

Full GC 时间变得特别长…这个就是上游超时的原因

环境

cloud版本

<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-gateway</artifactId>
<version>2.2.3.RELEASE</version>

skywalking 版本

<artifactId>java-agent-sniffer</artifactId>
<groupId>org.apache.skywalking</groupId>
<version>8.9.0</version>

复现

说实话，当时我本地起了，压测了一天，并没有出现OOM的情况，事实证明，还是量不够大。

后来同事找到了病根（下面两种情况原因是一样的）

1. TracingContext中的activeSpanStack在某些场景下没有清空，就是下面这个。

或者是

2. IgnoredTracerContext的 stackDepth 不等于0

最终的结果都是 ContextManager.Context/RuntimeContext 未清空，导致内存泄露

调试

可以参考这篇文章 https://www.jianshu.com/p/ba9254f38fa5

因为我只想调试网关相关包，把下载失败的包和编译失败的包都注释掉了，再在网关项目的导入module。

导入完了，结构如下图，该注释的注释，能编译打包就行。

断点打在 gateway-2.1.x-plugin的几个拦截器，可以看到debug成功

源码解析

剩下就跟着代码一步一步走了。

几个拦截器的顺序是 NettyRoutingFilterInterceptor -> HttpClientFinalizerSendInterceptor -> HttpClientFinalizerResponseConnectionInterceptor

可以看到 NettyRoutingFilterInterceptor 初次进入会执行 ContextManager.createLocalSpan

创建span对象(全链路用到的流转对象，感兴趣的可以看看谷歌的dapper https://blog.csdn.net/ruizhikai_ztq/article/details/123663633)

@Override
public void beforeMethod(EnhancedInstance objInst, Method method, Object[] allArguments, Class<?>[] argumentsTypes,
                         MethodInterceptResult result) throws Throwable {
    ServerWebExchange exchange = (ServerWebExchange) allArguments[0];
    EnhancedInstance enhancedInstance = getInstance(exchange);

    AbstractSpan span = ContextManager.createLocalSpan("SpringCloudGateway/RoutingFilter");
    if (enhancedInstance != null && enhancedInstance.getSkyWalkingDynamicField() != null) {
        ContextManager.continued((ContextSnapshot) enhancedInstance.getSkyWalkingDynamicField());
    }
    span.setComponent(SPRING_CLOUD_GATEWAY);
}

createLocalSpan，这里的两个实现，是否忽略trace，由于我引入了

apm-trace-ignore-plugin-8.9.0.jar 这个包，实现会走 ignore的，也就是复现里的第二种情况

这个方法里有一个栈深度 stackDepth 字段，只要创建span就会自增，删除span就会自减。

@Override
public AbstractSpan createLocalSpan(String operationName) {
    stackDepth++;
    return NOOP_SPAN;
}

@Override
public boolean stopSpan(AbstractSpan span) {
    stackDepth--;
    if (stackDepth == 0) {
        ListenerManager.notifyFinish(this);
    }
    return stackDepth == 0;
}

一般来说的话，方法的Interceptor的 beforeMethod 会执行

ContextManager.createLocalSpan();

afterMethod 会执行

AbstractSpan span = ContextManager.activeSpan();
ContextManager.stopSpan(span);

但是很多中间件的某些场景都是异步的，尤其网关是响应式的，所以入口和出口也可能在不同的类里。

比如网关的 createLocalSpan 是在 NettyRoutingFilterInterceptor

而 stopSpan 是在 HttpClientFinalizerSendInterceptor

再看下上面的 stopSpan 方法的调用的地方

stopSpan 方法返回值是根据 stackDepth 是否为0来的，如果 stackDepth != 0，返回false

那这种就有点危险了，如果有方法触发了 createLocalSpan 而后续没有执行 stopSpan 就会出现内存无法回收。

比如只执行了 NettyRoutingFilterInterceptor 而没有执行 HttpClientFinalizerSendInterceptor

网关异常代码

这种问题很长时间都没有人反馈，说明还是小众的。主要是我们写的不规范也有一定的原因。（不要问，问就是开源全锅）

public class CorsResponseHeaderFilter implements GlobalFilter{
    @Override
    public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain) {
        return chain.filter(exchange).then(Mono.defer(() -> {
            exchange.getResponse().getHeaders().entrySet().stream()
                    .filter(kv -> !CollectionUtils.isEmpty(kv.getValue()))
                    .filter(kv -> (
                            kv.getKey().equals(HttpHeaders.ACCESS_CONTROL_ALLOW_ORIGIN)
                                    || kv.getKey().equals(HttpHeaders.ACCESS_CONTROL_ALLOW_CREDENTIALS)
                                    || kv.getKey().equals(HttpHeaders.ACCESS_CONTROL_ALLOW_METHODS)
                                    || kv.getKey().equals(HttpHeaders.ACCESS_CONTROL_ALLOW_HEADERS)
                                    || kv.getKey().equals(HttpHeaders.ACCESS_CONTROL_MAX_AGE)))
                    .forEach(kv -> {
                        kv.setValue(new ArrayList<String>() {
                            {
                                add(kv.getValue().get(0));
                            }
                        });
                    });
            return chain.filter(exchange);
        }));
    }

}

这段代码主要是解决网关跨域的问题，记得有一些后台页面对返回的头有限制，所以做了这个逻辑处理，过滤一些响应头和指定格式。

乍一看没啥问题，问题就出现在 Mono.defer，一般我们使用的多的是Mono.just。

看一下官方文章这俩有啥区别 https://projectreactor.io/docs/core/release/api/reactor/core/publisher/Mono.html#create-java.util.function.Consumer-

简单介绍一下常用的api：

Mono.just 饿汉式：立即执行

Mono.defer 懒汉式：发布之后，等待订阅者来执行(有延迟)

Mono.create 完全自主控制：发布之后，自己添加/移除监听器，并且手动写回调

问题解决

饶了一大圈，在本应该skywalking 的gateway interceptor 走完了之后，stackDepth 为0。

而 Mono.defer 操作，又进入了 NettyRoutingFilterInterceptor，执行了 createLocalSpan，stackDepth ++，再之后的CONTEXT就无法remove了，造成内存泄漏。

访问两次之后就会出现这种情况了。

同事已经给修了。

https://github.com/apache/skywalking-java/pull/133

同一个链路上 ServerWebExchange.getAttributes() 是一直有的，进入的时候放一次，再次进入判断一下如果是同一个链路的话，就不再执行后面的代码了（避免重复创建span）

总结

开源项目就是有这样的魅力，发现其中问题，再fix提交。

不过线上运行也确实是坑啊，之前有别的网关已经接过了，没问题，就直接上了。

但是每个网关项目本身也不一样，一个小小的过滤器有这么大的能量。

额外说一句，一定要灰度！！！