记一次dubbo服务发现导致的OOM

某个平凡的下午,我们突然收到大量的线上告警:应用A的老年代内存使用率大于95%。登陆到监控管理平台可以看到3点半之后该应用的老年代内存使用率一路飙升,直逼100%,接着年轻代也一路上升。

记一次dubbo服务发现导致的OOM
我们查看了一下进来的请求也很平稳,并没有突然爆发,那这个地方的罪魁祸首会是谁呢?为了方便读者接下来的阅读,在介绍这次故障之前,我们首先介绍一下我司的dubbo服务发现的流程。

dubbo服务发现流程

我们的开发人员在使用远程服务的时候首先需要配置一个dubbo xml文件或者在使用的地方加上@Reference,二者都是用来对dubbo消费者引用服务进行一些配置,然后应用在启动的时候会将配置信息转化为一个ReferenceBean对象,并调用createProxy方法创建一个远程服务接口的代理对象。因为我们的消费者并不是和服务端直接地址相连的,而是订阅到公司的注册中心etcd上。订阅完之后会显示地调用一次notify接口,这个接口会尝试将远程服务注册的url转换成一个本地的invoker,如果消费者端配置的消费protocol时dubbo的,就会生成一个dubbo invoker;如果配置的是rest,就会生成一个rest invoker;如果消费端的protocol什么都没有配置,那么服务端提供什么服务,它就会生成什么服务的invoker。

第二个流程是应用启动完毕之后,如果服务注册地址发生了改变的话,会通知给消费者,注意这个地方dubbo协议里面明确讲到全量更新而不是增量更新。也就是说如果服务端有100台机器,现在其中某一台服务器我重启了,这个时候这台服务器的注册url就会发生变化,但是注册中心会将这100台机器的注册url全部通知给消费者。消费者会拿着更新之后的服务url尝试更新本地的invoker,如果这个url之前已经成功创建过invoker的话,那么就不会再创建了,如果没有的话就会去尝试创建。
记一次dubbo服务发现导致的OOM

熟悉相关概念和流程之后,接下来我们会详细介绍一下我们定位OOM的过程。

## OOM定位
我们登陆到故障机器,查看jvm内存的使用情况。
记一次dubbo服务发现导致的OOM
可以看到是hashmap的entry太多,难道是哪位童鞋使用了一个全局hashmap,并且忘了清理不用的数据了吗?但是即使要用hashmap一般也不太会用fastjson的IdentityHashMap啊?并且我们在应用中也没看到相关的使用代码。为了做更进一步的分析,我们通过jmap命令生成内存dump文件,并在运维的帮助下下载到本地,利用工具MAT对其进行分析。
记一次dubbo服务发现导致的OOM
从概况下可以看到,大对象占用了大概2.4G的内存空间。然后我们对dominator_tree进行分析,可以定位到大对象是dubbo协议类RestProtocol的一个list。
记一次dubbo服务发现导致的OOM
找到RestProtocol代码,我们可以定位到属性List clients,这个对象是一个Collections.synchronizedList(new LinkedList())。RestProtocol协议对象在生成远程服务invoker的时候会往这个list里面添加ResteasyClient对象,并且在它的生命周期结束之后才会把这个list清理掉。我们猜测由于某种原因导致这个RestProtocol对象不停的生成invoker,直至OOM。至此我们算是定位到OOM的地方,接下来将会探寻具体的泄漏原因。

内存泄漏分析

clients.add这块到底发生了什么?

我们在本地启动应用A,调试一下dubbo服务发现的过程,在RestProtocol的clients.add(client)打上断点。
记一次dubbo服务发现导致的OOM
从右下角的方框我们可以看到远程服务是应用B的interface xx.xx.service.ItemLockService,并且提供的是rest服务。我们继续调试往下走,结果在调用target.proxy方法的时候发生异常,导致生成rest invoker失败了。我们定位到异常的地方发现httpMethod为null。
记一次dubbo服务发现导致的OOM
我们找到应用B的ItemLockService服务,查看它的源代码,发现它的注解写在实现类而不是接口上面,导致消费端无法共享相应的REST配置信息,比如httpMethod等。这样消费者在创建rest invoker建立连接的时候就会因为不知道httpMethod而失败。
记一次dubbo服务发现导致的OOM

为什么消费者会去创建rest invoker?

到目前为止,我们知道消费者在创建rest invoker的时候,尝试和服务端建立rest连接,最后却失败了,并且导致rest invoker也没有创建成功,那么为什么消费者会去创建rest invoker呢?从上面图6的历史堆栈信息,我们发现ItemLockService服务的ReferenceConfig中的protocol为null,我们找到应用A消费端配置信息,发现itemLockService消费端没有配置protocol这个字段。从下面的图9可以看出,如果消费者配置protocol字段的话,会根据这个protocol对服务端提供的协议进行过滤。如果没有配置的话,会创建服务端提供的所有协议的invoker,ItemLockService服务端提供两种协议,即dubbo和rest,所以这个地方应用A的消费端会创建rest invoker。
记一次dubbo服务发现导致的OOM

为什么会重复创建rest invoker?

到这里,我们知道ItemLockService的消费者因为没有配置protocol字段导致会去创建rest invoker,并且会创建失败,但是为什么会去重复创建rest invoker呢?接下来我们需要探寻一下创建rest invoker的时机。消费者一般在两个场景下会去rest invoker,一个是应用启动的时候消费者在订阅到注册中心的时候,会主动拉去服务注册地址;另一个场景是当服务注册地址,即invoker url发生变化之后,注册中心会将变化之后的invoker url通知给消费端,这个时候消费端会将新的invoker url转换成invokers,如果这个url没有创建成功过invoker,就会尝试重新创建invoker。而消费者每次在创建rest invoker的时候都会失败,这样就会导致下次收到服务端的消息通知的时候还会去创建invoker。

真相大白

在和商品中心沟通之后,我们了解到他们下午3点半左右重新发布了应用B,应用B的100台机器是依次上线的,至此我们可以还原整个事情发生的过程:
1)应用A在调用应用B的ItemLockService服务时,它的消费端dubbo reference没有配置protocol,应用正常启动,但是它的rest invoker都创建失败了。
2)应用B机器有100台,然后发布的时候这些机器依次启动,每启动一台就会导致注册中心上ItemLockService服务的注册地址都会发生变化,每次变化都会导致注册中心会通知一次消费者,这样注册中心会通知100次消费者。
3)注册中心每次把变化之后的地址通知给消费者的时候,消费者这边会根据这个注册地址列表重新生成rest invoker,这个注册地址列表会包含当前在线的100台应用B的机器。由于之前所有的rest invoker都创建失败了,所以这次需要对这100个url生成rest invoker,这样每次注册中心通知一次消费者,消费者都要去创建100次invoker,并且都创建失败,这样下次会接着创建。
4)RestProtocol每次根据url创建rest invoker的时候,会生成ResteasyClient大对象,并且把这个对象放到列表里面去,这样应用B发布一次的话,就会创建100*100=10000个大对象,于是就导致了内存的溢出。
这也解释了为什么故障发生之后我们重启了应用A就临时解决了内存溢出的问题,但是一旦应用B重新发布的时候,应用A就会OOM。

思考

对开发人员来说,这个问题主要是由于使用方没有配置protocol字段所致,所以平时在写代码的时候尽量了解参数具体的含义,否则可能会出现一些意料之外的场景。
对dubbo框架而言,需要做好参数校验和防御性编程。在本次故障之后,我们中间件童鞋添加了如下代码:
记一次dubbo服务发现导致的OOM
另外目前ResteasyClient对象由RestProtocol协议对象持有,只有当RestProtocol对象销毁的时候才会把restclient对象销毁掉,这样是否合适?对于那种没有创建成功invoker的场景是不是应该把其对应的ResteasyClient销毁掉会更合适一点,因此认为可以对代码做如下修改:

ResteasyClient client = new ResteasyClientBuilder().httpEngine(engine).build();

client.register(RpcContextFilter.class);  
for (String clazz : Constants.COMMA_SPLIT_PATTERN.split(url.getParameter(Constants.EXTENSION_KEY, ""))) {  
    if (!StringUtils.isEmpty(clazz)) {
        try {
            client.register(Thread.currentThread().getContextClassLoader().loadClass(clazz.trim()));
        } catch (ClassNotFoundException e) {
            throw new RpcException("Error loading JAX-RS extension class: " + clazz.trim(), e);
        }
    }
}

// TODO protocol
ResteasyWebTarget target = client.target("http://" + url.getHost() + ":" + url.getPort() + "/" + getContextPath(url));  
try{  
    T t=target.proxy(serviceType);
    //invoker创建成功才会存储client
    clients.add(client);
    return t;
}catch(Exception e){
    logger.warn("fail to create proxy,serviceType:{}",serviceType,e);
    //invoker创建失败的话会把client也一起销毁掉
    try {
        if(null!=client){
            client.close();
        }
    } catch (Throwable t) {
        logger.warn("Error closing rest client", t);
    }
    throw e;
}

因此我们给apache dubbo提了个issue,从沟通的结果来看,也有其他的开发者碰到了这个问题,在pull request 4629里面他们详细记录了解决方案。他们首先用Map代替之前的List,key为url,这样可以保证同一个url只会创建一次ResteasyClient,接着为了进一步保证能够回收不用的ResteasyClient,他们又引入了WeakHashMap了,至此OOM的问题算是彻底解决了。

记一次dubbo服务发现导致的OOM

上一篇:线上服务的FGC问题排查,看这篇就够了!


下一篇:Java 并发编程:AQS 的自旋锁