Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Undertow with TLS causes IllegalStateException: Request has already been read #14811

Closed
renegrob opened this issue Feb 4, 2021 · 4 comments · Fixed by #14923
Closed

Undertow with TLS causes IllegalStateException: Request has already been read #14811

renegrob opened this issue Feb 4, 2021 · 4 comments · Fixed by #14923
Labels
area/undertow kind/bug Something isn't working
Milestone

Comments

@renegrob
Copy link
Contributor

renegrob commented Feb 4, 2021

Describe the bug
If Undertow is used with TLS then request in DEV mode occasionally leading to a java.lang.IllegalStateException: Request has already been read.

Expected behavior
Requests should be processed correctly.

Actual behavior
Not every request but 30-70% returns with a java.lang.IllegalStateException: Request has already been read.

To Reproduce

Link to a small reproducer (preferably a Maven project if the issue is not Gradle-specific).

Or attach an archive containing the reproducer to the issue.

Steps to reproduce the behavior:

  1. Checkout the reproducer project
git clone https://github.com/renegrob/reproducer-base.git
git checkout request-has-aldready-been-read
  1. Start Quarkus in DEV mode with
    ./gradlew quarkusDev`
  2. Issue a request via CURL or in the browser to https://localhost:8443/ or https://localhost:8443/void
curl -k https://localhost:8443
curl -k https://localhost:8443/void
  1. Remove the line implementation("io.quarkus:quarkus-undertow") from the file build.gradle.kts and execute the http requests again. The problem is gone. But without Undertow it is not possible to inject HttpServletRequest in JAX-RS.

Configuration

quarkus:
  http:
    insecure-requests: redirect
    host: 0.0.0.0
    port: 8080
    ssl-port: 8443
    http2: true
    ssl:
      certificate:
        key-store-file-type: PKCS12
        key-store-file: tls-server-keypair.p12
        key-store-password: ******

Stacktrace

java.lang.IllegalStateException: Request has already been read
	at io.vertx.core.http.impl.Http2ServerRequestImpl.checkEnded(Http2ServerRequestImpl.java:215)
	at io.vertx.core.http.impl.Http2ServerRequestImpl.pause(Http2ServerRequestImpl.java:241)
	at io.quarkus.vertx.http.runtime.ResumingRequestWrapper.pause(ResumingRequestWrapper.java:28)
	at io.vertx.ext.web.impl.HttpServerRequestWrapper.pause(HttpServerRequestWrapper.java:88)
	at io.quarkus.undertow.runtime.UndertowDeploymentRecorder$5.handle(UndertowDeploymentRecorder.java:377)
	at io.quarkus.undertow.runtime.UndertowDeploymentRecorder$5.handle(UndertowDeploymentRecorder.java:374)
	at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1038)
	at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:137)
	at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:132)
	at io.quarkus.vertx.http.runtime.VertxHttpRecorder$4.handle(VertxHttpRecorder.java:332)
	at io.quarkus.vertx.http.runtime.VertxHttpRecorder$4.handle(VertxHttpRecorder.java:310)
	at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1038)
	at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:137)
	at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:132)
	at io.quarkus.vertx.http.runtime.security.HttpAuthorizer.doPermissionCheck(HttpAuthorizer.java:116)
	at io.quarkus.vertx.http.runtime.security.HttpAuthorizer.access$100(HttpAuthorizer.java:27)
	at io.quarkus.vertx.http.runtime.security.HttpAuthorizer$2.accept(HttpAuthorizer.java:133)
	at io.quarkus.vertx.http.runtime.security.HttpAuthorizer$2.accept(HttpAuthorizer.java:122)
	at io.smallrye.mutiny.helpers.UniCallbackSubscriber.onItem(UniCallbackSubscriber.java:69)
	at io.smallrye.mutiny.operators.UniSerializedSubscriber.onItem(UniSerializedSubscriber.java:86)
	at io.smallrye.mutiny.operators.uni.builders.KnownItemUni.subscribing(KnownItemUni.java:25)
	at io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:54)
	at io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:49)
	at io.smallrye.mutiny.groups.UniSubscribe.withSubscriber(UniSubscribe.java:50)
	at io.smallrye.mutiny.groups.UniSubscribe.with(UniSubscribe.java:70)
	at io.quarkus.vertx.http.runtime.security.HttpAuthorizer.doPermissionCheck(HttpAuthorizer.java:122)
	at io.quarkus.vertx.http.runtime.security.HttpAuthorizer.checkPermission(HttpAuthorizer.java:99)
	at io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$3.handle(HttpSecurityRecorder.java:218)
	at io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$3.handle(HttpSecurityRecorder.java:210)
	at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1038)
	at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:137)
	at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:132)
	at io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$2$2$1.onItem(HttpSecurityRecorder.java:128)
	at io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$2$2$1.onItem(HttpSecurityRecorder.java:118)
	at io.smallrye.mutiny.operators.UniSerializedSubscriber.onItem(UniSerializedSubscriber.java:86)
	at io.smallrye.mutiny.operators.uni.builders.KnownItemUni.subscribing(KnownItemUni.java:25)
	at io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:54)
	at io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:49)
	at io.smallrye.mutiny.groups.UniSubscribe.withSubscriber(UniSubscribe.java:50)
	at io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$2$2.onItem(HttpSecurityRecorder.java:118)
	at io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$2$2.onItem(HttpSecurityRecorder.java:104)
	at io.smallrye.mutiny.operators.UniSerializedSubscriber.onItem(UniSerializedSubscriber.java:86)
	at io.smallrye.mutiny.operators.UniMemoizeOp.drain(UniMemoizeOp.java:145)
	at io.smallrye.mutiny.operators.UniMemoizeOp.onItem(UniMemoizeOp.java:171)
	at io.smallrye.mutiny.operators.UniSerializedSubscriber.onItem(UniSerializedSubscriber.java:86)
	at io.smallrye.mutiny.operators.uni.builders.SuppliedtemUni.subscribing(SuppliedtemUni.java:29)
	at io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:54)
	at io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:49)
	at io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:30)
	at io.smallrye.mutiny.operators.UniMemoizeOp.subscribing(UniMemoizeOp.java:70)
	at io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:54)
	at io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:49)
	at io.smallrye.mutiny.groups.UniSubscribe.withSubscriber(UniSubscribe.java:50)
	at io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$2.handle(HttpSecurityRecorder.java:104)
	at io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$2.handle(HttpSecurityRecorder.java:51)
	at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1038)
	at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:137)
	at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:132)
	at io.quarkus.vertx.http.runtime.devmode.VertxHttpHotReplacementSetup$3.handle(VertxHttpHotReplacementSetup.java:86)
	at io.quarkus.vertx.http.runtime.devmode.VertxHttpHotReplacementSetup$3.handle(VertxHttpHotReplacementSetup.java:75)
	at io.vertx.core.impl.ContextImpl.lambda$null$0(ContextImpl.java:327)
	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)

Environment (please complete the following information):

  • Output of uname -a or ver:

    Linux automatix 5.8.0-41-generic #46~20.04.1-Ubuntu SMP Mon Jan 18 17:52:23 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux
  • Output of java -version:

    java -version
    openjdk version "11.0.10" 2021-01-19 LTS
    OpenJDK Runtime Environment Zulu11.45+27-CA (build 11.0.10+9-LTS)
    OpenJDK 64-Bit Server VM Zulu11.45+27-CA (build 11.0.10+9-LTS, mixed mode)
  • GraalVM version (if different from Java):

    n/a
  • Quarkus version or git rev:

    1.11.1.Final
  • Build tool (ie. output of mvnw --version or gradlew --version):

    ------------------------------------------------------------
    Gradle 6.5.1
    ------------------------------------------------------------
    
    Build time:   2020-06-30 06:32:47 UTC
    Revision:     66bc713f7169626a7f0134bf452abde51550ea0a
    
    Kotlin:       1.3.72
    Groovy:       2.5.11
    Ant:          Apache Ant(TM) version 1.10.7 compiled on September 1 2019
    JVM:          11.0.10 (Azul Systems, Inc. 11.0.10+9-LTS)
    OS:           Linux 5.8.0-41-generic amd64

Additional context
n/a

@renegrob renegrob added the kind/bug Something isn't working label Feb 4, 2021
@ghost ghost added the area/kotlin label Feb 4, 2021
@ghost
Copy link

ghost commented Feb 4, 2021

/cc @evanchooly

@renegrob
Copy link
Contributor Author

renegrob commented Feb 4, 2021

@geoand @stuartwdouglas The bot tagged the wrong area. This concerns Undertow.

@markusdlugi
Copy link
Contributor

@renegrob Wow, I encountered the same bug yesterday, but you just beat me to it 😄

If it's still of any use, I also built a small sample project that reproduces the issue:

https://github.com/markusdlugi/undertow-https-example

Other than that, I can support everything @renegrob said, I've been encountering just the same issue, also running on Quarkus 1.11.1.Final.

One additional thing I noticed: this only happens if HTTP 2 is enabled. So you can also workaround this issue by setting quarkus.http.http2=false in your application.properties.

In fact, if you use a client that doesn't support HTTP 2 (Postman or IntelliJ HTTP Client), you won't ever run into the problem with Request has already been read.

@renegrob
Copy link
Contributor Author

renegrob commented Feb 4, 2021

About http2=falsethat also helped in our project however in my reproducer project it didn't help. It seems to be a timing / threading issue as it occurred less on my AMD Ryzen machine with 12 cores than on my college's Intel machine with 4 cores.

stuartwdouglas added a commit to stuartwdouglas/quarkus that referenced this issue Feb 9, 2021
@ghost ghost added this to the 1.12 - master milestone Feb 9, 2021
@gsmet gsmet modified the milestones: 1.12.0.CR1, 1.11.3.Final Feb 10, 2021
gsmet pushed a commit to gsmet/quarkus that referenced this issue Feb 10, 2021
Fixes quarkusio#14811

(cherry picked from commit 14f65f5)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/undertow kind/bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants