Micrometer Vert.x Binder Locks Shutdown on devmode

[brunolmfg]

Describe the bug

Using Micrometer extension the shutdown thread is locked on devmode waiting for Vert.x Binder to be undeployed.

Expected behavior

On devmode the application will shutdown when SIGINT (Ctrl+C) is fired.

Actual behavior

The application is locked waiting for Vert.x closure that's never fired due to an NPE on InvocationInterceptor#monitor.

java.lang.NullPointerException
	at io.quarkus.arc.runtime.devconsole.InvocationInterceptor.monitor(InvocationInterceptor.java:40)
	at io.quarkus.arc.runtime.devconsole.InvocationInterceptor_Bean.intercept(InvocationInterceptor_Bean.zig:521)
	at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:41)
	at io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:41)
	at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:32)
	at io.quarkus.micrometer.runtime.binder.vertx.VertxMeterBinderAdapter_Subclass.verticleUndeployed(VertxMeterBinderAdapter_Subclass.zig:3581)
	at io.vertx.core.impl.DeploymentManager$DeploymentImpl.lambda$null$5(DeploymentManager.java:701)
	at io.vertx.core.impl.FutureImpl.dispatch(FutureImpl.java:105)
	at io.vertx.core.impl.FutureImpl.tryComplete(FutureImpl.java:150)
	at io.vertx.core.impl.FutureImpl.tryComplete(FutureImpl.java:157)
	at io.vertx.core.impl.FutureImpl.complete(FutureImpl.java:118)
	at io.quarkus.vertx.http.runtime.VertxHttpRecorder$WebDeploymentVerticle.lambda$stop$2(VertxHttpRecorder.java:1012)
	at io.vertx.core.http.impl.HttpServerImpl.lambda$executeCloseDone$11(HttpServerImpl.java:507)
	at io.vertx.core.impl.ContextImpl.executeTask(ContextImpl.java:366)
	at io.vertx.core.impl.EventLoopContext.lambda$executeAsync$0(EventLoopContext.java:38)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
	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:834)

The stacktrace above isn't echoed on console but I've discovered that when debuging the verticle undeploy at io.vertx.core.impl.DeploymentManager$DeploymentImpl#doUndeploy line #701.

              VertxMetrics metrics = vertx.metricsSPI();
              if (metrics != null) {
                metrics.verticleUndeployed(verticleHolder.verticle);
              }

If the Micrometer Vert.x Binder – enabled by defaut – is disabled the issue is bypassed.

quarkus.micrometer.binder.vertx.enabled=false

I've realized that in 1.12.2.Final the method VertxMetrics#verticleUnployed isn't proxied and execute the default empty implementation at interface VertxMetrics. From version 1.13.0.CR1, the VertxMetricsFactory create a proxy bean that fire invocation interceptor, but ArC itself is already shuted down.

To Reproduce

The project bellow was generated at Quarkus Code Start enabling the Micrometer extension.

https://github.com/brunolmfg/micrometer-vertx-binder-issue

Steps to reproduce the behavior:

1. Start the application on devmode: mvn quarkus:dev
2. Fire SIGINT (Ctrl+C) to shutdown the application
3. The application init the shutdown and doesn't exit

Configuration

No additional configuration applied.

Screenshots

Not applicable.

Environment

Output of uname -a or ver

Linux captain 5.8.0-43-generic #49~20.04.1-Ubuntu SMP Fri Feb 5 09:57:56 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

Output of java -version

openjdk version "11.0.10" 2021-01-19
OpenJDK Runtime Environment (build 11.0.10+9-Ubuntu-0ubuntu1.20.04)
OpenJDK 64-Bit Server VM (build 11.0.10+9-Ubuntu-0ubuntu1.20.04, mixed mode, sharing)

GraalVM version (if different from Java)

Not applicable.

Quarkus version or git rev

1.13.CR1 and 1.13.0.Final
In 1.12.2.Final is non-reproducible.

Build tool (ie. output of mvnw --version or gradlew --version)

Apache Maven 3.6.3 (cecedd343002696d0abb50b32b541b8a6ba2883f)
Maven home: /usr/local/develop/apache-maven-3.6.3
Java version: 11.0.10, vendor: Ubuntu, runtime: /usr/lib/jvm/java-11-openjdk-amd64
Default locale: en_US, platform encoding: UTF-8
OS name: "linux", version: "5.8.0-43-generic", arch: "amd64", family: "unix"

[quarkus-bot]

/cc @ebullient

[geoand]

@mkouba it seems like we should be checking if the container is actually active at

https://github.com/quarkusio/quarkus/blob/main/extensions/arc/runtime/src/main/java/io/quarkus/arc/runtime/devconsole/InvocationInterceptor.java#L40

and if not, just proceed with the normal invocation, right?

[geoand]

Also, @ebullient, is there a good reason why VertxMeterBinderAdapter is a CDI bean?

[mkouba]

@mkouba it seems like we should be checking if the container is actually active at

https://github.com/quarkusio/quarkus/blob/main/extensions/arc/runtime/src/main/java/io/quarkus/arc/runtime/devconsole/InvocationInterceptor.java#L40

and if not, just proceed with the normal invocation, right?

So IIUIC the VertxMeterBinderAdapter is registered in vertx and io.vertx.core.spi.metrics.VertxMetrics.verticleUndeployed() is invoked after the CDI container is shut down.

A quick workaround is to set quarkus.arc.dev-mode.monitoring-enabled=false. VertxMeterBinderAdapter is @Singleton so no client proxy or subclass will be used.

We could add a check in the InvocationInterceptor but there's still a risk that some CDI-related stuff would break. So ideally this component should not be a CDI bean.

[geoand]

@mkouba it seems like we should be checking if the container is actually active at
https://github.com/quarkusio/quarkus/blob/main/extensions/arc/runtime/src/main/java/io/quarkus/arc/runtime/devconsole/InvocationInterceptor.java#L40
and if not, just proceed with the normal invocation, right?

So IIUIC the VertxMeterBinderAdapter is registered in vertx and io.vertx.core.spi.metrics.VertxMetrics.verticleUndeployed() is invoked after the CDI container is shut down.

Yes, it's invoked by Vert.x to undeploy the Metrics Verticle.

A quick workaround is to set quarkus.arc.dev-mode.monitoring-enabled=false. VertxMeterBinderAdapter is @Singleton so no client proxy or subclass will be used.

We could add a check in the InvocationInterceptor but there's still a risk that some CDI-related stuff would break. So ideally this component should not be a CDI bean.

I agree, which is why I asked @ebullient why it is a CDI bean. It doesn't look like it should be.

[ebullient]

Looking. You guys have a few hours on me.

Thank you @brunolmfg for chasing this down! I did notice this as well, but it only happened with master, and not in any of the other branches, and I was having a lot of problems w/ my system at the time, so I assumed it was "just me".. :sigh:

The VertxMeterBinderAdapter (Singleton) is retrieved from Arc along two different paths in the recorder (once during static init, once during runtime init) to connect together bits that are available statically and bits that are available at runtime in a predictable order that still follows injection patterms. I could disentangle it and make it not a bean (probably a passed RuntimeValue instead), but that seemed to move away from what we usually expect (lifecycle managed by CDI).