pinxiong commented on issue #8225: URL: https://github.com/apache/dubbo/issues/8225#issuecomment-890495008
@gang0713 I upgraded Nacos and the problem seems to have disappeared. #### What I did + **Upgrade Nacos** <img width="769" alt="Nacos 2 0 2" src="https://user-images.githubusercontent.com/7067417/127768101-0338bcaa-1f7b-484d-a4b6-3d0f58eccb0b.png";> + **Start Provider** ```shell [root@ip-192-0-4-195 spring-boot-dubbo-nacos-demo]# java -jar shop-service-provider/target/shop-service-provider-0.0.1.jar log4j:WARN No appenders could be found for logger (org.apache.dubbo.common.Version). log4j:WARN Please initialize the log4j system properly. log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info. 2021-08-01 10:12:06 INFO org.apache.dubbo.spring.boot.context.event.WelcomeLogoApplicationListener:64 - :: Dubbo Spring Boot (v3.0.1) : https://github.com/apache/dubbo-spring-boot-project :: Dubbo (v3.0.1) : https://github.com/apache/dubbo :: Discuss group : [email protected] . ____ _ __ _ _ /\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \ ( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \ \\/ ___)| |_)| | | | | || (_| | ) ) ) ) ' |____| .__|_| |_|_| |_\__, | / / / / =========|_|==============|___/=/_/_/_/ :: Spring Boot :: (v2.3.12.RELEASE) 2021-08-01 10:12:06 INFO com.alibaba.boot.nacos.config.util.NacosConfigPropertiesUtils:47 - nacosConfigProperties : NacosConfigProperties{serverAddr='127.0.0.1:8848', contextPath='null', encode='null', endpoint='null', namespace='null', accessKey='null', secretKey='null', ramRoleName='null', autoRefresh=false, dataId='null', dataIds='null', group='DEFAULT_GROUP', type=null, maxRetry='null', configLongPollTimeout='null', configRetryTime='null', enableRemoteSyncConfig=false, extConfig=[], bootstrap=Bootstrap{enable=false, logEnable=false}} 2021-08-01 10:12:06 INFO com.alibaba.boot.nacos.config.autoconfigure.NacosConfigApplicationContextInitializer:75 - [Nacos Config Boot] : The preload configuration is not enabled 2021-08-01 10:12:06 INFO cn.raysonblog.shopserviceprovider.ShopServiceProviderApplication:55 - Starting ShopServiceProviderApplication on 192-0-4-195 with PID 3261 (/root/****/workspace/spring-boot-dubbo-nacos-demo/shop-service-provider/target/shop-service-provider-0.0.1.jar started by root in /root/****/workspace/spring-boot-dubbo-nacos-demo) 2021-08-01 10:12:06 INFO cn.raysonblog.shopserviceprovider.ShopServiceProviderApplication:648 - No active profile set, falling back to default profiles: default 2021-08-01 10:12:07 INFO org.springframework.context.annotation.ConfigurationClassPostProcessor:413 - Cannot enhance @Configuration bean definition 'org.apache.dubbo.spring.boot.autoconfigure.DubboRelaxedBinding2AutoConfiguration' since its singleton instance has been created too early. The typical cause is a non-static @Bean method with a BeanDefinitionRegistryPostProcessor return type: Consider declaring such methods as 'static'. 2021-08-01 10:12:07 INFO org.springframework.context.annotation.ConfigurationClassPostProcessor:413 - Cannot enhance @Configuration bean definition 'org.apache.dubbo.spring.boot.autoconfigure.DubboAutoConfiguration' since its singleton instance has been created too early. The typical cause is a non-static @Bean method with a BeanDefinitionRegistryPostProcessor return type: Consider declaring such methods as 'static'. 2021-08-01 10:12:08 WARN org.springframework.boot.context.properties.PropertySourcesDeducer:66 - Multiple PropertySourcesPlaceholderConfigurer beans registered [propertySourcesPlaceholderConfigurer, org.springframework.context.support.PropertySourcesPlaceholderConfigurer], falling back to Environment 2021-08-01 10:12:08 INFO org.reflections.Reflections:232 - Reflections took 120 ms to scan 1 urls, producing 3 keys and 6 values 2021-08-01 10:12:08 INFO org.reflections.Reflections:232 - Reflections took 77 ms to scan 1 urls, producing 4 keys and 9 values 2021-08-01 10:12:08 INFO org.reflections.Reflections:232 - Reflections took 64 ms to scan 1 urls, producing 3 keys and 10 values 2021-08-01 10:12:09 INFO org.reflections.Reflections:232 - Reflections took 271 ms to scan 78 urls, producing 0 keys and 0 values 2021-08-01 10:12:09 INFO org.reflections.Reflections:232 - Reflections took 50 ms to scan 1 urls, producing 1 keys and 5 values 2021-08-01 10:12:09 INFO org.reflections.Reflections:232 - Reflections took 59 ms to scan 1 urls, producing 1 keys and 7 values 2021-08-01 10:12:09 INFO org.reflections.Reflections:232 - Reflections took 47 ms to scan 1 urls, producing 2 keys and 8 values 2021-08-01 10:12:09 INFO org.reflections.Reflections:232 - Reflections took 216 ms to scan 78 urls, producing 0 keys and 0 values 2021-08-01 10:12:13 INFO cn.raysonblog.shopserviceprovider.ShopServiceProviderApplication:61 - Started ShopServiceProviderApplication in 7.541 seconds (JVM running for 9.344) 2021-08-01 10:12:13 INFO org.apache.dubbo.spring.boot.context.event.AwaitingNonWebApplicationListener:159 - [Dubbo] Current Spring Boot Application is await... ``` + **Check registered configuration in Nacos** <img width="1102" alt="Nacos Data" src="https://user-images.githubusercontent.com/7067417/127768118-9815997b-5444-4292-a506-fc003f7373c5.png";> + **Start Consumer** ```shell [root@ip-192-0-4-195 spring-boot-dubbo-nacos-demo]# java -jar shop-service-consumer/target/shop-service-consumer-0.0.1.jar log4j:WARN No appenders could be found for logger (org.apache.dubbo.common.Version). log4j:WARN Please initialize the log4j system properly. log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info. 2021-08-01 10:14:28 INFO org.apache.dubbo.spring.boot.context.event.WelcomeLogoApplicationListener:64 - :: Dubbo Spring Boot (v3.0.1) : https://github.com/apache/dubbo-spring-boot-project :: Dubbo (v3.0.1) : https://github.com/apache/dubbo :: Discuss group : [email protected] . ____ _ __ _ _ /\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \ ( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \ \\/ ___)| |_)| | | | | || (_| | ) ) ) ) ' |____| .__|_| |_|_| |_\__, | / / / / =========|_|==============|___/=/_/_/_/ :: Spring Boot :: (v2.3.12.RELEASE) 2021-08-01 10:14:28 INFO com.alibaba.boot.nacos.config.util.NacosConfigPropertiesUtils:47 - nacosConfigProperties : NacosConfigProperties{serverAddr='127.0.0.1:8848', contextPath='null', encode='null', endpoint='null', namespace='null', accessKey='null', secretKey='null', ramRoleName='null', autoRefresh=false, dataId='null', dataIds='null', group='DEFAULT_GROUP', type=null, maxRetry='null', configLongPollTimeout='null', configRetryTime='null', enableRemoteSyncConfig=false, extConfig=[], bootstrap=Bootstrap{enable=false, logEnable=false}} 2021-08-01 10:14:28 INFO com.alibaba.boot.nacos.config.autoconfigure.NacosConfigApplicationContextInitializer:75 - [Nacos Config Boot] : The preload configuration is not enabled 2021-08-01 10:14:28 INFO cn.raysonblog.shopserviceconsumer.ShopServiceConsumerApplication:55 - Starting ShopServiceConsumerApplication on 192-0-4-195 with PID 3757 (/root/****/workspace/spring-boot-dubbo-nacos-demo/shop-service-consumer/target/shop-service-consumer-0.0.1.jar started by root in /root/****/workspace/spring-boot-dubbo-nacos-demo) 2021-08-01 10:14:28 INFO cn.raysonblog.shopserviceconsumer.ShopServiceConsumerApplication:648 - No active profile set, falling back to default profiles: default 2021-08-01 10:14:29 INFO org.springframework.context.annotation.ConfigurationClassPostProcessor:413 - Cannot enhance @Configuration bean definition 'org.apache.dubbo.spring.boot.autoconfigure.DubboAutoConfiguration' since its singleton instance has been created too early. The typical cause is a non-static @Bean method with a BeanDefinitionRegistryPostProcessor return type: Consider declaring such methods as 'static'. 2021-08-01 10:14:29 INFO org.apache.dubbo.config.spring.beans.factory.annotation.ReferenceAnnotationBeanPostProcessor:463 - Register dubbo reference bean: shopService = ReferenceBean:cn.raysonblog.shopservice.api.service.RpcShopService:1.0.0() at cn.raysonblog.shopservice.api.service.RpcShopService cn.raysonblog.shopserviceconsumer.ShopServiceConsumerApplication.shopService 2021-08-01 10:14:30 WARN org.springframework.boot.context.properties.PropertySourcesDeducer:66 - Multiple PropertySourcesPlaceholderConfigurer beans registered [propertySourcesPlaceholderConfigurer, org.springframework.context.support.PropertySourcesPlaceholderConfigurer], falling back to Environment 2021-08-01 10:14:30 INFO org.springframework.boot.web.embedded.tomcat.TomcatWebServer:108 - Tomcat initialized with port(s): 9081 (http) 2021-08-01 10:14:30 INFO org.apache.coyote.http11.Http11NioProtocol:173 - Initializing ProtocolHandler ["http-nio-9081"] 2021-08-01 10:14:30 INFO org.apache.catalina.core.StandardService:173 - Starting service [Tomcat] 2021-08-01 10:14:30 INFO org.apache.catalina.core.StandardEngine:173 - Starting Servlet engine: [Apache Tomcat/9.0.46] 2021-08-01 10:14:30 INFO org.apache.catalina.core.ContainerBase.[Tomcat].[localhost].[/]:173 - Initializing Spring embedded WebApplicationContext 2021-08-01 10:14:30 INFO org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext:285 - Root WebApplicationContext: initialization completed in 2458 ms 2021-08-01 10:14:31 INFO org.apache.dubbo.config.spring.reference.ReferenceCreator:95 - The configBean[type:ReferenceConfig] has been built. 2021-08-01 10:14:31 INFO org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor:181 - Initializing ExecutorService 'applicationTaskExecutor' 2021-08-01 10:14:32 INFO org.reflections.Reflections:232 - Reflections took 92 ms to scan 1 urls, producing 3 keys and 6 values 2021-08-01 10:14:32 INFO org.reflections.Reflections:232 - Reflections took 76 ms to scan 1 urls, producing 4 keys and 9 values 2021-08-01 10:14:32 INFO org.reflections.Reflections:232 - Reflections took 74 ms to scan 1 urls, producing 3 keys and 10 values 2021-08-01 10:14:32 INFO org.reflections.Reflections:232 - Reflections took 361 ms to scan 89 urls, producing 0 keys and 0 values 2021-08-01 10:14:32 INFO org.reflections.Reflections:232 - Reflections took 40 ms to scan 1 urls, producing 1 keys and 5 values 2021-08-01 10:14:32 INFO org.reflections.Reflections:232 - Reflections took 46 ms to scan 1 urls, producing 1 keys and 7 values 2021-08-01 10:14:33 INFO org.reflections.Reflections:232 - Reflections took 46 ms to scan 1 urls, producing 2 keys and 8 values 2021-08-01 10:14:33 INFO org.reflections.Reflections:232 - Reflections took 239 ms to scan 89 urls, producing 0 keys and 0 values 2021-08-01 10:14:34 INFO org.springframework.scheduling.concurrent.ThreadPoolTaskScheduler:181 - Initializing ExecutorService 'taskScheduler' 2021-08-01 10:14:34 INFO org.apache.coyote.http11.Http11NioProtocol:173 - Starting ProtocolHandler ["http-nio-9081"] 2021-08-01 10:14:34 INFO org.springframework.boot.web.embedded.tomcat.TomcatWebServer:220 - Tomcat started on port(s): 9081 (http) with context path '' 2021-08-01 10:14:37 INFO cn.raysonblog.shopserviceconsumer.ShopServiceConsumerApplication:61 - Started ShopServiceConsumerApplication in 9.722 seconds (JVM running for 11.424) 2021-08-01 10:14:40 INFO cn.raysonblog.shopserviceconsumer.ShopServiceConsumerApplication$$EnhancerBySpringCGLIB$$536b5aa2:41 - mercyblitz 2021-08-01 10:14:45 INFO cn.raysonblog.shopserviceconsumer.ShopServiceConsumerApplication$$EnhancerBySpringCGLIB$$536b5aa2:41 - mercyblitz 2021-08-01 10:14:50 INFO cn.raysonblog.shopserviceconsumer.ShopServiceConsumerApplication$$EnhancerBySpringCGLIB$$536b5aa2:41 - mercyblitz 2021-08-01 10:14:55 INFO cn.raysonblog.shopserviceconsumer.ShopServiceConsumerApplication$$EnhancerBySpringCGLIB$$536b5aa2:41 - mercyblitz 2021-08-01 10:15:00 INFO cn.raysonblog.shopserviceconsumer.ShopServiceConsumerApplication$$EnhancerBySpringCGLIB$$536b5aa2:41 - mercyblitz 2021-08-01 10:15:05 INFO cn.raysonblog.shopserviceconsumer.ShopServiceConsumerApplication$$EnhancerBySpringCGLIB$$536b5aa2:41 - mercyblitz ``` + **Check error log in Nacos** ```shell 2021-08-01 10:14:36.431 INFO [com.alibaba.nacos.client.Worker:remote.client] [a9472ae0-c1b9-4900-a038-fa0af3603162_config-0]Register server push request handler:com.alibaba.nacos.client.config.impl.ClientWorker$ConfigRpcTransportClient$$Lambda$609/15730323 2021-08-01 10:14:36.431 INFO [com.alibaba.nacos.client.Worker:remote.client] [a9472ae0-c1b9-4900-a038-fa0af3603162_config-0]Register server push request handler:com.alibaba.nacos.client.config.impl.ClientWorker$ConfigRpcTransportClient$$Lambda$610/18903937 2021-08-01 10:14:36.431 INFO [com.alibaba.nacos.client.Worker:remote.client] [a9472ae0-c1b9-4900-a038-fa0af3603162_config-0]Registry connection listener to current client:com.alibaba.nacos.client.config.impl.ClientWorker$ConfigRpcTransportClient$1 2021-08-01 10:14:36.431 INFO [com.alibaba.nacos.client.Worker:remote.client] [a9472ae0-c1b9-4900-a038-fa0af3603162_config-0]RpcClient init, ServerListFactory =com.alibaba.nacos.client.config.impl.ClientWorker$ConfigRpcTransportClient$2 2021-08-01 10:14:36.432 INFO [com.alibaba.nacos.client.Worker:remote.client] [a9472ae0-c1b9-4900-a038-fa0af3603162_config-0] Try to connect to server on start up, server: {serverIp='127.0.0.1', server main port=8848} 2021-08-01 10:14:36.547 INFO [com.alibaba.nacos.client.Worker:remote.client] [a9472ae0-c1b9-4900-a038-fa0af3603162_config-0] Success to connect to server [127.0.0.1:8848] on start up,connectionId=1627812876440_127.0.0.1_35512 2021-08-01 10:14:36.548 INFO [com.alibaba.nacos.client.Worker:remote.client] [a9472ae0-c1b9-4900-a038-fa0af3603162_config-0]Register server push request handler:com.alibaba.nacos.common.remote.client.RpcClient$ConnectResetRequestHandler 2021-08-01 10:14:36.548 INFO [com.alibaba.nacos.client.remote.worker:remote.client] [a9472ae0-c1b9-4900-a038-fa0af3603162_config-0]Notify connected event to listeners. 2021-08-01 10:14:36.548 INFO [com.alibaba.nacos.client.Worker:remote.client] [a9472ae0-c1b9-4900-a038-fa0af3603162_config-0]Register server push request handler:com.alibaba.nacos.common.remote.client.RpcClient$4 2021-08-01 10:14:37.096 INFO [nacos-grpc-client-executor-4:remote.client] [768a5fc3-53fc-4193-b489-c5c163fa5757]receive server push request,request=NotifySubscriberRequest,requestId=4 2021-08-01 10:14:37.096 INFO [nacos-grpc-client-executor-4:remote.client] [768a5fc3-53fc-4193-b489-c5c163fa5757]ack server push request,request=NotifySubscriberRequest,requestId=4 2021-08-01 10:14:40.700 INFO [nacos-grpc-client-executor-14:remote.client] [0dee41da-e287-4201-b718-dccb09fb86db]receive server push request,request=NotifySubscriberRequest,requestId=5 2021-08-01 10:14:40.701 INFO [nacos-grpc-client-executor-14:remote.client] [0dee41da-e287-4201-b718-dccb09fb86db]ack server push request,request=NotifySubscriberRequest,requestId=5 2021-08-01 10:14:40.705 INFO [nacos-grpc-client-executor-14:remote.client] [0dee41da-e287-4201-b718-dccb09fb86db]receive server push request,request=NotifySubscriberRequest,requestId=6 2021-08-01 10:14:40.705 INFO [nacos-grpc-client-executor-14:remote.client] [0dee41da-e287-4201-b718-dccb09fb86db]ack server push request,request=NotifySubscriberRequest,requestId=6 2021-08-01 10:15:09.732 INFO [SpringContextShutdownHook:remote.client] Shutdown rpc client ,set status to shutdown 2021-08-01 10:15:09.732 INFO [SpringContextShutdownHook:remote.client] Shutdown client event executor java.util.concurrent.ScheduledThreadPoolExecutor@1a69f9e[Running, pool size = 2, active threads = 2, queued tasks = 0, completed tasks = 0] 2021-08-01 10:15:09.732 INFO [SpringContextShutdownHook:remote.client] Close current connection 1627812876307_127.0.0.1_35510 2021-08-01 10:15:09.745 INFO [nacos-grpc-client-executor-15:grpc.GrpcClient] [1627812876307_127.0.0.1_35510]Ignore complete event,isRunning:false,isAbandon=false 2021-08-01 10:15:09.747 INFO [SpringContextShutdownHook:grpc.GrpcClient] Shutdown grpc executor java.util.concurrent.ThreadPoolExecutor@19b27c9[Running, pool size = 7, active threads = 0, queued tasks = 0, completed tasks = 16] 2021-08-01 10:15:09.894 INFO [SpringContextShutdownHook:remote.client] Shutdown rpc client ,set status to shutdown 2021-08-01 10:15:09.894 INFO [SpringContextShutdownHook:remote.client] Shutdown client event executor java.util.concurrent.ScheduledThreadPoolExecutor@114fca[Running, pool size = 2, active threads = 2, queued tasks = 0, completed tasks = 0] 2021-08-01 10:15:09.895 INFO [SpringContextShutdownHook:remote.client] Close current connection 1627812874131_127.0.0.1_35502 2021-08-01 10:15:09.896 INFO [SpringContextShutdownHook:grpc.GrpcClient] Shutdown grpc executor java.util.concurrent.ThreadPoolExecutor@b68b25[Running, pool size = 3, active threads = 0, queued tasks = 0, completed tasks = 13] ``` #### Conclusion + The provider works well, if Nacos upgrade to `2.0.2` + The errors disappeared in Nacos logs, if Nacos upgrade to `2.0.2` Can you check if the problem can be disappeared, after upgraded Nacos from `1.4.2` to `2.0.2` ? -- 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: [email protected] For queries about this service, please contact Infrastructure at: [email protected] --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
![https://user-images.githubusercontent.com/7067417/127768101-0338bcaa-1f7b-484d-a4b6-3d0f58eccb0b.png"](https://user-images.githubusercontent.com/7067417/127768101-0338bcaa-1f7b-484d-a4b6-3d0f58eccb0b.png"){kind=link}
![https://user-images.githubusercontent.com/7067417/127768118-9815997b-5444-4292-a506-fc003f7373c5.png"](https://user-images.githubusercontent.com/7067417/127768118-9815997b-5444-4292-a506-fc003f7373c5.png"){kind=link}