4.3.1 - problem with web socket - 'Request has already been read'

[Szymon G]

Hi,

Maybe someone can help with understanding the problem.

I am facing an issue with upgrade from 4.1.3 to 4.3.1.

We have a working application using web sockets (event bus).

We have the following set up of handlers (for problematic ws request):

- body / headers (on root)

- session /cors  (on root)

- OAuth / authentication (on root)

- authorization (on root)

- SockJSHandler (on sub-route)

works nice in 4.1.3, but after 4.3.1 upgrade I started getting this:

java.lang.IllegalStateException: Request has already been read
        at io.vertx.core.http.impl.Http1xServerRequest.checkEnded(Http1xServerRequest.java:651) ~[vertx-core-4.3.1.jar:4.3.1]
        at io.vertx.core.http.impl.Http1xServerRequest.handler(Http1xServerRequest.java:292) ~[vertx-core-4.3.1.jar:4.3.1]
        at io.vertx.core.http.impl.Http1xServerRequest.webSocket(Http1xServerRequest.java:424) ~[vertx-core-4.3.1.jar:4.3.1]
        at io.vertx.core.http.impl.Http1xServerRequest.webSocket(Http1xServerRequest.java:414) ~[vertx-core-4.3.1.jar:4.3.1]
        at io.vertx.core.http.impl.Http1xServerRequest.toWebSocket(Http1xServerRequest.java:403) ~[vertx-core-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.impl.HttpServerRequestWrapper.toWebSocket(HttpServerRequestWrapper.java:350) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.handler.sockjs.impl.WebSocketTransport.handleGet(WebSocketTransport.java:96) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:173) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.impl.RoutingContextWrapper.next(RoutingContextWrapper.java:200) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.impl.RouterImpl.handleContext(RouterImpl.java:250) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:173) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:140) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.handler.impl.AuthorizationHandlerImpl.checkOrFetchAuthorizations(AuthorizationHandlerImpl.java:93) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.handler.impl.AuthorizationHandlerImpl.handle(AuthorizationHandlerImpl.java:67) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.handler.impl.AuthorizationHandlerImpl.handle(AuthorizationHandlerImpl.java:36) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:173) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:140) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.handler.impl.AuthenticationHandlerInternal.postAuthentication(AuthenticationHandlerInternal.java:43) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.handler.impl.AuthenticationHandlerImpl.handle(AuthenticationHandlerImpl.java:73) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.handler.impl.AuthenticationHandlerImpl.handle(AuthenticationHandlerImpl.java:31) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:173) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:140) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.ext.web.handler.impl.SessionHandlerImpl.lambda$handle$7(SessionHandlerImpl.java:310) ~[vertx-web-4.3.1.jar:4.3.1]
        at io.vertx.core.impl.future.FutureImpl$1.onSuccess(FutureImpl.java:91) ~[vertx-core-4.3.1.jar:4.3.1]
        at io.vertx.core.impl.future.FutureImpl$ListenerArray.onSuccess(FutureImpl.java:262) ~[vertx-core-4.3.1.jar:4.3.1]
        at io.vertx.core.impl.future.FutureBase.lambda$emitSuccess$0(FutureBase.java:54) ~[vertx-core-4.3.1.jar:4.3.1]
        at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:174) [netty-common-4.1.77.Final.jar:4.1.77.Final]
        at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:167) [netty-common-4.1.77.Final.jar:4.1.77.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470) [netty-common-4.1.77.Final.jar:4.1.77.Final]
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:503) [netty-transport-4.1.77.Final.jar:4.1.77.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:995) [netty-common-4.1.77.Final.jar:4.1.77.Final]
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-common-4.1.77.Final.jar:4.1.77.Final]
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-common-4.1.77.Final.jar:4.1.77.Final]
        at java.lang.Thread.run(Thread.java:834) [?:?]

Any ideas what that could be - all the stack is library code, I have not found any deprecations / breaking changes that look relevant.

Maybe just order is messed up, but I can't find anything wrong there...

Many thanks,

Simon

[Paulo Lopes]

In 4.3.x and soon 4.3.2 we've been improving the way we handle asynchronous handlers that require the body to be parsed. The issue is that there are a few potential conflicts in your setup:

if a Body Handler and SockJS Handler before 4.3.0 were on the same route, the body handler could consume the request body to populate the `body()` property of the routing context, however the sockjs would attempt a protocol upgrade which requires the body to be available at parsing time.

In 4.3.1 we've improved a bit this by pausing and resuming the request, yet this didn't work on a few edge cases. In the current master we explicitly pause and resume the body parsing on all provided handlers that perform asynchronous calls so we don't loose it. This could be what you need. Note however, that if you're implementing your own handlers and perform asynchronous calls you need to perform this actions also manually.

Before protocol upgrades in vert.x core were not asynchronous calls, so you wouldn't notice this, but it would, however, block the event loop, which is never a good thing.

[Szymon G]

Than you Paulo, I will try to separate SockJS handler to not have body handler before it, and see if this helps.

best regards,

Simon

[Szymon G]

So changing order did not work, but switching to 4.3.2 seems to work - I just did some initial tests.

Many thanks, 

Simon