Hot reload crashes using dev mode with vert.x-web extension

[johnaohara]

Hot reload crashes intermittently when making changes to vert.x-web routes. The application becomes unresponsive to new requests and dev mode requires restarting.

An example stack trace is below;

__  ____  __  _____   ___  __ ____  ______ 
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/ 
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \   
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/   
2020-05-30 10:31:58,066 WARN  [io.qua.ver.web.dep.VertxWebProcessor] (build-3) Route io.quarkus.benchmark.resource.pgclient.JsonResource#json() can match the same request and has the same order [0] as:
        - io.quarkus.benchmark.resource.JsonResource#json()
2020-05-30 10:31:58,066 WARN  [io.qua.ver.web.dep.VertxWebProcessor] (build-3) Route io.quarkus.benchmark.resource.PlaintextResource#plaintext() can match the same request and has the same order [0] as:
        - io.quarkus.benchmark.resource.pgclient.PlaintextResource#plaintext()
2020-05-30 10:31:58,066 WARN  [io.qua.ver.web.dep.VertxWebProcessor] (build-3) You can use @Route#order() to ensure the routes are not executed in random order
2020-05-30 10:31:58,167 INFO  [io.quarkus] (Quarkus Main Thread) pgclient 1.0-SNAPSHOT (powered by Quarkus 1.4.2.Final) started in 0.043s. Listening on: http://0.0.0.0:8080
2020-05-30 10:31:58,167 INFO  [io.quarkus] (Quarkus Main Thread) Profile dev activated. Live Coding activated.
2020-05-30 10:31:58,167 INFO  [io.quarkus] (Quarkus Main Thread) Installed features: [cdi, jdbc-postgresql, mutiny, reactive-pg-client, resteasy-jackson, scheduler, vertx, vertx-web]
2020-05-30 10:31:58,167 INFO  [io.qua.dep.dev] (vert.x-worker-thread-0) Hot replace total time: 0.510s 
2020-05-30 10:31:58,170 ERROR [io.qua.ver.htt.run.QuarkusErrorHandler] (vert.x-eventloop-thread-1) HTTP Request to /updates?queries=2 failed, error id: dc58213c-5c11-4aa6-998e-aca1d14c6bd8-1: java.lang.IllegalStateException: Request has already been read
        at io.vertx.core.http.impl.HttpServerRequestImpl.checkEnded(HttpServerRequestImpl.java:600)
        at io.vertx.core.http.impl.HttpServerRequestImpl.handler(HttpServerRequestImpl.java:307)
        at io.quarkus.vertx.http.runtime.ResumingRequestWrapper.handler(ResumingRequestWrapper.java:18)
        at io.vertx.ext.web.impl.HttpServerRequestWrapper.handler(HttpServerRequestWrapper.java:78)
        at io.quarkus.vertx.http.runtime.ResumingRequestWrapper.handler(ResumingRequestWrapper.java:18)
        at io.vertx.ext.web.impl.HttpServerRequestWrapper.handler(HttpServerRequestWrapper.java:78)
        at io.vertx.ext.web.handler.impl.BodyHandlerImpl.handle(BodyHandlerImpl.java:86)
        at io.vertx.ext.web.handler.impl.BodyHandlerImpl.handle(BodyHandlerImpl.java:42)
        at io.quarkus.vertx.http.runtime.VertxHttpRecorder$14.handle(VertxHttpRecorder.java:958)
        at io.quarkus.vertx.http.runtime.VertxHttpRecorder$14.handle(VertxHttpRecorder.java:936)
        at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1034)
        at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:131)
        at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:130)
        at io.quarkus.vertx.http.runtime.devmode.VertxHotReplacementSetup.handleHotReplacementRequest(VertxHotReplacementSetup.java:39)
        at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1034)
        at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:131)
        at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:130)
        at io.quarkus.benchmark.resource.pgclient.ServerHeaderFilter.myFilter(ServerHeaderFilter.java:33)
        at io.quarkus.benchmark.resource.pgclient.ServerHeaderFilter_RouteHandler_myFilter_cef5c00e3333622174f01380528df26e19f4b101.invoke(ServerHeaderFilter_RouteHandler_myFilter_cef5c00e3333622174f01380528df26e19f4b101.zig:64)
        at io.quarkus.vertx.web.runtime.RouteHandler.handle(RouteHandler.java:40)
        at io.quarkus.vertx.web.runtime.RouteHandler.handle(RouteHandler.java:15)
        at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1034)
        at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:131)
        at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:130)
        at io.quarkus.vertx.http.runtime.devmode.VertxHotReplacementSetup.handleHotReplacementRequest(VertxHotReplacementSetup.java:39)
        at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1034)
        at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:131)
        at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:130)
        at io.vertx.ext.web.impl.RouterImpl.handle(RouterImpl.java:54)
        at io.vertx.ext.web.impl.RouterImpl.handle(RouterImpl.java:36)
        at io.quarkus.vertx.http.runtime.VertxHttpRecorder$7.handle(VertxHttpRecorder.java:334)
        at io.quarkus.vertx.http.runtime.VertxHttpRecorder$7.handle(VertxHttpRecorder.java:331)
        at io.quarkus.vertx.http.runtime.VertxHttpRecorder$1.handle(VertxHttpRecorder.java:112)
        at io.quarkus.vertx.http.runtime.VertxHttpRecorder$1.handle(VertxHttpRecorder.java:103)
        at io.quarkus.vertx.http.runtime.devmode.VertxHotReplacementSetup$2.handle(VertxHotReplacementSetup.java:72)
        at io.quarkus.vertx.http.runtime.devmode.VertxHotReplacementSetup$2.handle(VertxHotReplacementSetup.java:63)
        at io.vertx.core.impl.ContextImpl.lambda$null$0(ContextImpl.java:330)
        at io.vertx.core.impl.ContextImpl.executeTask(ContextImpl.java:369)
        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)

Steps to reproduce the behavior:

1. Add vertx-web extension
2. Define a @route endpoint
3. Start dev mode
4. make changes to vertx route endpoint that does not contain errors
5. hit endpoint with http client
6. introduce something that will cause compilation error
7. hit end point
8. remove code introduced in step 5
9. Hit endpoint a few times and exception should be thrown

[davsclaus]

Yes I have seen this too

[tsegismont]

I looked into a similar issue reported on the chat by a Quarkus GraphQL user. After reload the GraphQL query payload cannot been read most of the time.

For the record, the reason is that during reload, verticles are undeployed and the previous vertx instance closed, but the new Vert.x instance keeps the reference to the previous HTTP server and Vert.x instance.
Then when getOrCreateContext is invoked on an HTTP handler, it always creates a new EventLoopContext because the current context owner is the previous Vert.x instance, not the new one.
So most often the request is resumed on an event loop that is not the event loop bound to the HTTP connection. Consequently, the body is consumed before the BodyHandler is invoked, leading to the request has already been read error.
It is only when, by chance, the event loop associated to the created context is the same as the event loop bound to the HTTP connection that the body can be read.

@stuartwdouglas I had a look at d23059f and 8613162. Invoking executingBlocking on the context bound to the HTTP connection works around the issue, but can still lead to surprises if user or extension code:

• invokes executeBlocking on the Vert.x instance bound to the Router
• assumes the same thread that created a handler will invoke its methods

@cescoffier I believe you have made experiments for supporting verticles in Quarkus. Is that a problem you have already found and addressed?

[stuartwdouglas]

Looks like I did a fix for this but must have forgotten to actually open the PR, oops.

[phillip-kruger]

Please can this fix go in 1.6 !! @gsmet ?