You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@dubbo.apache.org by GitBox <gi...@apache.org> on 2022/11/21 03:21:41 UTC

[GitHub] [dubbo] HTFX-Cloud commented on issue #10965: nacos+dubbo服务负载,某消费端标记提供者节点为isAvailable导致负载不均衡

HTFX-Cloud commented on issue #10965:
URL: https://github.com/apache/dubbo/issues/10965#issuecomment-1321403386

   从10点开始出现[Dubbo-thread-2] ~ WARN  org.apache.dubbo.remoting.exchange.support.DefaultFuture 177 received -  [DUBBO] The timeout response finally returned at 2022-10-19 10:01:09.345, response status is 20, channel: /10.177.56.133:43182 -> /10.177.56.133:20882, please check provider side for detailed result., dubbo version: 2.7.8, current host: 161.2.56.133
   以及error的日志(该日志倒排取的,需要注意)
   10-19 10:27:32,600 [pool-7-thread-1700] ~c885fe8c32434010a0eb9f06892c1b6f INFO  a.b.c.bd.handler.DispatcherNodeInstanceHandler 675 doReleaseRes - NODE[c885fe8c32434010a0eb9f06892c1b6f] 执行任务释放资源步骤:释放资源!
   10-19 10:27:32,617 [pool-7-thread-2957] ~4031a4934f6c47cab380c66e2e46f4df INFO  a.b.c.bd.logic.impl.TodoTaskOperationService 269 processTodoTask - 处理代办时,workflowKey=03a7a64a0ce14b9b95d264036d964d89,workflowCurrentKey=69A7FA817268477B9C0DBF3686396C4F,nodeKey=fee5cfb39e9748de9fa152f55bc12b18,taskRunId=d1555c00314c4a759d333316327cecac对应的任务启动时的项目信息为{projectId=null, spaceId=0, WfbloodRerunInfo=}
   10-19 10:27:32,627 [pool-7-thread-4967] ~357eeb0785e2443a8d0f3594c8307ad5 DEBUG a.b.c.bd.dao.impl.TaskOperationDao 1503 getAllStatus - getAllStatus:[ ]
   10-19 10:27:32,627 [pool-7-thread-1405] ~720d2d06a8744456b4d740d5cd1be846 INFO  a.b.c.bd.handler.DispatcherNodeInstanceHandler 410 doBegin - NODE[720d2d06a8744456b4d740d5cd1be846] 执行任务开始步骤:初始化任务变量!
   
   	... 3 more
   	at com.alibaba.nacos.client.naming.core.EventDispatcher$Notifier.run(EventDispatcher.java:132) ~[nacos-client-1.3.0.jar:?]
   	at org.apache.dubbo.registry.nacos.NacosRegistry.lambda$subscribeEventListener$10(NacosRegistry.java:507) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.registry.nacos.NacosRegistry.notifySubscriber(NacosRegistry.java:529) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.registry.support.FailbackRegistry.notify(FailbackRegistry.java:398) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.registry.support.FailbackRegistry.doNotify(FailbackRegistry.java:407) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.registry.support.AbstractRegistry.notify(AbstractRegistry.java:426) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.registry.integration.RegistryDirectory.notify(RegistryDirectory.java:254) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.registry.integration.RegistryDirectory.refreshOverrideAndInvoker(RegistryDirectory.java:271) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.registry.integration.RegistryDirectory.refreshInvoker(RegistryDirectory.java:336) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.registry.integration.RegistryDirectory.destroyUnusedInvokers(RegistryDirectory.java:580) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.protocol.InvokerWrapper.destroy(InvokerWrapper.java:61) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.destroy(ProtocolFilterWrapper.java:131) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.listener.ListenerInvokerWrapper.destroy(ListenerInvokerWrapper.java:89) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.protocol.AsyncToSyncInvoker.destroy(AsyncToSyncInvoker.java:96) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.protocol.dubbo.DubboInvoker.destroy(DubboInvoker.java:153) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.protocol.dubbo.ReferenceCountExchangeClient.close(ReferenceCountExchangeClient.java:164) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.protocol.dubbo.LazyConnectExchangeClient.close(LazyConnectExchangeClient.java:204) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.remoting.exchange.support.header.HeaderExchangeClient.close(HeaderExchangeClient.java:144) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.remoting.exchange.support.header.HeaderExchangeChannel.close(HeaderExchangeChannel.java:177) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.remoting.exchange.support.header.HeaderExchangeChannel.close(HeaderExchangeChannel.java:152) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.remoting.exchange.support.DefaultFuture.closeChannel(DefaultFuture.java:147) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.common.threadpool.ThreadlessExecutor.shutdownNow(ThreadlessExecutor.java:164) ~[dubbo-2.7.8.jar:2.7.8]
   Caused by: java.lang.IllegalStateException: Consumer is shutting down and this call is going to be stopped without receiving any result, usually this is called by a slow provider instance or bad service implementation.
   	... 57 more
   	at org.apache.dubbo.rpc.cluster.support.FailoverClusterInvoker.doInvoke(FailoverClusterInvoker.java:82) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.protocol.InvokerWrapper.invoke(InvokerWrapper.java:56) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:83) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.filter.ConsumerContextFilter.invoke(ConsumerContextFilter.java:69) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:83) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.protocol.dubbo.filter.FutureFilter.invoke(FutureFilter.java:51) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:83) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.monitor.support.MonitorFilter.invoke(MonitorFilter.java:89) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.listener.ListenerInvokerWrapper.invoke(ListenerInvokerWrapper.java:78) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.protocol.AsyncToSyncInvoker.invoke(AsyncToSyncInvoker.java:61) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.AsyncRpcResult.get(AsyncRpcResult.java:181) ~[dubbo-2.7.8.jar:2.7.8]
   	at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915) ~[?:1.8.0_181]
   	at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:357) ~[?:1.8.0_181]
   Caused by: java.util.concurrent.ExecutionException: java.lang.IllegalStateException: Consumer is shutting down and this call is going to be stopped without receiving any result, usually this is called by a slow provider instance or bad service implementation.
   	at java.lang.Thread.run(Thread.java:748) ~[?:1.8.0_181]
   	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_181]
   	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_181]
   	at a.b.c.bd.handler.DispatcherNodeInstanceHandler.run(DispatcherNodeInstanceHandler.java:192) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.handler.DispatcherNodeInstanceHandler.exec(DispatcherNodeInstanceHandler.java:376) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.handler.DispatcherNodeInstanceHandler.doBegin(DispatcherNodeInstanceHandler.java:446) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.handler.DispatcherNodeInstanceHandler.doNextStep(DispatcherNodeInstanceHandler.java:1621) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.handler.DispatcherNodeInstanceHandler.exec(DispatcherNodeInstanceHandler.java:380) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.handler.DispatcherNodeInstanceHandler.doCompeteRes(DispatcherNodeInstanceHandler.java:478) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.handler.DispatcherNodeInstanceHandler.doNextStep(DispatcherNodeInstanceHandler.java:1621) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.handler.DispatcherNodeInstanceHandler.exec(DispatcherNodeInstanceHandler.java:384) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.handler.DispatcherNodeInstanceHandler.doBusiness(DispatcherNodeInstanceHandler.java:596) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.handler.DispatcherNodeInstanceHandler.doNextStep(DispatcherNodeInstanceHandler.java:1621) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.handler.DispatcherNodeInstanceHandler.exec(DispatcherNodeInstanceHandler.java:388) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.handler.DispatcherNodeInstanceHandler.doReceiveVar(DispatcherNodeInstanceHandler.java:666) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.handler.DispatcherNodeInstanceHandler.doNextStep(DispatcherNodeInstanceHandler.java:1621) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.handler.DispatcherNodeInstanceHandler.exec(DispatcherNodeInstanceHandler.java:392) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.handler.DispatcherNodeInstanceHandler.doReleaseRes(DispatcherNodeInstanceHandler.java:681) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.handler.DispatcherNodeInstanceHandler.doNextStep(DispatcherNodeInstanceHandler.java:1621) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.handler.DispatcherNodeInstanceHandler.exec(DispatcherNodeInstanceHandler.java:396) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.handler.DispatcherNodeInstanceHandler.doTrigger(DispatcherNodeInstanceHandler.java:749) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.handler.DispatcherNodeInstanceHandler.doNextStep(DispatcherNodeInstanceHandler.java:1621) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.handler.DispatcherNodeInstanceHandler.exec(DispatcherNodeInstanceHandler.java:400) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.handler.DispatcherNodeInstanceHandler.doEnd(DispatcherNodeInstanceHandler.java:794) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.logic.impl.TodoTaskOperationService$$EnhancerBySpringCGLIB$$1e7ef4d6.processBatchTodoTasksAsyncWithRerunTodos(<generated>) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688) ~[spring-aop-5.1.8.RELEASE.jar:5.1.8.RELEASE]
   	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.1.8.RELEASE.jar:5.1.8.RELEASE]
   	at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:93) ~[spring-aop-5.1.8.RELEASE.jar:5.1.8.RELEASE]
   	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.1.8.RELEASE.jar:5.1.8.RELEASE]
   	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98) ~[spring-tx-5.1.8.RELEASE.jar:5.1.8.RELEASE]
   	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:295) ~[spring-tx-5.1.8.RELEASE.jar:5.1.8.RELEASE]
   	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.1.8.RELEASE.jar:5.1.8.RELEASE]
   	at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:749) ~[spring-aop-5.1.8.RELEASE.jar:5.1.8.RELEASE]
   	at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) ~[spring-core-5.1.8.RELEASE.jar:5.1.8.RELEASE]
   	at a.b.c.bd.logic.impl.TodoTaskOperationService$$FastClassBySpringCGLIB$$29b976c.invoke(<generated>) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.logic.impl.TodoTaskOperationService.processBatchTodoTasksAsyncWithRerunTodos(TodoTaskOperationService.java:961) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.logic.impl.TodoTaskOperationService.processBatchTodoTasks(TodoTaskOperationService.java:1065) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.logic.impl.TodoTaskOperationService.processTodoTask(TodoTaskOperationService.java:415) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.manager.TaskExecutionService.executeTask(TaskExecutionService.java:78) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at a.b.c.bd.manager.TaskExecutionService.executeTask(TaskExecutionService.java:135) ~[dbd-service-5.3-MASTER-20220608.095809-138.jar:?]
   	at org.apache.dubbo.common.bytecode.proxy0$$EnhancerBySpringCGLIB$$75f0c32c.executeTask(<generated>) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688) ~[spring-aop-5.1.8.RELEASE.jar:5.1.8.RELEASE]
   	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.1.8.RELEASE.jar:5.1.8.RELEASE]
   	at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:93) ~[spring-aop-5.1.8.RELEASE.jar:5.1.8.RELEASE]
   	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.1.8.RELEASE.jar:5.1.8.RELEASE]
   	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98) ~[spring-tx-5.1.8.RELEASE.jar:5.1.8.RELEASE]
   	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:295) ~[spring-tx-5.1.8.RELEASE.jar:5.1.8.RELEASE]
   	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.1.8.RELEASE.jar:5.1.8.RELEASE]
   	at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:749) ~[spring-aop-5.1.8.RELEASE.jar:5.1.8.RELEASE]
   	at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) ~[spring-core-5.1.8.RELEASE.jar:5.1.8.RELEASE]
   	at org.apache.dubbo.common.bytecode.proxy0$$FastClassBySpringCGLIB$$c197671e.invoke(<generated>) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.common.bytecode.proxy0.executeTask(proxy0.java) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.proxy.InvokerInvocationHandler.invoke(InvokerInvocationHandler.java:74) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.cluster.support.wrapper.MockClusterInvoker.invoke(MockClusterInvoker.java:88) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.cluster.support.wrapper.AbstractCluster$InterceptorInvokerNode.invoke(AbstractCluster.java:92) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.cluster.interceptor.ClusterInterceptor.intercept(ClusterInterceptor.java:47) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.cluster.support.AbstractClusterInvoker.invoke(AbstractClusterInvoker.java:260) ~[dubbo-2.7.8.jar:2.7.8]
   	at org.apache.dubbo.rpc.cluster.support.FailoverClusterInvoker.doInvoke(FailoverClusterInvoker.java:113) ~[dubbo-2.7.8.jar:2.7.8]
   10-19 10:27:43,391 [pool-7-thread-4442] ~416ce361b8e9466f894a46a6e34adace ERROR a.b.c.bd.manager.TaskExecutionService 199 executeTask - 1次调用后非文件存储异常信息 org.apache.dubbo.rpc.RpcException: Failed to invoke the method executeTask in the service a.b.c.bd.api.IEngineService. Tried 1 times of the providers [10.177.56.133:20882] (1/4) from the registry 10.177.56.130:9908 on the consumer 161.2.56.133 using the dubbo version 2.7.8. Last error is: Fail to invoke remote method: executeTask, provider: dubbo://10.177.56.133:20882/engineService?anyhost=true&application=dbd-app&category=providers&check=false&deprecated=false&dubbo=2.0.2&dynamic=true&generic=false&group=public&init=true&interface=a.b.c.bd.api.IEngineService&metadata-type=remote&methods=reRunTask,executeTask&path=engineService&payload=104857600&pid=2378&protocol=dubbo&qos.enable=false&register.ip=161.2.56.133&release=2.7.8&remote.application=dbd-app&retries=0&revision=5.3-MASTER-20220608.095739-141&side=co
 nsumer&sticky=false&timeout=30000&timestamp=1655987866520&version=5.0, cause: java.lang.IllegalStateException: Consumer is shutting down and this call is going to be stopped without receiving any result, usually this is called by a slow provider instance or bad service implementation.
   10-19 10:27:32,632 [pool-7-thread-305] ~db4ed7dab49b42dcaa809c8f212a2e5e DEBUG a.b.c.bd.consumer.PrepareForTaskExecutor 110 prepareExecutionParameter - DataOps: key=projectId,value=null


-- 
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: notifications-unsubscribe@dubbo.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


---------------------------------------------------------------------
To unsubscribe, e-mail: notifications-unsubscribe@dubbo.apache.org
For additional commands, e-mail: notifications-help@dubbo.apache.org