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

本文转载自微信公众号「 搬运工来架构」,转载本文请联系 搬运工来架构公众号。

10年积累的成都网站建设、成都网站制作经验,可以快速应对客户对网站的新想法和需求。提供各种问题对应的解决方案。让选择我们的客户得到更好、更有力的网络服务。我虽然不认识你,你也不认识我。但先网站设计后付款的网站建设流程,更有习水免费网站建设让你可以放心的选择与我们合作。

[[329425]]

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

如下图:

 

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

当前使用的开发环境:操作系统是Windows10,JDK8,rocketMQ为4.5.2。

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

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

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

使用trace命令:

trace命令

方法内部调用路径,并输出方法路径上的每个节点上耗时。

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

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

 

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

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

 
 
 
 
  1. trace org.apache.rocketmq.client.consumer.DefaultMQPullConsumer  

 

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

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

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

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

 

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

 

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

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

 
 
 
 
  1. trace org.apache.rocketmq.client.ClientConfig cloneClientConfig 

 

接着看ClientConfig#cloneClientConfig方法:

 
 
 
 
  1. public ClientConfig cloneClientConfig() { 
  2.     ClientConfig cc = new ClientConfig(); 
  3.     cc.namesrvAddr = namesrvAddr; 
  4.     cc.clientIP = clientIP; 
  5.     cc.instanceName = instanceName; 
  6.     cc.clientCallbackExecutorThreads = clientCallbackExecutorThreads; 
  7.     cc.pollNameServerInterval = pollNameServerInterval; 
  8.     cc.heartbeatBrokerInterval = heartbeatBrokerInterval; 
  9.     cc.persistConsumerOffsetInterval = persistConsumerOffsetInterval; 
  10.     cc.unitMode = unitMode; 
  11.     cc.unitName = unitName; 
  12.     cc.vipChannelEnabled = vipChannelEnabled; 
  13.     cc.useTLS = useTLS; 
  14.     cc.namespace = namespace; 
  15.     cc.language = language; 
  16.     return cc; 

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

 
 
 
 
  1. trace org.apache.rocketmq.client.ClientConfig  

 

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

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

 

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

接着想查看JDK函数调用:

 
 
 
 
  1. 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。

 
 
 
 
  1. options unsafe true 

 

开启完成。

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

 

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

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

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

 
 
 
 
  1. public static Enumeration getNetworkInterfaces() 
  2.     throws SocketException { 
  3.     final NetworkInterface[] netifs = getAll(); 
  4.     // specified to return null if no network interfaces 
  5.     if (netifs == null) 
  6.         return null; 
  7.     return new Enumeration() { 
  8.         private int i = 0; 
  9.         public NetworkInterface nextElement() { 
  10.             if (netifs != null && i < netifs.length) { 
  11.                 NetworkInterface netif = netifs[i++]; 
  12.                 return netif; 
  13.             } else { 
  14.                 throw new NoSuchElementException(); 
  15.             } 
  16.         } 
  17.         public boolean hasMoreElements() { 
  18.             return (netifs != null && i < netifs.length); 
  19.         } 
  20.     }; 
  21. private native static NetworkInterface[] getAll() throws SocketException; 

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

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

 

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

 

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

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

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

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

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

总结

 

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

 

网站名称:rocketMQ很慢?引出了一个未解之谜
URL分享:http://www.shufengxianlan.com/qtweb/news43/241493.html

网站建设、网络推广公司-创新互联,是专注品牌与效果的网站制作,网络营销seo公司;服务项目有等

广告

声明:本网站发布的内容(图片、视频和文字)以用户投稿、用户转载内容为主,如果涉及侵权请尽快告知,我们将会在第一时间删除。文章观点不代表本网站立场,如需处理请联系客服。电话:028-86922220;邮箱:631063699@qq.com。内容未经允许不得转载,或转载时需注明来源: 创新互联