Mongoosej.Blog.Software.Application Software.Microservices.Service Manage.Nacos

official website
official Github
official manual
introduction

[NACOS ConnectException httpPost] currentServerAddr: http://127.0.0.1:8848, err : Connection refused: connect

Nacos启动时报异常，打开Nacos Dashboard可以看到服务已经成功注册到了Nacos，但是日志持续输出异常。具体异常日志如下：

  1. 2022-06-14 15:24:44.339  WARN 6460 --- [           main] c.a.c.n.c.NacosPropertySourceBuilder     : Ignore the empty nacos configuration and get it based on dataId[KSEC-WCS-BASE] & group[DEFAULT_GROUP]
  2. 2022-06-14 15:24:47.346  WARN 6460 --- [           main] c.a.c.n.c.NacosPropertySourceBuilder     : Ignore the empty nacos configuration and get it based on dataId[KSEC-WCS-BASE.properties] & group[DEFAULT_GROUP]
  3. 2022-06-14 15:24:50.351  WARN 6460 --- [           main] c.a.c.n.c.NacosPropertySourceBuilder     : Ignore the empty nacos configuration and get it based on dataId[KSEC-WCS-BASE-k.properties] & group[DEFAULT_GROUP]
  4. 2022-06-14 15:24:50.352  INFO 6460 --- [           main] b.c.PropertySourceBootstrapConfiguration : Located property source: [BootstrapPropertySource {name='bootstrapProperties-KSEC-WCS-BASE-k.properties,DEFAULT_GROUP'}, BootstrapPropertySource {name='bootstrapProperties-KSEC-WCS-BASE.properties,DEFAULT_GROUP'}, BootstrapPropertySource {name='bootstrapProperties-KSEC-WCS-BASE,DEFAULT_GROUP'}]
  5. 2022-06-14 15:24:50.368  INFO 6460 --- [           main] com.ksec.wcs4.base.BaseApplication       : The following profiles are active: k
  6. 2022-06-14 15:24:52.072  INFO 6460 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Multiple Spring Data modules found, entering strict repository configuration mode!
  7. 2022-06-14 15:24:52.076  INFO 6460 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data Redis repositories in DEFAULT mode.
  8. 2022-06-14 15:24:52.129  INFO 6460 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 31 ms. Found 0 Redis repository interfaces.
  9. 2022-06-14 15:24:52.439  INFO 6460 --- [           main] o.s.cloud.context.scope.GenericScope     : BeanFactory id=971da03f-7520-36b6-8aa8-086d4b1c3801
  10. 2022-06-14 15:24:53.224  INFO 6460 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.cloud.commons.config.CommonsConfigAutoConfiguration' of type [org.springframework.cloud.commons.config.CommonsConfigAutoConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
  11. 2022-06-14 15:24:53.228  INFO 6460 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.cloud.client.loadbalancer.LoadBalancerDefaultMappingsProviderAutoConfiguration' of type [org.springframework.cloud.client.loadbalancer.LoadBalancerDefaultMappingsProviderAutoConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
  12. 2022-06-14 15:24:53.229  INFO 6460 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'loadBalancerClientsDefaultsMappingsProvider' of type [org.springframework.cloud.client.loadbalancer.LoadBalancerDefaultMappingsProviderAutoConfiguration$$Lambda$460/1842314090] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
  13. 2022-06-14 15:24:53.232  INFO 6460 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'defaultsBindHandlerAdvisor' of type [org.springframework.cloud.commons.config.DefaultsBindHandlerAdvisor] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
  14. 2022-06-14 15:24:53.316  INFO 6460 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'spring.cloud.sentinel-com.alibaba.cloud.sentinel.SentinelProperties' of type [com.alibaba.cloud.sentinel.SentinelProperties] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
  15. 2022-06-14 15:24:53.319  INFO 6460 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'com.alibaba.cloud.sentinel.custom.SentinelAutoConfiguration' of type [com.alibaba.cloud.sentinel.custom.SentinelAutoConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
  16. 2022-06-14 15:24:53.707  INFO 6460 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 9001 (http)
  17. 2022-06-14 15:24:53.723  INFO 6460 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
  18. 2022-06-14 15:24:53.723  INFO 6460 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.56]
  19. 2022-06-14 15:24:53.927  INFO 6460 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
  20. 2022-06-14 15:24:53.927  INFO 6460 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 3536 ms
  21. 2022-06-14 15:24:54.831  INFO 6460 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
  22. 2022-06-14 15:24:58.865  INFO 6460 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
  23. 2022-06-14 15:24:59.926  INFO 6460 --- [           main] org.redisson.Version                     : Redisson 3.17.1
  24. 2022-06-14 15:25:09.364  INFO 6460 --- [sson-netty-2-12] o.r.c.pool.MasterPubSubConnectionPool    : 1 connections initialized for 172.16.194.240/172.16.194.240:6379
  25. 2022-06-14 15:25:09.412  INFO 6460 --- [sson-netty-2-19] o.r.c.pool.MasterConnectionPool          : 24 connections initialized for 172.16.194.240/172.16.194.240:6379
  26. 2022-06-14 15:25:09.968  INFO 6460 --- [           main] o.s.c.openfeign.FeignClientFactoryBean   : For 'route' URL not provided. Will try picking an instance via load-balancing.
  27. 2022-06-14 15:25:11.360  INFO 6460 --- [           main] c.a.c.sentinel.SentinelWebMvcConfigurer  : [Sentinel Starter] register SentinelWebInterceptor with urlPatterns: [/**].
  28. 2022-06-14 15:25:25.664  WARN 6460 --- [           main] iguration$LoadBalancerCaffeineWarnLogger : Spring Cloud LoadBalancer is currently working with the default cache. While this cache implementation is useful for development and tests, it's recommended to use Caffeine cache in production.You can switch to using Caffeine cache, by adding it and org.springframework.cache.caffeine.CaffeineCacheManager to the classpath.
  29. 2022-06-14 15:25:25.803  INFO 6460 --- [           main] com.alibaba.nacos.client.naming          : initializer namespace from System Property :null
  30. 2022-06-14 15:25:25.803  INFO 6460 --- [           main] com.alibaba.nacos.client.naming          : initializer namespace from System Environment :null
  31. 2022-06-14 15:25:25.804  INFO 6460 --- [           main] com.alibaba.nacos.client.naming          : initializer namespace from System Property :null
  32. 2022-06-14 15:25:25.896  INFO 6460 --- [           main] com.alibaba.nacos.client.naming          : new ips(2) service: DEFAULT_GROUP@@KSEC-WCS-BASE@@DEFAULT -> [{"instanceId":"172.16.194.167#9001#DEFAULT#DEFAULT_GROUP@@KSEC-WCS-BASE","ip":"172.16.194.167","port":9001,"weight":1.0,"healthy":true,"enabled":true,"ephemeral":true,"clusterName":"DEFAULT","serviceName":"DEFAULT_GROUP@@KSEC-WCS-BASE","metadata":{"preserved.register.source":"SPRING_CLOUD"},"ipDeleteTimeout":30000,"instanceHeartBeatInterval":5000,"instanceHeartBeatTimeOut":15000},{"instanceId":"172.17.23.8#9001#DEFAULT#DEFAULT_GROUP@@KSEC-WCS-BASE","ip":"172.17.23.8","port":9001,"weight":1.0,"healthy":true,"enabled":true,"ephemeral":true,"clusterName":"DEFAULT","serviceName":"DEFAULT_GROUP@@KSEC-WCS-BASE","metadata":{"preserved.register.source":"SPRING_CLOUD"},"ipDeleteTimeout":30000,"instanceHeartBeatInterval":5000,"instanceHeartBeatTimeOut":15000}]
  33. 2022-06-14 15:25:25.906  INFO 6460 --- [           main] com.alibaba.nacos.client.naming          : current ips:(2) service: DEFAULT_GROUP@@KSEC-WCS-BASE@@DEFAULT -> [{"instanceId":"172.16.194.167#9001#DEFAULT#DEFAULT_GROUP@@KSEC-WCS-BASE","ip":"172.16.194.167","port":9001,"weight":1.0,"healthy":true,"enabled":true,"ephemeral":true,"clusterName":"DEFAULT","serviceName":"DEFAULT_GROUP@@KSEC-WCS-BASE","metadata":{"preserved.register.source":"SPRING_CLOUD"},"ipDeleteTimeout":30000,"instanceHeartBeatInterval":5000,"instanceHeartBeatTimeOut":15000},{"instanceId":"172.17.23.8#9001#DEFAULT#DEFAULT_GROUP@@KSEC-WCS-BASE","ip":"172.17.23.8","port":9001,"weight":1.0,"healthy":true,"enabled":true,"ephemeral":true,"clusterName":"DEFAULT","serviceName":"DEFAULT_GROUP@@KSEC-WCS-BASE","metadata":{"preserved.register.source":"SPRING_CLOUD"},"ipDeleteTimeout":30000,"instanceHeartBeatInterval":5000,"instanceHeartBeatTimeOut":15000}]
  34. 2022-06-14 15:25:25.936  INFO 6460 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 9001 (http) with context path ''
  35. 2022-06-14 15:25:25.945  INFO 6460 --- [           main] com.alibaba.nacos.client.naming          : [BEAT] adding beat: BeatInfo{port=9001, ip='192.168.136.1', weight=1.0, serviceName='DEFAULT_GROUP@@KSEC-WCS-BASE', cluster='DEFAULT', metadata={preserved.register.source=SPRING_CLOUD}, scheduled=false, period=5000, stopped=false} to beat map.
  36. 2022-06-14 15:25:25.948  INFO 6460 --- [           main] com.alibaba.nacos.client.naming          : [REGISTER-SERVICE] public registering service DEFAULT_GROUP@@KSEC-WCS-BASE with instance: Instance{instanceId='null', ip='192.168.136.1', port=9001, weight=1.0, healthy=true, enabled=true, ephemeral=true, clusterName='DEFAULT', serviceName='null', metadata={preserved.register.source=SPRING_CLOUD}}
  37. 2022-06-14 15:25:25.957  INFO 6460 --- [           main] c.a.c.n.registry.NacosServiceRegistry    : nacos registry, DEFAULT_GROUP KSEC-WCS-BASE 192.168.136.1:9001 register finished
  38. 2022-06-14 15:25:26.915  INFO 6460 --- [.naming.updater] com.alibaba.nacos.client.naming          : new ips(1) service: DEFAULT_GROUP@@KSEC-WCS-BASE@@DEFAULT -> [{"instanceId":"192.168.136.1#9001#DEFAULT#DEFAULT_GROUP@@KSEC-WCS-BASE","ip":"192.168.136.1","port":9001,"weight":1.0,"healthy":true,"enabled":true,"ephemeral":true,"clusterName":"DEFAULT","serviceName":"DEFAULT_GROUP@@KSEC-WCS-BASE","metadata":{"preserved.register.source":"SPRING_CLOUD"},"ipDeleteTimeout":30000,"instanceHeartBeatInterval":5000,"instanceHeartBeatTimeOut":15000}]
  39. 2022-06-14 15:25:26.916  INFO 6460 --- [.naming.updater] com.alibaba.nacos.client.naming          : current ips:(3) service: DEFAULT_GROUP@@KSEC-WCS-BASE@@DEFAULT -> [{"instanceId":"172.16.194.167#9001#DEFAULT#DEFAULT_GROUP@@KSEC-WCS-BASE","ip":"172.16.194.167","port":9001,"weight":1.0,"healthy":true,"enabled":true,"ephemeral":true,"clusterName":"DEFAULT","serviceName":"DEFAULT_GROUP@@KSEC-WCS-BASE","metadata":{"preserved.register.source":"SPRING_CLOUD"},"ipDeleteTimeout":30000,"instanceHeartBeatInterval":5000,"instanceHeartBeatTimeOut":15000},{"instanceId":"192.168.136.1#9001#DEFAULT#DEFAULT_GROUP@@KSEC-WCS-BASE","ip":"192.168.136.1","port":9001,"weight":1.0,"healthy":true,"enabled":true,"ephemeral":true,"clusterName":"DEFAULT","serviceName":"DEFAULT_GROUP@@KSEC-WCS-BASE","metadata":{"preserved.register.source":"SPRING_CLOUD"},"ipDeleteTimeout":30000,"instanceHeartBeatInterval":5000,"instanceHeartBeatTimeOut":15000},{"instanceId":"172.17.23.8#9001#DEFAULT#DEFAULT_GROUP@@KSEC-WCS-BASE","ip":"172.17.23.8","port":9001,"weight":1.0,"healthy":true,"enabled":true,"ephemeral":true,"clusterName":"DEFAULT","serviceName":"DEFAULT_GROUP@@KSEC-WCS-BASE","metadata":{"preserved.register.source":"SPRING_CLOUD"},"ipDeleteTimeout":30000,"instanceHeartBeatInterval":5000,"instanceHeartBeatTimeOut":15000}]
  40. 2022-06-14 15:25:31.677  INFO 6460 --- [           main] com.ksec.wcs4.base.BaseApplication       : Started BaseApplication in 64.073 seconds (JVM running for 64.995)
  41. 2022-06-14 15:25:31.686  INFO 6460 --- [           main] c.a.n.client.config.impl.ClientWorker    : [fixed-127.0.0.1_8848] [subscribe] KSEC-WCS-BASE+DEFAULT_GROUP
  42. 2022-06-14 15:25:31.688  INFO 6460 --- [           main] c.a.nacos.client.config.impl.CacheData   : [fixed-127.0.0.1_8848] [add-listener] ok, tenant=, dataId=KSEC-WCS-BASE, group=DEFAULT_GROUP, cnt=1
  43. 2022-06-14 15:25:31.688  INFO 6460 --- [           main] c.a.c.n.refresh.NacosContextRefresher    : listening config: dataId=KSEC-WCS-BASE, group=DEFAULT_GROUP
  44. 2022-06-14 15:25:31.690  INFO 6460 --- [           main] c.a.n.client.config.impl.ClientWorker    : [fixed-127.0.0.1_8848] [subscribe] KSEC-WCS-BASE.properties+DEFAULT_GROUP
  45. 2022-06-14 15:25:31.690  INFO 6460 --- [           main] c.a.nacos.client.config.impl.CacheData   : [fixed-127.0.0.1_8848] [add-listener] ok, tenant=, dataId=KSEC-WCS-BASE.properties, group=DEFAULT_GROUP, cnt=1
  46. 2022-06-14 15:25:31.690  INFO 6460 --- [           main] c.a.c.n.refresh.NacosContextRefresher    : listening config: dataId=KSEC-WCS-BASE.properties, group=DEFAULT_GROUP
  47. 2022-06-14 15:25:31.690  INFO 6460 --- [           main] c.a.n.client.config.impl.ClientWorker    : [fixed-127.0.0.1_8848] [subscribe] KSEC-WCS-BASE-k.properties+DEFAULT_GROUP
  48. 2022-06-14 15:25:31.691  INFO 6460 --- [           main] c.a.nacos.client.config.impl.CacheData   : [fixed-127.0.0.1_8848] [add-listener] ok, tenant=, dataId=KSEC-WCS-BASE-k.properties, group=DEFAULT_GROUP, cnt=1
  49. 2022-06-14 15:25:31.691  INFO 6460 --- [           main] c.a.c.n.refresh.NacosContextRefresher    : listening config: dataId=KSEC-WCS-BASE-k.properties, group=DEFAULT_GROUP
  50. 2022-06-14 15:25:33.715 ERROR 6460 --- [-127.0.0.1_8848] c.a.n.c.config.http.ServerHttpAgent      : [NACOS ConnectException httpPost] currentServerAddr: http://127.0.0.1:8848, err : Connection refused: connect
  51. 2022-06-14 15:25:35.728 ERROR 6460 --- [-127.0.0.1_8848] c.a.n.c.config.http.ServerHttpAgent      : [NACOS ConnectException httpPost] currentServerAddr: http://127.0.0.1:8848, err : Connection refused: connect
  52. 2022-06-14 15:25:37.740 ERROR 6460 --- [-127.0.0.1_8848] c.a.n.c.config.http.ServerHttpAgent      : [NACOS ConnectException httpPost] currentServerAddr: http://127.0.0.1:8848, err : Connection refused: connect
  53. 2022-06-14 15:25:39.755 ERROR 6460 --- [-127.0.0.1_8848] c.a.n.c.config.http.ServerHttpAgent      : [NACOS ConnectException httpPost] currentServerAddr: http://127.0.0.1:8848, err : Connection refused: connect
  54. 2022-06-14 15:25:39.755 ERROR 6460 --- [-127.0.0.1_8848] c.a.n.client.config.impl.ClientWorker    : [fixed-127.0.0.1_8848] [check-update] get changed dataId exception
  56. java.net.ConnectException: [NACOS HTTP-POST] The maximum number of tolerable server reconnection errors has been reached
  57.     at com.alibaba.nacos.client.config.http.ServerHttpAgent.httpPost(ServerHttpAgent.java:181) ~[nacos-client-1.4.2.jar:na]
  58.     at com.alibaba.nacos.client.config.http.MetricsHttpAgent.httpPost(MetricsHttpAgent.java:67) ~[nacos-client-1.4.2.jar:na]
  59.     at com.alibaba.nacos.client.config.impl.ClientWorker.checkUpdateConfigStr(ClientWorker.java:380) [nacos-client-1.4.2.jar:na]
  60.     at com.alibaba.nacos.client.config.impl.ClientWorker.checkUpdateDataIds(ClientWorker.java:347) [nacos-client-1.4.2.jar:na]
  61.     at com.alibaba.nacos.client.config.impl.ClientWorker$LongPollingRunnable.run(ClientWorker.java:535) [nacos-client-1.4.2.jar:na]
  62.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_131]
  63.     at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_131]
  64.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_131]
  65.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [na:1.8.0_131]
  66.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_131]
  67.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_131]
  68.     at java.lang.Thread.run(Thread.java:748) [na:1.8.0_131]
  70. 2022-06-14 15:25:39.755 ERROR 6460 --- [-127.0.0.1_8848] c.a.n.client.config.impl.ClientWorker    : longPolling error : 
  72. java.net.ConnectException: [NACOS HTTP-POST] The maximum number of tolerable server reconnection errors has been reached
  73.     at com.alibaba.nacos.client.config.http.ServerHttpAgent.httpPost(ServerHttpAgent.java:181) ~[nacos-client-1.4.2.jar:na]
  74.     at com.alibaba.nacos.client.config.http.MetricsHttpAgent.httpPost(MetricsHttpAgent.java:67) ~[nacos-client-1.4.2.jar:na]
  75.     at com.alibaba.nacos.client.config.impl.ClientWorker.checkUpdateConfigStr(ClientWorker.java:380) ~[nacos-client-1.4.2.jar:na]
  76.     at com.alibaba.nacos.client.config.impl.ClientWorker.checkUpdateDataIds(ClientWorker.java:347) ~[nacos-client-1.4.2.jar:na]
  77.     at com.alibaba.nacos.client.config.impl.ClientWorker$LongPollingRunnable.run(ClientWorker.java:535) ~[nacos-client-1.4.2.jar:na]
  78.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_131]
  79.     at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_131]
  80.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_131]
  81.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [na:1.8.0_131]
  82.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_131]
  83.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_131]
  84.     at java.lang.Thread.run(Thread.java:748) [na:1.8.0_131]
  86. 2022-06-14 15:25:43.770 ERROR 6460 --- [-127.0.0.1_8848] c.a.n.c.config.http.ServerHttpAgent      : [NACOS ConnectException httpPost] currentServerAddr: http://127.0.0.1:8848, err : Connection refused: connect

从日志可以看出，报错位置为com.alibaba.nacos.client.config.http.ServerHttpAgent.httpPost(…)，日志输出currentServerAddr: http://127.0.0.1:8848，地址127.0.0.1由全局变量serverListMgr获取，而serverListMgr由ServerHttpAgent构造时通过properties创建，而ServerHttpAgent由NacosConfigService构造时创建，NacosConfigService由NacosConfigManager构造时通过反射创建，NacosConfigManager由NacosConfigAutoConfiguration自动配置类创建，创建过程使用NacosConfigProperties所定义的属性。整个调用链如下：
image.png
那么，可以断定，currentServerAddr是由NacosConfigProperties定义的。
但是application.yml中定义的配置为：spring.cloud.nacos.server-addr=
先加载了配置中心，配置中心自动配置NacosConfigBootstrapConfiguration时，注入NacosConfigProperties的bean使用new的方式，而不是@EnableConfigurationProperties注入NacosConfigProperties，所以new出来的bean属性都是默认值。一旦NacosConfigProperties注入之后，后面的再次注入，该对象已经由地址，所以不会被覆盖了。