RocketMQ的invokeSync call timeout異常的解決辦法

萬貓學社發表於2022-02-22
MQ

緣起

在RocketMQ客戶端的DefaultMQPushConsumer的start方法被執行時，時不時會報出invokeSync call timeout異常，如下：

Caused by: java.lang.IllegalStateException: org.apache.rocketmq.remoting.exception.RemotingTimeoutException: invokeSync call timeout
	at org.apache.rocketmq.client.impl.factory.MQClientInstance.updateTopicRouteInfoFromNameServer(MQClientInstance.java:679) ~[rocketmq-client-4.7.1.jar:4.7.1]
	at org.apache.rocketmq.client.impl.factory.MQClientInstance.updateTopicRouteInfoFromNameServer(MQClientInstance.java:509) ~[rocketmq-client-4.7.1.jar:4.7.1]
	at org.apache.rocketmq.client.impl.consumer.DefaultMQPushConsumerImpl.updateTopicSubscribeInfoWhenSubscriptionChanged(DefaultMQPushConsumerImpl.java:872) ~[rocketmq-client-4.7.1.jar:4.7.1]
	at org.apache.rocketmq.client.impl.consumer.DefaultMQPushConsumerImpl.start(DefaultMQPushConsumerImpl.java:653) ~[rocketmq-client-4.7.1.jar:4.7.1]
	at org.apache.rocketmq.client.consumer.DefaultMQPushConsumer.start(DefaultMQPushConsumer.java:698) ~[rocketmq-client-4.7.1.jar:4.7.1]
	at cn.xdf.xcloud.rocketmq.support.DefaultRocketMQListenerContainer.start(DefaultRocketMQListenerContainer.java:276) ~[xcloud-rocketmq-core-1.2.0.RELEASE.jar:1.2.0.RELEASE]
	at cn.xdf.xcloud.rocketmq.autoconfigure.ListenerContainerConfiguration.registerContainer(ListenerContainerConfiguration.java:103) ~[xcloud-rocketmq-core-1.2.0.RELEASE.jar:1.2.0.RELEASE]
	... 12 common frames omitted
Caused by: org.apache.rocketmq.remoting.exception.RemotingTimeoutException: invokeSync call timeout
	at org.apache.rocketmq.remoting.netty.NettyRemotingClient.invokeSync(NettyRemotingClient.java:375) ~[rocketmq-remoting-4.7.1.jar:4.7.1]
	at org.apache.rocketmq.client.impl.MQClientAPIImpl.getTopicRouteInfoFromNameServer(MQClientAPIImpl.java:1363) ~[rocketmq-client-4.7.1.jar:4.7.1]
	at org.apache.rocketmq.client.impl.MQClientAPIImpl.getTopicRouteInfoFromNameServer(MQClientAPIImpl.java:1353) ~[rocketmq-client-4.7.1.jar:4.7.1]
	at org.apache.rocketmq.client.impl.factory.MQClientInstance.updateTopicRouteInfoFromNameServer(MQClientInstance.java:622) ~[rocketmq-client-4.7.1.jar:4.7.1]
	... 18 common frames omitted

如果著急馬上找到解決辦法，可以直接跳到解決辦法。不過，授人以魚，不如授之以漁。還是建議把尋找解決辦法的過程看完，第一：可以給你以後遇到類似問題提供解決思路；第二：雖然都報這個異常，但產生的原因可能不一樣。

尋找解決辦法之路

做為面向搜尋引擎程式設計的一員，立馬複製關鍵字invokeSync call timeout去搜尋引擎，得到的解決辦法總結起來有兩點：

  1. RocketMQ客戶端和服務端版本不一致，檢查了一下客戶端和服務端的版本，都是4.7.1。
  2. 降低RocketMQ客戶端的版本，這個我時不能接受的。

搜尋引擎無法解決，只能自己想辦法了。首先找到報異常的地方：

    public RemotingCommand invokeSync(String addr, final RemotingCommand request, long timeoutMillis)
        throws InterruptedException, RemotingConnectException, RemotingSendRequestException, RemotingTimeoutException {
        long beginStartTime = System.currentTimeMillis();
        final Channel channel = this.getAndCreateChannel(addr);
        if (channel != null && channel.isActive()) {
            try {
                doBeforeRpcHooks(addr, request);
                long costTime = System.currentTimeMillis() - beginStartTime;
                if (timeoutMillis < costTime) {
                    throw new RemotingTimeoutException("invokeSync call timeout");
                }
                RemotingCommand response = this.invokeSyncImpl(channel, request, timeoutMillis - costTime);
                doAfterRpcHooks(RemotingHelper.parseChannelRemoteAddr(channel), request, response);
                return response;
            }
            //省略部分無關程式碼
        } else {
            this.closeChannel(addr, channel);
            throw new RemotingConnectException(addr);
        }
    }

原來是因為程式碼執行的時間過長，才報出了invokeSync call timeout異常。首先想到的是延長超時時間，繼續分析原始碼，向上尋找呼叫方，發現在MQClientInstance的updateTopicRouteInfoFromNameServer方法中有：

topicRouteData = this.mQClientAPIImpl.getTopicRouteInfoFromNameServer(topic, 1000 * 3);

居然是寫死了3秒，沒有辦法修改，我竟無語凝噎。

再向下一步一步地分析原始碼，到底是哪裡慢？

org.apache.rocketmq.remoting.netty.NettyRemotingClient.getAndCreateChannel
org.apache.rocketmq.remoting.netty.NettyRemotingClient.getAndCreateNameserverChannel
org.apache.rocketmq.remoting.netty.NettyRemotingClient.createChannel
io.netty.bootstrap.Bootstrap.connect(java.net.SocketAddress)
io.netty.bootstrap.Bootstrap.doResolveAndConnect
io.netty.bootstrap.AbstractBootstrap.initAndRegister
io.netty.bootstrap.ChannelFactory.newChannel
io.netty.channel.socket.nio.NioSocketChannel.NioSocketChannel()
io.netty.channel.nio.AbstractNioChannel.AbstractNioChannel
io.netty.channel.AbstractChannel.AbstractChannel(io.netty.channel.Channel)
io.netty.channel.AbstractChannel.newId
io.netty.channel.DefaultChannelId.newInstance

最終找到了：

    public static DefaultChannelId newInstance() {
        return new DefaultChannelId();
    }

在建立DefaultChannelId的例項時，執行了這個類的靜態程式碼塊，就是這段靜態程式碼塊比較耗時。

那麼，解決辦法就有了，提前載入DefaultChannelId類，使其靜態程式碼塊先執行完成。

解決辦法

在呼叫DefaultMQPushConsumer的start方法之前，插入如下程式碼：

DefaultChannelId.newInstance();

微信公眾號：萬貓學社

微信掃描二維碼

關注後回覆「電子書」

獲取12本Java必讀技術書籍

RocketMQ的invokeSync call timeout異常的解決辦法

最後，感謝你的點贊和關注，帥氣又美麗。

相關文章