quarkiverse / quarkus-renarde

Server-side Web Framework with Qute templating, magic/easier controllers, auth, reverse-routing
Apache License 2.0
78 stars 19 forks source link

jakarta.ws.rs.BadRequestException: Malformed quality value #121

Closed omidontop closed 1 year ago

omidontop commented 1 year ago

I just compiled the project from the main branch on c0894e5cff4dd31f4a0d0f92d7b680d8ad8b8ca7 and tried the same process as the one below:

mvn archetype:generate \
       -DarchetypeGroupId=io.quarkus \
       -DarchetypeArtifactId=quarkus-amazon-lambda-archetype \
       -DarchetypeVersion=3.0.2.Final

And simply added Renarde like this:

quarkus ext add io.quarkiverse.renarde:quarkus-renarde

Originally posted by @omidontop in https://github.com/quarkiverse/quarkus-renarde/issues/116#issuecomment-1539969134

This time I get:

e431dc3f-35: jakarta.ws.rs.BadRequestException: Malformed quality value.
        at org.jboss.resteasy.reactive.server.core.request.QualityValue.parseAsInteger(QualityValue.java:86)
        at org.jboss.resteasy.reactive.server.core.request.QualityValue.valueOf(QualityValue.java:33)
        at org.jboss.resteasy.reactive.server.core.request.AcceptHeaders.evaluateAcceptParameters(AcceptHeaders.java:250)
        at org.jboss.resteasy.reactive.server.core.request.AcceptHeaders.getMediaTypeQualityValues(AcceptHeaders.java:154)
        at org.jboss.resteasy.reactive.server.core.request.ServerDrivenNegotiation.setAcceptHeaders(ServerDrivenNegotiation.java:35)
        at io.quarkus.resteasy.reactive.server.runtime.NotFoundExceptionMapper.selectVariant(NotFoundExceptionMapper.java:259)
        at io.quarkus.resteasy.reactive.server.runtime.NotFoundExceptionMapper.respond(NotFoundExceptionMapper.java:102)
        at io.quarkus.resteasy.reactive.server.runtime.NotFoundExceptionMapper.toResponse(NotFoundExceptionMapper.java:92)
        at io.quarkus.resteasy.reactive.server.runtime.NotFoundExceptionMapper$GeneratedExceptionHandlerFor$Throwable$OfMethod$toResponse.toResponse(Unknown Source)
        at org.jboss.resteasy.reactive.server.core.RuntimeExceptionMapper.mapException(RuntimeExceptionMapper.java:97)
        at org.jboss.resteasy.reactive.server.core.ResteasyReactiveRequestContext.mapExceptionIfPresent(ResteasyReactiveRequestContext.java:337)
        at org.jboss.resteasy.reactive.server.handlers.ExceptionHandler.handle(ExceptionHandler.java:15)
        at io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:150)
        at org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:145)
        at org.jboss.resteasy.reactive.server.handlers.RestInitialHandler.beginProcessing(RestInitialHandler.java:48)
        at org.jboss.resteasy.reactive.server.vertx.ResteasyReactiveVertxHandler.handle(ResteasyReactiveVertxHandler.java:23)
        at org.jboss.resteasy.reactive.server.vertx.ResteasyReactiveVertxHandler.handle(ResteasyReactiveVertxHandler.java:10)
        at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
        at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:177)
        at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
        at io.quarkus.vertx.http.runtime.options.HttpServerCommonHandlers$1.handle(HttpServerCommonHandlers.java:58)
        at io.quarkus.vertx.http.runtime.options.HttpServerCommonHandlers$1.handle(HttpServerCommonHandlers.java:36)
        at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
        at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:177)
        at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
        at io.quarkiverse.renarde.util.AuthenticationFailedExceptionMapper.myFilter(AuthenticationFailedExceptionMapper.java:97)
        at io.quarkiverse.renarde.util.AuthenticationFailedExceptionMapper_RouteHandler_myFilter_dc247f9502a33787ac476eab0f2e905053c2515c.invoke(Unknown Source)
        at io.quarkus.vertx.web.runtime.RouteHandler.handle(RouteHandler.java:97)
        at io.quarkus.vertx.web.runtime.RouteHandler.handle(RouteHandler.java:22)
        at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
        at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:177)
        at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
        at io.quarkus.vertx.http.runtime.security.AbstractHttpAuthorizer.doPermissionCheck(AbstractHttpAuthorizer.java:110)
        at io.quarkus.vertx.http.runtime.security.AbstractHttpAuthorizer.checkPermission(AbstractHttpAuthorizer.java:93)
        at io.quarkus.vertx.http.runtime.security.HttpAuthorizer.checkPermission(HttpAuthorizer.java:15)
        at io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$2.handle(HttpSecurityRecorder.java:85)
        at io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$2.handle(HttpSecurityRecorder.java:77)
        at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
        at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:177)
        at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
        at io.quarkus.resteasy.reactive.server.runtime.ResteasyReactiveRecorder$13.handle(ResteasyReactiveRecorder.java:380)
        at io.quarkus.resteasy.reactive.server.runtime.ResteasyReactiveRecorder$13.handle(ResteasyReactiveRecorder.java:373)
        at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
        at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:177)
        at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
        at io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$AbstractAuthenticationHandler$3$1.onItem(HttpSecurityRecorder.java:438)
        at io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$AbstractAuthenticationHandler$3$1.onItem(HttpSecurityRecorder.java:428)
        at io.smallrye.mutiny.operators.uni.UniOnItemTransformToUni$UniOnItemTransformToUniProcessor.onItem(UniOnItemTransformToUni.java:60)
        at io.smallrye.mutiny.operators.uni.builders.DefaultUniEmitter.complete(DefaultUniEmitter.java:37)
        at io.smallrye.mutiny.groups.UniOnNull.lambda$failWith$1(UniOnNull.java:46)
        at io.smallrye.context.impl.wrappers.SlowContextualBiConsumer.accept(SlowContextualBiConsumer.java:21)
        at io.smallrye.mutiny.groups.UniOnItem.lambda$transformToUni$4(UniOnItem.java:177)
        at io.smallrye.context.impl.wrappers.SlowContextualConsumer.accept(SlowContextualConsumer.java:21)
        at io.smallrye.mutiny.operators.uni.builders.UniCreateWithEmitter.subscribe(UniCreateWithEmitter.java:22)
        at io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
        at io.smallrye.mutiny.operators.uni.UniOnItemTransformToUni$UniOnItemTransformToUniProcessor.performInnerSubscription(UniOnItemTransformToUni.java:81)
        at io.smallrye.mutiny.operators.uni.UniOnItemTransformToUni$UniOnItemTransformToUniProcessor.onItem(UniOnItemTransformToUni.java:57)
        at io.smallrye.mutiny.operators.uni.builders.UniCreateFromKnownItem$KnownItemSubscription.forward(UniCreateFromKnownItem.java:38)
        at io.smallrye.mutiny.operators.uni.builders.UniCreateFromKnownItem.subscribe(UniCreateFromKnownItem.java:23)
        at io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
        at io.smallrye.mutiny.operators.uni.UniOnItemTransformToUni.subscribe(UniOnItemTransformToUni.java:25)
        at io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
        at io.smallrye.mutiny.groups.UniSubscribe.withSubscriber(UniSubscribe.java:51)
        at io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$AbstractAuthenticationHandler$3.onItem(HttpSecurityRecorder.java:428)
        at io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$AbstractAuthenticationHandler$3.onItem(HttpSecurityRecorder.java:414)
        at io.smallrye.mutiny.operators.uni.UniMemoizeOp.drain(UniMemoizeOp.java:160)
        at io.smallrye.mutiny.operators.uni.UniMemoizeOp.onItem(UniMemoizeOp.java:180)
        at io.smallrye.mutiny.operators.uni.builders.UniCreateFromItemSupplier.subscribe(UniCreateFromItemSupplier.java:29)
        at io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
        at io.smallrye.mutiny.operators.uni.UniMemoizeOp.subscribe(UniMemoizeOp.java:84)
        at io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
        at io.smallrye.mutiny.groups.UniSubscribe.withSubscriber(UniSubscribe.java:51)
        at io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$AbstractAuthenticationHandler.handle(HttpSecurityRecorder.java:414)
        at io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$AbstractAuthenticationHandler.handle(HttpSecurityRecorder.java:368)
       vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
        at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:177)
        at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
        at io.quarkus.vertx.http.runtime.devmode.VertxHttpHotReplacementSetup.handleHotReplacementRequest(VertxHttpHotReplacementSetup.java:135)
        at io.quarkus.vertx.http.runtime.VertxHttpRecorder$5.handle(VertxHttpRecorder.java:437)
        at io.quarkus.vertx.http.runtime.VertxHttpRecorder$5.handle(VertxHttpRecorder.java:433)
        at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
        at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:177)
        at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
        at io.vertx.ext.web.impl.RouterImpl.handle(RouterImpl.java:68)
        at io.vertx.ext.web.impl.RouterImpl.handle(RouterImpl.java:37)
        at io.quarkus.vertx.http.runtime.options.HttpServerCommonHandlers$2.handle(HttpServerCommonHandlers.java:82)
        at io.quarkus.vertx.http.runtime.options.HttpServerCommonHandlers$2.handle(HttpServerCommonHandlers.java:65)
        at io.quarkus.vertx.http.runtime.VertxHttpRecorder$1.handle(VertxHttpRecorder.java:180)
        at io.quarkus.vertx.http.runtime.VertxHttpRecorder$1.handle(VertxHttpRecorder.java:156)
        at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:55)
        at io.vertx.core.impl.DuplicatedContext.emit(DuplicatedContext.java:158)
        at io.vertx.core.http.impl.Http1xServerConnection.handleMessage(Http1xServerConnection.java:167)
        at io.vertx.core.net.impl.ConnectionBase.read(ConnectionBase.java:158)
        at io.vertx.core.net.impl.VertxHandler.channelRead(VertxHandler.java:153)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
        at io.vertx.core.http.impl.Http1xUpgradeToH2CHandler.channelRead(Http1xUpgradeToH2CHandler.java:124)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
        at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
        at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:346)
        at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:318)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
        at io.vertx.core.http.impl.Http1xOrH2CHandler.end(Http1xOrH2CHandler.java:61)
        at io.vertx.core.http.impl.Http1xOrH2CHandler.channelRead(Http1xOrH2CHandler.java:38)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
        at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
        at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
        at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
        at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
        at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650)
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562)
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
        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:833)
FroMage commented 1 year ago

Could you show me the problematic header value?

omidontop commented 1 year ago

Could you show me the problematic header value?

.2 it seems...

Screenshot 2023-05-10 at 12 24 03

omidontop commented 1 year ago

resteasy/reactive/resteasy-reactive/3.0.2.Final/resteasy-reactive-3.0.2.Final.jar!/org/jboss/resteasy/reactive/server/core/request/ServerDrivenNegotiation.class

Screenshot 2023-05-10 at 12 29 06

FroMage commented 1 year ago

Can I get the entire header value please?

omidontop commented 1 year ago

Can I get the entire header value please?

Sure,  Screenshot 2023-05-10 at 12 42 01 

FroMage commented 1 year ago

So, the value appears to be Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2

FroMage commented 1 year ago

Note that according to the stack trace this appears to be happening in reaction to a 404. Lemme try to reproduce it.

FroMage commented 1 year ago

Well, I'm not sure exactly why I fail to reproduce it, but the code implies that .2 is an invalid value, and the specification agrees this is not valid: https://www.rfc-editor.org/rfc/rfc7231#section-5.3.1 it should be 0.2. Can I ask what HTTP client you're using?

I also see your 404 is related to /_renarde/security, so, perhaps that's a clue. It would help if you could provide a reproducer.

omidontop commented 1 year ago

I created a new VM and tried to start from scratch in order to create a project that would help you reproduce it. In doing so, I found the problem! It seems both Quarkus and the lambda extension try to listen to HTTP port 8080:

__  ____  __  _____   ___  __ ____  ______ 
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/ 
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \   
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/   
2023-05-11 11:35:05,681 INFO  [io.qua.ama.lam.run.AbstractLambdaPollLoop] (Lambda Thread (DEVELOPMENT)) Listening on: http://localhost:8080/_lambda_/2018-06-01/runtime/invocation/next
2023-05-11 11:35:05,685 INFO  [io.quarkus] (Quarkus Main Thread) mgmt-lambda 1.0-SNAPSHOT on JVM (powered by Quarkus 3.0.2.Final) started in 1.329s. Listening on: http://localhost:8080
2023-05-11 11:35:05,685 INFO  [io.quarkus] (Quarkus Main Thread) Profile dev activated. Live Coding activated.
2023-05-11 11:35:05,686 INFO  [io.quarkus] (Quarkus Main Thread) Installed features: [amazon-lambda, cdi, hibernate-validator, narayana-jta, qute, reactive-routes, renarde, resteasy-reactive, resteasy-reactive-qute, security, smallrye-context-propagation, smallrye-jwt, vertx]

This is the reason for the clash. I have no idea why it doesn't fail when two processes try to listen to the same port on MacOS while on the Linux VM I created, it simply fails with an error.

One can either use a different port for Quarkus:

quarkus.http.port=8081

Or use a different one for Lambda:

quarkus.lambda.mock-event-server.dev-port=8082
quarkus.lambda.mock-event-server.test-port=8083

Now doing that and navigating to Quarkus's HTTP server, I get:

Screenshot 2023-05-11 at 11 40 13

But I have no idea who is asking for /_renarde/security and why it's missing. So I guess if you want to reproduce it, you've got to use the same ports for both Lambda and Quarkus and run quarkus dev.

FroMage commented 1 year ago

Ah well. This is too weird, let's not try to reproduce this. But I'll file an issue on Quarkus to detect the conflict in ports: https://github.com/quarkusio/quarkus/issues/33312

Meanwhile I'll close this issue.

Thanks for reporting and your help figuring it out :)

omidontop commented 1 year ago

Ah well. This is too weird, let's not try to reproduce this. But I'll file an issue on Quarkus to detect the conflict in ports: quarkusio/quarkus#33312

Meanwhile I'll close this issue.

Thanks for reporting and your help figuring it out :)

I agree, thanks a lot for your help!