记一次线上rocketmq耗时很久的bug

问题

接口耗时久。

代码如下

    @PostMapping("/checkmqtime")
    public long checkMqTime(@RequestBody MqDto mqDto){
        long time = System.currentTimeMillis();

        DefaultMQPullConsumer defaultMQPullConsumer = new DefaultMQPullConsumer();
        defaultMQPullConsumer.setNamesrvAddr(mqDto.getEndPoint());
        // 重点：新建连接mq信息
        defaultMQPullConsumer.setUnitMode(true);
        defaultMQPullConsumer.setUnitName("aa");

        defaultMQPullConsumer.setConsumerGroup(mqDto.getCheckConsumerGroup());
        try {
            System.out.println("init" + (System.currentTimeMillis() - time));
            defaultMQPullConsumer.start();
            System.out.println("lianjie" + (System.currentTimeMillis() - time));
            Set<MessageQueue> mqs = defaultMQPullConsumer.fetchSubscribeMessageQueues(mqDto.getTopic());
            System.out.println("fetch queue" + (System.currentTimeMillis() - time));
            for (MessageQueue mq : mqs) {

                long min = 0;
                long max = 0;

                min = defaultMQPullConsumer.minOffset(mq);
                max = defaultMQPullConsumer.maxOffset(mq);


//                if (min <= mqDto.getFirst() && mqDto.getLast() <= max) {
//                    return true;
//                }
                System.out.println("每次耗时" + (System.currentTimeMillis() - time));
            }
        } catch (MQClientException e) {
            System.out.println("mqDto = " + e);
        } finally {
            defaultMQPullConsumer.shutdown();
        }

        return System.currentTimeMillis() - time;
    }

    public static void main(String[] args) throws SocketException {
        long time = System.currentTimeMillis();
        NetworkInterface.getNetworkInterfaces();
        System.out.println("每次耗时" + (System.currentTimeMillis() - time));
    }
}

开始分析解决问题

1. Arthas 借助分析

获取arthas，启动服务
$ $curl -O https://arthas.aliyun.com/arthas-demo.jar
$ $java -jar arthas-boot.jar

选择应用java进程：
$ $ava -jar arthas-boot.jar
* [1]: 35542
  [2]: 71560 arthas-demo.jar
选择需要查看的序号即可：
[INFO] Try to attach process 71560
[INFO] Attach process 71560 success.
[INFO] arthas-client connect 127.0.0.1 3658
  ,---.  ,------. ,--------.,--.  ,--.  ,---.   ,---.
 /  O  \ |  .--. ''--.  .--'|  '--'  | /  O  \ '   .-'
|  .-.  ||  '--'.'   |  |   |  .--.  ||  .-.  |`.  `-.
|  | |  ||  |\  \    |  |   |  |  |  ||  | |  |.-'    |
`--' `--'`--' '--'   `--'   `--'  `--'`--' `--'`-----'
 
wiki: https://arthas.aliyun.com/doc
version: 3.0.5.20181127201536
pid: 71560
time: 2018-11-28 19:16:24
 
$ $
这样即可进入到使用开始。但是现场问题就是那么步走寻常路，第一次启动arthas，需要加载用到插件，在内网环境使用不了的，所以，需要从有网络的环境下拷贝插件包到内网环境即可。

3. 分析耗时具体位置

使用trace命令查询：
	trace com.example.springboottest.controller.RocketController  checkMqTime
结果如下图，然后逐层分析。
分析后卡顿地方：
1、卡顿1
	trace java.net.NetworkInterface getAll(本地复现发现问题，windows系统)
2、卡顿2
	trace org.apache.rocketmq.common.UtilAll getPid (现场问题，该地方就需要10s)

分析耗时具体原因

1、卡顿1

查看代码为如下：
	private native static NetworkInterface[] getAll() throws SocketException;
需要查看c源码,登录AndroidXRef网站（http://androidxref.com/），然后选择对应版本，进行查找，搜索关键词为“类名_方法名”

结论：暂未具体分析出来

2、卡顿2

查看代码为如下：
	public static int getPid() {
        RuntimeMXBean runtime = ManagementFactory.getRuntimeMXBean();
        String name = runtime.getName();// 耗时10s

        try {
            return Integer.parseInt(name.substring(0, name.indexOf(64)));
        } catch (Exception var3) {
            return -1;
        }
    }
    
 结论：
 	具体原因如下图所示，因为InetAddress.getLocalHost().getHostName()获取很慢，具体可以参考   https://stackoverflow.com/questions/7388847/does-inetaddress-getlocalhost-gethostaddress-involve-dns-server#:~:text=InetAddress%20%28in%20particular%2C%20the%20result%20of%20InetAddress.getLocalHost%20%28%29%29,-%20it%20may%20perform%20a%20reverse%20DNS%20lookup%3A
 	去修改服务的dns信息。
 	发现 cat /etc/hosts 中设置的ip对应的主机名和 /etc/sysconfig/network 中设置的主机名不一致导致的，修改为一致就可以了(待验证)

注，参考资料：

• RocketMQ 很慢？引出了一个未解之谜 ：https://blog.csdn.net/alisystemsoftware/article/details/110393552
• arthas 官方文档 : https://arthas.aliyun.com/doc/quick-start.html
• 如何查看Java中的native源码 ： https://blog.csdn.net/LosingCarryJie/article/details/78244823
• RuntimeMXBean getName 耗时长 : https://blog.csdn.net/liyun919/article/details/102615307