You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@rocketmq.apache.org by GitBox <gi...@apache.org> on 2022/01/07 08:16:09 UTC
[GitHub] [rocketmq] yrg5101 opened a new issue #3726: rocketmq客户端 invokeSync: close socket because of timeout, 3000ms
yrg5101 opened a new issue #3726:
URL: https://github.com/apache/rocketmq/issues/3726
rocketmq版本信息：4.9.1
springboot:
<groupId>org.apache.rocketmq</groupId>
<artifactId>rocketmq-spring-boot-starter</artifactId>
<version>2.2.1</version>
客户端报错:(一直报这个信息)
15:50:28.835 [MQClientFactoryScheduledThread] INFO RocketmqRemoting - [info,90] - createChannel: begin to connect remote host[x.x.x.x:10911] asynchronously
15:50:28.835 [NettyClientWorkerThread_4] INFO RocketmqRemoting - [info,90] - NETTY CLIENT PIPELINE: CLOSE x.x.x.x:10911
15:50:28.835 [NettyClientWorkerThread_4] INFO RocketmqRemoting - [info,90] - eventCloseChannel: the channel[null] has been removed from the channel table before
15:50:28.835 [NettyClientWorkerThread_2] INFO RocketmqRemoting - [info,95] - NETTY CLIENT PIPELINE: CONNECT UNKNOWN => x.x.x.x:10911
15:50:28.836 [NettyClientSelector_1] INFO RocketmqRemoting - [info,95] - closeChannel: close the connection to remote address[x.x.x.x:10911] result: true
15:50:28.853 [MQClientFactoryScheduledThread] INFO RocketmqRemoting - [info,95] - createChannel: connect remote host[x.x.x.x:10911] success, AbstractBootstrap$PendingRegistrationPromise@2bcc4a73(success)
15:50:28.959 [MQClientFactoryScheduledThread] INFO RocketmqRemoting - [info,95] - closeChannel: begin close the channel[x.x.x.x:10911] Found: true
15:50:28.959 [MQClientFactoryScheduledThread] INFO RocketmqRemoting - [info,90] - closeChannel: the channel[x.x.x.x:10911] was removed from channel table
15:50:28.959 [MQClientFactoryScheduledThread] WARN RocketmqRemoting - [warn,125] - invokeSync: close socket because of timeout, 3000ms, x.x.x.x:10911
15:50:28.959 [NettyClientWorkerThread_3] INFO RocketmqRemoting - [info,90] - NETTY CLIENT PIPELINE: CLOSE x.x.x.x:10911
15:50:28.959 [MQClientFactoryScheduledThread] WARN RocketmqRemoting - [warn,115] - invokeSync: wait response timeout exception, the channel[x.x.x.x:10911]
15:50:28.960 [NettyClientWorkerThread_3] INFO RocketmqRemoting - [info,90] - eventCloseChannel: the channel[null] has been removed from the channel table before
15:50:28.960 [NettyClientSelector_1] INFO RocketmqRemoting - [info,95] - closeChannel: close the connection to remote address[x.x.x.x:10911] result: true
15:50:28.960 [MQClientFactoryScheduledThread] INFO RocketmqRemoting - [info,90] - createChannel: begin to connect remote host[x.x.x.x:10911] asynchronously
15:50:28.960 [NettyClientWorkerThread_4] INFO RocketmqRemoting - [info,95] - NETTY CLIENT PIPELINE: CONNECT UNKNOWN => x.x.x.x:10911
15:50:28.977 [MQClientFactoryScheduledThread] INFO RocketmqRemoting - [info,95] - createChannel: connect remote host[x.x.x.x:10911] success, AbstractBootstrap$PendingRegistrationPromise@5d0af6f(success)
15:50:29.042 [MQClientFactoryScheduledThread] INFO RocketmqRemoting - [info,95] - closeChannel: begin close the channel[x.x.x.x:10911] Found: true
15:50:29.042 [MQClientFactoryScheduledThread] INFO RocketmqRemoting - [info,90] - closeChannel: the channel[x.x.x.x:10911] was removed from channel table
15:50:29.042 [MQClientFactoryScheduledThread] WARN RocketmqRemoting - [warn,125] - invokeSync: close socket because of timeout, 3000ms, x.x.x.x:10911
15:50:29.042 [MQClientFactoryScheduledThread] WARN RocketmqRemoting - [warn,115] - invokeSync: wait response timeout exception, the channel[x.x.x.x:10911]
15:50:29.042 [NettyClientWorkerThread_4] INFO RocketmqRemoting - [info,90] - NETTY CLIENT PIPELINE: CLOSE x.x.x.x:10911
15:50:29.042 [MQClientFactoryScheduledThread] INFO RocketmqRemoting - [info,90] - createChannel: begin to connect remote host[x.x.x.x:10911] asynchronously
15:50:29.043 [NettyClientWorkerThread_4] INFO RocketmqRemoting - [info,90] - eventCloseChannel: the channel[null] has been removed from the channel table before
15:50:29.043 [NettyClientWorkerThread_1] INFO RocketmqRemoting - [info,95] - NETTY CLIENT PIPELINE: CONNECT UNKNOWN => x.x.x.x:10911
15:50:29.043 [NettyClientSelector_1] INFO RocketmqRemoting - [info,95] - closeChannel: close the connection to remote address[x.x.x.x:10911] result: true
15:50:29.057 [MQClientFactoryScheduledThread] INFO RocketmqRemoting - [info,95] - createChannel: connect remote host[x.x.x.x:10911] success, AbstractBootstrap$PendingRegistrationPromise@7c02fe16(success)
15:50:31.050 [MQClientFactoryScheduledThread] INFO RocketmqRemoting - [info,95] - closeChannel: begin close the channel[x.x.x.x:10911] Found: true
15:50:31.050 [MQClientFactoryScheduledThread] INFO RocketmqRemoting - [info,90] - closeChannel: the channel[x.x.x.x:10911] was removed from channel table
15:50:31.050 [MQClientFactoryScheduledThread] WARN RocketmqRemoting - [warn,125] - invokeSync: close socket because of timeout, 3000ms, x.x.x.x:10911
broker报错信息：
io.netty.channel.StacklessClosedChannelException: null
at io.netty.channel.AbstractChannel$AbstractUnsafe.write(Object, ChannelPromise)(Unknown Source) ~[netty-all-4.1.65.Final.jar:4.1.65.Final]
2022-01-07 16:11:57 ERROR NettyServerNIOSelector_3_1 - RemotingCommand [code=11, language=JAVA, version=395, opaque=25308, flag(B)=0, remark=null, extFields={queueId=0, maxMsgNums=32, sysFlag=2, suspendTimeoutMillis=15000, commitOffset=0, topic=jsjlr, queueOffset=0, expressionType=TAG, subVersion=1641541883872, consumerGroup=jsjlr_remove_njxxgcdx}, serializeTypeCurrentRPC=JSON]
2022-01-07 16:11:57 ERROR NettyServerNIOSelector_3_1 - RemotingCommand [code=19, language=JAVA, version=395, opaque=25308, flag(B)=1, remark=NO_MESSAGE_IN_QUEUE, extFields=null, serializeTypeCurrentRPC=JSON]
2022-01-07 16:11:57 ERROR NettyServerNIOSelector_3_3 - RemotingCommand [code=11, language=JAVA, version=395, opaque=25806, flag(B)=0, remark=null, extFields={queueId=0, maxMsgNums=32, sysFlag=2, suspendTimeoutMillis=15000, commitOffset=0, topic=jsjlr, queueOffset=0, expressionType=TAG, subVersion=1641541930456, consumerGroup=jsjlr_remove_njxxgcdx}, serializeTypeCurrentRPC=JSON]
2022-01-07 16:11:57 ERROR NettyServerNIOSelector_3_3 - RemotingCommand [code=19, language=JAVA, version=395, opaque=25806, flag(B)=1, remark=NO_MESSAGE_IN_QUEUE, extFields=null, serializeTypeCurrentRPC=JSON]
2022-01-07 16:11:57 ERROR NettyServerNIOSelector_3_2 - processRequestWrapper response to /x.x.x.x:45867 failed
io.netty.channel.StacklessClosedChannelException: null
at io.netty.channel.AbstractChannel$AbstractUnsafe.write(Object, ChannelPromise)(Unknown Source) ~[netty-all-4.1.65.Final.jar:4.1.65.Final]
2022-01-07 16:11:57 ERROR NettyServerNIOSelector_3_2 - RemotingCommand [code=11, language=JAVA, version=395, opaque=25814, flag(B)=0, remark=null, extFields={queueId=1, maxMsgNums=32, sysFlag=3, suspendTimeoutMillis=15000, commitOffset=10, topic=xqts, queueOffset=10, expressionType=TAG, subVersion=1641541884177, consumerGroup=xqts_remove_njxxgcdx}, serializeTypeCurrentRPC=JSON]
2022-01-07 16:11:57 ERROR NettyServerNIOSelector_3_2 - RemotingCommand [code=19, language=JAVA, version=395, opaque=25814, flag(B)=1, remark=OFFSET_OVERFLOW_ONE, extFields=null, serializeTypeCurrentRPC=JSON]
2022-01-07 16:11:58 WARN PullMessageThread_19 - the consumer's group info not exist, group: jsjlr_edit_njxxgcdx
2022-01-07 16:11:58 WARN PullMessageThread_10 - the consumer's group info not exist, group: jsjlr_edit_njxxgcdx
2022-01-07 16:11:58 WARN PullMessageThread_15 - the consumer's group info not exist, group: jsjlr_edit_njxxgcdx
2022-01-07 16:11:58 WARN PullMessageThread_19 - the consumer's group info not exist, group: jsjlr_edit_njxxgcdx
2022-01-07 16:11:59 WARN PullMessageThread_7 - the consumer's group info not exist, group: jsjlr_edit_njxxgcdx
2022-01-07 16:12:01 WARN ConsumerManageThread_16 - getConsumerGroupInfo failed, xqts_edit_njxxgcdx x.x.x.x:41571
2022-01-07 16:12:01 INFO NettyEventExecutor - NETTY EVENT: remove channel[ClientChannelInfo [channel=[id: 0x400a059c, L:/192.168.0.100:10911 ! R:/x.x.x.x:50244], clientId=202.195.225.78@124.71.156.165:9876@2815@155974395232204, language=JAVA, version=395, lastUpdateTimestamp=1641543114094]][x.x.x.x:50244] from ProducerManager groupChannelTable, producer group: CLIENT_INNER_PRODUCER
2022-01-07 16:12:01 WARN NettyEventExecutor - NETTY EVENT: remove not active channel[ClientChannelInfo [channel=[id: 0x400a059c, L:/192.168.0.100:10911 ! R:/x.x.x.x:50244], clientId=202.195.225.78@124.71.156.165:9876@2815@155974395232204, language=JAVA, version=395, lastUpdateTimestamp=1641543114094]] from ConsumerGroupInfo groupChannelTable, consumer group: xqpp_rematch_njxxgcdx
2022-01-07 16:12:01 INFO NettyEventExecutor - unregister consumer ok, no any connection, and remove consumer group, xqpp_rematch_njxxgcdx
2022-01-07 16:12:02 WARN ClientHousekeepingScheduledThread1 - SCAN: remove expired channel[x.x.x.x:22068] from ProducerManager groupChannelTable, producer group name: CLIENT_INNER_PRODUCER
2022-01-07 16:12:02 ERROR NettyServerNIOSelector_3_3 - processRequestWrapper response to /x.x.x.x:38281 failed
io.netty.channel.StacklessClosedChannelException: null
at io.netty.channel.AbstractChannel$AbstractUnsafe.write(Object, ChannelPromise)(Unknown Source) ~[netty-all-4.1.65.Final.jar:4.1.65.Final]
2022-01-07 16:12:02 ERROR NettyServerNIOSelector_3_3 - RemotingCommand [code=11, language=JAVA, version=395, opaque=25863, flag(B)=0, remark=null, extFields={queueId=0, maxMsgNums=32, sysFlag=2, suspendTimeoutMillis=15000, commitOffset=0, topic=%RETRY%xqts_remove_njxxgcdx, queueOffset=0, expressionType=TAG, subVersion=1641540113347, consumerGroup=xqts_remove_njxxgcdx}, serializeTypeCurrentRPC=JSON]
2022-01-07 16:12:02 ERROR NettyServerNIOSelector_3_3 - RemotingCommand [code=19, language=JAVA, version=395, opaque=25863, flag(B)=1, remark=NO_MESSAGE_IN_QUEUE, extFields=null, serializeTypeCurrentRPC=JSON]
2022-01-07 16:12:02 ERROR NettyServerNIOSelector_3_3 - processRequestWrapper response to /x.x.x.x:38281 failed
io.netty.channel.StacklessClosedChannelException: null
at io.netty.channel.AbstractChannel$AbstractUnsafe.write(Object, ChannelPromise)(Unknown Source) ~[netty-all-4.1.65.Final.jar:4.1.65.Final]
2022-01-07 16:12:02 ERROR NettyServerNIOSelector_3_3 - RemotingCommand [code=11, language=JAVA, version=395, opaque=25865, flag(B)=0, remark=null, extFields={queueId=0, maxMsgNums=32, sysFlag=3, suspendTimeoutMillis=15000, commitOffset=8, topic=xqts, queueOffset=8, expressionType=TAG, subVersion=1641541884177, consumerGroup=xqts_remove_njxxgcdx}, serializeTypeCurrentRPC=JSON]
2022-01-07 16:12:02 ERROR NettyServerNIOSelector_3_3 - RemotingCommand [code=19, language=JAVA, version=395, opaque=25865, flag(B)=1, remark=OFFSET_OVERFLOW_ONE, extFields=null, serializeTypeCurrentRPC=JSON]
2022-01-07 16:12:02 ERROR NettyServerNIOSelector_3_3 - processRequestWrapper response to /x.x.x.x:38281 failed
io.netty.channel.StacklessClosedChannelException: null
at io.netty.channel.AbstractChannel$AbstractUnsafe.write(Object, ChannelPromise)(Unknown Source) ~[netty-all-4.1.65.Final.jar:4.1.65.Final]
2022-01-07 16:12:02 ERROR NettyServerNIOSelector_3_3 - RemotingCommand [code=11, language=JAVA, version=395, opaque=25864, flag(B)=0, remark=null, extFields={queueId=1, maxMsgNums=32, sysFlag=3, suspendTimeoutMillis=15000, commitOffset=10, topic=xqts, queueOffset=10, expressionType=TAG, subVersion=1641541884177, consumerGroup=xqts_remove_njxxgcdx}, serializeTypeCurrentRPC=JSON]
2022-01-07 16:12:02 ERROR NettyServerNIOSelector_3_3 - RemotingCommand [code=19, language=JAVA, version=395, opaque=25864, flag(B)=1, remark=OFFSET_OVERFLOW_ONE, extFields=null, serializeTypeCurrentRPC=JSON]
2022-01-07 16:12:04 WARN PullMessageThread_16 - the consumer's group info not exist, group: xqts_edit_njxxgcdx
2022-01-07 16:12:04 WARN PullMessageThread_12 - the consumer's group info not exist, group: xqts_edit_njxxgcdx
2022-01-07 16:12:05 WARN PullMessageThread_22 - the consumer's group info not exist, group: jsjlr_edit_njxxgcdx
2022-01-07 16:12:05 WARN PullMessageThread_22 - the consumer's group info not exist, group: jsjlr_edit_njxxgcdx
2022-01-07 16:12:05 WARN PullMessageThread_22 - the consumer's group info not exist, group: jsjlr_edit_njxxgcdx
2022-01-07 16:12:05 WARN PullMessageThread_22 - the consumer's group info not exist, group: jsjlr_edit_njxxgcdx
2022-01-07 16:12:05 WARN PullMessageThread_22 - the consumer's group info not exist, group: jsjlr_edit_njxxgcdx
2022-01-07 16:12:09 WARN PullMessageThread_20 - the consumer's group info not exist, group: jsjlr_add_njxxgcdx
2022-01-07 16:12:09 WARN PullMessageThread_12 - the consumer's group info not exist, group: jsjlr_add_njxxgcdx
2022-01-07 16:12:09 WARN PullMessageThread_20 - the consumer's group info not exist, group: jsjlr_add_njxxgcdx
2022-01-07 16:12:09 WARN PullMessageThread_16 - the consumer's group info not exist, group: jsjlr_add_njxxgcdx
2022-01-07 16:12:09 WARN PullMessageThread_20 - the consumer's group info not exist, group: jsjlr_add_njxxgcdx
2022-01-07 16:12:12 INFO BrokerControllerScheduledThread1 - dispatch behind commit log 0 bytes
2022-01-07 16:12:12 INFO BrokerControllerScheduledThread1 - Slave fall behind master: 82029 bytes
2022-01-07 16:12:12 WARN ClientHousekeepingScheduledThread1 - SCAN: remove expired channel[x.x.x.x:26120] from ProducerManager groupChannelTable, producer group name: CLIENT_INNER_PRODUCER
2022-01-07 16:12:12 INFO brokerOutApi_thread_4 - register broker[0]to name server 124.71.156.165:9876 OK
2022-01-07 16:12:13 WARN PullMessageThread_2 - the consumer's group info not exist, group: jsjlr_add_njxxgcdx
2022-01-07 16:12:13 WARN PullMessageThread_18 - the consumer's group info not exist, group: jsjlr_add_njxxgcdx
2022-01-07 16:12:13 WARN PullMessageThread_2 - the consumer's group info not exist, group: jsjlr_add_njxxgcdx
2022-01-07 16:12:13 WARN PullMessageThread_19 - the consumer's group info not exist, group: jsjlr_add_njxxgcdx
2022-01-07 16:12:13 INFO HeartbeatThread_1 - new consumer connected, group: jsjlr_add_njxxgcdx CONSUME_PASSIVELY CLUSTERING channel: ClientChannelInfo [channel=[id: 0x0be0a28c, L:0.0.0.0/0.0.0.0:10911 ! R:/x.x.x.x:3353], clientId=202.195.225.78@124.71.156.165:9876@2815@155974091247466, language=JAVA, version=395, lastUpdateTimestamp=1641543133227]
2022-01-07 16:12:13 INFO HeartbeatThread_1 - subscription changed, add new topic, group: jsjlr_add_njxxgcdx SubscriptionData [classFilterMode=false, topic=%RETRY%jsjlr_add_njxxgcdx, subString=*, tagsSet=[], codeSet=[], subVersion=1641540112843, expressionType=TAG]
2022-01-07 16:12:13 INFO HeartbeatThread_1 - subscription changed, add new topic, group: jsjlr_add_njxxgcdx SubscriptionData [classFilterMode=false, topic=jsjlr, subString=add, tagsSet=[add], codeSet=[96417], subVersion=1641541913309, expressionType=TAG]
2022-01-07 16:12:13 INFO HeartbeatThread_1 - registerConsumer info changed ConsumerData [groupName=jsjlr_add_njxxgcdx, consumeType=CONSUME_PASSIVELY, messageModel=CLUSTERING, consumeFromWhere=CONSUME_FROM_LAST_OFFSET, unitMode=false, subscriptionDataSet=[SubscriptionData [classFilterMode=false, topic=%RETRY%jsjlr_add_njxxgcdx, subString=*, tagsSet=[], codeSet=[], subVersion=1641540112843, expressionType=TAG], SubscriptionData [classFilterMode=false, topic=jsjlr, subString=add, tagsSet=[add], codeSet=[96417], subVersion=1641541913309, expressionType=TAG]]] x.x.x.x:3353
2022-01-07 16:12:13 INFO HeartbeatThread_1 - new producer connected, group: CLIENT_INNER_PRODUCER channel: ClientChannelInfo [channel=[id: 0x0be0a28c, L:0.0.0.0/0.0.0.0:10911 ! R:/x.x.x.x:3353], clientId=202.195.225.78@124.71.156.165:9876@2815@155974091247466, language=JAVA, version=395, lastUpdateTimestamp=1641543133227]
nameserver报错信息：
io.netty.channel.unix.Errors$NativeIoException: readAddress(..) failed: Connection reset by peer
2022-01-07 16:12:41 INFO NettyServerCodecThread_5 - NETTY SERVER PIPELINE: channelInactive, the channel[157.0.78.2:14429]
2022-01-07 16:12:41 INFO NettyServerEPOLLSelector_3_3 - closeChannel: close the connection to remote address[157.0.78.2:14429] result: true
2022-01-07 16:12:41 INFO NettyServerCodecThread_5 - NETTY SERVER PIPELINE: channelUnregistered, the channel[157.0.78.2:14429]
2022-01-07 16:12:44 WARN NettyServerCodecThread_4 - NETTY SERVER PIPELINE: exceptionCaught 157.0.78.2:55833
2022-01-07 16:12:44 WARN NettyServerCodecThread_4 - NETTY SERVER PIPELINE: exceptionCaught exception.
io.netty.channel.unix.Errors$NativeIoException: readAddress(..) failed: Connection reset by peer
2022-01-07 16:12:44 INFO NettyServerEPOLLSelector_3_2 - closeChannel: close the connection to remote address[157.0.78.2:55833] result: true
2022-01-07 16:12:44 INFO NettyServerCodecThread_4 - NETTY SERVER PIPELINE: channelInactive, the channel[157.0.78.2:55833]
2022-01-07 16:12:44 INFO NettyServerCodecThread_4 - NETTY SERVER PIPELINE: channelUnregistered, the channel[157.0.78.2:55833]
2022-01-07 16:12:48 INFO NettyServerCodecThread_8 - NETTY SERVER PIPELINE: channelInactive, the channel[157.0.78.2:38213]
2022-01-07 16:12:48 INFO NettyServerCodecThread_8 - NETTY SERVER PIPELINE: channelUnregistered, the channel[157.0.78.2:38213]
2022-01-07 16:12:50 INFO NettyServerCodecThread_7 - NETTY SERVER PIPELINE: channelRegistered 157.0.78.2:16109
2022-01-07 16:12:50 INFO NettyServerCodecThread_7 - NETTY SERVER PIPELINE: channelActive, the channel[157.0.78.2:16109]
2022-01-07 16:12:53 WARN NettyServerCodecThread_7 - NETTY SERVER PIPELINE: exceptionCaught 157.0.78.2:16951
2022-01-07 16:12:53 WARN NettyServerCodecThread_7 - NETTY SERVER PIPELINE: exceptionCaught exception.
io.netty.channel.unix.Errors$NativeIoException: readAddress(..) failed: Connection reset by peer
2022-01-07 16:12:53 INFO NettyServerEPOLLSelector_3_3 - closeChannel: close the connection to remote address[157.0.78.2:16951] result: true
2022-01-07 16:12:53 INFO NettyServerCodecThread_7 - NETTY SERVER PIPELINE: channelInactive, the channel[157.0.78.2:16951]
2022-01-07 16:12:53 INFO NettyServerCodecThread_7 - NETTY SERVER PIPELINE: channelUnregistered, the channel[157.0.78.2:16951]
2022-01-07 16:13:15 INFO NettyServerCodecThread_8 - NETTY SERVER PIPELINE: channelRegistered 157.0.78.2:1260
2022-01-07 16:13:15 INFO NettyServerCodecThread_8 - NETTY SERVER PIPELINE: channelActive, the channel[157.0.78.2:1260]
2022-01-07 16:13:15 INFO NettyServerCodecThread_6 - NETTY SERVER PIPELINE: channelInactive, the channel[157.0.78.2:13023]
2022-01-07 16:13:15 INFO NettyServerCodecThread_6 - NETTY SERVER PIPELINE: channelUnregistered, the channel[157.0.78.2:13023]
2022-01-07 16:13:20 INFO NettyServerCodecThread_1 - NETTY SERVER PIPELINE: channelRegistered 157.0.78.2:24209
2022-01-07 16:13:20 INFO NettyServerCodecThread_1 - NETTY SERVER PIPELINE: channelActive, the channel[157.0.78.2:24209]
2022-01-07 16:13:23 INFO NettyServerCodecThread_3 - NETTY SERVER PIPELINE: channelInactive, the channel[157.0.78.2:48726]
2022-01-07 16:13:23 INFO NettyServerCodecThread_3 - NETTY SERVER PIPELINE: channelUnregistered, the channel[157.0.78.2:48726]
2022-01-07 16:13:25 INFO NettyServerCodecThread_1 - NETTY SERVER PIPELINE: channelInactive, the channel[157.0.78.2:24209]
2022-01-07 16:13:25 INFO NettyServerCodecThread_1 - NETTY SERVER PIPELINE: channelUnregistered, the channel[157.0.78.2:24209]
2022-01-07 16:13:26 INFO NettyServerCodecThread_2 - NETTY SERVER PIPELINE: channelInactive, the channel[157.0.78.2:62978]
2022-01-07 16:13:26 INFO NettyServerCodecThread_2 - NETTY SERVER PIPELINE: channelUnregistered, the channel[157.0.78.2:62978]
2022-01-07 16:13:26 INFO NettyServerCodecThread_8 - NETTY SERVER PIPELINE: channelInactive, the channel[157.0.78.2:1260]
2022-01-07 16:13:26 INFO NettyServerCodecThread_8 - NETTY SERVER PIPELINE: channelUnregistered, the channel[157.0.78.2:1260]
store存储信息：
2022-01-07 15:47:02 WARN main - found a illegal magic code 0x0
2022-01-07 15:47:02 INFO main - recover physics file end, /data/rocketMq/rocketmq4.9.1/store/commitlog/00000000000000000000
2022-01-07 15:47:02 WARN main - maxPhyOffsetOfConsumeQueue(41375) >= processOffset(41375), truncate dirty logic files
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: xqts, queueId: 0
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: xqts, queueId: 1
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: xqts, queueId: 2
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: xqts, queueId: 3
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: jiebang, queueId: 0
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: jiebang, queueId: 1
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: jiebang, queueId: 2
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: jsjlr, queueId: 1
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: RMQ_SYS_TRACE_TOPIC, queueId: 0
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: RMQ_SYS_TRACE_TOPIC, queueId: 1
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: RMQ_SYS_TRACE_TOPIC, queueId: 2
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: RMQ_SYS_TRACE_TOPIC, queueId: 3
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: OFFSET_MOVED_EVENT, queueId: 0
2022-01-07 15:47:02 INFO main - load over, and the max phy offset = 41375
2022-01-07 15:47:02 INFO main - [SetReputOffset] maxPhysicalPosInLogicQueue=41375 clMinOffset=0 clMaxOffset=41375 clConfirmedOffset=-1
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: xqts, queueId: 0
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: xqts, queueId: 1
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: xqts, queueId: 2
2022-01-07 15:47:02 INFO ReputMessageService - ReputMessageService service started
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: xqts, queueId: 3
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: jiebang, queueId: 0
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: jiebang, queueId: 1
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: jiebang, queueId: 2
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: jsjlr, queueId: 1
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: RMQ_SYS_TRACE_TOPIC, queueId: 0
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: RMQ_SYS_TRACE_TOPIC, queueId: 1
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: RMQ_SYS_TRACE_TOPIC, queueId: 2
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: RMQ_SYS_TRACE_TOPIC, queueId: 3
2022-01-07 15:47:02 INFO main - Compute logical min offset: 0, topic: OFFSET_MOVED_EVENT, queueId: 0
2022-01-07 15:47:02 INFO AcceptSocketService - AcceptSocketService service started
2022-01-07 15:47:02 INFO GroupTransferService - GroupTransferService service started
2022-01-07 15:47:02 INFO HAClient - HAClient service started
2022-01-07 15:47:02 INFO FlushConsumeQueueService - FlushConsumeQueueService service started
2022-01-07 15:47:02 INFO GroupCommitService - GroupCommitService service started
2022-01-07 15:47:02 INFO main - /data/rocketMq/rocketmq4.9.1/store/abort create OK
2022-01-07 15:47:02 INFO StoreStatsService - StoreStatsService service started
2022-01-07 15:48:02 INFO StoreStatsService - [STORETPS] put_tps get_found_tps get_miss_tps get_transfered_tps
2022-01-07 15:48:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 4, PutMessageDistributeTime [<=0ms]:0 [0~10ms]:3 [10~50ms]:1 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 15:49:02 INFO StoreStatsService - [STORETPS] put_tps 0.0 get_found_tps 0.0 get_miss_tps 5.91617365219565 get_transfered_tps 0.0
2022-01-07 15:49:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 0, PutMessageDistributeTime [<=0ms]:0 [0~10ms]:0 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 15:50:02 INFO StoreStatsService - [STORETPS] put_tps 0.0666611115740355 get_found_tps 0.0666611115740355 get_miss_tps 5.366219481709857 get_transfered_tps 0.0666611115740355
2022-01-07 15:50:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 4, PutMessageDistributeTime [<=0ms]:1 [0~10ms]:3 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 15:51:02 INFO StoreStatsService - [STORETPS] put_tps 0.0 get_found_tps 0.016665277893508874 get_miss_tps 5.399550037496875 get_transfered_tps 0.016665277893508874
2022-01-07 15:51:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 0, PutMessageDistributeTime [<=0ms]:0 [0~10ms]:0 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 15:52:02 INFO StoreStatsService - [STORETPS] put_tps 0.0666611115740355 get_found_tps 0.016665277893508874 get_miss_tps 6.382801433213899 get_transfered_tps 0.016665277893508874
2022-01-07 15:52:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 4, PutMessageDistributeTime [<=0ms]:1 [0~10ms]:3 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 15:53:02 INFO StoreStatsService - [STORETPS] put_tps 0.0 get_found_tps 0.0 get_miss_tps 6.9160903258061825 get_transfered_tps 0.0
2022-01-07 15:53:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 0, PutMessageDistributeTime [<=0ms]:0 [0~10ms]:0 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 15:54:02 INFO StoreStatsService - [STORETPS] put_tps 0.0 get_found_tps 0.0 get_miss_tps 6.966202253183122 get_transfered_tps 0.0
2022-01-07 15:54:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 0, PutMessageDistributeTime [<=0ms]:0 [0~10ms]:0 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 15:55:02 INFO StoreStatsService - [STORETPS] put_tps 0.1999833347221065 get_found_tps 0.14998750104157987 get_miss_tps 6.082826431130739 get_transfered_tps 0.16665277893508876
2022-01-07 15:55:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 12, PutMessageDistributeTime [<=0ms]:4 [0~10ms]:8 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 15:56:02 INFO StoreStatsService - [STORETPS] put_tps 0.0 get_found_tps 0.03333111125924938 get_miss_tps 6.199586694220385 get_transfered_tps 0.03333111125924938
2022-01-07 15:56:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 0, PutMessageDistributeTime [<=0ms]:0 [0~10ms]:0 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 15:57:02 INFO StoreStatsService - [STORETPS] put_tps 0.0666611115740355 get_found_tps 0.03333055578701775 get_miss_tps 6.016165319556704 get_transfered_tps 0.03333055578701775
2022-01-07 15:57:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 4, PutMessageDistributeTime [<=0ms]:1 [0~10ms]:3 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 15:58:02 INFO StoreStatsService - [STORETPS] put_tps 0.13332444503699753 get_found_tps 0.03333111125924938 get_miss_tps 4.533031131257916 get_transfered_tps 0.03333111125924938
2022-01-07 15:58:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 8, PutMessageDistributeTime [<=0ms]:2 [0~10ms]:6 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 15:59:02 INFO StoreStatsService - [STORETPS] put_tps 0.0 get_found_tps 0.09999166736105325 get_miss_tps 6.299475043746354 get_transfered_tps 0.09999166736105325
2022-01-07 15:59:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 0, PutMessageDistributeTime [<=0ms]:0 [0~10ms]:0 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 16:00:02 INFO StoreStatsService - [STORETPS] put_tps 0.1999833347221065 get_found_tps 0.049995833680526625 get_miss_tps 4.332972252312308 get_transfered_tps 0.049995833680526625
2022-01-07 16:00:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 12, PutMessageDistributeTime [<=0ms]:4 [0~10ms]:8 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 16:01:02 INFO StoreStatsService - [STORETPS] put_tps 0.4666355576294914 get_found_tps 0.1833211119258716 get_miss_tps 4.699686687554163 get_transfered_tps 0.216652223185121
2022-01-07 16:01:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 28, PutMessageDistributeTime [<=0ms]:9 [0~10ms]:19 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 16:02:02 INFO StoreStatsService - [STORETPS] put_tps 0.133322223148071 get_found_tps 0.133322223148071 get_miss_tps 6.21614865427881 get_transfered_tps 0.266644446296142
2022-01-07 16:02:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 8, PutMessageDistributeTime [<=0ms]:3 [0~10ms]:5 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 16:03:02 INFO StoreStatsService - [STORETPS] put_tps 0.0 get_found_tps 0.0 get_miss_tps 6.382907806146257 get_transfered_tps 0.0
2022-01-07 16:03:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 0, PutMessageDistributeTime [<=0ms]:0 [0~10ms]:0 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 16:04:02 INFO StoreStatsService - [STORETPS] put_tps 0.0 get_found_tps 0.0 get_miss_tps 5.182901424881259 get_transfered_tps 0.0
2022-01-07 16:04:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 0, PutMessageDistributeTime [<=0ms]:0 [0~10ms]:0 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 16:05:02 INFO StoreStatsService - [STORETPS] put_tps 0.0 get_found_tps 0.016665277893508874 get_miss_tps 6.649445879510041 get_transfered_tps 0.049995833680526625
2022-01-07 16:05:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 0, PutMessageDistributeTime [<=0ms]:0 [0~10ms]:0 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 16:06:02 INFO StoreStatsService - [STORETPS] put_tps 0.0 get_found_tps 0.0 get_miss_tps 5.616292247183521 get_transfered_tps 0.0
2022-01-07 16:06:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 0, PutMessageDistributeTime [<=0ms]:0 [0~10ms]:0 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 16:07:02 INFO StoreStatsService - [STORETPS] put_tps 0.0 get_found_tps 0.0 get_miss_tps 5.649529205899508 get_transfered_tps 0.0
2022-01-07 16:07:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 0, PutMessageDistributeTime [<=0ms]:0 [0~10ms]:0 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 16:08:02 INFO StoreStatsService - [STORETPS] put_tps 0.0 get_found_tps 0.0 get_miss_tps 6.832763936338638 get_transfered_tps 0.0
2022-01-07 16:08:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 0, PutMessageDistributeTime [<=0ms]:0 [0~10ms]:0 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 16:09:02 INFO StoreStatsService - [STORETPS] put_tps 0.0 get_found_tps 0.0 get_miss_tps 6.282914472368509 get_transfered_tps 0.0
2022-01-07 16:09:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 0, PutMessageDistributeTime [<=0ms]:0 [0~10ms]:0 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 16:10:02 INFO StoreStatsService - [STORETPS] put_tps 0.0 get_found_tps 0.0 get_miss_tps 6.966086159486709 get_transfered_tps 0.0
2022-01-07 16:10:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 0, PutMessageDistributeTime [<=0ms]:0 [0~10ms]:0 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 16:11:02 INFO StoreStatsService - [STORETPS] put_tps 0.0 get_found_tps 0.0 get_miss_tps 6.166255582961136 get_transfered_tps 0.0
2022-01-07 16:11:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 0, PutMessageDistributeTime [<=0ms]:0 [0~10ms]:0 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 16:12:02 INFO StoreStatsService - [STORETPS] put_tps 0.0 get_found_tps 0.0 get_miss_tps 5.232897258561787 get_transfered_tps 0.0
2022-01-07 16:12:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 0, PutMessageDistributeTime [<=0ms]:0 [0~10ms]:0 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 16:13:02 INFO StoreStatsService - [STORETPS] put_tps 0.0 get_found_tps 0.0 get_miss_tps 5.8662755816278915 get_transfered_tps 0.0
2022-01-07 16:13:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 0, PutMessageDistributeTime [<=0ms]:0 [0~10ms]:0 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
2022-01-07 16:14:02 INFO StoreStatsService - [STORETPS] put_tps 0.0 get_found_tps 0.0 get_miss_tps 6.266144487959337 get_transfered_tps 0.0
2022-01-07 16:14:02 INFO StoreStatsService - [PAGECACHERT] TotalPut 0, PutMessageDistributeTime [<=0ms]:0 [0~10ms]:0 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [rocketmq] yrg5101 commented on issue #3726: rocketmq client invokeSync: close socket because of timeout, 3000ms
Posted by GitBox <gi...@apache.org>.
yrg5101 commented on issue #3726:
URL: https://github.com/apache/rocketmq/issues/3726#issuecomment-1018083036
网络架构比较简单， 无LB和NGINX, 只是感觉rocketmq不太适合这种公网数据传输的场景， 在内网环境用感觉还行， 目前由于项目赶期， 已经换了解决方案，关闭此单，谢谢各位大佬
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [rocketmq] yrg5101 closed issue #3726: rocketmq client invokeSync: close socket because of timeout, 3000ms
Posted by GitBox <gi...@apache.org>.
yrg5101 closed issue #3726:
URL: https://github.com/apache/rocketmq/issues/3726
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [rocketmq] RongtongJin commented on issue #3726: rocketmq client invokeSync: close socket because of timeout, 3000ms
Posted by GitBox <gi...@apache.org>.
RongtongJin commented on issue #3726:
URL: https://github.com/apache/rocketmq/issues/3726#issuecomment-1007872975
可以先检查一下客户端到broker的网络情况
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [rocketmq] yrg5101 commented on issue #3726: rocketmq client invokeSync: close socket because of timeout, 3000ms
Posted by GitBox <gi...@apache.org>.
yrg5101 commented on issue #3726:
URL: https://github.com/apache/rocketmq/issues/3726#issuecomment-1007899495
现在客户端的日志
14:42:36.926 [PullMessageService] INFO RocketmqRemoting - [info,95] - createChannel: connect remote host[x.x.x.x:10911] success, AbstractBootstrap$PendingRegistrationPromise@34a37bc3(success)
14:42:37.891 [RebalanceService] INFO RocketmqRemoting - [info,95] - closeChannel: begin close the channel[x.x.x.x:10911] Found: true
14:42:37.891 [RebalanceService] INFO RocketmqRemoting - [info,90] - closeChannel: the channel[x.x.x.x:10911] was removed from channel table
14:42:37.891 [RebalanceService] WARN RocketmqRemoting - [warn,125] - invokeSync: close socket because of timeout, 5000ms, x.x.x.x:10911
14:42:37.891 [RebalanceService] WARN RocketmqRemoting - [warn,115] - invokeSync: wait response timeout exception, the channel[x.x.x.x:10911]
14:42:37.891 [NettyClientWorkerThread_3] INFO RocketmqRemoting - [info,90] - NETTY CLIENT PIPELINE: CLOSE x.x.x.x:10911
14:42:37.891 [NettyClientWorkerThread_3] INFO RocketmqRemoting - [info,90] - eventCloseChannel: the channel[null] has been removed from the channel table before
14:42:37.892 [NettyClientSelector_1] INFO RocketmqRemoting - [info,95] - closeChannel: close the connection to remote address[x.x.x.x:10911] result: true
14:42:37.892 [RebalanceService] INFO RocketmqRemoting - [info,90] - createChannel: begin to connect remote host[x.x.x.x:10911] asynchronously
14:42:37.892 [NettyClientWorkerThread_4] INFO RocketmqRemoting - [info,95] - NETTY CLIENT PIPELINE: CONNECT UNKNOWN => x.x.x.x:10911
14:42:37.906 [RebalanceService] INFO RocketmqRemoting - [info,95] - createChannel: connect remote host[x.x.x.x:10911] success, AbstractBootstrap$PendingRegistrationPromise@5864b3f9(success)
14:42:38.780 [RebalanceService] INFO RocketmqRemoting - [info,95] - closeChannel: begin close the channel[x.x.x.x:10911] Found: true
14:42:38.780 [RebalanceService] INFO RocketmqRemoting - [info,90] - closeChannel: the channel[x.x.x.x:10911] was removed from channel table
14:42:38.781 [RebalanceService] WARN RocketmqRemoting - [warn,125] - invokeSync: close socket because of timeout, 3000ms, x.x.x.x:10911
14:42:38.781 [RebalanceService] WARN RocketmqRemoting - [warn,115] - invokeSync: wait response timeout exception, the channel[x.x.x.x:10911]
14:42:38.781 [NettyClientWorkerThread_4] INFO RocketmqRemoting - [info,90] - NETTY CLIENT PIPELINE: CLOSE x.x.x.x:10911
14:42:38.781 [NettyClientWorkerThread_4] INFO RocketmqRemoting - [info,90] - eventCloseChannel: the channel[null] has been removed from the channel table before
14:42:38.781 [NettyClientSelector_1] INFO RocketmqRemoting - [info,95] - closeChannel: close the connection to remote address[x.x.x.x:10911] result: true
14:42:38.815 [RebalanceService] INFO RocketmqRemoting - [info,95] - closeChannel: begin close the channel[x.x.x.x:10911] Found: true
14:42:38.815 [RebalanceService] INFO RocketmqRemoting - [info,90] - closeChannel: the channel[x.x.x.x:10911] was removed from channel table
14:42:38.815 [RebalanceService] WARN RocketmqRemoting - [warn,125] - invokeSync: close socket because of timeout, 3000ms, x.x.x.x:10911
14:42:38.815 [RebalanceService] WARN RocketmqRemoting - [warn,115] - invokeSync: wait response timeout exception, the channel[x.x.x.x:10911]
14:42:38.815 [NettyClientWorkerThread_2] INFO RocketmqRemoting - [info,90] - NETTY CLIENT PIPELINE: CLOSE x.x.x.x:10911
14:42:38.815 [NettyClientWorkerThread_2] INFO RocketmqRemoting - [info,90] - eventCloseChannel: the channel[null] has been removed from the channel table before
14:42:38.815 [RebalanceService] INFO RocketmqRemoting - [info,90] - createChannel: begin to connect remote host[x.x.x.x:10911] asynchronously
14:42:38.815 [NettyClientSelector_1] INFO RocketmqRemoting - [info,95] - closeChannel: close the connection to remote address[x.x.x.x:10911] result: true
14:42:38.816 [NettyClientWorkerThread_3] INFO RocketmqRemoting - [info,95] - NETTY CLIENT PIPELINE: CONNECT UNKNOWN => x.x.x.x:10911
14:42:38.828 [RebalanceService] INFO RocketmqRemoting - [info,95] - createChannel: connect remote host[x.x.x.x:10911] success, AbstractBootstrap$PendingRegistrationPromise@3d61fd3c(success)
14:42:39.782 [PullMessageService] INFO RocketmqRemoting - [info,90] - createChannel: begin to connect remote host[x.x.x.x:10911] asynchronously
14:42:39.782 [NettyClientWorkerThread_1] INFO RocketmqRemoting - [info,95] - NETTY CLIENT PIPELINE: CONNECT UNKNOWN => x.x.x.x:10911
14:42:39.796 [PullMessageService] INFO RocketmqRemoting - [info,95] - createChannel: connect remote host[x.x.x.x:10911] success, AbstractBootstrap$PendingRegistrationPromise@18194d88(success)
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [rocketmq] yrg5101 commented on issue #3726: rocketmq client invokeSync: close socket because of timeout, 3000ms
Posted by GitBox <gi...@apache.org>.
yrg5101 commented on issue #3726:
URL: https://github.com/apache/rocketmq/issues/3726#issuecomment-1007897372
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [rocketmq] RongtongJin commented on issue #3726: rocketmq client invokeSync: close socket because of timeout, 3000ms
Posted by GitBox <gi...@apache.org>.
RongtongJin commented on issue #3726:
URL: https://github.com/apache/rocketmq/issues/3726#issuecomment-1007872975
可以先检查一下客户端到broker的网络情况
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [rocketmq] pinkhello edited a comment on issue #3726: rocketmq client invokeSync: close socket because of timeout, 3000ms
Posted by GitBox <gi...@apache.org>.
pinkhello edited a comment on issue #3726:
URL: https://github.com/apache/rocketmq/issues/3726#issuecomment-1017690742
你们直接在客户端链接 华为云上的 broker 配置的什么，前面有无 LB 或 NGINX，是不是这些导致的。
可以先描述一下你们的这个环境的网络架构
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [rocketmq] odbozhou commented on issue #3726: rocketmq client invokeSync: close socket because of timeout, 3000ms
Posted by GitBox <gi...@apache.org>.
odbozhou commented on issue #3726:
URL: https://github.com/apache/rocketmq/issues/3726#issuecomment-1009626970
It can continuously detect whether the network has fluctuations, and network fluctuations often occur over a period of time.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [rocketmq] pinkhello commented on issue #3726: rocketmq client invokeSync: close socket because of timeout, 3000ms
Posted by GitBox <gi...@apache.org>.
pinkhello commented on issue #3726:
URL: https://github.com/apache/rocketmq/issues/3726#issuecomment-1017690742
你们直接在客户端链接 华为云上的 broker 配置的什么，前面有无 LB 或 NGINX，是不是这些导致的。
可以先藐视一下你们的这个环境的网络架构
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [rocketmq] yrg5101 commented on issue #3726: rocketmq client invokeSync: close socket because of timeout, 3000ms
Posted by GitBox <gi...@apache.org>.
yrg5101 commented on issue #3726:
URL: https://github.com/apache/rocketmq/issues/3726#issuecomment-1007897372
> 可以先检查一下客户端到broker的网络情况
谢谢回复，这样的我们这个broker是放在华为云上的， 提供公网访问， 外部的客户端通过公网访问broker，前期一直是好好的， 就这几点大面积的出现超时， 不是一个客户端出问题， 感觉是broker端出了问题， 但是看了端口，网络带宽都没有什么异常， 所有感觉没什么思路，期间修改了client的超时时间从3000ms到10000ms， 但是还是出问题
定位代码：RemotingCommand response = this.invokeSyncImpl(channel, request, timeoutMillis - costTime);应该在这边抛的异常
if (channel != null && channel.isActive()) {
try {
doBeforeRpcHooks(addr, request);
long costTime = System.currentTimeMillis() - beginStartTime;
log.info("+++++++++++++++++++++++++++++++++++++++++++++++++++++");
log.info("invokeSync: costTime is , {}ms", costTime);
System.out.println("++++++++++++++++++++++++++++++++++++++++++++++");
System.out.println("invokeSync: costTime is" + costTime +"ms");
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;
} catch (RemotingSendRequestException e) {
log.warn("invokeSync: send request exception, so close the channel[{}]", addr);
this.closeChannel(addr, channel);
throw e;
} catch (RemotingTimeoutException e) {
if (nettyClientConfig.isClientCloseSocketIfTimeout()) {
this.closeChannel(addr, channel);
log.warn("invokeSync: close socket because of timeout, {}ms, {}", timeoutMillis, addr);
}
log.warn("invokeSync: wait response timeout exception, the channel[{}]", addr);
throw e;
}
try {
final ResponseFuture responseFuture = new ResponseFuture(channel, opaque, timeoutMillis, null, null);
this.responseTable.put(opaque, responseFuture);
final SocketAddress addr = channel.remoteAddress();
channel.writeAndFlush(request).addListener(new ChannelFutureListener() {
@Override
public void operationComplete(ChannelFuture f) throws Exception {
if (f.isSuccess()) {
responseFuture.setSendRequestOK(true);
return;
} else {
responseFuture.setSendRequestOK(false);
}
responseTable.remove(opaque);
responseFuture.setCause(f.cause());
responseFuture.putResponse(null);
log.warn("send a request command to channel <" + addr + "> failed.");
}
});
**RemotingCommand responseCommand = responseFuture.waitResponse(timeoutMillis);
if (null == responseCommand) {**
if (responseFuture.isSendRequestOK()) {
throw new RemotingTimeoutException(RemotingHelper.parseSocketAddressAddr(addr), timeoutMillis,
responseFuture.getCause());
} else {
**throw new RemotingSendRequestException(RemotingHelper.parseSocketAddressAddr(addr), responseFuture.getCause());**
}
}
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org