search

sofastack / sofa-bolt

SOFABolt is a lightweight, easy to use and high performance remoting framework based on Netty.
https://www.sofastack.tech/projects/sofa-bolt/
Apache License 2.0
2.4k stars 856 forks source link

Diffrent thread send heartbeat to server at the same time #329

Closed tongtaodragon closed 10 months ago

tongtaodragon commented 1 year ago

Describe the bug In bolt log, we found the below message. It shows different thread send heartbeat almost at the same time. And they all were counted in retry times. 2023-06-12 10:25:19,532 ERROR [RpcHeartbeatTrigger$1#110] [Bolt-default-executor-4-thread-1] Heartbeat timeout! The address is 11.54.90.112:10211 2023-06-12 10:25:19,633 ERROR [RpcHeartbeatTrigger$1#110] [Bolt-default-executor-4-thread-2] Heartbeat timeout! The address is 11.54.90.112:10211 2023-06-12 10:25:34,639 ERROR [RpcHeartbeatTrigger$1#110] [Bolt-default-executor-4-thread-3] Heartbeat timeout! The address is 11.54.90.112:10211 2023-06-12 10:36:13,550 ERROR [RpcHeartbeatTrigger$1#110] [Bolt-default-executor-4-thread-16] Heartbeat timeout! The address is 11.54.90.112:10211 2023-06-12 10:36:13,620 ERROR [RpcHeartbeatTrigger$1#110] [Bolt-default-executor-4-thread-17] Heartbeat timeout! The address is 11.54.90.112:10211 2023-06-12 10:36:28,627 ERROR [RpcHeartbeatTrigger$1#110] [Bolt-default-executor-4-thread-18] Heartbeat timeout! The address is 11.54.90.112:10211

Expected behavior

With the default configuration, the heartbeat should be sent one by one at 15s interval.

Actual behavior

Heartbeat sent at the same time.

Steps to reproduce

With the default configuration, deploy a Java client and java server based on sofa-bolt, after the connetion established, use tool like iptables make client can't send data to server. Repeat several times then find the issue.

Environment

tongtaodragon commented 1 year ago

Environment SOFABolt version: com.alipay.sofa bolt 1.6.5 JVM version (e.g. java -version): java version "1.8.0_331" Java(TM) SE Runtime Environment (build 1.8.0_331-b09) Java HotSpot(TM) 64-Bit Server VM (build 25.331-b09, mixed mode)

OS version (e.g. uname -a): Linux ecs-sps-srv-sit.novalocal 3.10.0-862.el7.x86_64 #1 SMP Wed Mar 21 18:14:51 EDT 2018 x86_64 x86_64 x86_64 GNU/Linux Windows

OrezzerO commented 1 year ago

HeartBeat is triggered by IdleStateEvent. When a connection reach its idle time , an IdleStateEvent is raised. Please check how many connection is created between client and server . If there are more than one connection, multiple hearbeat will be send.

tongtaodragon commented 1 year ago

Thanks for the answer! In our implementation, client only create one connection to server, we used netstat for confirmation.

OrezzerO commented 1 year ago

In the condition you say, there may be more than one IdleStateEvent is raised or there may be more than one listener is listening. You can use Arthas's stack command to monitor com.alipay.remoting.rpc.HeartbeatHandler#userEventTriggered and related methods like com.alipay.remoting.rpc.protocol.RpcHeartbeatTrigger#heartbeatTriggered

tongtaodragon commented 10 months ago

Thanks OrezzerO!

Using arthas monitor command, heartbeatTriggered shows triggered with 15s frequency and handled with the same thread, this is expected behavior. But the log message in connection-event log is still strange and mislead the analysis. I close this one since the behavior is correct.