com.alibaba.nacos.api.exception.NacosException: Request nacos server failed:)
[2023-04-05 19:33:09.205] [ERROR] [com.alibaba.nacos.client.remote.worker] c.a.n.c.r.c.g.GrpcClient.printIfErrorEnabled [LoggerUtils.java:99 ] - Server check fail, please check server **.*.*.*** ,port 9848 is available , error ={} java.util.concurrent.TimeoutException: Waited 3000 milliseconds (plus 133573 nanoseconds delay) for com.alibaba.nacos.shaded.io.grpc.stub.Cl ientCalls$GrpcFuture@68226c97[status=PENDING, info=[GrpcFuture{clientCall={delegate={delegate=ClientCallImpl{method=MethodDescriptor{fullMet hodName=Request/request, type=UNARY, idempotent=false, safe=false, sampledToLocalTracing=true, requestMarshaller=com.alibaba.nacos.shaded.io .grpc.protobuf.lite.ProtoLiteUtils$MessageMarshaller@7add5b19, responseMarshaller=com.alibaba.nacos.shaded.io.grpc.protobuf.lite.ProtoLiteUt ils$MessageMarshaller@a1c659e, schemaDescriptor=com.alibaba.nacos.api.grpc.auto.RequestGrpc$RequestMethodDescriptorSupplier@2517bae6}}}}}]] at com.alibaba.nacos.shaded.com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:508) at com.alibaba.nacos.common.remote.client.grpc.GrpcClient.serverCheck(GrpcClient.java:192) at com.alibaba.nacos.common.remote.client.grpc.GrpcClient.connectToServer(GrpcClient.java:302) at com.alibaba.nacos.common.remote.client.RpcClient.reconnect(RpcClient.java:521) at com.alibaba.nacos.common.remote.client.RpcClient.lambda$start$2(RpcClient.java:369) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) [2023-04-05 19:33:09.206] [INFO ] [com.alibaba.nacos.client.remote.worker] c.a.n.c.r.client.printIfInfoEnabled [LoggerUtils.java:60] - [d6f69698-6284-4758-9812-163aea9a1cd6] Fail to connect server, after trying 5 times, last try server is {serverIp = '**.*.*.***', server main port = 8848}, error = unknown [2023-04-05 19:33:10.828] [ERROR] [com.alibaba.nacos.client.naming.updater.1] c.a.n.c.r.client.printIfErrorEnabled [LoggerUtils.java:99] - Send request fail, request = ServiceQueryRequest{headers={app=unknown}, requestId='null'}, retryTimes = 0, errorMessage = Client not connected, current status:UNHEALTHY [2023-04-05 19:33:10.928] [ERROR] [com.alibaba.nacos.client.naming.updater.1] c.a.n.c.r.client.printIfErrorEnabled [LoggerUtils.java:99] - Send request fail, request = ServiceQueryRequest{headers={app=unknown}, requestId='null'}, retryTimes = 1, errorMessage = Client not connected, current status:UNHEALTHY [2023-04-05 19:33:11.029] [ERROR] [com.alibaba.nacos.client.naming.updater.1] c.a.n.c.r.client.printIfErrorEnabled [LoggerUtils.java:99] - Send request fail, request = ServiceQueryRequest{headers={app=unknown}, requestId='null'}, retryTimes = 2, errorMessage = Client not connected, current status:UNHEALTHY [2023-04-05 19:33:11.029] [WARN ] [com.alibaba.nacos.client.naming.updater.1] c.a.n.client.naming.run [ServiceInfoUpdateService.java:198] - [NA] failed to update serviceName: UAT_GROUP@@dfcg-contract com.alibaba.nacos.api.exception.NacosException: Request nacos server failed: [NA] failed to update serviceName: UAT_GROUP@@dfcg-contract com.alibaba.nacos.api.exception.NacosException: Request nacos server failed: at com.alibaba.nacos.client.naming.remote.gprc.NamingGrpcClientProxy.requestToServer(NamingGrpcClientProxy.java:288) at com.alibaba.nacos.client.naming.remote.gprc.NamingGrpcClientProxy.queryInstancesOfService(NamingGrpcClientProxy.java:168) at com.alibaba.nacos.client.naming.remote.NamingClientProxyDelegate.queryInstancesOfService(NamingClientProxyDelegate.java:110) at com.alibaba.nacos.client.naming.core.ServiceInfoUpdateService$UpdateTask.run(ServiceInfoUpdateService.java:185) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) Caused by: com.alibaba.nacos.api.exception.NacosException: Client not connected, current status:UNHEALTHY at com.alibaba.nacos.common.remote.client.RpcClient.request(RpcClient.java:651) at com.alibaba.nacos.common.remote.client.RpcClient.request(RpcClient.java:631) at com.alibaba.nacos.client.naming.remote.gprc.NamingGrpcClientProxy.requestToServer(NamingGrpcClientProxy.java:278) ... 10 common frames omitted
[devuser@dev-cg-platform logs]$ grep 'Thread starvation or clock leap detected' nacos.log.2023-04-05.0 2023-04-05 19:33:42,633 WARN HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=1m8s776ms847µs171ns). [devuser@dev-cg-platform logs]$ grep 'Thread starvation or clock leap detected' nacos.log.2023-04-04.0 2023-04-04 06:38:02,534 WARN HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=1m46s556ms115µs835ns). [devuser@dev-cg-platform logs]$ grep 'Thread starvation or clock leap detected' nacos.log.2023-04-03.0 2023-04-03 13:00:45,036 WARN HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=45s336ms970µs889ns). [devuser@dev-cg-platform logs]$ grep 'Thread starvation or clock leap detected' nacos.log.2023-04-02.0 2023-04-02 23:30:59,155 WARN HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=1m20s824ms191µs759ns). [devuser@dev-cg-platform logs]$ grep 'Thread starvation or clock leap detected' nacos.log.2023-04-01.0 2023-04-01 20:07:07,371 WARN HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=1m12s612ms153µs480ns).
起初一天的异常信息没留意,然后连续查了几天发现都有一个共同点,每当nacos日志出现 Thread starvation or clock leap detected 时,子服务就会出现服务连接超时
Nacos 是一个基于服务发现和配置管理的平台,它会定期进行一些任务,如清理无效配置等,这些任务通常是由一个叫做“housekeeper”的线程执行的。当该线程因为某些原因被阻塞或者被长时间占用时,就可能会出现 Thread starvation 或者 clock leap detected 的问题,导致 Nacos 的运行出现异常。
增加 housekeeper 线程数:可以通过修改 Nacos 的配置文件(如 application.properties)来增加 housekeeper 线程数,让它们能够更快地完成任务,从而减少阻塞时间。
调整 housekeeper 的执行间隔:可以根据实际情况调整 housekeeper 的执行间隔,让它们能够更加高效地执行任务,从而减少占用时间。
检查系统资源:如果系统资源(如 CPU、内存等)不足,也会导致 housekeeper 线程被阻塞或者占用过长时间。因此,可以通过监控系统资源使用情况,及时增加资源,避免出现这种问题。
升级 Nacos 版本:Nacos 的新版本通常会修复一些已知问题,因此,如果出现 Thread starvation 或者 clock leap detected 的问题,可以尝试升级 Nacos 版本,看看是否能够解决问题。
总之,避免 Thread starvation 或者 clock leap detected 的关键是确保 housekeeper 线程能够高效地执行任务,同时保证系统资源充足
在 Nacos 中,housekeeper 是用来执行定期任务的线程,如删除过期的配置信息、清理无效的缓存等。默认情况下,Nacos 中只有一个 housekeeper 线程,如果系统中的配置信息比较多,这个线程可能会出现阻塞,导致 Nacos 的性能下降。
为了解决这个问题,可以通过修改 Nacos 的配置文件(如 application.properties)来配置 housekeeper 线程的数量和执行时间间隔。具体操作如下:
配置 housekeeper 线程数量:可以通过配置项 nacos.core.thread.count 来指定 housekeeper 线程的数量。例如,将其设置为 10,则会启动 10 个 housekeeper 线程来执行定期任务。默认情况下,该值为 1,也就是只有一个 housekeeper 线程。
# 设置 housekeeper 线程数量 nacos.core.thread.count=10
可以通过配置项 nacos.core.task.maxTime 来指定 housekeeper 执行任务的时间间隔。例如,将其设置为 30 分钟,则每隔 30 分钟会执行一次定期任务。默认情况下,该值为 15 分钟。
# 设置 housekeeper 执行时间间隔 nacos.core.task.maxTime=30m
nacos.cmdb.dumpTaskTimeInterval:dump 定时任务执行时间间隔,用于打印出定时任务执行的时间情况。 nacos.core.task.check.maxDelta:检查系统时间与 NTP 时间的最大差距,用于检测系统时间是否被篡改。 nacos.core.task.delete.task.interval:删除任务执行的时间间隔。
总之,配置 housekeeper 可以帮助优化 Nacos 的性能和稳定性,避免出现线程阻塞和性能下降等问题。
# 转储外部CMDB的间隔(以秒为单位): nacos.cmdb.dumpTaskInterval=3600
# 设置检查系统时间与 NTP 时间的最大差距 nacos.core.task.check.maxDelta=600000
# 设置定期清理过期数据的时间间隔 nacos.core.task.delete.task.interval=2h