You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@rocketmq.apache.org by "Zhao jian (JIRA)" <ji...@apache.org> on 2017/10/27 02:53:00 UTC

[jira] [Created] (ROCKETMQ-305) When using FilterServer consumption, the client reports a timeout error

Zhao jian created ROCKETMQ-305:
----------------------------------

             Summary: When using FilterServer consumption, the client reports a timeout error
                 Key: ROCKETMQ-305
                 URL: https://issues.apache.org/jira/browse/ROCKETMQ-305
             Project: Apache RocketMQ
          Issue Type: Bug
         Environment: version : 4.1
config:
    2M/2S
    SYNC_MASTER
    SYNC_FLUSH
    filterServerNums=1
CentOS Linux release 7.2.1511
Linux 10.13.13.49 3.10.0-327.el7.x86_64 #1 SMP Thu Nov 19 22:10:57 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux
            Reporter: Zhao jian
            Assignee: vongosling


I used FilterServer in the deployment of the cluster, When the client consumes messages frequently reported timeout errors when requesting FilterServer. The client and server network latency is less than 2 milliseconds, and the time is consistent.

*consumer log:*

2017-10-27 10:40:19.830 Thread-22 RocketmqClient [WARN] execute the pull request exception
org.apache.rocketmq.client.exception.MQClientException: wait response from 10.15.224.214:44949 timeout :30000ms. Request: RemotingCommand [code=11, language=JAVA, version=232, opaque=1184254, flag(B)=0, remark=null, extFields={queueId=924, maxMsgNums=32, sysFlag=11, suspendTimeoutMillis=15000, commitOffset=171, topic=BenchmarkTest, queueOffset=171, subVersion=1509070444572, consumerGroup=zhaojian_test}, serializeTypeCurrentRPC=JSON]
For more information, please visit the url, http://rocketmq.apache.org/docs/faq/
	at org.apache.rocketmq.client.impl.MQClientAPIImpl$2.operationComplete(MQClientAPIImpl.java:603) [rocketmq-client-4.1.0-incubating.jar:4.1.0-incubating]
	at org.apache.rocketmq.remoting.netty.ResponseFuture.executeInvokeCallback(ResponseFuture.java:51) [rocketmq-remoting-4.1.0-incubating.jar:4.1.0-incubating]
	at org.apache.rocketmq.remoting.netty.NettyRemotingAbstract$2.run(NettyRemotingAbstract.java:275) [rocketmq-remoting-4.1.0-incubating.jar:4.1.0-incubating]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_11]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_11]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_11]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_11]
	at java.lang.Thread.run(Thread.java:745) [?:1.8.0_11]
2017-10-27 10:40:19.883 Thread-19 RocketmqRemoting [WARN] receive response, but not matched any request, 10.15.224.214:44949
2017-10-27 10:40:19.883 Thread-19 RocketmqRemoting [WARN] RemotingCommand [code=19, language=JAVA, version=232, opaque=714268, flag(B)=1, remark=null, extFields={suggestWhichBrokerId=0, nextBeginOffset=171, maxOffset=171, minOffset=0}, serializeTypeCurrentRPC=JSON]
2017-10-27 10:40:19.883 Thread-19 RocketmqRemoting [WARN] receive response, but not matched any request, 10.15.224.214:44949
2017-10-27 10:40:19.883 Thread-19 RocketmqRemoting [WARN] RemotingCommand [code=19, language=JAVA, version=232, opaque=714275, flag(B)=1, remark=null, extFields={suggestWhichBrokerId=0, nextBeginOffset=170, maxOffset=170, minOffset=0}, serializeTypeCurrentRPC=JSON]
2017-10-27 10:40:19.883 Thread-19 RocketmqRemoting [WARN] receive response, but not matched any request, 10.15.224.214:44949
2017-10-27 10:40:19.883 Thread-19 RocketmqRemoting [WARN] RemotingCommand [code=19, language=JAVA, version=232, opaque=714322, flag(B)=1, remark=null, extFields={suggestWhichBrokerId=0, nextBeginOffset=171, maxOffset=171, minOffset=0}, serializeTypeCurrentRPC=JSON]

*I added some log print on the client and FilterServer, found that the client sends a request FilterServer more than 15 seconds to process the request, this may be the reason for overtime, but I don't know how to troubleshoot and solve the problem.
The following is the content of the log*


*consumer log*
2017-10-27 10:46:45.633 Thread-18 RocketmqRemoting [INFO] send request success, code=11, opaque=1076871 [id: 0x8e5d2316, L:/10.15.244.244:44817 - R:/10.13.13.49:45238]
2017-10-27 10:47:18.820 Thread-24 RocketmqRemoting [WARN] RemotingCommand [code=19, language=JAVA, version=232, opaque=1076871, flag(B)=1, remark=null, extFields={suggestWhichBrokerId=0, nextBeginOffset=168, maxOffset=168, minOffset=0}, serializeTypeCurrentRPC=JSON]

*filtersrv.log*
2017-10-27 10:46:56 INFO RemotingExecutorThread_446 - receive request, 11 10.15.244.244:44817 RemotingCommand [code=11, language=JAVA, version=232, opaque=1076871, flag(B)=0, remark=null, extFields={queueId=399, maxMsgNums=32, sysFlag=11, suspendTimeoutMillis=15000, commitOffset=168, topic=BenchmarkTest, queueOffset=168, subVersion=1509070444572, consumerGroup=zhaojian_test}, serializeTypeCurrentRPC=JSON]



--
This message was sent by Atlassian JIRA
(v6.4.14#64029)