search

quarkusio / quarkus

Quarkus: Supersonic Subatomic Java.
https://quarkus.io
Apache License 2.0
13.73k stars 2.67k forks source link

gradle quarkusDev: failed to start quarkus #32638

Closed ce-bo closed 1 year ago

ce-bo commented 1 year ago

Describe the bug

When running gradlew quarkusDev

Expected behavior

quarkus should start properly

Actual behavior

quarkus fails with the error messages below:

2023-04-14 08:44:13,506 ERROR [io.qua.run.boo.StartupActionImpl] (Quarkus Main Thread) Error running Quarkus: java.lang.reflect.InvocationTargetException
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at io.quarkus.runner.bootstrap.StartupActionImpl$1.run(StartupActionImpl.java:104)
        at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.lang.ExceptionInInitializerError
        at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:70)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:44)
        ... 6 more
Caused by: java.lang.RuntimeException: Failed to start quarkus
        at io.quarkus.runner.ApplicationImpl.(Unknown Source)
        ... 13 more
Caused by: java.lang.RuntimeException: java.lang.RuntimeException: java.lang.NullPointerException
        at io.quarkus.undertow.runtime.UndertowDeploymentRecorder.bootServletContainer(UndertowDeploymentRecorder.java:532)
        at io.quarkus.deployment.steps.UndertowBuildStep$build767851419.deploy_0(Unknown Source)
        at io.quarkus.deployment.steps.UndertowBuildStep$build767851419.deploy(Unknown Source)
        ... 14 more
Caused by: java.lang.RuntimeException: java.lang.NullPointerException
        at io.undertow.servlet.core.DeploymentManagerImpl.deploy(DeploymentManagerImpl.java:253)
        at io.quarkus.undertow.runtime.UndertowDeploymentRecorder.bootServletContainer(UndertowDeploymentRecorder.java:521)
        ... 16 more
Caused by: java.lang.NullPointerException
        at io.undertow.servlet.core.ManagedServlet.setupMultipart(ManagedServlet.java:106)
        at io.undertow.servlet.core.ManagedServlet.(ManagedServlet.java:78)
        at io.undertow.servlet.core.ManagedServlets.addServlet(ManagedServlets.java:46)
        at io.undertow.servlet.core.DeploymentManagerImpl.createServletsAndFilters(DeploymentManagerImpl.java:266)
        at io.undertow.servlet.core.DeploymentManagerImpl.access$100(DeploymentManagerImpl.java:121)
        at io.undertow.servlet.core.DeploymentManagerImpl$1.call(DeploymentManagerImpl.java:195)
        at io.undertow.servlet.core.DeploymentManagerImpl$1.call(DeploymentManagerImpl.java:186)
        at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:42)
        at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
        at io.quarkus.undertow.runtime.UndertowDeploymentRecorder$9$1.call(UndertowDeploymentRecorder.java:580)
        at io.undertow.servlet.core.DeploymentManagerImpl.deploy(DeploymentManagerImpl.java:251)
        ... 17 more

2023-04-14 08:44:13,524 DEBUG [io.qua.ver.cor.run.VertxCoreRecorder] (main) Vert.x Cache configured to: C:\Users\CedrikB\AppData\Local\Temp\vertx-cache\4482210639645067350
2023-04-14 08:44:13,534 DEBUG [io.net.cha.MultithreadEventLoopGroup] (main) -Dio.netty.eventLoopThreads: 40
2023-04-14 08:44:13,551 DEBUG [io.net.cha.nio.NioEventLoop] (main) -Dio.netty.noKeySetOptimization: false
2023-04-14 08:44:13,551 DEBUG [io.net.cha.nio.NioEventLoop] (main) -Dio.netty.selectorAutoRebuildThreshold: 512
2023-04-14 08:44:13,551 DEBUG [io.net.uti.int.PlatformDependent] (main) org.jctools-core.MpscChunkedArrayQueue: available
     2023-04-14 08:44:13,573 DEBUG [io.qua.ver.cor.run.VertxCoreRecorder] (main) Vertx has Native Transport Enabled: false
2023-04-14 08:44:13,591 DEBUG [io.net.uti.NetUtil] (vert.x-eventloop-thread-0) -Djava.net.preferIPv4Stack: false          
2023-04-14 08:44:13,591 DEBUG [io.net.uti.NetUtil] (vert.x-eventloop-thread-0) -Djava.net.preferIPv6Addresses: false      
     2023-04-14 08:44:13,705 DEBUG [io.net.uti.NetUtilInitializations] (vert.x-eventloop-thread-0) Loopback interface: lo (Software Loopback Interface 1, 127.0.0.1)
2023-04-14 08:44:13,705 DEBUG [io.net.uti.NetUtil] (vert.x-eventloop-thread-0) Failed to get SOMAXCONN from sysctl and file \proc\sys\net\core\somaxconn. Default: 200
2023-04-14 08:44:13,715 DEBUG [io.net.buf.PooledByteBufAllocator] (vert.x-eventloop-thread-0) -Dio.netty.allocator.numHeapArenas: 40
2023-04-14 08:44:13,715 DEBUG [io.net.buf.PooledByteBufAllocator] (vert.x-eventloop-thread-0) -Dio.netty.allocator.numDirectArenas: 40
2023-04-14 08:44:13,715 DEBUG [io.net.buf.PooledByteBufAllocator] (vert.x-eventloop-thread-0) -Dio.netty.allocator.pageSize: 8192
2023-04-14 08:44:13,715 DEBUG [io.net.buf.PooledByteBufAllocator] (vert.x-eventloop-thread-0) -Dio.netty.allocator.maxOrder: 3
2023-04-14 08:44:13,715 DEBUG [io.net.buf.PooledByteBufAllocator] (vert.x-eventloop-thread-0) -Dio.netty.allocator.chunkSize: 65536
2023-04-14 08:44:13,715 DEBUG [io.net.buf.PooledByteBufAllocator] (vert.x-eventloop-thread-0) -Dio.netty.allocator.smallCacheSize: 256
2023-04-14 08:44:13,715 DEBUG [io.net.buf.PooledByteBufAllocator] (vert.x-eventloop-thread-0) -Dio.netty.allocator.normalCacheSize: 64
2023-04-14 08:44:13,715 DEBUG [io.net.buf.PooledByteBufAllocator] (vert.x-eventloop-thread-0) -Dio.netty.allocator.maxCachedBufferCapacity: 32768
2023-04-14 08:44:13,715 DEBUG [io.net.buf.PooledByteBufAllocator] (vert.x-eventloop-thread-0) -Dio.netty.allocator.cacheTrimInterval: 8192
2023-04-14 08:44:13,715 DEBUG [io.net.buf.PooledByteBufAllocator] (vert.x-eventloop-thread-0) -Dio.netty.allocator.cacheTrimIntervalMillis: 0
2023-04-14 08:44:13,715 DEBUG [io.net.buf.PooledByteBufAllocator] (vert.x-eventloop-thread-0) -Dio.netty.allocator.useCacheForAllThreads: false
2023-04-14 08:44:13,715 DEBUG [io.net.buf.PooledByteBufAllocator] (vert.x-eventloop-thread-0) -Dio.netty.allocator.maxCachedByteBuffersPerChunk: 1023
2023-04-14 08:44:13,724 DEBUG [io.net.cha.DefaultChannelId] (vert.x-eventloop-thread-0) -Dio.netty.processId: 37152 (auto-detected)
2023-04-14 08:44:13,724 DEBUG [io.net.cha.DefaultChannelId] (vert.x-eventloop-thread-0) -Dio.netty.machineId: d1:71:06:e9:9f:6a:c2:b7 (user-set)
2023-04-14 08:44:13,729 DEBUG [io.net.buf.ByteBufUtil] (vert.x-eventloop-thread-0) -Dio.netty.allocator.type: pooled
2023-04-14 08:44:13,729 DEBUG [io.net.buf.ByteBufUtil] (vert.x-eventloop-thread-0) -Dio.netty.threadLocalDirectBufferSize: 0
2023-04-14 08:44:13,729 DEBUG [io.net.buf.ByteBufUtil] (vert.x-eventloop-thread-0) -Dio.netty.maxThreadLocalCharBufferSize: 16384
     Press [h] for more options>
2023-04-14 08:44:13,924 ERROR [io.qua.dep.dev.IsolatedDevModeMain] (main) Failed to start quarkus: io.quarkus.dev.appstate.ApplicationStartException: java.lang.RuntimeException: java.lang.RuntimeException: java.lang.NullPointerException
        at io.quarkus.dev.appstate.ApplicationStateNotification.waitForApplicationStart(ApplicationStateNotification.java:58)                                                                                                               
        at io.quarkus.runner.bootstrap.StartupActionImpl.runMainClass(StartupActionImpl.java:123)                                                                                                                                           
        at io.quarkus.deployment.dev.IsolatedDevModeMain.firstStart(IsolatedDevModeMain.java:137)
        at io.quarkus.deployment.dev.IsolatedDevModeMain.accept(IsolatedDevModeMain.java:447)
        at io.quarkus.deployment.dev.IsolatedDevModeMain.accept(IsolatedDevModeMain.java:59)
        at io.quarkus.bootstrap.app.CuratedApplication.runInCl(CuratedApplication.java:149)
        at io.quarkus.bootstrap.app.CuratedApplication.runInAugmentClassLoader(CuratedApplication.java:104)
        at io.quarkus.deployment.dev.DevModeMain.start(DevModeMain.java:131)
        at io.quarkus.deployment.dev.DevModeMain.main(DevModeMain.java:62)
Caused by: java.lang.RuntimeException: java.lang.RuntimeException: java.lang.NullPointerException
        at io.quarkus.undertow.runtime.UndertowDeploymentRecorder.bootServletContainer(UndertowDeploymentRecorder.java:532)
        at io.quarkus.deployment.steps.UndertowBuildStep$build767851419.deploy_0(Unknown Source)
        at io.quarkus.deployment.steps.UndertowBuildStep$build767851419.deploy(Unknown Source)
        at io.quarkus.runner.ApplicationImpl.(Unknown Source)
        at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:70)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:44)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at io.quarkus.runner.bootstrap.StartupActionImpl$1.run(StartupActionImpl.java:104)
        at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.lang.RuntimeException: java.lang.NullPointerException
        at io.undertow.servlet.core.DeploymentManagerImpl.deploy(DeploymentManagerImpl.java:253)
        at io.quarkus.undertow.runtime.UndertowDeploymentRecorder.bootServletContainer(UndertowDeploymentRecorder.java:521)
        ... 16 more
Caused by: java.lang.NullPointerException
        at io.undertow.servlet.core.ManagedServlet.setupMultipart(ManagedServlet.java:106)
        at io.undertow.servlet.core.ManagedServlet.(ManagedServlet.java:78)
        at io.undertow.servlet.core.ManagedServlets.addServlet(ManagedServlets.java:46)
        at io.undertow.servlet.core.DeploymentManagerImpl.createServletsAndFilters(DeploymentManagerImpl.java:266)
        at io.undertow.servlet.core.DeploymentManagerImpl.access$100(DeploymentManagerImpl.java:121)
        at io.undertow.servlet.core.DeploymentManagerImpl$1.call(DeploymentManagerImpl.java:195)
        at io.undertow.servlet.core.DeploymentManagerImpl$1.call(DeploymentManagerImpl.java:186)
        at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:42)
        at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
        at io.quarkus.undertow.runtime.UndertowDeploymentRecorder$9$1.call(UndertowDeploymentRecorder.java:580)
        at io.undertow.servlet.core.DeploymentManagerImpl.deploy(DeploymentManagerImpl.java:251)
        ... 17 more

2023-04-14 08:44:13,924 ERROR [io.qua.dep.dev.IsolatedDevModeMain] (main) Failed to recover after failed start: java.lang.RuntimeException: java.lang.RuntimeException: Unable to start HTTP server
        at io.quarkus.vertx.http.runtime.VertxHttpRecorder.startServerAfterFailedStart(VertxHttpRecorder.java:281)
        at io.quarkus.vertx.http.runtime.devmode.VertxHttpHotReplacementSetup.handleFailedInitialStart(VertxHttpHotReplacementSetup.java:61)
        at io.quarkus.deployment.dev.RuntimeUpdatesProcessor.startupFailed(RuntimeUpdatesProcessor.java:1139)
        at io.quarkus.deployment.dev.IsolatedDevModeMain.firstStart(IsolatedDevModeMain.java:175)
        at io.quarkus.deployment.dev.IsolatedDevModeMain.accept(IsolatedDevModeMain.java:447)
        at io.quarkus.deployment.dev.IsolatedDevModeMain.accept(IsolatedDevModeMain.java:59)
        at io.quarkus.bootstrap.app.CuratedApplication.runInCl(CuratedApplication.java:149)
        at io.quarkus.bootstrap.app.CuratedApplication.runInAugmentClassLoader(CuratedApplication.java:104)
        at io.quarkus.deployment.dev.DevModeMain.start(DevModeMain.java:131)
        at io.quarkus.deployment.dev.DevModeMain.main(DevModeMain.java:62)
Caused by: java.lang.RuntimeException: Unable to start HTTP server
        at io.quarkus.vertx.http.runtime.VertxHttpRecorder.doServerStart(VertxHttpRecorder.java:770)
        at io.quarkus.vertx.http.runtime.VertxHttpRecorder.startServerAfterFailedStart(VertxHttpRecorder.java:274)
        ... 9 more
Caused by: java.util.concurrent.ExecutionException: io.quarkus.runtime.QuarkusBindException: Port(s) already bound: 8090: Address already in use: bind
        at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:395)
        at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1999)
        at io.quarkus.vertx.http.runtime.VertxHttpRecorder.doServerStart(VertxHttpRecorder.java:736)
        ... 10 more
Caused by: io.quarkus.runtime.QuarkusBindException: Port(s) already bound: 8090: Address already in use: bind
        at io.quarkus.vertx.http.runtime.VertxHttpRecorder$18.handle(VertxHttpRecorder.java:727)
        at io.quarkus.vertx.http.runtime.VertxHttpRecorder$18.handle(VertxHttpRecorder.java:710)

How to Reproduce?

No response

Output of uname -a or ver

Microsoft Windows [Version 10.0.19045.2846]

Output of java -version

java 11.0.8 2020-07-14 LTS

GraalVM version (if different from Java)

No response

Quarkus version or git rev

2.16.6-Final

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

gradlew

Additional information

it also failes via Quarkus IntelliJ Run Configuration

quarkus-bot[bot] commented 1 year ago

/cc @glefloch, @quarkusio/devtools

maxandersen commented 1 year ago

What app are you deploying ? Can you provide a reproducer ?

ce-bo commented 1 year ago

I thought about providing a reproducer. Unfortunately, it is closed source. But maybe I can show you, how the application is started:

@QuarkusMain
public class MyQuarkusMain {
    public static void main(String[] args) {
        Quarkus.run(MyQuarkusApplication.class, args);
    }
}

Gradle Dependencies:

quarkusPluginId=io.quarkus
quarkusPluginVersion=2.16.6.Final
quarkusPlatformGroupId=io.quarkus
quarkusPlatformArtifactId=quarkus-universe-bom
quarkusPlatformVersion=2.16.6.Final

dependencies {
  implementation enforcedPlatform("${quarkusPlatformGroupId}:${quarkusPlatformArtifactId}:${quarkusPlatformVersion}")
  implementation 'io.quarkus:quarkus-oidc'
  implementation 'io.quarkus:quarkus-arc'
  implementation 'io.quarkus:quarkus-agroal'
  implementation 'io.quarkus:quarkus-jdbc-postgresql'
  implementation 'io.quarkus:quarkus-jdbc-db2'
  implementation 'io.quarkus:quarkus-narayana-jta'
  implementation 'io.quarkus:quarkus-resteasy'
  implementation 'io.quarkus:quarkus-undertow'
  implementation 'io.quarkus:quarkus-elytron-security-properties-file'
  implementation 'io.quarkus:quarkus-junit5'
// ...

When building the app with gradlew quarkusBuild and running the jar in a Docker Container, it worked fine. Now I just wanted to get rid of my local Docker development environment and run quarkus without it.

I set this option quarkus.devservices.enabled=false to disable the dev services, otherwise I get these errors:

2023-04-14 09:26:33,636 DEBUG [com.git.doc.zer.ApacheDockerHttpClientImpl$ApacheResponse] (docker-java-stream-623622257) Failed to close the response: java.io.IOException: java.nio.channels.ClosedChannelException
    at java.base/java.nio.channels.Channels$2.read(Channels.java:241)
    at com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.LoggingInputStream.read(LoggingInputStream.java:81)
    at com.github.dockerjava.zerodep.shaded.org.apache.hc.core5.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:149)
    at com.github.dockerjava.zerodep.shaded.org.apache.hc.core5.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:280)
    at com.github.dockerjava.zerodep.shaded.org.apache.hc.core5.http.impl.io.ChunkedInputStream.getChunkSize(ChunkedInputStream.java:261)
    at com.github.dockerjava.zerodep.shaded.org.apache.hc.core5.http.impl.io.ChunkedInputStream.nextChunk(ChunkedInputStream.java:222)
    at com.github.dockerjava.zerodep.shaded.org.apache.hc.core5.http.impl.io.ChunkedInputStream.read(ChunkedInputStream.java:147)
    at com.github.dockerjava.zerodep.shaded.org.apache.hc.core5.http.impl.io.ChunkedInputStream.close(ChunkedInputStream.java:314)
    at com.github.dockerjava.zerodep.shaded.org.apache.hc.core5.io.Closer.close(Closer.java:48)
    at com.github.dockerjava.zerodep.shaded.org.apache.hc.core5.http.impl.io.IncomingHttpEntity.close(IncomingHttpEntity.java:111)
    at com.github.dockerjava.zerodep.shaded.org.apache.hc.core5.http.io.entity.HttpEntityWrapper.close(HttpEntityWrapper.java:120)
    at com.github.dockerjava.zerodep.shaded.org.apache.hc.core5.io.Closer.close(Closer.java:48)
    at com.github.dockerjava.zerodep.shaded.org.apache.hc.core5.http.message.BasicClassicHttpResponse.close(BasicClassicHttpResponse.java:93)
    at com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.CloseableHttpResponse.close(CloseableHttpResponse.java:200)
    at com.github.dockerjava.zerodep.ApacheDockerHttpClientImpl$ApacheResponse.close(ApacheDockerHttpClientImpl.java:256)
    at org.testcontainers.shaded.com.github.dockerjava.core.DefaultInvocationBuilder.lambda$executeAndStream$1(DefaultInvocationBuilder.java:277)
    at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.nio.channels.ClosedChannelException
    at java.base/sun.nio.ch.WindowsAsynchronousFileChannelImpl.implRead(WindowsAsynchronousFileChannelImpl.java:519)
    at java.base/sun.nio.ch.AsynchronousFileChannelImpl.read(AsynchronousFileChannelImpl.java:229)
    at com.github.dockerjava.transport.NamedPipeSocket$AsynchronousFileByteChannel.read(NamedPipeSocket.java:117)
    at java.base/java.nio.channels.Channels$2.read(Channels.java:239)
    ... 16 more

Any advice how I can continue debugging?

ce-bo commented 1 year ago

It seems that undertow is not working on my Windows machine but on a Mac Machine it is working fine. The app is using two servlets to expose two REST API endpoints. By removing the quarkus-undertow dependency it is working but then the API is not available of course.

maxandersen commented 1 year ago

Yes so something about Those servlets config/annotations is triggering is My assumption.

Try mimick it in a reproducer and See when it fails. The body of the code most likely does not matter.

ce-bo commented 1 year ago

I figured out that the following path configuration was not working on my Windows machine:

<servlet>
<multipart-config>
            <location>/tmp</location>
....
ce-bo commented 1 year ago

Issue fixed by specifying the right tmp path.