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.

Sign up for GitHub

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

Jump to bottom

Keycloak Claim Information Point - timeout after trying to read the body for the second time - 1.4.1.Final #9054

Closed
tpenakov opened this issue May 4, 2020 · 2 comments
Closed

Keycloak Claim Information Point - timeout after trying to read the body for the second time - 1.4.1.Final #9054

tpenakov opened this issue May 4, 2020 · 2 comments
Labels
area/keycloak-authorization area/oidc kind/question Further information is requested

Comments

@tpenakov
Copy link

tpenakov commented May 4, 2020 •
edited
Loading

Previous issues related to this one: #5959 and #8478
Now instead of NPE - the timeout error is present.

When you try to read body through Claim Information Point the result is java.io.IOException: Read timeout.

When you add the following to your application.properties file:

quarkus.keycloak.policy-enforcer.claim-information-point.claims.claim-from-body={request.body}

And execute the post request against the endpoint /api/auth-entry

The result is:

2020-05-04 18:01:56,924 ERROR [org.ota.enf.cla.can.not.rea.bod.web.con.RestApiController] (executor-thread-1) uanble to read input stream: java.io.IOException: Read timeout
        at io.undertow.vertx.VertxHttpExchange.readBlocking(VertxHttpExchange.java:434)
        at io.undertow.server.HttpServerExchange.readBlocking(HttpServerExchange.java:937)
        at io.undertow.servlet.spec.ServletInputStreamImpl.readIntoBuffer(ServletInputStreamImpl.java:178)
        at io.undertow.servlet.spec.ServletInputStreamImpl.read(ServletInputStreamImpl.java:158)
        at java.base/sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
        at java.base/sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
        at java.base/sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
        at java.base/java.io.InputStreamReader.read(InputStreamReader.java:185)
        at java.base/java.io.Reader.read(Reader.java:229)
        at org.apache.commons.io.IOUtils.copyLarge(IOUtils.java:2537)
        at org.apache.commons.io.IOUtils.copyLarge(IOUtils.java:2516)
        at org.apache.commons.io.IOUtils.copy(IOUtils.java:2493)
        at org.apache.commons.io.IOUtils.copy(IOUtils.java:2441)
        at org.apache.commons.io.IOUtils.toString(IOUtils.java:1084)
        at org.otaibe.enforcer.claim.can.not.read.body.web.controller.RestApiController.post(RestApiController.java:27)
        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 org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:167)
        at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:130)
        at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:621)
        at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:487)
        at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:437)
        at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:362)
        at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:439)
        at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:400)
        at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:374)
        at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:67)
        at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:488)
        at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:259)
        at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:160)
        at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:362)
        at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:163)
        at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:245)
        at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:249)
        at io.quarkus.resteasy.runtime.ResteasyFilter.doFilter(ResteasyFilter.java:30)
        at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
        at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
        at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
        at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:63)
        at io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68)
        at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
        at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:133)
        at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
        at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
        at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:65)
        at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
        at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
        at io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
        at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
        at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:270)
        at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:59)
        at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:116)
        at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:113)
        at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
        at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
        at io.quarkus.undertow.runtime.UndertowDeploymentRecorder$10$1$1.call(UndertowDeploymentRecorder.java:563)
        at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:250)
        at io.undertow.servlet.handlers.ServletInitialHandler.handleRequest(ServletInitialHandler.java:175)
        at io.undertow.server.handlers.HttpContinueReadHandler.handleRequest(HttpContinueReadHandler.java:43)
        at io.undertow.server.handlers.PathHandler.handleRequest(PathHandler.java:91)
        at io.quarkus.undertow.runtime.UndertowDeploymentRecorder$1.handleRequest(UndertowDeploymentRecorder.java:113)
        at io.undertow.server.Connectors.executeRootHandler(Connectors.java:290)
        at io.undertow.server.DefaultExchangeHandler.handle(DefaultExchangeHandler.java:18)
        at io.quarkus.undertow.runtime.UndertowDeploymentRecorder$6.handle(UndertowDeploymentRecorder.java:391)
        at io.quarkus.undertow.runtime.UndertowDeploymentRecorder$6.handle(UndertowDeploymentRecorder.java:373)
        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.RoutingContextWrapper.next(RoutingContextWrapper.java:160)
        at io.quarkus.vertx.http.runtime.security.HttpAuthorizer.doPermissionCheck(HttpAuthorizer.java:107)
        at io.quarkus.vertx.http.runtime.security.HttpAuthorizer.access$100(HttpAuthorizer.java:26)
        at io.quarkus.vertx.http.runtime.security.HttpAuthorizer$2.accept(HttpAuthorizer.java:124)
        at io.quarkus.vertx.http.runtime.security.HttpAuthorizer$2.accept(HttpAuthorizer.java:113)
        at io.smallrye.mutiny.helpers.UniCallbackSubscriber.onItem(UniCallbackSubscriber.java:68)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.onItem(UniSerializedSubscriber.java:72)
        at io.smallrye.mutiny.operators.DefaultUniEmitter.complete(DefaultUniEmitter.java:36)
        at io.smallrye.mutiny.groups.UniCreate.lambda$item$2(UniCreate.java:205)
        at io.smallrye.mutiny.operators.UniCreateWithEmitter.subscribing(UniCreateWithEmitter.java:22)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:43)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:38)
        at io.smallrye.mutiny.groups.UniSubscribe.withSubscriber(UniSubscribe.java:49)
        at io.smallrye.mutiny.groups.UniSubscribe.with(UniSubscribe.java:69)
        at io.quarkus.vertx.http.runtime.security.HttpAuthorizer.doPermissionCheck(HttpAuthorizer.java:113)
        at io.quarkus.vertx.http.runtime.security.HttpAuthorizer.access$100(HttpAuthorizer.java:26)
        at io.quarkus.vertx.http.runtime.security.HttpAuthorizer$2.accept(HttpAuthorizer.java:120)
        at io.quarkus.vertx.http.runtime.security.HttpAuthorizer$2.accept(HttpAuthorizer.java:113)
        at io.smallrye.mutiny.helpers.UniCallbackSubscriber.onItem(UniCallbackSubscriber.java:68)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.onItem(UniSerializedSubscriber.java:72)
        at io.smallrye.mutiny.operators.DefaultUniEmitter.complete(DefaultUniEmitter.java:36)
        at io.smallrye.mutiny.groups.UniCreate.lambda$item$2(UniCreate.java:205)
        at io.smallrye.mutiny.operators.UniCreateWithEmitter.subscribing(UniCreateWithEmitter.java:22)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:43)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:38)
        at io.smallrye.mutiny.groups.UniSubscribe.withSubscriber(UniSubscribe.java:49)
        at io.smallrye.mutiny.groups.UniSubscribe.with(UniSubscribe.java:69)
        at io.quarkus.vertx.http.runtime.security.HttpAuthorizer.doPermissionCheck(HttpAuthorizer.java:113)
        at io.quarkus.vertx.http.runtime.security.HttpAuthorizer.checkPermission(HttpAuthorizer.java:91)
        at io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$3.handle(HttpSecurityRecorder.java:155)
        at io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$3.handle(HttpSecurityRecorder.java:147)
        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.RoutingContextWrapper.next(RoutingContextWrapper.java:160)
        at io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$2$5.accept(HttpSecurityRecorder.java:135)
        at io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$2$5.accept(HttpSecurityRecorder.java:129)
        at io.smallrye.mutiny.helpers.UniCallbackSubscriber.onItem(UniCallbackSubscriber.java:68)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.onItem(UniSerializedSubscriber.java:72)
        at io.smallrye.mutiny.operators.UniOnEventConsume$1.onItem(UniOnEventConsume.java:27)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.onItem(UniSerializedSubscriber.java:72)
        at io.smallrye.mutiny.operators.UniOnEventConsume$1.onItem(UniOnEventConsume.java:27)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.onItem(UniSerializedSubscriber.java:72)
        at io.smallrye.mutiny.operators.UniDelegatingSubscriber.onItem(UniDelegatingSubscriber.java:24)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.onItem(UniSerializedSubscriber.java:72)
        at io.smallrye.mutiny.operators.DefaultUniEmitter.complete(DefaultUniEmitter.java:36)
        at io.smallrye.mutiny.groups.UniCreate.lambda$item$2(UniCreate.java:205)
        at io.smallrye.mutiny.operators.UniCreateWithEmitter.subscribing(UniCreateWithEmitter.java:22)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:43)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:38)
        at io.smallrye.mutiny.groups.UniSubscribe.withSubscriber(UniSubscribe.java:49)
        at io.smallrye.mutiny.operators.UniFlatMapOnItem.invokeAndSubstitute(UniFlatMapOnItem.java:48)
        at io.smallrye.mutiny.operators.UniFlatMapOnItem$2.onItem(UniFlatMapOnItem.java:65)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.onItem(UniSerializedSubscriber.java:72)
        at io.smallrye.mutiny.operators.UniDelegatingSubscriber.onItem(UniDelegatingSubscriber.java:24)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.onItem(UniSerializedSubscriber.java:72)
        at io.smallrye.mutiny.operators.DefaultUniEmitter.complete(DefaultUniEmitter.java:36)
        at io.smallrye.mutiny.groups.UniCreate.lambda$item$2(UniCreate.java:205)
        at io.smallrye.mutiny.operators.UniCreateWithEmitter.subscribing(UniCreateWithEmitter.java:22)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:43)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:38)
        at io.smallrye.mutiny.groups.UniSubscribe.withSubscriber(UniSubscribe.java:49)
        at io.smallrye.mutiny.operators.UniFlatMapOnItem.invokeAndSubstitute(UniFlatMapOnItem.java:48)
        at io.smallrye.mutiny.operators.UniFlatMapOnItem$2.onItem(UniFlatMapOnItem.java:65)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.onItem(UniSerializedSubscriber.java:72)
        at io.smallrye.mutiny.operators.UniDelegatingSubscriber.onItem(UniDelegatingSubscriber.java:24)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.onItem(UniSerializedSubscriber.java:72)
        at io.smallrye.mutiny.operators.DefaultUniEmitter.complete(DefaultUniEmitter.java:36)
        at io.smallrye.mutiny.groups.UniCreate.lambda$item$2(UniCreate.java:205)
        at io.smallrye.mutiny.operators.UniCreateWithEmitter.subscribing(UniCreateWithEmitter.java:22)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:43)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:38)
        at io.smallrye.mutiny.groups.UniSubscribe.withSubscriber(UniSubscribe.java:49)
        at io.smallrye.mutiny.operators.UniFlatMapOnItem.invokeAndSubstitute(UniFlatMapOnItem.java:48)
        at io.smallrye.mutiny.operators.UniFlatMapOnItem$2.onItem(UniFlatMapOnItem.java:65)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.onItem(UniSerializedSubscriber.java:72)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.onItem(UniSerializedSubscriber.java:72)
        at io.smallrye.mutiny.operators.UniSerializedSubscriber.onItem(UniSerializedSubscriber.java:72)
        at io.smallrye.mutiny.operators.DefaultUniEmitter.complete(DefaultUniEmitter.java:36)
        at io.quarkus.security.runtime.QuarkusIdentityProviderManagerImpl$1$1$1$1.run(QuarkusIdentityProviderManagerImpl.java:58)
        at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
        at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:2046)
        at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1578)
        at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1452)
        at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
        at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
        at java.base/java.lang.Thread.run(Thread.java:834)
        at org.jboss.threads.JBossThread.run(JBossThread.java:479)
        Suppressed: java.io.IOException: Read timeout
                at io.undertow.vertx.VertxHttpExchange.readBlocking(VertxHttpExchange.java:434)
                at io.undertow.server.HttpServerExchange.readBlocking(HttpServerExchange.java:937)
                at io.undertow.servlet.spec.ServletInputStreamImpl.readIntoBuffer(ServletInputStreamImpl.java:178)
                at io.undertow.servlet.spec.ServletInputStreamImpl.close(ServletInputStreamImpl.java:206)
                at org.otaibe.enforcer.claim.can.not.read.body.web.controller.RestApiController.post(RestApiController.java:26)
                ... 144 more

Here is the Sample Project

You can create the quarkus realm from src/test/resources/keycloack/quarkus-realm.json file.

Then you can retrieve the token for user (alice/alice) as described here: https://quarkus.io/guides/security-keycloak-authorization

Then you have to put the token in org.otaibe.enforcer.claim.can.not.read.body.web.controller.RestControllerTest#TOKEN

If you execute the test org.otaibe.enforcer.claim.can.not.read.body.web.controller.RestControllerTest#testPostEndpoint

Then you will receive the Timeout Error
@tpenakov tpenakov added the kind/bug Something isn't working label May 4, 2020
@tpenakov tpenakov mentioned this issue May 4, 2020
Closed
@pedroigor
Copy link
Contributor

@tpenakov I've run your example. Thanks for sharing.

The root cause is that the changes we did to buffer the input stream are only available if you are using quarkus-vertx.

In your project, you are using quarkus-undertow.

I suggest you use quarkus-vertx as a rule. I think it is the recommended stack to run Quarkus applications. So, in order to make your project work, you need to:

  • Replace quarkus-undertow with quarkus-vertx
  • To your org.otaibe.enforcer.claim.can.not.read.body.web.controller.RestApiController#post, change the parameter to InputStream inputStream

If you do that, everything should be fine.

@tpenakov
Copy link
Author

tpenakov commented May 7, 2020

Hi @pedroigor ,
Thank you for the feedback.
I've did it after I wrote the bug. Initially I have been started with Reactive Routes, however during that time there was a #5809 problem, so I've switched to Undertow.
Now I am back to reactive routes. IMO - they are most suitable for REST API, because the Undertow have some unexpected side effects - for example it interpreted the PATCH method to GET and POST requests.

@tpenakov tpenakov closed this as completed May 7, 2020
@gsmet gsmet added kind/question Further information is requested and removed kind/bug Something isn't working labels May 18, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
area/keycloak-authorization area/oidc kind/question Further information is requested
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@sberyozkin @pedroigor @gsmet @tpenakov