micronaut-projects / micronaut-discovery-client

Micronaut's Discovery Client
Apache License 2.0
21 stars 18 forks source link

Consul deregistration not working for multi-registered application #486

Open FrogDevelopper opened 1 year ago

FrogDevelopper commented 1 year ago

Expected Behavior

GIVEN an application with both netty and gRPC server WHEN application start THEN both server are registered as service WHEN application stop THEN both services are deregistered

Actual Behaviour

The 1st server (netty) only is deregistered, the seconde one (gRPC) is on timeout

2023-06-28 15:39:46,059 INFO [main ] [GrpcEmbeddedServerListener.java] - GRPC started on port 9380 - [] - [] 2023-06-28 15:39:46,062 INFO [main ] [Micronaut.java] - Startup completed in 1538ms. Server Running: http://localhost:9381 - [] - [] 2023-06-28 15:39:46,092 INFO [default-nioEventLoopGroup-3-2] [DiscoveryServiceAutoRegistration.java] - Registered service [my-applicationr-grpc] with Consul - [] - [] 2023-06-28 15:39:46,094 INFO [default-nioEventLoopGroup-3-3] [DiscoveryServiceAutoRegistration.java] - Registered service [my-application] with Consul - [] - [] Disconnected from the target VM, address: '127.0.0.1:51820', transport: 'socket' 2023-06-28 15:39:49,621 INFO [Thread-4 ] [Micronaut.java] - Embedded Application shutting down - [] - [] 2023-06-28 15:39:49,651 INFO [Thread-4 ] [DiscoveryServiceAutoRegistration.java] - De-registered service [generic-data-provider] with Consul - [] - [] 2023-06-28 15:39:49,652 INFO [Thread-4 ] [ApplicationLifeCycleHook.java] - Cooling down - [] - [] 2023-06-28 15:39:49,652 INFO [Thread-4 ] [ApplicationLifeCycleHook.java] - Cooling down - [] - [] 2023-06-28 15:39:49,656 INFO [ForkJoinPool.commonPool-worker-4] [ConsulConfigurationsWatchesHook.java] - All watches closed - [] - [] 2023-06-28 15:39:49,656 INFO [ForkJoinPool.commonPool-worker-4] [ConsulConfigurationsWatchesHook.java] - All watches closed - [] - [] 2023-06-28 15:39:55,785 WARN [parallel-7] [AbstractChannel.java:490] - Force-closing a channel whose registration task was not accepted by an event loop: [id: 0xd7b3aa4c] - [] - [] - java.util.concurrent.RejectedExecutionException: event executor terminated at io.netty.util.concurrent.SingleThreadEventExecutor.reject(SingleThreadEventExecutor.java:934) at io.netty.util.concurrent.SingleThreadEventExecutor.offerTask(SingleThreadEventExecutor.java:351) at io.netty.util.concurrent.SingleThreadEventExecutor.addTask(SingleThreadEventExecutor.java:344) at io.netty.util.concurrent.SingleThreadEventExecutor.execute(SingleThreadEventExecutor.java:836) at io.netty.util.concurrent.SingleThreadEventExecutor.execute0(SingleThreadEventExecutor.java:827) at io.netty.util.concurrent.SingleThreadEventExecutor.execute(SingleThreadEventExecutor.java:817) at io.netty.channel.AbstractChannel$AbstractUnsafe.register(AbstractChannel.java:483) at io.netty.channel.SingleThreadEventLoop.register(SingleThreadEventLoop.java:89) at io.netty.channel.SingleThreadEventLoop.register(SingleThreadEventLoop.java:83) at io.netty.channel.MultithreadEventLoopGroup.register(MultithreadEventLoopGroup.java:86) at io.netty.bootstrap.AbstractBootstrap.initAndRegister(AbstractBootstrap.java:323) at io.netty.bootstrap.Bootstrap.doResolveAndConnect(Bootstrap.java:155) at io.netty.bootstrap.Bootstrap.connect(Bootstrap.java:139) at io.netty.bootstrap.Bootstrap.connect(Bootstrap.java:123) at io.micronaut.http.client.netty.ConnectionManager.doConnect(ConnectionManager.java:419) at io.micronaut.http.client.netty.ConnectionManager.lambda$connectForExchange$8(ConnectionManager.java:487) at reactor.core.publisher.MonoCreate.subscribe(MonoCreate.java:58) at reactor.core.publisher.InternalFluxOperator.subscribe(InternalFluxOperator.java:62) at io.micronaut.configuration.metrics.binder.web.WebMetricsPublisher.subscribe(WebMetricsPublisher.java:151) at reactor.core.publisher.Flux.subscribe(Flux.java:8660) at reactor.core.publisher.FluxSwitchMapNoPrefetch$SwitchMapMain.subscribeInner(FluxSwitchMapNoPrefetch.java:218) at reactor.core.publisher.FluxSwitchMapNoPrefetch$SwitchMapMain.onNext(FluxSwitchMapNoPrefetch.java:164) at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:129) at reactor.core.publisher.MonoCallable$MonoCallableSubscription.request(MonoCallable.java:156) at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.request(FluxMapFuseable.java:171) at reactor.core.publisher.FluxSwitchMapNoPrefetch$SwitchMapMain.onSubscribe(FluxSwitchMapNoPrefetch.java:147) at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onSubscribe(FluxMapFuseable.java:96) at reactor.core.publisher.MonoCallable.subscribe(MonoCallable.java:48) at reactor.core.publisher.InternalFluxOperator.subscribe(InternalFluxOperator.java:62) at reactor.core.publisher.FluxDelaySubscription.accept(FluxDelaySubscription.java:59) at reactor.core.publisher.FluxDelaySubscription.accept(FluxDelaySubscription.java:36) at reactor.core.publisher.FluxDelaySubscription$DelaySubscriptionOtherSubscriber.onNext(FluxDelaySubscription.java:131) at reactor.core.publisher.MonoDelay$MonoDelayRunnable.propagateDelay(MonoDelay.java:271) at reactor.core.publisher.MonoDelay$MonoDelayRunnable.run(MonoDelay.java:286) at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:68) at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:28) at java.base/java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:264) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java) at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) at java.base/java.lang.Thread.run(Thread.java:833) ... (lot of the same error) 2023-06-28 15:40:45,898 ERROR [scheduled-executor-thread-4] [DefaultPromise.java:864] - Failed to submit a listener notification task. Event loop shut down? - [] - [] - java.util.concurrent.RejectedExecutionException: event executor terminated at io.netty.util.concurrent.SingleThreadEventExecutor.reject(SingleThreadEventExecutor.java:934) at io.netty.util.concurrent.SingleThreadEventExecutor.offerTask(SingleThreadEventExecutor.java:351) at io.netty.util.concurrent.SingleThreadEventExecutor.addTask(SingleThreadEventExecutor.java:344) at io.netty.util.concurrent.SingleThreadEventExecutor.execute(SingleThreadEventExecutor.java:836) at io.netty.util.concurrent.SingleThreadEventExecutor.execute0(SingleThreadEventExecutor.java:827) at io.netty.util.concurrent.SingleThreadEventExecutor.execute(SingleThreadEventExecutor.java:817) at io.netty.util.concurrent.DefaultPromise.safeExecute(DefaultPromise.java:862) at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:500) at io.netty.util.concurrent.DefaultPromise.addListener(DefaultPromise.java:185) at io.netty.channel.DefaultChannelPromise.addListener(DefaultChannelPromise.java:95) at io.netty.channel.DefaultChannelPromise.addListener(DefaultChannelPromise.java:30) at io.micronaut.http.client.netty.ConnectionManager.addInstrumentedListener(ConnectionManager.java:905) at io.micronaut.http.client.netty.ConnectionManager.lambda$connectForExchange$8(ConnectionManager.java:488) at reactor.core.publisher.MonoCreate.subscribe(MonoCreate.java:58) at reactor.core.publisher.InternalFluxOperator.subscribe(InternalFluxOperator.java:62) at io.micronaut.configuration.metrics.binder.web.WebMetricsPublisher.subscribe(WebMetricsPublisher.java:151) at reactor.core.publisher.Flux.subscribe(Flux.java:8660) at reactor.core.publisher.FluxSwitchMapNoPrefetch$SwitchMapMain.subscribeInner(FluxSwitchMapNoPrefetch.java:218) at reactor.core.publisher.FluxSwitchMapNoPrefetch$SwitchMapMain.onNext(FluxSwitchMapNoPrefetch.java:164) at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:129) at reactor.core.publisher.MonoCallable$MonoCallableSubscription.request(MonoCallable.java:156) at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.request(FluxMapFuseable.java:171) at reactor.core.publisher.FluxSwitchMapNoPrefetch$SwitchMapMain.onSubscribe(FluxSwitchMapNoPrefetch.java:147) at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onSubscribe(FluxMapFuseable.java:96) at reactor.core.publisher.MonoCallable.subscribe(MonoCallable.java:48) at reactor.core.publisher.Flux.subscribe(Flux.java:8660) at reactor.core.publisher.FluxFlatMap$FlatMapMain.onNext(FluxFlatMap.java:426) at reactor.core.publisher.FluxIterable$IterableSubscription.slowPath(FluxIterable.java:272) at reactor.core.publisher.FluxIterable$IterableSubscription.request(FluxIterable.java:230) at reactor.core.publisher.FluxFlatMap$FlatMapMain.onSubscribe(FluxFlatMap.java:371) at reactor.core.publisher.FluxIterable.subscribe(FluxIterable.java:165) at reactor.core.publisher.FluxIterable.subscribe(FluxIterable.java:87) at reactor.core.publisher.Mono.subscribe(Mono.java:4444) at io.micronaut.management.health.monitor.HealthMonitorTask.monitor(HealthMonitorTask.java:98) at io.micronaut.management.health.monitor.$HealthMonitorTask$Definition$Exec.dispatch(Unknown Source) at io.micronaut.context.AbstractExecutableMethodsDefinition$DispatchedExecutableMethod.invoke(AbstractExecutableMethodsDefinition.java:371) at io.micronaut.inject.DelegatingExecutableMethod.invoke(DelegatingExecutableMethod.java:76) at io.micronaut.scheduling.processor.ScheduledMethodProcessor.lambda$process$5(ScheduledMethodProcessor.java:127) at io.micrometer.core.instrument.composite.CompositeTimer.record(CompositeTimer.java:141) at io.micrometer.core.instrument.Timer.lambda$wrap$0(Timer.java:196) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) at java.base/java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:305) at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java) at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) at java.base/java.lang.Thread.run(Thread.java:833) 2023-06-28 15:40:45,904 ERROR [ForkJoinPool.commonPool-worker-4] [HealthMonitorTask.java:116] - Health monitor check failed with exception: Unable to start GRPC server: Failed to bind to address 0.0.0.0/0.0.0.0:9380 - [] - [] - io.micronaut.runtime.exceptions.ApplicationStartupException: Unable to start GRPC server: Failed to bind to address 0.0.0.0/0.0.0.0:9380 at io.micronaut.grpc.server.GrpcEmbeddedServer.start(GrpcEmbeddedServer.java:194) at io.micronaut.grpc.server.GrpcEmbeddedServer.getPort(GrpcEmbeddedServer.java:130) at io.micronaut.grpc.server.health.GrpcServerHealthIndicator.getHealthResult(GrpcServerHealthIndicator.java:76) at io.micronaut.core.async.publisher.AsyncSingleResultPublisher$ExecutorServiceSubscription.lambda$request$1(AsyncSingleResultPublisher.java:100) at java.base/java.util.concurrent.ForkJoinTask$AdaptedRunnableAction.exec(ForkJoinTask.java:1375) at java.base/java.util.concurrent.ForkJoinTask.doExec$$$capture(ForkJoinTask.java:373) at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java) at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1182) at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1655) at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1622) at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:165) Caused by: java.io.IOException: Failed to bind to address 0.0.0.0/0.0.0.0:9380 at io.grpc.netty.NettyServer.start(NettyServer.java:328) at io.grpc.internal.ServerImpl.start(ServerImpl.java:184) at io.grpc.internal.ServerImpl.start(ServerImpl.java:93) at io.micronaut.grpc.server.GrpcEmbeddedServer.start(GrpcEmbeddedServer.java:169) ... 10 common frames omitted Caused by: java.net.BindException: Address already in use at java.base/sun.nio.ch.Net.bind0(Native Method) at java.base/sun.nio.ch.Net.bind(Net.java:555) at java.base/sun.nio.ch.ServerSocketChannelImpl.netBind(ServerSocketChannelImpl.java:337) at java.base/sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:294) at io.netty.channel.socket.nio.NioServerSocketChannel.doBind(NioServerSocketChannel.java:141) at io.netty.channel.AbstractChannel$AbstractUnsafe.bind(AbstractChannel.java:562) at io.netty.channel.DefaultChannelPipeline$HeadContext.bind(DefaultChannelPipeline.java:1334) at io.netty.channel.AbstractChannelHandlerContext.invokeBind(AbstractChannelHandlerContext.java:600) at io.netty.channel.AbstractChannelHandlerContext.bind(AbstractChannelHandlerContext.java:579) at io.netty.channel.DefaultChannelPipeline.bind(DefaultChannelPipeline.java:973) at io.netty.channel.AbstractChannel.bind(AbstractChannel.java:260) at io.netty.bootstrap.AbstractBootstrap$2.run(AbstractBootstrap.java:356) at io.netty.util.concurrent.AbstractEventExecutor.runTask$$$capture(AbstractEventExecutor.java:174) at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java) at io.netty.util.concurrent.AbstractEventExecutor.safeExecute$$$capture(AbstractEventExecutor.java:167) at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java) at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:569) at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997) at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.base/java.lang.Thread.run(Thread.java:833) 2023-06-28 15:40:49,805 ERROR [Thread-4] [DiscoveryServiceAutoRegistration.java:140] - Error occurred de-registering service [generic-data-provider-grpc] with Consul: Read Timeout - [] - [] - io.micronaut.http.client.exceptions.ReadTimeoutException: Read Timeout at io.micronaut.http.client.exceptions.ReadTimeoutException.(ReadTimeoutException.java:26) at io.micronaut.http.client.netty.DefaultHttpClient.lambda$exchangeImpl$33(DefaultHttpClient.java:1097) at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:94) at reactor.core.publisher.SerializedSubscriber.onError(SerializedSubscriber.java:124) at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.handleTimeout(FluxTimeout.java:295) at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.doTimeout(FluxTimeout.java:280) at reactor.core.publisher.FluxTimeout$TimeoutTimeoutSubscriber.onNext(FluxTimeout.java:419) at reactor.core.publisher.FluxOnErrorReturn$ReturnSubscriber.onNext(FluxOnErrorReturn.java:162) at reactor.core.publisher.MonoDelay$MonoDelayRunnable.propagateDelay(MonoDelay.java:271) at reactor.core.publisher.MonoDelay$MonoDelayRunnable.run(MonoDelay.java:286) at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:68) at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:28) at java.base/java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:264) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java) at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) at java.base/java.lang.Thread.run(Thread.java:833)

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

Note: suffixing grpc instance

consul:
  client:
    registration:
      enabled: true
grpc:
  server:
    instance-id: ${micronaut.application.name}-grpc

Steps To Reproduce

  1. Create a simple application with netty and grpc server
  2. Have a consul (docker) running
  3. Have the consul registration enabled
  4. Start the application
  5. Stop the application

Environment Information

Example Application

No response

Version

3.3.1

FrogDevelopper commented 1 year ago

Just for information, I don't have the error anymore when I set the consul.client.registration.fail-fast to false