[alibaba/nacos]Nacos Server push服务实例信息异常

2023-12-18 554 views
9

Version: Nacos Server 2.0.2 Nacos Client 1.4.2

Problem: NacosClient一台节点在30s收到了3条推送通知 2023-02-16 21:14:45.602 第一条:收到order-pro服务的实例变更(服务下3台节点ip:1、2、3) 2023-02-16 21:15:05.782 第二条:收到order-pro服务的实例变更(服务下2台节点ip:1、2) 发现3节点下线,客户端做出相应处理 2023-02-16 21:15:15.682 第三条:收到order-pro服务的实例变更(服务下3台节点ip:1、2、3) 注:IP为3的节点在这15s内一直在正常运行,并未发生故障或重启

Nacos Client ip=3 naming.log日志(3节点实际IP是10.0.0.88,之所以用1,2,3代替是因为这个服务下面48台机器,所以用1,2,3代替)

2023-02-16 21:15:12.100 INFO [com.alibaba.nacos.naming.beat.sender:client.naming] [REGISTER-SERVICE] public registering service DEFAULT_GROUP@@order-pro with instance: Instance{instanceId='null', ip='10.0.0.88', port=7001, weight=1.0, healthy=true, enabled=true, ephemeral=true, clusterName='DEFAULT', serviceName='DEFAULT_GROUP@@order-pro', metadata={all=512, app_registry_tag=a6ea380c-b38f-4a35-88f6-4bfac2d17cd0, role=1, management.port=7002, priority=12, userName=admin, counterClusterId=1, okcoin.nacos.client=1.4.2, mode=1, management.endpoints.web.base-path=/, shards=[0,1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20,21,22,23,24,25,26,27,28,29,30,31], port=10000, commitPositionCounterId=37, preserved.register.source=SPRING_CLOUD, status=NORMAL}} 2023-02-16 21:15:12.170 INFO [com.alibaba.nacos.naming.beat.sender:client.naming] [buildEnableParam] public service DEFAULT-DEFAULT_GROUP-DEFAULT_GROUP@@order-pro instance 10.0.0.88:7001 with enable: true 可以发现,3节点在2023-02-16 21:15:12.100向服务端注册实例。naming.log中在这之前未有任何异常。查看客户端代码,该日志只在服务启动、或者向服务端发送心跳时,发现自身IP实例不存在时,才会走注册流程

Nacos Server naming-server.log日志 2023-02-16 21:14:46,586 INFO Client connection 10.2.9.88:7001#true connect 2023-02-16 21:15:01,620 INFO Client connection 10.2.9.88:7001#true connect 2023-02-16 21:15:01,620 INFO Client remove for service Service{namespace='public', group='DEFAULT_GROUP', name='order-pro', ephemeral=true, revision=3666}, 10.2.9.88:7001#true 2023-02-16 21:15:04,627 INFO Client connection 10.2.9.88:7001#true disconnect, remove instances and subscribers 2023-02-16 21:15:14,049 INFO Client connection 10.2.9.888:7001#true connect 可以发现,Nacos Server在15:01s时,Client remove for service Service,将3节点IP移除的,并在15:04,627 remove instances and subscribers。

服务端日志和客户端日志相互印证,可知,服务端15:01 Client remove for service Service 15:14remove instances and subscribers。 我查看了服务端的代码,发现Client remove for service Service这个日志打印的方法是事件驱动的。所以我想知道,服务端在什么情况下会执行(Client remove for service Service) and (remove instances and subscribers) 流程。 并且一个运行正常的客户端为什么会被服务端认为 2023-02-16 21:15:01,620 INFO Client remove for service Service{namespace='public', group='DEFAULT_GROUP', name='order-pro', ephemeral=true, revision=3666}, 10.2.9.88:7001#true 2023-02-16 21:15:04,627 INFO Client connection 10.2.9.88:7001#true disconnect, remove instances and subscribers。

回答

5
  1. 网络问题导致链接断开。
  2. 节点运行问题(cpu、内存、FullGC等)导致链接无法保活,断开。

断开后会尝试重连,重连后会自动重新注册和订阅。

5

从日志看, 使用的是1.X版本的客户端。

那么就是30s未发送心跳至服务端,可能原因和上述一致。

5

是的,我们是1.x的客户端,使用的http发送心跳请求。 我们将心跳间隔设置成了5s。 请问,如果网络问题导致链接断开,心跳客户端不是发生http请求么,并未跟服务端建立长链接?为什么会有链接断开的情况

4

根据你的提示,我们查看了节点运行问题(cpu、内存、FullGC等)。发现这个指标都正常,也就是说,服务是正常运行的,并未出现故障

8

我明白你的意思了,如果我们是2.x的client,就是指我们的长连接断开。 如果我们是1.x的客户端,就是指我们发送3次心跳时间内未发送心跳至服务端。导致服务端移除该实例。 但是我有个问题,首先我们是阿里云内网,网络都是好的,并且这个一段时间仍有其他服务进行调用。 并且客户端发送心跳日志失败时,会在naming.log日志文件中打印错误,这些我们都没有见到

4

那有可能是节点其他的问题导致心跳线程被卡住,导致没有发送。

服务端只是未检测到心跳续约,移除了

2023-02-16 21:15:01,620 INFO Client remove for service Service{namespace='public', group='DEFAULT_GROUP', name='order-pro', ephemeral=true, revision=3666}, [10.2.9.88:7001](http://10.2.9.88:7001/)#true
2023-02-16 21:15:04,627 INFO Client connection [10.2.9.88:7001](http://10.2.9.88:7001/)#true disconnect, remove instances and subscribers。
7

是的,通过日志,我们发现客户端在40s内并未向NacosServer发送心跳请求,我们设置的心跳间隔是5s

4

那就是客户端问题或者网络问题了。 需要排查应用和环境。