rocketMQ 很慢？引出了一个未解之谜

本文转载自微信公众号「 搬运工来架构」，慢引转载本文请联系 搬运工来架构公众号。未解

前段时间发现，慢引在使用rockerMQ console时，未解查询消息的慢引时候出现很慢，查询耗时大于10秒，未解少则5、慢引6秒，未解多则14+秒。慢引

如下图：

这到底是未解为什么?查询消息为啥会出现这么大的耗时?

当前使用的开发环境：操作系统是Windows10，JDK8，慢引rocketMQ为4.5.2。未解

在其它机器上则没有此问题，慢引也在本机器上的未解虚拟机VMware上安装的Linux部署了rocketMQ 和 console，并且验证是慢引没问题的。

那么到底我的机器是怎么了???

由于当前是接口的耗时问题，我们并不知道耗时主要在哪个地方，所以使用Arthas来跟踪下调用链的耗时。

使用trace命令：

trace命令

方法内部调用路径，并输出方法路径上的b2b供应网每个节点上耗时。

trace 命令能主动搜索 class-pattern/method-pattern 对应的方法调用路径，渲染和统计整个调用链路上的所有性能开销和追踪调用链路。

trace org.apache.rocketmq.console.service.impl.MessageServiceImpl queryMessageByTopic

从当前调用路径得到主要耗时在于：DefaultMQPullConsumer构造器初始化 + DefaultMQPullConsumer启动耗时。那么接下来我们继续往内部跟进。

此时我们关注下DefaultMQPullConsumer构造器初始化：

trace org.apache.rocketmq.client.consumer.DefaultMQPullConsumer <init> 

从构造器初始化入口看，耗时并不大。

那么接下来再看下DefaultMQPullConsumer的启动方法：

[E] 开启正则表达式匹配，默认为通配符匹配

trace -E  org.apache.rocketmq.client.consumer.DefaultMQPullConsumer start 

trace -E org.apache.rocketmq.client.consumer.DefaultMQPullConsumer |start

接着发现耗时主要是在获取MQClientInstance实例。

trace org.apache.rocketmq.client.impl.MQClientManager getAndCreateMQClientInstance  

trace org.apache.rocketmq.client.ClientConfig cloneClientConfig 

接着看ClientConfig#cloneClientConfig方法：

public ClientConfig cloneClientConfig() {     ClientConfig cc = new ClientConfig();     cc.namesrvAddr = namesrvAddr;     cc.clientIP = clientIP;     cc.instanceName = instanceName;     cc.clientCallbackExecutorThreads = clientCallbackExecutorThreads;     cc.pollNameServerInterval = pollNameServerInterval;     cc.heartbeatBrokerInterval = heartbeatBrokerInterval;     cc.persistConsumerOffsetInterval = persistConsumerOffsetInterval;     cc.unitMode = unitMode;     cc.unitName = unitName;     cc.vipChannelEnabled = vipChannelEnabled;     cc.useTLS = useTLS;     cc.namespace = namespace;     cc.language = language;     return cc; } 

可以看到很多赋值操作，这些可以不关注，只要关注new ClientConfig()：

trace org.apache.rocketmq.client.ClientConfig <init> 

可以看到主要耗时在3~4秒，并且耗时主要是这个工具类方法：RemotingUtil#getLocalAddress

trace org.apache.rocketmq.remoting.common.RemotingUtil getLocalAddress 

到现在，已经跟踪到JDK方法调用了：NetworkInterface#getNetworkInterfaces。

接着想查看JDK函数调用：

trace --skipJDKMethod false java.net.NetworkInterface getNetworkInterfaces 

--skipJDKMethod skip jdk method trace, default value true.

默认情况下，trace不会包含jdk里的函数调用，如果希望trace jdk里的函数，需要显式设置--skipJDKMethod false。

此时不能跟踪，那么根据4点提示排查和issue：https://github.com/alibaba/arthas/issues/47

https://github.com/alibaba/arthas/issues/807

最后确定需要开启unsafe。

options unsafe true 

开启完成。

再次执行，即可看到jdk的调用链了。

到这里，算是服务器托管把rocketMQ console查询慢的罪魁祸首找到了：在获取本机网卡接口时，出现耗时时间长。这其实也算是jdk跟操作系统层面的意思了，与中间件rocketMQ无关，一开始我是怀疑是不是持久化存储在加载时慢的可能(基本排除)。

那么为什么会调用当前操作系统的网卡接口时会出现耗时严重呢?

此时关注到了java.net.NetworkInterface#getNetworkInterfaces

public static Enumeration<NetworkInterface> getNetworkInterfaces()     throws SocketException {     final NetworkInterface[] netifs = getAll();     // specified to return null if no network interfaces     if (netifs == null)         return null;     return new Enumeration<NetworkInterface>() {         private int i = 0;         public NetworkInterface nextElement() {             if (netifs != null && i < netifs.length) {                 NetworkInterface netif = netifs[i++];                 return netif;             } else {                 throw new NoSuchElementException();             }         }         public boolean hasMoreElements() {             return (netifs != null && i < netifs.length);         }     }; } private native static NetworkInterface[] getAll() throws SocketException; 

可以看到jdk函数已经调用到了native方法，也就是jdk底层的实现(c/c++)了，跟操作系统非常紧密。

接着debug进getNetworkInterfaces方法查看到底有哪些网卡接口：

一查发现竟然有81个!接着查看本机的网络适配器：

本机Windows上有Wlan、vpn、VMware等网络适配器。

最后事实就是跟他们有关，我把相应的适配器禁用之后，重新调用NetworkInterface#getNetworkInterfaces，此时耗时从3+秒降到几百毫秒。

最后，很遗憾还是没能剖析出为什么Windows下调用网卡接口native方法会出现那么大耗时。并且肯定跟我的机器有关，云南idc服务商因为其他机器验证没有问题。

如果要剖析原因，就得需要有c/c++更加底层的功底才能搞定吧?

如果你有遇过知道怎么解决、或熟悉底层实现或者有更好的思路麻烦留言指导下。(抱拳)

总结

Windows下可能容易出现一些非正常问题，竟然也能给我遇到这个^@^。幸好一般使用Windows还是比较少，除非是开发机器较多，Linux(unix)部署rocketMQ等中间件还是很稳的。 使用Arthas trace可以跟踪方法的调用路径，并且追踪每一步的耗时，可以方便的排查瓶颈问题。 -E参数支持正则表达式匹配;--skipJDKMethod false支持包含JDK的函数调用;跟踪jdk函数等，如果找不到对应类或者方法，可能需要开启unsafe。