Keycloak with policy-enforcer enabled: Request has already been read

PiotrRaszkowski commented 2 years ago

Describe the bug

I tried to configure my application with the provided guide https://quarkus.io/guides/security-keycloak-authorization.

I was unable to open the DEV UI for the first try. After 2-3 page refresh requests it was possible to open it but the DEV UI was very slow, I was unable to login to KeyCloak.

Expected behavior

DEV UI works fine.

Actual behavior

2022-05-03 20:45:28,896 ERROR [io.qua.ver.htt.run.QuarkusErrorHandler] (executor-thread-0) HTTP Request to /q/dev/ failed, error id: 4e3ffba2-7af3-428a-9fb1-12cba3a3ce54-1: java.lang.IllegalStateException: Request has already been read
    at io.vertx.core.http.impl.Http1xServerRequest.checkEnded(Http1xServerRequest.java:651)
    at io.vertx.core.http.impl.Http1xServerRequest.body(Http1xServerRequest.java:507)
    at io.vertx.core.http.HttpServerRequest.bodyHandler(HttpServerRequest.java:273)
    at io.quarkus.vertx.http.runtime.ResumingRequestWrapper.bodyHandler(ResumingRequestWrapper.java:57)
    at io.vertx.ext.web.impl.HttpServerRequestWrapper.bodyHandler(HttpServerRequestWrapper.java:285)
    at io.quarkus.vertx.http.runtime.devmode.DevConsoleFilter.handle(DevConsoleFilter.java:49)
    at io.quarkus.vertx.http.runtime.devmode.DevConsoleFilter.handle(DevConsoleFilter.java:27)
    at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1212)
    at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:163)
    at io.vertx.ext.web.impl.RoutingContextWrapper.next(RoutingContextWrapper.java:201)
    at io.vertx.ext.web.impl.RouterImpl.handleContext(RouterImpl.java:248)
    at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1212)
    at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:163)
    at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
    at io.quarkus.vertx.http.runtime.VertxHttpRecorder$5.handle(VertxHttpRecorder.java:380)
    at io.quarkus.vertx.http.runtime.VertxHttpRecorder$5.handle(VertxHttpRecorder.java:358)
    at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1212)
    at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:163)
    at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
    at io.quarkus.vertx.http.runtime.security.HttpAuthorizer.doPermissionCheck(HttpAuthorizer.java:117)
    at io.quarkus.vertx.http.runtime.security.HttpAuthorizer$2.accept(HttpAuthorizer.java:134)
    at io.quarkus.vertx.http.runtime.security.HttpAuthorizer$2.accept(HttpAuthorizer.java:123)
    at io.smallrye.context.impl.wrappers.SlowContextualConsumer.accept(SlowContextualConsumer.java:21)
    at io.smallrye.mutiny.helpers.UniCallbackSubscriber.onItem(UniCallbackSubscriber.java:77)
    at io.smallrye.mutiny.operators.uni.builders.DefaultUniEmitter.complete(DefaultUniEmitter.java:37)
    at io.quarkus.vertx.http.runtime.security.HttpAuthorizer$1$1$1.run(HttpAuthorizer.java:76)
    at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:548)
    at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2449)
    at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1478)
    at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
    at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
    at java.base/java.lang.Thread.run(Thread.java:832)

How to Reproduce?

Steps how to reproduce:

Build simple application with dependencies:

dependencies {
implementation enforcedPlatform("${quarkusPlatformGroupId}:${quarkusPlatformArtifactId}:${quarkusPlatformVersion}")
implementation 'io.quarkus:quarkus-arc'

implementation 'io.quarkus:quarkus-resteasy-reactive-jackson'

implementation 'io.quarkus:quarkus-hibernate-orm-panache'
implementation 'io.quarkus:quarkus-jdbc-mariadb'
implementation 'io.quarkus:quarkus-liquibase'

implementation 'io.quarkus:quarkus-oidc'
implementation 'io.quarkus:quarkus-keycloak-authorization'

implementation 'org.projectlombok:lombok:1.18.24'

testImplementation 'io.quarkus:quarkus-junit5'

testImplementation 'io.quarkus:quarkus-test-h2'
testImplementation 'io.quarkus:quarkus-jdbc-h2'
testImplementation 'io.quarkus:quarkus-panache-mock'

testImplementation 'io.rest-assured:rest-assured'
}

application.properties configuration:


quarkus.datasource.db-kind=mariadb
quarkus.datasource.username=xxx
quarkus.datasource.password=xxx
quarkus.datasource.jdbc.url=jdbc:mariadb://localhost:3306/xxx

quarkus.hibernate-orm.dialect=org.hibernate.dialect.MariaDBDialect

quarkus.hibernate-orm.log.sql=true quarkus.hibernate-orm.log.bind-parameters=true quarkus.log.min-level=TRACE

quarkus.liquibase.migrate-at-start=true

%prod.quarkus.oidc.auth-server-url=https://localhost:8543/realms/quarkus quarkus.oidc.client-id=backend-service quarkus.oidc.credentials.secret=secret quarkus.oidc.tls.verification=none

quarkus.keycloak.policy-enforcer.enable=true

quarkus.keycloak.devservices.realm-path=quarkus-realm.json quarkus.keycloak.devservices.image-name=quay.io/keycloak/keycloak:18.0.0



3. Go to Dev UI

### Output of `uname -a` or `ver`

Darwin Piotrs-MBP 21.4.0 Darwin Kernel Version 21.4.0: Fri Mar 18 00:47:26 PDT 2022; root:xnu-8020.101.4~15/RELEASE_ARM64_T8101 arm

### Output of `java -version`

openjdk version "18.0.1" 2022-04-19

### GraalVM version (if different from Java)

_No response_

### Quarkus version or git rev

2.8.2.Final

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

_No response_

### Additional information

Works fine in 2.8.0.Final.

quarkus-bot[bot] commented 2 years ago

/cc @pedroigor, @sberyozkin

sberyozkin commented 2 years ago

@PiotrRaszkowski Keycloak 18.0.0 is not supported yet, specifically if the uploaded realm contains scripts, see https://github.com/quarkusio/quarkus/pull/25109

CC @pedroigor

pedroigor commented 2 years ago

@PiotrRaszkowski Can you try to disable tests or toggle broken only mode when running in dev mode?

I was able to reproduce the problem and it seems related to tests running and causing some instability when rendering the dev UI.

PiotrRaszkowski commented 2 years ago

@sberyozkin Quarkus 2.8.2.Final + Keycloak 17.0.0 -> same problem, Quarkus 2.8.0.Final + Keycloak 17.0.0 -> no problem. So yes, maybe Keycloak 18.0.0 is not supported yet but it is not related to Keycloak version.

PiotrRaszkowski commented 2 years ago

@pedroigor With broken only mode there is no big difference, with second or third request/refresh I am able to open DEV UI but it is turbo slow. With quarkus.test.continuous-testing=disabled I still have this errors as the first request, but then it is working fine, I was able to log in to Keycloak it it wasn't slow. This could be a temp workaround but... for someone continuous-testing might be a nice feature...

sberyozkin commented 2 years ago

@PiotrRaszkowski @pedroigor I have reproduced on the main branch as well, and it is only keycloak-authorization which is affected, oidc bearer and oidc web-app quickstarts are good, I'm sure it is to do with /q/dev not being treated as a public resource (given HttpAuthorizer is referenced in the logs), however, adding

quarkus.http.auth.permission.public.paths=/q/dev/*
quarkus.http.auth.permission.public.policy=permit

does not help, nor

quarkus.keycloak.policy-enforcer.paths.2.path=/q/dev/*
quarkus.keycloak.policy-enforcer.paths.2.enforcement-mode=DISABLED

I'm not sure why it has started failing now but was working in 2.8.0

sberyozkin commented 2 years ago

I was wrong, with or without these properties, since there are no annotations, it is deduced correctly it is a public resource.

Something has changed at the Vert.x level or Dev UI level.

@stuartwdouglas @phillip-kruger Can you have a look please when get a chance ? It can be reproduced on main, build it and go to quarkus-quickstarts/security-keycloak-authorization-quickstarts and do mvn quarkus:dev and try to access http://localhost:8080/q/dev/.

I have confirmed in the debug mode that KeycloakPolicyEnforcerAuthorizer (which is HttpSecurityPolicy) will be invoked and PERMIT will be returned here.

So it is the only thing which is different from the other OIDC quickstarts where Dev UI is accessed, that HttpAuthorizer is involved here to check HttpSecurityPolicy.

@PiotrRaszkowski has confirmed it works with 2.8.0 but started failing with 2.8.2

quarkusio / quarkus