Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

nacos 2.0.0 trigger java.util.concurrent.RejectedExecutionException when stopping #5327

Closed
lishangbu opened this issue Apr 9, 2021 · 3 comments
Labels
kind/bug Category issues or prs related to bug.
Milestone

Comments

@lishangbu
Copy link

lishangbu commented Apr 9, 2021

Describe the bug
Application with nacos 2.0.0 client cannot stop.

Expected behavior
stop application quietly and deregister application from nacos server
Acutally behavior
trigger java.util.concurrent.RejectedExecutionException
How to Reproduce
Steps to reproduce the behavior:

  1. Run nacos 2.0.0 server
  2. Import demo project,run it
  3. Stop demo application
  4. See error

Desktop (please complete the following information):

  • OS: OSX 11.2
  • Version [e.g. nacos-server 2.0.0, nacos-client 2.0.0]
  • Module [e.g. naming/config]
  • SDK [e.g. original, spring-cloud-alibaba-nacos]

Additional context

2021-04-09 23:44:50.153 ERROR 12321 --- [extShutdownHook] c.a.cloud.nacos.discovery.NacosWatch     : namingService unsubscribe failed, properties:NacosDiscoveryProperties{serverAddr='localhost:8848', endpoint='', namespace='public', watchDelay=30000, logName='', service='demo', weight=1.0, clusterName='DEFAULT', group='DEFAULT_GROUP', namingLoadCacheAtStart='false', metadata={preserved.register.source=SPRING_CLOUD}, registerEnabled=true, ip='192.168.0.104', networkInterface='', port=-1, secure=false, accessKey='', secretKey='', heartBeatInterval=null, heartBeatTimeout=null, ipDeleteTimeout=null}

com.alibaba.nacos.api.exception.NacosException: Request nacos server failed: 
	at com.alibaba.nacos.client.naming.remote.gprc.NamingGrpcClientProxy.requestToServer(NamingGrpcClientProxy.java:213) ~[nacos-client-2.0.0.jar:na]
	at com.alibaba.nacos.client.naming.remote.gprc.NamingGrpcClientProxy.unsubscribe(NamingGrpcClientProxy.java:182) ~[nacos-client-2.0.0.jar:na]
	at com.alibaba.nacos.client.naming.remote.NamingClientProxyDelegate.unsubscribe(NamingClientProxyDelegate.java:156) ~[nacos-client-2.0.0.jar:na]
	at com.alibaba.nacos.client.naming.NacosNamingService.unsubscribe(NacosNamingService.java:411) ~[nacos-client-2.0.0.jar:na]
	at com.alibaba.cloud.nacos.discovery.NacosWatch.stop(NacosWatch.java:166) ~[spring-cloud-starter-alibaba-nacos-discovery-2021.1.jar:2021.1]
	at com.alibaba.cloud.nacos.discovery.NacosWatch.stop(NacosWatch.java:97) ~[spring-cloud-starter-alibaba-nacos-discovery-2021.1.jar:2021.1]
	at org.springframework.context.support.DefaultLifecycleProcessor.doStop(DefaultLifecycleProcessor.java:234) ~[spring-context-5.3.5.jar:5.3.5]
	at org.springframework.context.support.DefaultLifecycleProcessor.access$300(DefaultLifecycleProcessor.java:54) ~[spring-context-5.3.5.jar:5.3.5]
	at org.springframework.context.support.DefaultLifecycleProcessor$LifecycleGroup.stop(DefaultLifecycleProcessor.java:373) ~[spring-context-5.3.5.jar:5.3.5]
	at org.springframework.context.support.DefaultLifecycleProcessor.stopBeans(DefaultLifecycleProcessor.java:206) ~[spring-context-5.3.5.jar:5.3.5]
	at org.springframework.context.support.DefaultLifecycleProcessor.onClose(DefaultLifecycleProcessor.java:129) ~[spring-context-5.3.5.jar:5.3.5]
	at org.springframework.context.support.AbstractApplicationContext.doClose(AbstractApplicationContext.java:1067) ~[spring-context-5.3.5.jar:5.3.5]
	at org.springframework.context.support.AbstractApplicationContext$1.run(AbstractApplicationContext.java:991) ~[spring-context-5.3.5.jar:5.3.5]
Caused by: com.alibaba.nacos.api.exception.NacosException: java.util.concurrent.RejectedExecutionException: Task com.alibaba.nacos.shaded.io.grpc.internal.SerializingExecutor@5af2eac rejected from java.util.concurrent.ThreadPoolExecutor@6a3fc74f[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 18]
	at com.alibaba.nacos.common.remote.client.RpcClient.request(RpcClient.java:675) ~[nacos-client-2.0.0.jar:na]
	at com.alibaba.nacos.common.remote.client.RpcClient.request(RpcClient.java:608) ~[nacos-client-2.0.0.jar:na]
	at com.alibaba.nacos.client.naming.remote.gprc.NamingGrpcClientProxy.requestToServer(NamingGrpcClientProxy.java:203) ~[nacos-client-2.0.0.jar:na]
	... 12 common frames omitted
Caused by: java.util.concurrent.RejectedExecutionException: Task com.alibaba.nacos.shaded.io.grpc.internal.SerializingExecutor@5af2eac rejected from java.util.concurrent.ThreadPoolExecutor@6a3fc74f[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 18]
	at java.base/java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2055) ~[na:na]
	at java.base/java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:825) ~[na:na]
	at java.base/java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1355) ~[na:na]
	at com.alibaba.nacos.shaded.io.grpc.internal.SerializingExecutor.schedule(SerializingExecutor.java:93) ~[nacos-client-2.0.0.jar:na]
	at com.alibaba.nacos.shaded.io.grpc.internal.SerializingExecutor.execute(SerializingExecutor.java:86) ~[nacos-client-2.0.0.jar:na]
	at com.alibaba.nacos.shaded.io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.closedInternal(ClientCallImpl.java:696) ~[nacos-client-2.0.0.jar:na]
	at com.alibaba.nacos.shaded.io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.closed(ClientCallImpl.java:646) ~[nacos-client-2.0.0.jar:na]
	at com.alibaba.nacos.shaded.io.grpc.internal.FailingClientStream.start(FailingClientStream.java:54) ~[nacos-client-2.0.0.jar:na]
	at com.alibaba.nacos.shaded.io.grpc.internal.ClientCallImpl.startInternal(ClientCallImpl.java:290) ~[nacos-client-2.0.0.jar:na]
	at com.alibaba.nacos.shaded.io.grpc.internal.ClientCallImpl.start(ClientCallImpl.java:190) ~[nacos-client-2.0.0.jar:na]
	at com.alibaba.nacos.shaded.io.grpc.internal.CensusTracingModule$TracingClientInterceptor$1.start(CensusTracingModule.java:394) ~[nacos-client-2.0.0.jar:na]
	at com.alibaba.nacos.shaded.io.grpc.internal.CensusStatsModule$StatsClientInterceptor$1.start(CensusStatsModule.java:695) ~[nacos-client-2.0.0.jar:na]
	at com.alibaba.nacos.shaded.io.grpc.stub.ClientCalls.startCall(ClientCalls.java:310) ~[nacos-client-2.0.0.jar:na]
	at com.alibaba.nacos.shaded.io.grpc.stub.ClientCalls.asyncUnaryRequestCall(ClientCalls.java:282) ~[nacos-client-2.0.0.jar:na]
	at com.alibaba.nacos.shaded.io.grpc.stub.ClientCalls.futureUnaryCall(ClientCalls.java:191) ~[nacos-client-2.0.0.jar:na]
	at com.alibaba.nacos.api.grpc.auto.RequestGrpc$RequestFutureStub.request(RequestGrpc.java:212) ~[nacos-client-2.0.0.jar:na]
	at com.alibaba.nacos.common.remote.client.grpc.GrpcConnection.request(GrpcConnection.java:73) ~[nacos-client-2.0.0.jar:na]
	at com.alibaba.nacos.common.remote.client.RpcClient.request(RpcClient.java:630) ~[nacos-client-2.0.0.jar:na]
	... 14 common frames omitted


Process finished with exit code 130 (interrupted by signal 2: SIGINT)

A demo application for this bug:
demo.zip

@KomachiSion
Copy link
Collaborator

Please upgrade to 2.0.0-bugfix and retry

@lishangbu
Copy link
Author

When using 2.0.0-bugfix version,a different error is occured.See the log below:


  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v2.4.4)

2021-04-13 16:01:24.841  INFO 11025 --- [           main] com.example.demo.DemoApplication         : Starting DemoApplication using Java 15.0.2 on lishangbudeMacBook-Pro.local with PID 11025 (/Users/lishangbu/Downloads/demo/target/demo-0.0.1-SNAPSHOT.jar started by lishangbu in /Users/lishangbu/Downloads/demo/target)
2021-04-13 16:01:24.844  INFO 11025 --- [           main] com.example.demo.DemoApplication         : No active profile set, falling back to default profiles: default
2021-04-13 16:01:25.374  INFO 11025 --- [           main] o.s.cloud.context.scope.GenericScope     : BeanFactory id=c30cba25-e6d9-3499-a529-5962e684ec43
2021-04-13 16:01:25.467  INFO 11025 --- [           main] o.s.s.c.ThreadPoolTaskScheduler          : Initializing ExecutorService 'Nacos-Watch-Task-Scheduler'
2021-04-13 16:01:26.078  INFO 11025 --- [           main] org.reflections.Reflections              : Reflections took 122 ms to scan 1 urls, producing 3 keys and 6 values 
2021-04-13 16:01:26.159  INFO 11025 --- [           main] org.reflections.Reflections              : Reflections took 60 ms to scan 1 urls, producing 4 keys and 9 values 
2021-04-13 16:01:26.224  INFO 11025 --- [           main] org.reflections.Reflections              : Reflections took 61 ms to scan 1 urls, producing 3 keys and 10 values 
2021-04-13 16:01:26.362  INFO 11025 --- [           main] org.reflections.Reflections              : Reflections took 135 ms to scan 38 urls, producing 0 keys and 0 values 
2021-04-13 16:01:26.421  INFO 11025 --- [           main] org.reflections.Reflections              : Reflections took 58 ms to scan 1 urls, producing 1 keys and 5 values 
2021-04-13 16:01:26.490  INFO 11025 --- [           main] org.reflections.Reflections              : Reflections took 66 ms to scan 1 urls, producing 1 keys and 7 values 
2021-04-13 16:01:26.566  INFO 11025 --- [           main] org.reflections.Reflections              : Reflections took 73 ms to scan 1 urls, producing 2 keys and 8 values 
2021-04-13 16:01:26.680  INFO 11025 --- [           main] org.reflections.Reflections              : Reflections took 110 ms to scan 38 urls, producing 0 keys and 0 values 
2021-04-13 16:01:27.919  INFO 11025 --- [           main] com.example.demo.DemoApplication         : Started DemoApplication in 3.493 seconds (JVM running for 3.9)
2021-04-13 16:01:39.356  WARN 11025 --- [       Thread-4] c.a.nacos.common.notify.NotifyCenter     : [NotifyCenter] Start destroying Publisher
2021-04-13 16:01:39.356  WARN 11025 --- [       Thread-4] c.a.nacos.common.notify.NotifyCenter     : [NotifyCenter] Destruction of the end
2021-04-13 16:01:39.356  WARN 11025 --- [       Thread-7] c.a.n.common.http.HttpClientBeanHolder   : [HttpClientBeanHolder] Start destroying common HttpClient
2021-04-13 16:01:39.356  WARN 11025 --- [       Thread-7] c.a.n.common.http.HttpClientBeanHolder   : [HttpClientBeanHolder] Destruction of the end
2021-04-13 16:01:39.357  INFO 11025 --- [extShutdownHook] o.s.s.c.ThreadPoolTaskScheduler          : Shutting down ExecutorService 'Nacos-Watch-Task-Scheduler'
2021-04-13 16:01:39.369 ERROR 11025 --- [extShutdownHook] c.a.cloud.nacos.discovery.NacosWatch     : namingService unsubscribe failed, properties:NacosDiscoveryProperties{serverAddr='localhost:8848', endpoint='', namespace='public', watchDelay=30000, logName='', service='demo', weight=1.0, clusterName='DEFAULT', group='DEFAULT_GROUP', namingLoadCacheAtStart='false', metadata={preserved.register.source=SPRING_CLOUD}, registerEnabled=true, ip='192.168.1.13', networkInterface='', port=-1, secure=false, accessKey='', secretKey='', heartBeatInterval=null, heartBeatTimeout=null, ipDeleteTimeout=null}

com.alibaba.nacos.api.exception.NacosException: Request nacos server failed: 
	at com.alibaba.nacos.client.naming.remote.gprc.NamingGrpcClientProxy.requestToServer(NamingGrpcClientProxy.java:213) ~[nacos-client-2.0.0.jar!/:na]
	at com.alibaba.nacos.client.naming.remote.gprc.NamingGrpcClientProxy.unsubscribe(NamingGrpcClientProxy.java:182) ~[nacos-client-2.0.0.jar!/:na]
	at com.alibaba.nacos.client.naming.remote.NamingClientProxyDelegate.unsubscribe(NamingClientProxyDelegate.java:156) ~[nacos-client-2.0.0.jar!/:na]
	at com.alibaba.nacos.client.naming.NacosNamingService.unsubscribe(NacosNamingService.java:411) ~[nacos-client-2.0.0.jar!/:na]
	at com.alibaba.cloud.nacos.discovery.NacosWatch.stop(NacosWatch.java:166) ~[spring-cloud-starter-alibaba-nacos-discovery-2021.1.jar!/:2021.1]
	at com.alibaba.cloud.nacos.discovery.NacosWatch.stop(NacosWatch.java:97) ~[spring-cloud-starter-alibaba-nacos-discovery-2021.1.jar!/:2021.1]
	at org.springframework.context.support.DefaultLifecycleProcessor.doStop(DefaultLifecycleProcessor.java:234) ~[spring-context-5.3.5.jar!/:5.3.5]
	at org.springframework.context.support.DefaultLifecycleProcessor.access$300(DefaultLifecycleProcessor.java:54) ~[spring-context-5.3.5.jar!/:5.3.5]
	at org.springframework.context.support.DefaultLifecycleProcessor$LifecycleGroup.stop(DefaultLifecycleProcessor.java:373) ~[spring-context-5.3.5.jar!/:5.3.5]
	at org.springframework.context.support.DefaultLifecycleProcessor.stopBeans(DefaultLifecycleProcessor.java:206) ~[spring-context-5.3.5.jar!/:5.3.5]
	at org.springframework.context.support.DefaultLifecycleProcessor.onClose(DefaultLifecycleProcessor.java:129) ~[spring-context-5.3.5.jar!/:5.3.5]
	at org.springframework.context.support.AbstractApplicationContext.doClose(AbstractApplicationContext.java:1067) ~[spring-context-5.3.5.jar!/:5.3.5]
	at org.springframework.context.support.AbstractApplicationContext$1.run(AbstractApplicationContext.java:991) ~[spring-context-5.3.5.jar!/:5.3.5]
Caused by: com.alibaba.nacos.api.exception.NacosException: java.util.concurrent.RejectedExecutionException: Task com.alibaba.nacos.shaded.io.grpc.internal.SerializingExecutor@64134151 rejected from java.util.concurrent.ThreadPoolExecutor@3bcadf05[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 20]
	at com.alibaba.nacos.common.remote.client.RpcClient.request(RpcClient.java:675) ~[nacos-client-2.0.0.jar!/:na]
	at com.alibaba.nacos.common.remote.client.RpcClient.request(RpcClient.java:608) ~[nacos-client-2.0.0.jar!/:na]
	at com.alibaba.nacos.client.naming.remote.gprc.NamingGrpcClientProxy.requestToServer(NamingGrpcClientProxy.java:203) ~[nacos-client-2.0.0.jar!/:na]
	... 12 common frames omitted
Caused by: java.util.concurrent.RejectedExecutionException: Task com.alibaba.nacos.shaded.io.grpc.internal.SerializingExecutor@64134151 rejected from java.util.concurrent.ThreadPoolExecutor@3bcadf05[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 20]
	at java.base/java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2057) ~[na:na]
	at java.base/java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:827) ~[na:na]
	at java.base/java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1357) ~[na:na]
	at com.alibaba.nacos.shaded.io.grpc.internal.SerializingExecutor.schedule(SerializingExecutor.java:93) ~[nacos-client-2.0.0.jar!/:na]
	at com.alibaba.nacos.shaded.io.grpc.internal.SerializingExecutor.execute(SerializingExecutor.java:86) ~[nacos-client-2.0.0.jar!/:na]
	at com.alibaba.nacos.shaded.io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.closedInternal(ClientCallImpl.java:696) ~[nacos-client-2.0.0.jar!/:na]
	at com.alibaba.nacos.shaded.io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.closed(ClientCallImpl.java:646) ~[nacos-client-2.0.0.jar!/:na]
	at com.alibaba.nacos.shaded.io.grpc.internal.FailingClientStream.start(FailingClientStream.java:54) ~[nacos-client-2.0.0.jar!/:na]
	at com.alibaba.nacos.shaded.io.grpc.internal.ClientCallImpl.startInternal(ClientCallImpl.java:290) ~[nacos-client-2.0.0.jar!/:na]
	at com.alibaba.nacos.shaded.io.grpc.internal.ClientCallImpl.start(ClientCallImpl.java:190) ~[nacos-client-2.0.0.jar!/:na]
	at com.alibaba.nacos.shaded.io.grpc.internal.CensusTracingModule$TracingClientInterceptor$1.start(CensusTracingModule.java:394) ~[nacos-client-2.0.0.jar!/:na]
	at com.alibaba.nacos.shaded.io.grpc.internal.CensusStatsModule$StatsClientInterceptor$1.start(CensusStatsModule.java:695) ~[nacos-client-2.0.0.jar!/:na]
	at com.alibaba.nacos.shaded.io.grpc.stub.ClientCalls.startCall(ClientCalls.java:310) ~[nacos-client-2.0.0.jar!/:na]
	at com.alibaba.nacos.shaded.io.grpc.stub.ClientCalls.asyncUnaryRequestCall(ClientCalls.java:282) ~[nacos-client-2.0.0.jar!/:na]
	at com.alibaba.nacos.shaded.io.grpc.stub.ClientCalls.futureUnaryCall(ClientCalls.java:191) ~[nacos-client-2.0.0.jar!/:na]
	at com.alibaba.nacos.api.grpc.auto.RequestGrpc$RequestFutureStub.request(RequestGrpc.java:212) ~[nacos-client-2.0.0.jar!/:na]
	at com.alibaba.nacos.common.remote.client.grpc.GrpcConnection.request(GrpcConnection.java:73) ~[nacos-client-2.0.0.jar!/:na]
	at com.alibaba.nacos.common.remote.client.RpcClient.request(RpcClient.java:630) ~[nacos-client-2.0.0.jar!/:na]
	... 14 common frames omitted


@KomachiSion KomachiSion added kind/bug Category issues or prs related to bug. and removed status/need feedback labels Apr 14, 2021
@KomachiSion KomachiSion added this to the 2.0.1 milestone Apr 14, 2021
@KomachiSion
Copy link
Collaborator

Fixed by #5237 for client-2.0.1

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
kind/bug Category issues or prs related to bug.
Projects
None yet
Development

No branches or pull requests

2 participants